vicidial.org

by **bmxmike** » Fri Sep 29, 2017 2:19 pm

VERSION: 2.14-631a
BUILD: 170926-1618
Server: Dedicated
Install: ViciBox v7.0.4
2 x Intel Xenon X5670, 64 GB Ram
DB: 2.14.sql

System:
Is a dedicated server updated to the latest SVN. Did a clean install and then a restore of a backup to the server.

Issue:
On-Hook agents not receiving INBOUND queue calls, real time shows status of ringing but no phone ever rings.

- Agents who are set to "On-Hook = n", works but seems to be a very long delay in adding the caller
- Agents who are set to "On-Hook = y", extensions never ring and no screen pop(alerts). Real time report shows status of "Ring" and is following the ring strategy
- Agents who are set to "On-Hook = y", If the agent clicks "Ring" at the top of the panel and then selects "Take Call" they can answer the call. If the queue rolls back over to that agent who hit "Ring" it
does not connect the caller to the call but still status of ring

So installed a clean copy of Vicibox v7.0.4 on a dedicated server with no issue and performed a SVN update. I then restored the backup and everything seemed fine until we began to do some testing before this server goes live. Agents who are set to "On-Hook = N" have no issues being queued and receiving calls and works as it should minus what seems to be a longer delay than usual. Agents who are set to "On-Hook = Y" seem to have an issue as the queue seems to want to send them a call, seeing a status of "Ring", but the phones never ring. Also if the on-hook agent selects "Ring", then unpauses, the call still isn't connected even though they are running essentially as a "Off-Hook". They can however select "Ring" and then "Take Call" and this works, but if the agent doesn't "RING" and just selects "Take Call" it just sends the customer into a conference by themselves; the agent does get a screen pop and everything shows the call is connected but the agents phone never rings.

I'm assuming that it has something to do with the "On-Hook", reason I assume this is that "Off-Hook" agents work although with what seems to be a longer delay than usual. I have gone through and archived all of my astgui logs to try and see if I can find something there.

Any help, advice, or a point in the right direction would be great! I'm assuming that astgui logs are where I should start if I'm incorrect please let me know!

Thanks in advance for any insight you may have

by **mflorell** » Fri Sep 29, 2017 7:33 pm

What does the Asterisk CLI output look like when this happens?

by **bmxmike** » Tue Oct 03, 2017 12:58 pm

So first ran "sip show peers" to make sure the phone was connected, 2236.

Code: Select all: agentphone1*CLI> sip show peers Name/username Host Dyn Forcerport Comedia ACL Port Status Description 2230/2230 (Unspecified) D Yes Yes 0 UNKNOWN 2232/2232 (Unspecified) D Yes Yes 0 UNKNOWN 2233/2233 ############ D Yes Yes 5060 OK (66 ms) 2236/2236 ############ D Yes Yes 12836 OK (55 ms) 2237/2237 (Unspecified) D Yes Yes 0 UNKNOWN 2271/2271 (Unspecified) D Yes Yes 0 UNKNOWN 2272/2272 ############ D Yes Yes 25820 OK (66 ms) 2301/2301 (Unspecified) D Yes Yes 0 UNKNOWN 2303/2303 (Unspecified) D Yes Yes 0 UNKNOWN 2306/2306 (Unspecified) D Yes Yes 0 UNKNOWN 2308/2308 (Unspecified) D Yes Yes 0 UNKNOWN 2309/2309 (Unspecified) D Yes Yes 0 UNKNOWN 2310/2310 ############ D Yes Yes 1069 OK (57 ms) gs102/gs102 (Unspecified) D Yes Yes 0 UNKNOWN vi-dial1 64.136.174.35 Yes Yes 5060 OK (45 ms) vi-dial2 64.136.173.32 Yes Yes 5060 UNREACHABLE vi-dial3 209.166.128.200 Yes Yes 5060 OK (59 ms) vi-dial4 192.240.151.100 Yes Yes 5060 OK (88 ms) vi-in1 64.136.173.31 Yes Yes 5060 OK (46 ms) vi-in2 64.136.174.30 Yes Yes 5060 OK (54 ms) vi-in3 64.136.174.20 Yes Yes 5060 UNREACHABLE vi-in4 209.166.154.70 Yes Yes 5060 OK (63 ms) vi-in5 192.240.151.100 Yes Yes 5060 OK (88 ms) vi-out1 64.136.174.30 Yes Yes 5060 OK (53 ms) vi-out2 64.136.173.22 Yes Yes 5060 OK (37 ms) vi-out3 209.166.128.200 Yes Yes 5060 OK (59 ms) vi-out4 192.240.151.100 Yes Yes 5060 OK (89 ms) 27 sip peers [Monitored: 15 online, 12 offline Unmonitored: 0 online, 0 offline]

Here is me logging in the agent:

Code: Select all: [Oct 3 12:52:27] -- Executing [8300@default:1] Hangup("Local/8300@default-0000000a;2", "") in new stack [Oct 3 12:52:27] == Spawn extension (default, 8300, 1) exited non-zero on 'Local/8300@default-0000000a;2' [Oct 3 12:52:27] -- Executing [h@default:1] AGI("Local/8300@default-0000000a;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack [Oct 3 12:52:27] -- <Local/8300@default-0000000a;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0

This is the incoming call:

Code: Select all: [Oct 3 12:54:08] == Using SIP RTP CoS mark 5 [Oct 3 12:54:08] -- Executing [405XXXXXXX@trunkinbound:1] AGI("SIP/vi-in1-00000007", "agi-DID_route.agi") in new stack [Oct 3 12:54:08] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-DID_route.agi [Oct 3 12:54:08] -- AGI Script Executing Application: (Monitor) Options: (wav,/var/spool/asterisk/monitor/MIX/20171003125408_405XXXXXXX_1405698XXXX) [Oct 3 12:54:08] -- <SIP/vi-in1-00000007>AGI Script agi-DID_route.agi completed, returning 0 [Oct 3 12:54:08] -- Executing [s@CastleAlert_Intro:1] Answer("SIP/vi-in1-00000007", "") in new stack [Oct 3 12:54:09] -- Executing [s@CastleAlert_Intro:2] AGI("SIP/vi-in1-00000007", "agi-VDAD_inbound_calltime_check.agi,CALLMENU-----YES-----CastleAlert_Intro-------------------------NO") in new stack [Oct 3 12:54:09] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_inbound_calltime_check.agi [Oct 3 12:54:09] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:09] > 0x7f540c0216b0 -- Probation passed - setting RTP source address to 4.55.9.194:11708 [Oct 3 12:54:09] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:09] -- <SIP/vi-in1-00000007>AGI Script agi-VDAD_inbound_calltime_check.agi completed, returning 0 [Oct 3 12:54:09] -- Executing [s@CastleAlert_Intro:3] Set("SIP/vi-in1-00000007", "INVCOUNT=0") in new stack [Oct 3 12:54:09] -- Executing [s@CastleAlert_Intro:4] BackGround("SIP/vi-in1-00000007", "CastleAlert_Intro_IVR") in new stack [Oct 3 12:54:09] -- <SIP/vi-in1-00000007> Playing 'CastleAlert_Intro_IVR.slin' (language 'en') [Oct 3 12:54:15] DTMF[14589][C-00000017]: channel.c:4215 __ast_read: DTMF begin '1' received on SIP/vi-in1-00000007 [Oct 3 12:54:15] DTMF[14589][C-00000017]: channel.c:4219 __ast_read: DTMF begin ignored '1' on SIP/vi-in1-00000007 [Oct 3 12:54:15] DTMF[14589][C-00000017]: channel.c:4129 __ast_read: DTMF end '1' received on SIP/vi-in1-00000007, duration 400 ms [Oct 3 12:54:15] DTMF[14589][C-00000017]: channel.c:4199 __ast_read: DTMF end passthrough '1' on SIP/vi-in1-00000007 [Oct 3 12:54:15] -- Executing [1@CastleAlert_Intro:1] AGI("SIP/vi-in1-00000007", "cm.agi,CALLMENU-----1-----comments-----0-----0") in new stack [Oct 3 12:54:15] -- Launched AGI Script /usr/share/asterisk/agi-bin/cm.agi [Oct 3 12:54:15] -- <SIP/vi-in1-00000007>AGI Script cm.agi completed, returning 0 [Oct 3 12:54:15] -- Executing [1@CastleAlert_Intro:2] AGI("SIP/vi-in1-00000007", "agi-VDAD_ALL_inbound.agi,CID-----LB-----CastleAlert_IN-----CastleAlert_Intro--------------------100-----1-----Inbound------------------------------") in new stack [Oct 3 12:54:15] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi [Oct 3 12:54:16] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:16] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:16] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 12:54:17] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 12:54:18] -- Started music on hold, class 'default', on SIP/vi-in1-00000007 [Oct 3 12:54:21] -- Stopped music on hold on SIP/vi-in1-00000007 [Oct 3 12:54:21] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:21] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:21] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:21] -- <SIP/vi-in1-00000007> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:54:27] -- Started music on hold, class 'default', on SIP/vi-in1-00000007

This time it actually did something different, It played the hold message again and then just hungup:

Code: Select all: [Oct 3 12:55:27] -- Stopped music on hold on SIP/vi-in1-00000007 [Oct 3 12:55:27] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:55:27] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:55:27] -- <SIP/vi-in1-00000007> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:55:27] -- <SIP/vi-in1-00000007> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 12:55:28] -- <SIP/vi-in1-00000007>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 4 [Oct 3 12:55:28] == Spawn extension (CastleAlert_Intro, 1, 2) exited non-zero on 'SIP/vi-in1-00000007' [Oct 3 12:55:28] -- Executing [h@CastleAlert_Intro:1] AGI("SIP/vi-in1-00000007", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Oct 3 12:55:28] -- <SIP/vi-in1-00000007>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0

I should add that their are alot of "sendcron" jobs which I'm assuming are just reporting tasks:

