Auto dial drops call
Posted: Fri Mar 30, 2012 2:57 pm
Asterisk Version
1.4.39.2-vici
VICIdial Version
VERSION: 2.4-351a
BUILD: 111223-0043
Manual dial works fine. When using Ratio, the call drops after the called party answers the phone. Here's the CLI output:
[Mar 30 15:51:59] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:51:59] -- Executing [913054039999@default:1] AGI("Local/913054039999@default-c933,2", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 30 15:51:59] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 30 15:51:59] -- Executing [913054039999@default:2] Dial("Local/913054039999@default-c933,2", "SIP/velocity/3054039999||To") in new stack
[Mar 30 15:51:59] -- Called velocity/3054039999
[Mar 30 15:52:01] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:01] Found
[Mar 30 15:52:01] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:01] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:01] Found
[Mar 30 15:52:01] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:01] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:01] -- SIP/velocity-00000036 is ringing
[Mar 30 15:52:02] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:06] -- SIP/velocity-00000036 answered Local/913054039999@default-c933,2
[Mar 30 15:52:06] > Channel Local/913054039999@default-c933,1 was answered.
[Mar 30 15:52:06] -- Executing [8368@default:1] Playback("Local/913054039999@default-c933,1", "sip-silence") in new stack
[Mar 30 15:52:06] -- <Local/913054039999@default-c933,1> Playing 'sip-silence' (language 'en')
[Mar 30 15:52:06] WARNING[28300]: file.c:1297 waitstream_core: Unexpected control subclass '-1'
[Mar 30 15:52:06] -- Executing [h@default:1] DeadAGI("Local/913054039999@default-c933,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---- -ANSWER-----7-----0") in new stack
[Mar 30 15:52:06] -- Executing [8368@default:2] AGI("SIP/velocity-00000036", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:3] AGI("SIP/velocity-00000036", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Mar 30 15:52:06] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---7-----0 completed, returning 0
[Mar 30 15:52:06] == Spawn extension (default, 913054039999, 2) exited non-zero on 'Local/913054039999@default-c933,2'
[Mar 30 15:52:06] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:4] AGI("SIP/velocity-00000036", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Mar 30 15:52:06] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Mar 30 15:52:06] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:06] Found
[Mar 30 15:52:06] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:06] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:06] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:5] Hangup("SIP/velocity-00000036", "") in new stack
[Mar 30 15:52:06] == Spawn extension (default, 8368, 5) exited non-zero on 'SIP/velocity-00000036'
[Mar 30 15:52:06] -- Executing [h@default:1] DeadAGI("SIP/velocity-00000036", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------" ) in new stack
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
Here's AGIOUT:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|callerID changed: V3301551590033177911
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- accountcode =
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callerid = 3054039999
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- calleridname = V3301551590033177911
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callington = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- channel = SIP/velocity-00000036
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- context = default
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- language = en
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- priority = 4
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- type = SIP
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1333137119.266
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|AGI Variables: |1333137119.266|SIP/velocity-00000036|8368|SIP|V3301551590033177911|V3301551590033177911|4|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |33177911|2012-03-30 15:52:06|1.4.21.2|4|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_live_agents where callerid='V3301551590033177911';|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|1|SELECT count(*) FROM vicidial_auto_calls where callerid='V3301551590033177911' and status IN('LIVE','XFER');|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|+++++ VDAD START DIALPLAN DUPLICATE: EXITING- 4
1.4.39.2-vici
VICIdial Version
VERSION: 2.4-351a
BUILD: 111223-0043
Manual dial works fine. When using Ratio, the call drops after the called party answers the phone. Here's the CLI output:
[Mar 30 15:51:59] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:51:59] -- Executing [913054039999@default:1] AGI("Local/913054039999@default-c933,2", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 30 15:51:59] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 30 15:51:59] -- Executing [913054039999@default:2] Dial("Local/913054039999@default-c933,2", "SIP/velocity/3054039999||To") in new stack
[Mar 30 15:51:59] -- Called velocity/3054039999
[Mar 30 15:52:01] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:01] Found
[Mar 30 15:52:01] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:01] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:01] Found
[Mar 30 15:52:01] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:01] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:01] -- SIP/velocity-00000036 is ringing
[Mar 30 15:52:02] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:06] -- SIP/velocity-00000036 answered Local/913054039999@default-c933,2
[Mar 30 15:52:06] > Channel Local/913054039999@default-c933,1 was answered.
[Mar 30 15:52:06] -- Executing [8368@default:1] Playback("Local/913054039999@default-c933,1", "sip-silence") in new stack
[Mar 30 15:52:06] -- <Local/913054039999@default-c933,1> Playing 'sip-silence' (language 'en')
[Mar 30 15:52:06] WARNING[28300]: file.c:1297 waitstream_core: Unexpected control subclass '-1'
[Mar 30 15:52:06] -- Executing [h@default:1] DeadAGI("Local/913054039999@default-c933,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---- -ANSWER-----7-----0") in new stack
[Mar 30 15:52:06] -- Executing [8368@default:2] AGI("SIP/velocity-00000036", "agi://127.0.0.1:4577/call_log") in new stack
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:3] AGI("SIP/velocity-00000036", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Mar 30 15:52:06] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---7-----0 completed, returning 0
[Mar 30 15:52:06] == Spawn extension (default, 913054039999, 2) exited non-zero on 'Local/913054039999@default-c933,2'
[Mar 30 15:52:06] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:4] AGI("SIP/velocity-00000036", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Mar 30 15:52:06] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Mar 30 15:52:06] == Parsing '/etc/asterisk/manager.conf': [Mar 30 15:52:06] Found
[Mar 30 15:52:06] == Manager 'sendcron' logged on from 127.0.0.1
[Mar 30 15:52:06] == Manager 'sendcron' logged off from 127.0.0.1
[Mar 30 15:52:06] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Mar 30 15:52:06] -- Executing [8368@default:5] Hangup("SIP/velocity-00000036", "") in new stack
[Mar 30 15:52:06] == Spawn extension (default, 8368, 5) exited non-zero on 'SIP/velocity-00000036'
[Mar 30 15:52:06] -- Executing [h@default:1] DeadAGI("SIP/velocity-00000036", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------" ) in new stack
[Mar 30 15:52:06] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
Here's AGIOUT:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|callerID changed: V3301551590033177911
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- accountcode =
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callerid = 3054039999
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- calleridname = V3301551590033177911
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- callington = 0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- channel = SIP/velocity-00000036
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- context = default
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- language = en
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- priority = 4
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- type = SIP
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1333137119.266
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|AGI Variables: |1333137119.266|SIP/velocity-00000036|8368|SIP|V3301551590033177911|V3301551590033177911|4|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |33177911|2012-03-30 15:52:06|1.4.21.2|4|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_live_agents where callerid='V3301551590033177911';|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|1|SELECT count(*) FROM vicidial_auto_calls where callerid='V3301551590033177911' and status IN('LIVE','XFER');|
2012-03-30 15:52:06|agi-VDAD_ALL_outbound.agi|+++++ VDAD START DIALPLAN DUPLICATE: EXITING- 4