Code: Select all: [Oct 3 13:01:32] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi [Oct 3 13:01:32] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:32] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:32] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:01:33] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:01:34] -- Started music on hold, class 'default', on SIP/vi-in1-00000009 [Oct 3 13:01:37] -- Stopped music on hold on SIP/vi-in1-00000009 [Oct 3 13:01:37] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:37] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:37] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:37] -- <SIP/vi-in1-00000009> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:01:43] -- Started music on hold, class 'default', on SIP/vi-in1-00000009 [Oct 3 13:02:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:02:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:02:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:02:03] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:02:07] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:02:07] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:02:07] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:02:08] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:02:38] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:02:39] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:02:44] -- Stopped music on hold on SIP/vi-in1-00000009 [Oct 3 13:02:44] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:02:44] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:02:44] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:02:44] -- <SIP/vi-in1-00000009> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:02:50] -- Started music on hold, class 'default', on SIP/vi-in1-00000009 [Oct 3 13:03:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:03:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:03:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:03:03] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:03:07] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:03:07] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:03:14] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:03:15] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:03:44] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:03:45] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:03:50] -- Stopped music on hold on SIP/vi-in1-00000009 [Oct 3 13:03:50] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:03:50] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:03:50] -- <SIP/vi-in1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:03:50] -- <SIP/vi-in1-00000009> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 3 13:03:56] -- Started music on hold, class 'default', on SIP/vi-in1-00000009 [Oct 3 13:04:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:04:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:04:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:04:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:04:06] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:04:06] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 3 13:04:20] == Manager 'sendcron' logged on from 127.0.0.1

Here is the output if I try and "Take Call" from the queue, while being on hook. Plays to the customer "Only Person In This Conference".

Code: Select all: [Oct 3 13:23:16] -- <SIP/vi-in4-0000000a>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0 [Oct 3 13:23:16] -- Executing [038*130*206*209*8600051@default:1] Goto("SIP/vi-in4-0000000a", "default,8600051,1") in new stack [Oct 3 13:23:16] -- Goto (default,8600051,1) [Oct 3 13:23:16] -- Executing [8600051@default:1] MeetMe("SIP/vi-in4-0000000a", "8600051,F") in new stack [Oct 3 13:23:16] == Parsing '/etc/asterisk/meetme.conf': Found [Oct 3 13:23:16] == Parsing '/etc/asterisk/meetme-vicidial.conf': Found [Oct 3 13:23:16] -- Created MeetMe conference 1023 for conference '8600051' [Oct 3 13:23:16] -- <SIP/vi-in4-0000000a> Playing 'conf-onlyperson.gsm' (language 'en') [Oct 3 13:23:24] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 3 13:23:24] -- Executing [58600051@default:1] MeetMe("Local/58600051@default-0000000e;2", "8600051,Fmq") in new stack [Oct 3 13:23:24] > Channel Local/58600051@default-0000000e;1 was answered [Oct 3 13:23:24] -- Executing [8309@default:1] Answer("Local/58600051@default-0000000e;1", "") in new stack [Oct 3 13:23:24] -- Executing [8309@default:2] Monitor("Local/58600051@default-0000000e;1", "wav,4056987832_2236_20171003-132316") in new stack [Oct 3 13:23:24] -- Executing [8309@default:3] Wait("Local/58600051@default-0000000e;1", "3600") in new stack

by **mflorell** » Tue Oct 03, 2017 8:41 pm

Could you post the agiout logfile output for these calls?

by **bmxmike** » Wed Oct 04, 2017 9:58 am

Here is the log from yesterday, one thing I already notice is "No available balance agent found". This is a trimmed version due to the character limit as the original is over 600,000 lines for just the few calls made yesterday :

Code: Select all: 2017-10-03 12:54:08|agi-DID_route.agi||INSERT INTO vicidial_did_log SET uniqueid='1507053248.33',channel='SIP/vi-in1-00000007',server_ip='11.111.111.111',caller_id_number='4055555556',caller_id_name='',extension='4055555555',call_date='2017-10-03 12:54:08',did_id='166',did_route='CALLMENU';| 2017-10-03 12:54:08|agi-DID_route.agi|-- DID LOG : |1|INSERT INTO vicidial_did_log SET uniqueid='1507053248.33',channel='SIP/vi-in1-00000007',server_ip='11.111.111.111',caller_id_number='4055555556',caller_id_name='',extension='4055555555',call_date='2017-10-03 12:54:08',did_id='166',did_route='CALLMENU';| 2017-10-03 12:54:08|agi-DID_route.agi|-- CALL LOG : |1|INSERT INTO call_log SET uniqueid='1507053248.33', channel='SIP/vi-in1-00000007', channel_group='DID_INBOUND', server_ip='11.111.111.111', type='SIP', extension='4055555555', number_dialed='4055555555', caller_code='4055555556', start_time='2017-10-03 12:54:08', start_epoch='1507053248';| 2017-10-03 12:54:08|agi-DID_route.agi|-- DID AGENT LOG : |1|INSERT INTO vicidial_did_agent_log SET uniqueid='1507053248.33',server_ip='11.111.111.111',caller_id_number='4055555556',caller_id_name='',extension='4055555555',call_date='2017-10-03 12:54:08',did_id='166',did_route='CALLMENU',user='VDCL',group_id='',did_description='Nicole';| 2017-10-03 12:54:08|agi-DID_route.agi|exiting the DID app, transferring call to CALLMENU CastleAlert_Intro 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|Perl Environment Dump: 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|0|CALLMENU-----YES-----CastleAlert_Intro-------------------------NO 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- accountcode = 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- arg_1 = CALLMENU-----YES-----CastleAlert_Intro-------------------------NO 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- callerid = 4055555556 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- calleridname = unknown 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- callingani2 = 0 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- callingpres = 0 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- callingtns = 0 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- callington = 0 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- channel = SIP/vi-in1-00000007 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- context = CastleAlert_Intro 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- dnid = 4055555555 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- enhanced = 0.0 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- extension = s 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- language = en 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- priority = 2 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- rdnis = unknown 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- request = agi-VDAD_inbound_calltime_check.agi 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- threadid = 140002811016960 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- type = SIP 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- uniqueid = 1507053248.33 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi| -- version = 11.25.1-vici 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|AGI Variables: |1507053248.33|SIP/vi-in1-00000007|s|SIP|4055555556| 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|+++++ INBOUND CALL VDCL STARTED : |CALLMENU|4055555556-|2017-10-03 12:54:09 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|-- VDAC vac record deleted: |0E0| 1507053248.33|4055555556| 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,lead_id,status,uniqueid,callerid,channel,phone_code,phone_number,call_time,call_type,stage,queue_priority,last_update_time) values('11.111.111.111','CALLMENU','0','IVR','1507053248.33','4055555556','SIP/vi-in1-00000007','','4055555556','2017-10-03 12:54:09','IN','IVR-0','','20171003130409')| 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|-- VAC insert: |1|1507053248.33|4055555556|s| 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi||INSERT INTO live_inbound_log (uniqueid,channel,server_ip,caller_id,extension,phone_ext,start_time,comment_a,comment_b,comment_d,comment_e) values('1507053248.33','SIP/vi-in1-00000007','11.111.111.111','4055555556','s','4055555556','2017-10-03 12:54:09','CALLMENU','CastleAlert_Intro','CastleAlert_Intro','2')| 2017-10-03 12:54:09|agi-VDAD_inbound_calltime_check.agi|-- LIL insert: |1|1507053248.33|4055555556|s| 2017-10-03 12:54:15|cm.agi|Perl Environment Dump: 2017-10-03 12:54:15|cm.agi|0|CALLMENU-----1-----comments-----0-----0 2017-10-03 12:54:15|cm.agi| -- accountcode = 2017-10-03 12:54:15|cm.agi| -- arg_1 = CALLMENU-----1-----comments-----0-----0 2017-10-03 12:54:15|cm.agi| -- callerid = 4055555556 2017-10-03 12:54:15|cm.agi| -- calleridname = unknown 2017-10-03 12:54:15|cm.agi| -- callingani2 = 0 2017-10-03 12:54:15|cm.agi| -- callingpres = 0 2017-10-03 12:54:15|cm.agi| -- callingtns = 0 2017-10-03 12:54:15|cm.agi| -- callington = 0 2017-10-03 12:54:15|cm.agi| -- channel = SIP/vi-in1-00000007 2017-10-03 12:54:15|cm.agi| -- context = CastleAlert_Intro 2017-10-03 12:54:15|cm.agi| -- dnid = 4055555555 2017-10-03 12:54:15|cm.agi| -- enhanced = 0.0 2017-10-03 12:54:15|cm.agi| -- extension = 1 2017-10-03 12:54:15|cm.agi| -- language = en 2017-10-03 12:54:15|cm.agi| -- priority = 1 2017-10-03 12:54:15|cm.agi| -- rdnis = unknown 2017-10-03 12:54:15|cm.agi| -- request = cm.agi 2017-10-03 12:54:15|cm.agi| -- threadid = 140002811016960 2017-10-03 12:54:15|cm.agi| -- type = SIP 2017-10-03 12:54:15|cm.agi| -- uniqueid = 1507053248.33 2017-10-03 12:54:15|cm.agi| -- version = 11.25.1-vici 2017-10-03 12:54:15|cm.agi|AGI Variables: |1507053248.33|SIP/vi-in1-00000007|1|SIP|4055555556| 2017-10-03 12:54:15|cm.agi|+++++ DTMF LOG STARTED : |CALLMENU|4055555556-|2017-10-03 12:54:15 2017-10-03 12:54:15|cm.agi||INSERT INTO live_inbound_log (uniqueid,channel,server_ip,caller_id,extension,phone_ext,start_time,comment_a,comment_b,comment_d,comment_e) values('1507053248.33','SIP/vi-in1-00000007','11.111.111.111','4055555556','1','4055555556','2017-10-03 12:54:15','CALLMENU','1','CastleAlert_Intro>1','1');| 2017-10-03 12:54:15|cm.agi|-- LIL insert: |1|1507053248.33|4055555556|1| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|Perl Environment Dump: 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|CID-----LB-----CastleAlert_IN-----CastleAlert_Intro--------------------100-----1-----Inbound------------------------------ 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|North America CID Check: 1|4055555556| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- accountcode = 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- arg_1 = CID-----LB-----CastleAlert_IN-----CastleAlert_Intro--------------------100-----1-----Inbound------------------------------ 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- callerid = 4055555556 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- callingpres = 0 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- callingtns = 0 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- callington = 0 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- channel = SIP/vi-in1-00000007 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- context = CastleAlert_Intro 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- dnid = 4055555555 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- extension = 1 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- language = en 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- priority = 2 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- threadid = 140002811016960 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- type = SIP 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1507053248.33 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi| -- version = 11.25.1-vici 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|AGI Variables: |1507053248.33|SIP/vi-in1-00000007|1|SIP|4055555556| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |CastleAlert_IN|4055555556-CastleAlert_Intro|2017-10-03 12:54:16 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|DAILY STATS UPDATE CastleAlert_IN|1|UPDATE vicidial_daily_max_stats SET update_time=NOW(),max_inbound='1' where campaign_id='CastleAlert_IN' and stats_type='INGROUP' and stats_flag='OPEN';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_allow_inbound='Y';|117| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|callerID changed: "Y0031254160000000117 <4055555556>" 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|1|SELECT auto_call_id from vicidial_auto_calls where uniqueid='1507053248.33' and server_ip='11.111.111.111';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|1|UPDATE vicidial_auto_calls SET campaign_id='CastleAlert_IN',status='LIVE',lead_id='117',callerid='Y0031254160000000117',channel='SIP/vi-in1-00000007',phone_code='1',phone_number='4055555556',call_time='2017-10-03 12:54:16',call_type='IN',stage='LIVE-0',queue_priority='89' WHERE auto_call_id='6';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|1|SELECT count(*) from vicidial_auto_calls where status = 'LIVE' and campaign_id='CastleAlert_IN';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|1|UPDATE vicidial_auto_calls SET queue_position='1' WHERE auto_call_id='6';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log SET lead_id='117', campaign_id='CastleAlert_IN', call_date='2017-10-03 12:54:16', start_epoch='1507053256', status='QUEUE', phone_code='1', phone_number='4055555556', user='VDCL', processed='N', xfercallid='0', uniqueid='1507053248.33', queue_position='1',called_count='1',list_id='100' ;| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- VDCL : |117|0|80|insert to vicidial_closer_log 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- ENTER QUEUE VLE insert: |1| |INSERT INTO vicidial_log_extended set uniqueid='1507053248.33',server_ip='11.111.111.111',call_date='2017-10-03 12:54:16',lead_id = '117',caller_code='Y0031254160000000117',custom_call_id='';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|DID IVR time logged: 2017-10-03 12:54:16|1507053256|1|UPDATE call_log set end_time='2017-10-03 12:54:16',end_epoch='1507053256',length_in_sec=8,length_in_min=' 0.13',extension='Y0031254160000000117' where uniqueid='1507053248.33'| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|RING-AGENT CALL SENT: |CastleAler4055555556|138331*6*Y0031254160000000117*2236*2236|0|30|CUSTOMER_PHONE_INGROUP|18882488362| SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|0|50|60|0|0||0|update of vla table: CastleAlert_IN| |INSERT INTO vicidial_manager values('','','2017-10-03 12:54:16','NEW','N','11.111.111.111','','Originate','CastleAler4055555556','Exten: 138331*6*Y0031254160000000117*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: "CastleAler4055555556" <18882488362>','Timeout: 29000','','','','')| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 29.75|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|0.25|51|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 29.5|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|0.5|52|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 29.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|0.75|53|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:16|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 29|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|1|54|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 28.75|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|1.25|55|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 28.5|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|1.5|56|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 28.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|1.75|57|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:17|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:18|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:18|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:18|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 27.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:18|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|2|58|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:18|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:19|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:19|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:19|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 26.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:19|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|3|59|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:19|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:20|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:20|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:20|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 25.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:20|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|4|60|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:20|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 24.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|5|61|60|0|0||0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:21|agi-VDAD_ALL_inbound.agi|-- VDAC posttime record: |1|20171003125430|Y0031254160000000117|,call_time='2017-10-03 12:54:21'| 2017-10-03 12:54:16|12:54:26|agi-VDAD_ALL_inbound.agi|-- No-Block Prompt Set: |1|2017-10-03 12:54:16|Y0031254160000000117| 2017-10-03 12:54:16|12:54:27|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:27|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:27|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 23.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:27|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|11|0|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:27|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:28|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:28|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:28|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 22.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:28|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|12|1|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:28|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:29|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:29|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:29|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 21.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:29|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|13|2|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:29|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:30|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:30|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:30|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 20.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:30|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|14|3|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:30|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:31|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:31|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:31|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 19.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:31|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|15|4|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:31|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:32|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:32|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:32|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 18.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:32|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|16|5|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:32|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:33|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:33|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:33|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 17.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:33|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|17|6|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:33|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:34|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:34|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:34|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 16.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:34|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|18|7|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:34|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:35|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:35|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:35|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 15.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:35|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|19|8|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:35|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:36|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:36|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:36|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 14.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:36|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|20|9|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:36|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:37|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:37|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:37|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 13.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:37|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|21|10|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:37|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 12.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|22|11|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 11.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|22|12|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:38|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:39|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:39|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:39|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 10.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:39|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|23|13|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:39|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:40|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:40|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:40|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 9.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:40|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|24|14|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:40|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:41|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:41|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:41|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 8.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:41|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|25|15|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:41|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:42|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:42|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:42|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 7.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:42|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|26|16|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:42|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:43|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:43|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:43|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 6.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:43|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|27|17|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:43|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:44|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:44|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:44|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 5.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:44|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|28|18|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:44|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:45|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:45|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:45|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 4.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:45|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|29|19|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:45|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:46|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:46|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:46|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 3.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:46|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|30|20|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:46|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:47|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:47|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:47|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 2.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:47|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|31|21|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:47|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:48|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:48|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:48|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 1.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:48|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|32|22|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:48|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:49|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:49|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:49|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 0.25|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:49|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|33|23|60|0|0|0|0|update of vla table: CastleAlert_IN| |UPDATE vicidial_live_agents SET ring_callerid='' where ring_callerid='Y0031254160000000117';| 2017-10-03 12:54:16|12:54:49|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:50|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:50|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:50|agi-VDAD_ALL_inbound.agi|RING-AGENT CALL SENT: |CastleAler4055555556|138331*6*Y0031254160000000117*2236*2236|0|30|CUSTOMER_PHONE_INGROUP|18882488362| SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:50|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|34|24|60|0|0|0|0|update of vla table: CastleAlert_IN| |INSERT INTO vicidial_manager values('','','2017-10-03 12:54:16','NEW','N','11.111.111.111','','Originate','CastleAler4055555556','Exten: 138331*6*Y0031254160000000117*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: "CastleAler4055555556" <18882488362>','Timeout: 29000','','','','')| 2017-10-03 12:54:16|12:54:50|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:51|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:51|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:51|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 29|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:51|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|35|25|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:51|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:52|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:52|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:52|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 28|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:52|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|36|26|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:52|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:53|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:53|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:53|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 27|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:53|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|37|27|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:53|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-03 12:54:16|12:54:54|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'CastleAlert_IN' and call_time < "2017-10-03 12:54:16" and lead_id != '117' and queue_priority >= '89' and agent_only='';| 2017-10-03 12:54:16|12:54:54|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:54|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 26|30|30 SIP/vi-in1-00000007|Y0031254160000000117 2017-10-03 12:54:16|12:54:54|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |900|38|28|60|0|0|0|0|update of vla table: CastleAlert_IN| |SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '117' and agent_only='' and ( (queue_priority > '89') or (queue_priority = '89' and call_time < "2017-10-03 12:54:16") );| 2017-10-03 12:54:16|12:54:54|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found

Edit:
Just want to add, I haven't tested inbound calling since I first got it working and not since I imported the database which I'm thinking is where my problem is at. I just tried to call through directly to the extension and it went straight to voicemail.

Edit 2:
So after deleting the phone entry and recreating it the extension began working, could directly dial to it and ring instead of going straight to voicemail. The call still doesn't ring the agent but leads me to believe that the DB is corrupt or something. Tried running "mysqlcheck -u root -p --auto-repair --check --optimize --all-databases" which seems to have run fine, but issue still present.

by **mflorell** » Wed Oct 04, 2017 3:48 pm

This is the command that triggers the call to the agent:

INSERT INTO vicidial_manager values('','','2017-10-03 12:54:16','NEW','N','11.111.111.111','','Originate','CastleAler4055555556','Exten: 138331*6*Y0031254160000000117*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: "CastleAler4055555556" <18882488362>','Timeout: 29000','','','','')

So, take a look in your "listen" logfile in /var/log/astguiclient to see if that command is executed or not.

by **bmxmike** » Thu Oct 05, 2017 5:07 pm

I looked through listen and never saw anything pop up other than some sip messages,

I went ahead and just reinstalled Vicibox and rebuilding instead of doing an import, just probably be faster that way at the moment as we only have 4 agents that will be using and I remember the configuration. Although now I have a new issue with sendercron that I will create a new post for.

Thanks so much for trying to help! I really appreciate it and wish I could have narrowed it down if for nothing else get a better understanding of the techinical parts of vicidial

mflorell you are the best

by **bmxmike** » Tue Oct 10, 2017 12:53 pm

Okay so still having this issue even after a clean install with no DB restore,

One thing I notice is that if I call the "EXTEN" the call goes through fine, if I call the "AGENT" who is using that phone the call DOES NOT go through.

I also noticed:

-Play welcome message = never
-On Hold Prompt No Block = y
-No Delay Call Route = n

That even if the agent does sign in with "On-Hook = n" that the calls do not come through at all but removing all the previous settings the call goes through correctly only if set to not on hook.

Here is from the listen log file, I clicked on the take call since it wasn't routing and the other messages are all SIP-RESPONSE :

Code: Select all: 2017-10-10 12:45:04|Event: Newchannel Privilege: call,all Channel: SIP/vi-out1-00000011 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 18888070544 CallerIDName: AccountCode: Exten: 4057572232 Context: trunkinbound Uniqueid: 1507657517.38 Event: ChannelUpdate Privilege: system,all Channel: SIP/vi-out1-00000011 Uniqueid: 1507657517.38 Channeltype: SIP SIPcallid: 394227482-0-629731362@64.136.174.224 SIPfullcontact: Event: Newstate Privilege: call,all Channel: SIP/vi-out1-00000011 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 18888070544 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1507657517.38 | 2017-10-10 12:45:45|Event: Newchannel Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 038*130*206*209*78600051 Context: default Uniqueid: 1507657583.39 Event: Newchannel Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 038*130*206*209*78600051 Context: default Uniqueid: 1507657583.40 Event: NewAccountCode Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 Uniqueid: 1507657583.39 AccountCode: OldAccountCode: Event: NewCallerid Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 CallerIDNum: ding CallerIDName: ding Uniqueid: 1507657583.39 CID-CallingPres: 0 (Presentation Allowed, Not Screened) Event: LocalBridge Privilege: call,all Channel1: Local/038*130*206*209*78600051@default-00000008;1 Channel2: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid1: 1507657583.39 Uniqueid2: 1507657583.40 Context: default Exten: 038*130*206*209*78600051 LocalOptimization: Yes Event: Newstate Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Uniqueid: 1507657583.40 Event: Newstate Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Uniqueid: 1507657583.39 Event: Newchannel Privilege: call,all Channel: DAHDI/pseudo-1652530586 ChannelState: 1 ChannelStateDesc: Rsrvd CallerIDNum: CallerIDName: AccountCode: Exten: Context: default Uniqueid: 1507657583.41 Event: DAHDIChannel Privilege: call,all Channel: DAHDI/pseudo-1652530586 Uniqueid: 1507657583.41 DAHDISpan: 0 DAHDIChannel: pseudo Event: MeetmeJoin Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid: 1507657583.40 Meetme: 8600051 Usernum: 1 CallerIDnum: ding CallerIDname: ding 2017-10-10 12:45:45|Event: SoftHangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 Uniqueid: 1507657583.39 Cause: 16 | 2017-10-10 12:45:45|Event: HangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid: 1507657583.40 Event: Hangup Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;1 Uniqueid: 1507657583.39 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding AccountCode: Cause: 16 Cause-txt: Normal Clearing Event: MeetmeLeave Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid: 1507657583.40 Meetme: 8600051 Usernum: 1 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Duration: 1 Event: MeetmeEnd Privilege: call,all Meetme: 8600051 Event: Hangup Privilege: call,all Channel: DAHDI/pseudo-1652530586 Uniqueid: 1507657583.41 CallerIDNum: <unknown> CallerIDName: <unknown> ConnectedLineNum: <unknown> ConnectedLineName: <unknown> AccountCode: Event: SoftHangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid: 1507657583.40 Cause: 16 Event: Hangup Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000008;2 Uniqueid: 1507657583.40 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding AccountCode: Cause: 0 Cause-txt: Unknown

by **mflorell** » Tue Oct 10, 2017 1:59 pm

What do the asterisk CLI and agiout logfiles show for this call?

by **bmxmike** » Tue Oct 10, 2017 5:22 pm

Everything is almost identical to above, I'm doing another clean install. I've already wiped the drives using dd to make sure everything is wiped.

This worked perfect not but a week or so ago before my first post. After the intern basically broke the system we decided to just install a new system; 1)I had learned more from the previous install ; 2)We only have 2 agents that will be using the system for awhile so after creating everything the first time it goes pretty quick with just 2 people when you know where and what needs to be set.

So here's my process and I will post logs tommorrow if it's still not working or possibly later tonight:

-Wipe drives using dd
-run os-install and follow prompts
-Create 10gb Swap (sda1)/ rest of SSD for system 220+gb (sda2) / 1.8tb SATA-RAID symlink /var (since logs and recordings are gonna be my biggest size problem, and i've done this on each install)
-yast lan then update
-install system

I did no svn or anything else this time and will not be doing a db restore. I'm trying to keep this one as close to bare bones as possible, I ran 1 quick test call in after setting up 1 carrier, the campaign, 1 did and inbound group and still doing same thing but might have missed something.

by **bmxmike** » Wed Oct 11, 2017 10:59 am

Here is a call log for an off-hook agent, with call routing successfully:

Code: Select all: [Oct 11 10:08:31] Connected to Asterisk 11.25.1-vici currently running on agentphone (pid = 1803) [Oct 11 10:08:34] == Using SIP RTP CoS mark 5 [Oct 11 10:08:34] -- Executing [4057572232@trunkinbound:1] AGI("SIP/vi-out1-00000009", "agi-DID_route.agi") in new stack [Oct 11 10:08:34] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-DID_route.agi [Oct 11 10:08:34] -- <SIP/vi-out1-00000009>AGI Script agi-DID_route.agi completed, returning 0 [Oct 11 10:08:34] -- Executing [99909*2***DID@default:1] Answer("SIP/vi-out1-00000009", "") in new stack [Oct 11 10:08:34] -- Executing [99909*2***DID@default:2] AGI("SIP/vi-out1-00000009", "agi-VDAD_ALL_inbound.agi") in new stack [Oct 11 10:08:34] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi [Oct 11 10:08:35] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:35] > 0x7f3b1801c3c0 -- Probation passed - setting RTP source address to 104.198.50.101:20862 [Oct 11 10:08:35] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:35] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:08:35] -- Executing [038*130*206*209*78600051@default:1] Goto("Local/038*130*206*209*78600051@default-00000004;2", "default,78600051,1") in new stack [Oct 11 10:08:35] -- Goto (default,78600051,1) [Oct 11 10:08:35] -- Executing [78600051@default:1] MeetMe("Local/038*130*206*209*78600051@default-00000004;2", "8600051,Fq") in new stack [Oct 11 10:08:35] > Channel Local/038*130*206*209*78600051@default-00000004;1 was answered [Oct 11 10:08:35] -- Executing [83047777777777@vicidial-auto:1] Answer("Local/038*130*206*209*78600051@default-00000004;1", "") in new stack [Oct 11 10:08:35] -- Executing [83047777777777@vicidial-auto:2] Playback("Local/038*130*206*209*78600051@default-00000004;1", "ding") in new stack [Oct 11 10:08:35] -- <Local/038*130*206*209*78600051@default-00000004;1> Playing 'ding.gsm' (language 'en') [Oct 11 10:08:35] -- Executing [83047777777777@vicidial-auto:3] Hangup("Local/038*130*206*209*78600051@default-00000004;1", "") in new stack [Oct 11 10:08:35] == Spawn extension (vicidial-auto, 83047777777777, 3) exitednon-zero on 'Local/038*130*206*209*78600051@default-00000004;1' [Oct 11 10:08:35] -- Executing [h@vicidial-auto:1] AGI("Local/038*130*206*209*78600051@default-00000004;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI--- --NODEBUG-----16---------------") in new stack [Oct 11 10:08:35] -- <Local/038*130*206*209*78600051@default-00000004;1>AGIScript agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------- ----- completed, returning 0 [Oct 11 10:08:35] == Spawn extension (default, 78600051, 1) exited non-zero on 'Local/038*130*206*209*78600051@default-00000004;2' [Oct 11 10:08:35] -- Executing [h@default:1] AGI("Local/038*130*206*209*78600051@default-00000004;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODE BUG-----0---------------") in new stack [Oct 11 10:08:35] -- <Local/038*130*206*209*78600051@default-00000004;2>AGScript agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0----------- ---- completed, returning 0 [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] -- <SIP/vi-out1-00000009> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:08:36] -- <SIP/vi-out1-00000009>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0 [Oct 11 10:08:36] -- Executing [038*130*206*209*8600051@default:1] Goto("SIP/vi-out1-00000009", "default,8600051,1") in new stack [Oct 11 10:08:36] -- Goto (default,8600051,1) [Oct 11 10:08:36] -- Executing [8600051@default:1] MeetMe("SIP/vi-out1-00000009", "8600051,F") in new stack [Oct 11 10:08:41] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:08:41] -- Manager 'sendcron' from 127.0.0.1, hanging up channel:SIP/vi-out1-00000009 [Oct 11 10:08:41] == Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/vi-out1-00000009' [Oct 11 10:08:41] -- Executing [h@default:1] AGI("SIP/vi-out1-00000009", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Oct 11 10:08:41] -- <SIP/vi-out1-00000009>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0 [Oct 11 10:08:41] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:08:41] NOTICE[1552]: manager.c:3407 action_hangup: Request to hangup non-existent channel: SIP/vi-out1-00000009

Here is the agiout for this call:
https://pastebin.com/DX1LEV4J

Here is the listen log file for this call:

Code: Select all: Event: Newchannel Privilege: call,all Channel: SIP/vi-out1-00000009 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 18888070544 CallerIDName: AccountCode: Exten: 4057572232 Context: trunkinbound Uniqueid: 1507734514.22 Event: ChannelUpdate Privilege: system,all Channel: SIP/vi-out1-00000009 Uniqueid: 1507734514.22 Channeltype: SIP SIPcallid: 395806882-0-706716822@64.136.174.224 SIPfullcontact: | 2017-10-11 10:08:25|Event: Newstate Privilege: call,all Channel: SIP/vi-out1-00000009 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 18888070544 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1507734514.22 Event: Newstate Privilege: call,all Channel: SIP/vi-out1-00000009 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 18888070544 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1507734514.22 | 2017-10-11 10:08:25|Event: NewCallerid Privilege: call,all Channel: SIP/vi-out1-00000009 CallerIDNum: 8888070544 CallerIDName: Y0111008340000000014 Uniqueid: 1507734514.22 CID-CallingPres: 0 (Presentation Allowed, Not Screened) 2017-10-11 10:08:25|Event: Newchannel Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 038*130*206*209*78600051 Context: default Uniqueid: 1507734515.23 Event: Newchannel Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 038*130*206*209*78600051 Context: default Uniqueid: 1507734515.24 | 2017-10-11 10:08:25|Event: NewAccountCode Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 Uniqueid: 1507734515.23 AccountCode: OldAccountCode: Event: NewCallerid Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 CallerIDNum: ding CallerIDName: ding Uniqueid: 1507734515.23 CID-CallingPres: 0 (Presentation Allowed, Not Screened) Event: LocalBridge Privilege: call,all Channel1: Local/038*130*206*209*78600051@default-00000004;1 Channel2: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid1: 1507734515.23 Uniqueid2: 1507734515.24 Context: default Exten: 038*130*206*209*78600051 LocalOptimization: Yes Event: Newstate Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Uniqueid: 1507734515.24 Event: Newstate Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Uniqueid: 1507734515.23 Event: MeetmeJoin Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid: 1507734515.24 Meetme: 8600051 Usernum: 2 CallerIDnum: ding CallerIDname: ding ConnectedLineNum: ding ConnectedLineName: ding | 2017-10-11 10:08:25|Event: SoftHangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 Uniqueid: 1507734515.23 Cause: 16 | 2017-10-11 10:08:25|Event: HangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid: 1507734515.24 Event: Hangup Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;1 Uniqueid: 1507734515.23 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding AccountCode: Cause: 16 Cause-txt: Normal Clearing Event: MeetmeLeave Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid: 1507734515.24 Meetme: 8600051 Usernum: 2 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding Duration: 0 Event: SoftHangupRequest Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid: 1507734515.24 Cause: 16 Event: Hangup Privilege: call,all Channel: Local/038*130*206*209*78600051@default-00000004;2 Uniqueid: 1507734515.24 CallerIDNum: ding CallerIDName: ding ConnectedLineNum: ding ConnectedLineName: ding AccountCode: Cause: 0 Cause-txt: Unknown | 2017-10-11 10:08:25|Event: MeetmeJoin Privilege: call,all Channel: SIP/vi-out1-00000009 Uniqueid: 1507734514.22 Meetme: 8600051 Usernum: 2 CallerIDnum: 8888070544 CallerIDname: Y0111008340000000014 ConnectedLineNum: <unknown> ConnectedLineName: <unknown> 2017-10-11 10:08:25|Event: MeetmeLeave Privilege: call,all Channel: SIP/vi-out1-00000009 Uniqueid: 1507734514.22 Meetme: 8600051 Usernum: 2 CallerIDNum: 8888070544 CallerIDName: Y0111008340000000014 ConnectedLineNum: <unknown> ConnectedLineName: <unknown> Duration: 5 Event: SoftHangupRequest Privilege: call,all Channel: SIP/vi-out1-00000009 Uniqueid: 1507734514.22 Cause: 16 Event: Hangup Privilege: call,all Channel: SIP/vi-out1-00000009 Uniqueid: 1507734514.22 CallerIDNum: 8888070544 CallerIDName: Y0111008340000000014 ConnectedLineNum: <unknown> ConnectedLineName: <unknown> AccountCode: Cause: 0 Cause-txt: Unknown

With everything the same and only changing the phone from Onhook = N to Onhook = Y, nothing else was changed from the first test call but call not routing. In the live report I can see that the call is ringing the agent (Calls Waiting = 1/Agents Waiting = 0). The when it plays the hold prompt and the phone stops ringing the agent goes to waiting and then once the call starts ringing the agent again it registers that their are no waiting agents:

Code: Select all: [Oct 11 10:14:52] Connected to Asterisk 11.25.1-vici currently running on agentphone (pid = 1803) [Oct 11 10:14:57] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:14:57] -- Executing [8300@default:1] Hangup("Local/8300@default-00000006;2", "") in new stack [Oct 11 10:14:57] == Spawn extension (default, 8300, 1) exited non-zero on 'Local/8300@default-00000006;2' [Oct 11 10:14:57] -- Executing [h@default:1] AGI("Local/8300@default-00000006;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack [Oct 11 10:14:57] -- <Local/8300@default-00000006;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0 [Oct 11 10:14:58] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:06] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:06] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:08] == Using SIP RTP CoS mark 5 [Oct 11 10:15:08] -- Executing [4057572232@trunkinbound:1] AGI("SIP/vi-out1-0000000a", "agi-DID_route.agi") in new stack [Oct 11 10:15:08] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-DID_route.agi [Oct 11 10:15:09] -- <SIP/vi-out1-0000000a>AGI Script agi-DID_route.agi completed, returning 0 [Oct 11 10:15:09] -- Executing [99909*2***DID@default:1] Answer("SIP/vi-out1-0000000a", "") in new stack [Oct 11 10:15:09] -- Executing [99909*2***DID@default:2] AGI("SIP/vi-out1-0000000a", "agi-VDAD_ALL_inbound.agi") in new stack [Oct 11 10:15:09] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi [Oct 11 10:15:09] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:09] > 0x7f3b18020cb0 -- Probation passed - setting RTP source address to 104.198.50.101:28462 [Oct 11 10:15:09] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:09] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:10] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:11] -- Started music on hold, class 'default', on SIP/vi-out1-0000000a [Oct 11 10:15:14] -- Stopped music on hold on SIP/vi-out1-0000000a [Oct 11 10:15:14] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:14] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:14] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:14] -- <SIP/vi-out1-0000000a> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:15:20] -- Started music on hold, class 'default', on SIP/vi-out1-0000000a [Oct 11 10:15:30] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:31] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:15:47] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:15:48] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:04] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:05] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:06] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:06] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:21] -- Stopped music on hold on SIP/vi-out1-0000000a [Oct 11 10:16:21] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:16:21] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:16:21] -- <SIP/vi-out1-0000000a> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:16:21] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:21] -- <SIP/vi-out1-0000000a> Playing 'generic_hold.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 10:16:22] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:16:27] -- Started music on hold, class 'default', on SIP/vi-out1-0000000a [Oct 11 10:16:43] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:16:44] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:00] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:17:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:17:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:17:01] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:06] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:17:06] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:16] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 10:17:17] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 10:17:26] -- Stopped music on hold on SIP/vi-out1-0000000a [Oct 11 10:17:26] -- <SIP/vi-out1-0000000a>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 4 [Oct 11 10:17:26] == Spawn extension (default, 99909*2***DID, 2) exited non-zero on 'SIP/vi-out1-0000000a' [Oct 11 10:17:26] -- Executing [h@default:1] AGI("SIP/vi-out1-0000000a", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Oct 11 10:17:26] -- <S

Here is the agiout for the onhook call:
https://pastebin.com/LdK6twjd

Here is the listen for this onhook call that did not right the agents phone:

Code: Select all: Event: MeetmeLeave Privilege: call,all Channel: SIP/2236-00000006 Uniqueid: 1507734331.16 Meetme: 8600051 Usernum: 1 CallerIDNum: 0000000000 CallerIDName: S1710111005318600051 ConnectedLineNum: 0000000000 ConnectedLineName: S1710111005318600051 Duration: 529 | 2017-10-11 10:14:19|Event: MeetmeEnd Privilege: call,all Meetme: 8600051 Event: Hangup Privilege: call,all Channel: DAHDI/pseudo-2105982810 Uniqueid: 1507734333.17 CallerIDNum: <unknown> CallerIDName: <unknown> ConnectedLineNum: <unknown> ConnectedLineName: <unknown> AccountCode: Cause: 0 Cause-txt: Unknown Event: SoftHangupRequest Privilege: call,all Channel: SIP/2236-00000006 Uniqueid: 1507734331.16 Cause: 16 Event: Hangup Privilege: call,all Channel: SIP/2236-00000006 Uniqueid: 1507734331.16 CallerIDNum: 0000000000 CallerIDName: S1710111005318600051 ConnectedLineNum: 0000000000 ConnectedLineName: S1710111005318600051 AccountCode: Cause: 16 Cause-txt: Normal Clearing Event: Newchannel Privilege: call,all Channel: Local/55558600051@default-00000005;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 55558600051 Context: default Uniqueid: 1507734862.25 Event: Newchannel Privilege: call,all Channel: Local/55558600051@default-00000005;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 55558600051 Context: default Uniqueid: 1507734862.26 Event: NewAccountCode Privilege: call,all Channel: Local/55558600051@default-00000005;1 Uniqueid: 1507734862.25 AccountCode: OldAccountCode: Event: NewCallerid Privilege: call,all Channel: Local/55558600051@default-00000005;1 CallerIDNum: CallerIDName: ULGH34581507734861 Uniqueid: 1507734862.25 CID-CallingPres: 0 (Presentation Allowed, Not Screened) Event: LocalBridge Privilege: call,all Channel1: Local/55558600051@default-00000005;1 Channel2: Local/55558600051@default-00000005;2 Uniqueid1: 1507734862.25 Uniqueid2: 1507734862.26 Context: default Exten: 55558600051 LocalOptimization: Yes Event: SoftHangupRequest Privilege: call,all Channel: Local/55558600051@default-00000005;2 Uniqueid: 1507734862.26 Cause: 16 Event: Hangup Privilege: call,all Channel: Local/55558600051@default-00000005;2 Uniqueid: 1507734862.26 CallerIDNum: <unknown> CallerIDName: ULGH34581507734861 ConnectedLineNum: <unknown> ConnectedLineName: ULGH34581507734861 AccountCode: Cause: 16 Cause-txt: Normal Clearing Event: Hangup Privilege: call,all Channel: Local/55558600051@default-00000005;1 Uniqueid: 1507734862.25 CallerIDNum: <unknown> CallerIDName: ULGH34581507734861 ConnectedLineNum: <unknown> ConnectedLineName: ULGH34581507734861 AccountCode: Cause: 16 Cause-txt: Normal Clearing | 2017-10-11 10:14:19|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: BYE Result: 200|OK | 2017-10-11 10:14:19|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK 2017-10-11 10:14:19|Event: Newchannel Privilege: call,all Channel: Local/8300@default-00000006;1 ChannelState: 0 ChannelStateDesc: Down CallerIDNum: CallerIDName: AccountCode: Exten: 8300 Context: default Uniqueid: 1507734897.27 Event: Newchannel Privilege: call,all Channel: Local/8300@default-00000006;2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: CallerIDName: AccountCode: Exten: 8300 Context: default Uniqueid: 1507734897.28 Event: NewAccountCode Privilege: call,all Channel: Local/8300@default-00000006;1 Uniqueid: 1507734897.27 AccountCode: OldAccountCode: Event: NewCallerid Privilege: call,all Channel: Local/8300@default-00000006;1 CallerIDNum: 0000000000 CallerIDName: S1710111014578600051 Uniqueid: 1507734897.27 CID-CallingPres: 0 (Presentation Allowed, Not Screened) Event: LocalBridge Privilege: call,all Channel1: Local/8300@default-00000006;1 Channel2: Local/8300@default-00000006;2 Uniqueid1: 1507734897.27 Uniqueid2: 1507734897.28 Context: default Exten: 8300 LocalOptimization: Yes 2017-10-11 10:14:19|Event: SoftHangupRequest Privilege: call,all Channel: Local/8300@default-00000006;2 Uniqueid: 1507734897.28 Cause: 16 Event: Hangup Privilege: call,all Channel: Local/8300@default-00000006;2 Uniqueid: 1507734897.28 CallerIDNum: 0000000000 CallerIDName: S1710111014578600051 ConnectedLineNum: 0000000000 ConnectedLineName: S1710111014578600051 AccountCode: Cause: 16 Cause-txt: Normal Clearing Event: Hangup Privilege: call,all Channel: Local/8300@default-00000006;1 Uniqueid: 1507734897.27 CallerIDNum: 0000000000 CallerIDName: S1710111014578600051 ConnectedLineNum: 0000000000 ConnectedLineName: S1710111014578600051 AccountCode: Cause: 16 Cause-txt: Normal Clearing | 2017-10-11 10:14:19|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:14:19|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:14:19|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK Event: Newchannel Privilege: call,all Channel: SIP/vi-out1-0000000a ChannelState: 0 ChannelStateDesc: Down CallerIDNum: 18888070544 CallerIDName: AccountCode: Exten: 4057572232 Context: trunkinbound Uniqueid: 1507734908.29 Event: ChannelUpdate Privilege: system,all Channel: SIP/vi-out1-0000000a Uniqueid: 1507734908.29 Channeltype: SIP SIPcallid: 395825119-0-707111192@64.136.174.224 SIPfullcontact: | 2017-10-11 10:15:07|Event: Newstate Privilege: call,all Channel: SIP/vi-out1-0000000a ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 18888070544 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1507734908.29 Event: Newstate Privilege: call,all Channel: SIP/vi-out1-0000000a ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 18888070544 CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1507734908.29 2017-10-11 10:15:07|Event: NewCallerid Privilege: call,all Channel: SIP/vi-out1-0000000a CallerIDNum: 8888070544 CallerIDName: Y0111015090000000015 Uniqueid: 1507734908.29 CID-CallingPres: 0 (Presentation Allowed, Not Screened) | 2017-10-11 10:15:07|Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/vi-out1-0000000a UniqueID: 1507734908.29 Class: default | 2017-10-11 10:15:07|Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/vi-out1-0000000a UniqueID: 1507734908.29 Class: default | 2017-10-11 10:15:07|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:15:57|PROCESS: keepalive length: 3|4|2017-10-11 10:15:57| 2017-10-11 10:15:57|Response: Follows Privilege: Command System uptime: 17 hours, 4 minutes, 39 seconds Last reload: 33 minutes, 53 seconds Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:15:57|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK 2017-10-11 10:15:57|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:15:57|Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/vi-out1-0000000a UniqueID: 1507734908.29 Class: default | 2017-10-11 10:15:57|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:16:47|PROCESS: keepalive length: 3|4|2017-10-11 10:16:47| 2017-10-11 10:16:47|Response: Follows Privilege: Command System uptime: 17 hours, 5 minutes, 29 seconds Last reload: 34 minutes, 43 seconds Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:16:47|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK | 2017-10-11 10:16:47|Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK 2017-10-11 10:16:47|Event: HangupRequest Privilege: call,all Channel: SIP/vi-out1-0000000a Uniqueid: 1507734908.29 | 2017-10-11 10:16:47|Event: SoftHangupRequest Privilege: call,all Channel: SIP/vi-out1-0000000a Uniqueid: 1507734908.29 Cause: 16 Event: Hangup Privilege: call,all Channel: SIP/vi-out1-0000000a Uniqueid: 1507734908.29 CallerIDNum: 8888070544 CallerIDName: Y0111015090000000015 ConnectedLineNum: <unknown> ConnectedLineName: <unknown> AccountCode: Cause: 0 Cause-txt: Unknown | 2017-10-11 10:17:37|PROCESS: keepalive length: 3|4|2017-10-11 10:17:37| 2017-10-11 10:17:37|Response: Follows Privilege: Command System uptime: 17 hours, 6 minutes, 19 seconds Last reload: 35 minutes, 33 seconds Event: SIP-Response Privilege: system,all ChannelDriver: SIP Method: OPTIONS Result: 200|OK

This is a base install with nothing changed and following the steps in the Manager manual.

System Information-
VERSION: 2.14-635a
BUILD: 171006-2039
SVN Version: 2836
DB Schema Version: 1521
Type: Dedicated
CPU: 2 x Xenon 5670 2.93
DDR3: 64GB
System Drive: 240 GB SSD
Secondary: 2TB SATA
Partitioning: 10gb "SWAP" (sda1)| 220+gb "/" (system)(sda2)|1.8TB "/var" (symlink)(sdb1)

by **bmxmike** » Wed Oct 11, 2017 11:36 am

To try and make this easier I was comparing the agiout and noticed that this is where it seems like I'm having an issue, and looks to be with the VLA table:

agioutput of ON-Hook agent:

Code: Select all: 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|2236|2017-10-11 10:14:57|SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1 and campaign_id IN('Test_in') and closer_campaigns LIKE "% TestLine %" and last_update_time > '20171011101502' and vicidial_live_agents.user NOT IN('','') order by vicidial_live_agents.last_call_finish limit 1;| 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|ON-HOOK-AGENT UPDATE: |UPDATE vicidial_live_agents set ring_callerid='Y0111015090000000015' where user='2236';|1|Y|0 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|RING-AGENT CALL SENT: |RINGAGENT00000000005|138331*5*Y0111015090000000015*2236*2236|0|15|GENERIC|| SIP/vi-out1-0000000a|Y0111015090000000015 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0|50|60|0|0||0|update of vla table: TestLine| |INSERT INTO vicidial_manager values('','','2017-10-11 10:15:09','NEW','N','38.130.206.209','','Originate','RINGAGENT00000000005','Exten: 138331*5*Y0111015090000000015*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: RINGAGENT00000000005','Timeout: 14000','','','','')| 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found

agioutpout of Off-Hook agent:

Code: Select all: 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|2236|2017-10-11 10:08:09|SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1 and campaign_id IN('Test_in') and closer_campaigns LIKE "% TestLine %" and last_update_time > '20171011100827' and vicidial_live_agents.user NOT IN('','') order by vicidial_live_agents.last_call_finish limit 1;| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0|50|60|1|1||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y0111008340000000014 |UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y0111008340000000014';| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |0E0|14|2236 |UPDATE vicidial_xfer_log set closer='2236' where lead_id = '14' order by xfercallid desc limit 1;| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 14 |UPDATE vicidial_closer_log set user='2236' where lead_id='14' order by closecallid desc limit 1;| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- DID AGENT LOG UPDATE: |1|UPDATE vicidial_did_agent_log SET user='2236' where uniqueid='1507734514.22' and user='VDCL' order by call_date desc limit 1;| 2017-10-11 10:08:34|10:08:35|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH0111008348600051|038*130*206*209*78600051|ding|"ding" <ding>|SIP/vi-out1-00000009|insert to vicidial_manager 2017-10-11 10:08:34|10:08:36|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 038*130*206*209*8600051

I can see where the the issue is but I'm not sure why, because after this command of trying to ring the agent and then update the table is when it finds no agent; and I have limited knowledge of exactly how and where each field is instered into the DB if it's specific for On or Off hook, but since the first call can make DB calls I would assume that the On Hook should have no issue either with accessing the DB:

Code: Select all: 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|RING-AGENT CALL SENT: |RINGAGENT00000000005|138331*5*Y0111015090000000015*2236*2236|0|15|GENERIC|| SIP/vi-out1-0000000a|Y0111015090000000015 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0|50|60|0|0||0|update of vla table: TestLine| |INSERT INTO vicidial_manager values('','','2017-10-11 10:15:09','NEW','N','38.130.206.209','','Originate','RINGAGENT00000000005','Exten: 138331*5*Y0111015090000000015*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: RINGAGENT00000000005','Timeout: 14000','','','','')| 2017-10-11 10:15:09|10:15:09|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found

From the DB showing it did run the command you had mentioned previously:

Code: Select all: 50 | 2017-10-11 11:14:37 | SENT | N | 38.130.206.209 | Originate | RINGAGENT00000000006 | Exten: 138331*6*Y0111114370000000016*2236*2236 | Context: default | Channel: Local/038*130*206*209*2236@default | Priority: 1 | Callerid: RINGAGENT00000000006 | Timeout: 14000

by **mflorell** » Wed Oct 11, 2017 12:16 pm

What is the Asterisk Version set to for this server in the modify server page?

You might have actually found a new bug!

Please try upgrading to the latest svn/trunk on this system and test again.

Thanks for all of the debug information, it really did help to pinpoint this issue.

by **bmxmike** » Wed Oct 11, 2017 12:19 pm

Asterisk Version: 11.25.1-vici

That make me happy that I'm not crazy, and it's working!!!

SVN: 2836 => 2839

Below is the log information incase it helps you in anyway
-----------------------------------------------------------------------------
This is the information for the On-Hook = Y

Asterisk CLI:

Code: Select all: [Oct 11 12:34:48] Connected to Asterisk 11.25.1-vici currently running on agentphone (pid = 1809) [Oct 11 12:34:50] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:34:50] -- Executing [8300@default:1] Hangup("Local/8300@default-00000002;2", "") in new stack [Oct 11 12:34:50] == Spawn extension (default, 8300, 1) exited non-zero on 'Local/8300@default-00000002;2' [Oct 11 12:34:50] -- Executing [h@default:1] AGI("Local/8300@default-00000002;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack [Oct 11 12:34:50] -- <Local/8300@default-00000002;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0 [Oct 11 12:34:51] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:01] == Using SIP RTP CoS mark 5 [Oct 11 12:35:01] -- Executing [4057572232@trunkinbound:1] AGI("SIP/vi-out1-00000002", "agi-DID_route.agi") in new stack [Oct 11 12:35:01] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-DID_route.agi [Oct 11 12:35:01] -- <SIP/vi-out1-00000002>AGI Script agi-DID_route.agi completed, returning 0 [Oct 11 12:35:01] -- Executing [99909*2***DID@default:1] Answer("SIP/vi-out1-00000002", "") in new stack [Oct 11 12:35:01] -- Executing [99909*2***DID@default:2] AGI("SIP/vi-out1-00000002", "agi-VDAD_ALL_inbound.agi") in new stack [Oct 11 12:35:01] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_inbound.agi [Oct 11 12:35:01] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:01] > 0x7f1cc002a650 -- Probation passed - setting RTP source address to 104.198.50.101:16564 [Oct 11 12:35:01] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:01] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:35:01] -- Executing [038*130*206*209*2236@default:1] Goto("Local/038*130*206*209*2236@default-00000003;2", "default,2236,1") in new stack [Oct 11 12:35:01] -- Goto (default,2236,1) [Oct 11 12:35:01] -- Executing [2236@default:1] Dial("Local/038*130*206*209*2236@default-00000003;2", "SIP/2236,60,") in new stack [Oct 11 12:35:01] == Using SIP RTP CoS mark 5 [Oct 11 12:35:01] -- Called SIP/2236 [Oct 11 12:35:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:35:02] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:35:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:02] -- SIP/2236-00000003 is ringing [Oct 11 12:35:02] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:03] -- Started music on hold, class 'default', on SIP/vi-out1-00000002 [Oct 11 12:35:05] > 0x7f1bb0015310 -- Probation passed - setting RTP source address to 70.182.89.90:18986 [Oct 11 12:35:05] -- SIP/2236-00000003 answered Local/038*130*206*209*2236@default-00000003;2 [Oct 11 12:35:05] > Channel Local/038*130*206*209*2236@default-00000003;1 was answered [Oct 11 12:35:05] -- Executing [h@default:1] AGI("Local/038*130*206*209*2236@default-00000003;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----4-----0") in new stack [Oct 11 12:35:05] -- Executing [8331*2*Y0111235010000000019*2236*2236@default:1] Playback("SIP/2236-00000003", "sip-silence") in new stack [Oct 11 12:35:05] -- <SIP/2236-00000003> Playing 'sip-silence.gsm' (language 'en') [Oct 11 12:35:05] -- <Local/038*130*206*209*2236@default-00000003;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----4-----0 completed, returning 0 [Oct 11 12:35:05] == Spawn extension (default, 2236, 1) exited non-zero on 'Local/038*130*206*209*2236@default-00000003;2' [Oct 11 12:35:05] -- Executing [8331*2*Y0111235010000000019*2236*2236@default:2] AGI("SIP/2236-00000003", "agi-VDAD_RINGALL.agi,8331*2*Y0111235010000000019*2236*2236") in new stack [Oct 11 12:35:05] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_RINGALL.agi [Oct 11 12:35:05] -- <SIP/2236-00000003> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:05] -- <SIP/2236-00000003> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:05] -- <SIP/2236-00000003> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:06] -- <SIP/2236-00000003> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:06] -- <SIP/2236-00000003>AGI Script agi-VDAD_RINGALL.agi completed, returning 0 [Oct 11 12:35:06] -- Executing [038*130*206*209*78600051@default:1] Goto("SIP/2236-00000003", "default,78600051,1") in new stack [Oct 11 12:35:06] -- Goto (default,78600051,1) [Oct 11 12:35:06] -- Executing [78600051@default:1] MeetMe("SIP/2236-00000003", "8600051,Fq") in new stack [Oct 11 12:35:06] == Parsing '/etc/asterisk/meetme.conf': Found [Oct 11 12:35:06] == Parsing '/etc/asterisk/meetme-vicidial.conf': Found [Oct 11 12:35:06] -- Created MeetMe conference 1023 for conference '8600051' [Oct 11 12:35:06] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:35:06] -- Executing [038*130*206*209*78600051@default:1] Goto("Local/038*130*206*209*78600051@default-00000004;2", "default,78600051,1") in new stack [Oct 11 12:35:06] -- Goto (default,78600051,1) [Oct 11 12:35:06] -- Executing [78600051@default:1] MeetMe("Local/038*130*206*209*78600051@default-00000004;2", "8600051,Fq") in new stack [Oct 11 12:35:06] > Channel Local/038*130*206*209*78600051@default-00000004;1 was answered [Oct 11 12:35:06] -- Executing [83047777777777@vicidial-auto:1] Answer("Local/038*130*206*209*78600051@default-00000004;1", "") in new stack [Oct 11 12:35:06] -- Executing [83047777777777@vicidial-auto:2] Playback("Local/038*130*206*209*78600051@default-00000004;1", "ding") in new stack [Oct 11 12:35:06] -- <Local/038*130*206*209*78600051@default-00000004;1> Playing 'ding.gsm' (language 'en') [Oct 11 12:35:06] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:06] -- Executing [83047777777777@vicidial-auto:3] Hangup("Local/038*130*206*209*78600051@default-00000004;1", "") in new stack [Oct 11 12:35:06] == Spawn extension (vicidial-auto, 83047777777777, 3) exited non-zero on 'Local/038*130*206*209*78600051@default-00000004;1' [Oct 11 12:35:06] -- Executing [h@vicidial-auto:1] AGI("Local/038*130*206*209*78600051@default-00000004;1", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack [Oct 11 12:35:06] -- <Local/038*130*206*209*78600051@default-00000004;1>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0 [Oct 11 12:35:06] == Spawn extension (default, 78600051, 1) exited non-zero on 'Local/038*130*206*209*78600051@default-00000004;2' [Oct 11 12:35:06] -- Executing [h@default:1] AGI("Local/038*130*206*209*78600051@default-00000004;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Oct 11 12:35:06] -- <Local/038*130*206*209*78600051@default-00000004;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0 [Oct 11 12:35:07] == Manager 'sendcron' logged on from 127.0.0.1 [Oct 11 12:35:07] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:07] -- Stopped music on hold on SIP/vi-out1-00000002 [Oct 11 12:35:07] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:07] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:07] == Manager 'sendcron' logged off from 127.0.0.1 [Oct 11 12:35:08] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:08] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:08] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:08] -- <SIP/vi-out1-00000002> Playing 'sip-silence.gsm' (escape_digits=) (sample_offset 0) (language 'en') [Oct 11 12:35:08] -- <SIP/vi-out1-00000002>AGI Script agi-VDAD_ALL_inbound.agi completed, returning 0 [Oct 11 12:35:08] -- Executing [038*130*206*209*8600051@default:1] Goto("SIP/vi-out1-00000002", "default,8600051,1") in new stack [Oct 11 12:35:08] -- Goto (default,8600051,1) [Oct 11 12:35:08] -- Executing [8600051@default:1] MeetMe("SIP/vi-out1-00000002", "8600051,F") in new stack [Oct 11 12:35:09] > 0x7f1bb0015310 -- Probation passed - setting RTP source address to 70.182.89.90:18986 [Oct 11 12:35:09] > 0x7f1bb0015310 -- Probation passed - setting RTP source address to 70.182.89.90:18986 [Oct 11 12:35:30] == Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/vi-out1-00000002' [Oct 11 12:35:30] -- Executing [h@default:1] AGI("SIP/vi-out1-00000002", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Oct 11 12:35:30] -- <SIP/vi-out1-00000002>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0 [Oct 11 12:36:01] == Manager 'sendcron' logged on from 127.0.0.1

agioutput of On-Hook = Y:

Code: Select all: 2017-10-11 12:35:01|agi-DID_route.agi||INSERT INTO vicidial_did_log SET uniqueid='1507743301.9',channel='SIP/vi-out1-00000002',server_ip='38.130.206.209',caller_id_number='18888070544',caller_id_name='',extension='4057572232',call_date='2017-10-11 12:35:01',did_id='2',did_route='IN_GROUP';| 2017-10-11 12:35:01|agi-DID_route.agi|-- DID LOG : |1|INSERT INTO vicidial_did_log SET uniqueid='1507743301.9',channel='SIP/vi-out1-00000002',server_ip='38.130.206.209',caller_id_number='18888070544',caller_id_name='',extension='4057572232',call_date='2017-10-11 12:35:01',did_id='2',did_route='IN_GROUP';| 2017-10-11 12:35:01|agi-DID_route.agi|-- CALL LOG : |1|INSERT INTO call_log SET uniqueid='1507743301.9', channel='SIP/vi-out1-00000002', channel_group='DID_INBOUND', server_ip='38.130.206.209', type='SIP', extension='4057572232', number_dialed='4057572232', caller_code='18888070544', start_time='2017-10-11 12:35:01', start_epoch='1507743301';| 2017-10-11 12:35:01|agi-DID_route.agi|-- DID AGENT LOG : |1|INSERT INTO vicidial_did_agent_log SET uniqueid='1507743301.9',server_ip='38.130.206.209',caller_id_number='18888070544',caller_id_name='',extension='4057572232',call_date='2017-10-11 12:35:01',did_id='2',did_route='IN_GROUP',user='VDCL',group_id='TestLine',did_description='';| 2017-10-11 12:35:01|agi-DID_route.agi|exiting the DID app, transferring call to 99909*2***DID @ default 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|North America CID Check: 1|8888070544| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- accountcode = 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- callerid = 18888070544 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- callingpres = 0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- callingtns = 0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- callington = 0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- channel = SIP/vi-out1-00000002 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- context = default 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- dnid = 4057572232 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- extension = 99909*2***DID 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- language = en 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- priority = 2 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- threadid = 139759759390464 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- type = SIP 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1507743301.9 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi| -- version = 11.25.1-vici 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|AGI Variables: |1507743301.9|SIP/vi-out1-00000002|99909*2***DID|SIP|8888070544| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |TestLine|8888070544-4057572232|2017-10-11 12:35:01 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_allow_inbound='Y';|19| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|callerID changed: "Y0111235010000000019 <8888070544>" 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|0|SELECT auto_call_id from vicidial_auto_calls where uniqueid='1507743301.9' and server_ip='38.130.206.209';| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls SET server_ip='38.130.206.209', campaign_id='TestLine', status='LIVE', lead_id='19', uniqueid='1507743301.9', callerid='Y0111235010000000019', channel='SIP/vi-out1-00000002', phone_code='1', phone_number='8888070544', call_time='2017-10-11 12:35:01', call_type='IN', stage='LIVE-0', queue_priority='0' ;| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|1|SELECT count(*) from vicidial_auto_calls where status = 'LIVE' and campaign_id='TestLine';| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|1|UPDATE vicidial_auto_calls SET queue_position='1' WHERE auto_call_id='2';| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log SET lead_id='19', campaign_id='TestLine', call_date='2017-10-11 12:35:01', start_epoch='1507743301', status='QUEUE', phone_code='1', phone_number='8888070544', user='VDCL', processed='N', xfercallid='0', uniqueid='1507743301.9', queue_position='1',called_count='1',list_id='999' ;| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|-- VDCL : |19|0|12|insert to vicidial_closer_log 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|-- ENTER QUEUE VLE insert: |1| |INSERT INTO vicidial_log_extended set uniqueid='1507743301.9',server_ip='38.130.206.209',call_date='2017-10-11 12:35:01',lead_id = '19',caller_code='Y0111235010000000019',custom_call_id='';| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|DID IVR time logged: 2017-10-11 12:35:01|1507743301|1|UPDATE call_log set end_time='2017-10-11 12:35:01',end_epoch='1507743301',length_in_sec=0,length_in_min=' 0.00',extension='Y0111235010000000019' where uniqueid='1507743301.9'| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|2236|2017-10-11 12:34:49|SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1 and campaign_id IN('Test_in') and closer_campaigns LIKE "% TestLine %" and last_update_time > '20171011123454' and vicidial_live_agents.user NOT IN('','') order by vicidial_live_agents.last_call_finish limit 1;| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|ON-HOOK-AGENT UPDATE: |UPDATE vicidial_live_agents set ring_callerid='Y0111235010000000019' where user='2236';|1|Y|0 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|RING-AGENT CALL SENT: |RINGAGENT00000000002|8331*2*Y0111235010000000019*2236*2236|0|15|GENERIC|| SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0|50|60|0|0||0|update of vla table: TestLine| |INSERT INTO vicidial_manager values('','','2017-10-11 12:35:01','NEW','N','38.130.206.209','','Originate','RINGAGENT00000000002','Exten: 8331*2*Y0111235010000000019*2236*2236','Context: default','Channel: Local/038*130*206*209*2236@default','Priority: 1','Callerid: RINGAGENT00000000002','Timeout: 14000','','','','')| 2017-10-11 12:35:01|12:35:01|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 14.75|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0.25|51|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 14.5|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0.5|52|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 14.25|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|0.75|53|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 14|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|1|54|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 13.75|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|1.25|55|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:02|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 13.5|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|1.5|56|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 13.25|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|1.75|57|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 12.25|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|2|58|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:03|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:04|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:04|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:04|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 11.25|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:04|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|3|59|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:04|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:01|12:35:05|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:05|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:05|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 10.25|15|15 SIP/vi-out1-00000002|Y0111235010000000019 2017-10-11 12:35:01|12:35:05|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|4|60|60|0|0||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:05|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|AGI Environment Dump: 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- accountcode = 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- arg_1 = 8331*2*Y0111235010000000019*2236*2236 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- callerid = 4057572236 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- calleridname = sip2236 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- callingani2 = 0 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- callingpres = 0 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- callingtns = 0 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- callington = 0 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- channel = SIP/2236-00000003 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- context = default 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- dnid = unknown 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- enhanced = 0.0 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- extension = 8331*2*Y0111235010000000019*2236*2236 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- language = en 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- priority = 2 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- rdnis = unknown 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- request = agi-VDAD_RINGALL.agi 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- threadid = 139759756850944 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- type = SIP 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- uniqueid = 1507743301.10 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi| -- version = 11.25.1-vici 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|AGI Variables: |1507743301.10|SIP/2236-00000003|8331*2*Y0111235010000000019*2236*2236|SIP|4057572236|2| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|RING-AGENT AGI STARTED 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- VAC Call Found: |4057572236|TestLine|IN||8888070544|19|2| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- VLA Agent Found: |4057572236|8600051|SIP/2236|38.130.206.209||TEST_IN|2| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- Ringing agents for this call: |Y0111235010000000019|0|2236|SIP/2236|8600051|38.130.206.209| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- Ringing stats: |Y0111235010000000019|1|0|SIP/2236| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- VAC Call Grabbed: |4057572236|2|2236|1| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- Check for in-group next agent call setting: |4057572236|TestLine|oldest_call_finish| 2017-10-11 12:35:05|agi-VDAD_RINGALL.agi|-- Ring-Agent Sending Call: |4057572236|2|2236|038*130*206*209*78600051| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|AGENT GRAB TRIGGERED: |2236|8600051|1| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|0|1|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TestLine' and call_time < "2017-10-11 12:35:01" and lead_id != '19' and queue_priority >= '0' and agent_only='';| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '19' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2017-10-11 12:35:01") );| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi||2017-10-11 12:34:49|SELECT conf_exten,user,extension,server_ip,last_call_time,ra_user,campaign_id,on_hook_agent,on_hook_ring_time FROM vicidial_live_agents where status IN('CLOSER','READY') and lead_id<1 and campaign_id IN('Test_in') and closer_campaigns LIKE "% TestLine %" and last_update_time > '20171011123454' and vicidial_live_agents.user NOT IN('','2236','') order by vicidial_live_agents.last_call_finish limit 1;| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,extension,server_ip,ra_user,campaign_id from vicidial_live_agents WHERE user='2236';| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|AGENT GRAB EXTENSION OVERRIDE: |8600051|8600051| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|5|61|60|1|1||0|update of vla table: TestLine| |UNLOCK TABLES;| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y0111235010000000019 |UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-5' where callerid='Y0111235010000000019';| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |0E0|19|2236 |UPDATE vicidial_xfer_log set closer='2236' where lead_id = '19' order by xfercallid desc limit 1;| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 19 |UPDATE vicidial_closer_log set user='2236' where lead_id='19' order by closecallid desc limit 1;| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- DID AGENT LOG UPDATE: |1|UPDATE vicidial_did_agent_log SET user='2236' where uniqueid='1507743301.9' and user='VDCL' order by call_date desc limit 1;| 2017-10-11 12:35:01|12:35:06|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH0111235018600051|038*130*206*209*78600051|ding|"ding" <ding>|SIP/vi-out1-00000002|insert to vicidial_manager 2017-10-11 12:35:01|12:35:07|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 038*130*206*209*8600051 2017-10-11 12:35:01|12:35:07|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='2236' and group_id='TestLine';| 2017-10-11 12:35:01|12:35:07|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |4|2236|TestLine| 2017-10-11 12:35:01|12:35:08|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|19| |UPDATE vicidial_closer_log set queue_seconds='5' where lead_id = '19' and call_date='2017-10-11 12:35:01' order by closecallid desc limit 1;| 2017-10-11 12:35:08|12:35:08|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2017-10-11 12:35:01|2017-10-11 12:35:08|038*130*206*209*8600051

by **rrb555** » Wed Nov 14, 2018 11:43 pm

I am having the same issue

Code: Select all: 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|0|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = 'TEST' and call_time < "2018-11-14 23:34:57" and lead_id != '22530' and queue_priority >= '0' and agent_only='';| 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_inbound_callback_queue where icbq_status IN('LIVE','SENDING') and group_id='TEST' and call_date < "2018-11-14 23:34:57" and lead_id != '22530' and queue_priority >= '0';| 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and lead_id != '22530' and agent_only='' and ( (queue_priority > '0') or (queue_priority = '0' and call_time < "2018-11-14 23:34:57") );| 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|0|SELECT count(*) FROM vicidial_inbound_callback_queue where icbq_status IN('LIVE','SENDING') and lead_id != '22530' and ( (queue_priority > '0') or (queue_priority = '0' and call_date < "2018-11-14 23:34:57") );| 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|RING-AGENT TIMER: 5|15|15 SIP/2TALK-00001b0c|Y1142334570000022530 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |360|20|10|60|0|0|0|0|update of vla table: TEST| |UNLOCK TABLES;| 2018-11-14 23:34:57|23:35:17|agi-VDAD_ALL_inbound.agi|NNNNN No available balance agent found

vicidial.org

(Solved)On Hook Agents not receiving call

(Solved)On Hook Agents not receiving call

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call (Unless use "Ring")

Re: On Hook Agents not receiving call

Who is online