No routing a call (agi-VDAD_ALL_outbound.agi)
Posted: Tue Jan 26, 2016 4:32 pmThere is the troubles with a routing the calls to agent.
Description of problem:
ViciDial does outgoing call to a subscriber.
Agent is online and associated with a campaing for which ViciDial does a current outgoing call. Other agents are not presented in ViciDial.
When a callee subscriber answered, ViciDial (Asterisk) should route the call to free agent.
But ViciDial (Asterisk) drops this call after 3 seconds.
During this time the agent stays to listen a music on hold (being in conference).
As I see the problem is in AGI-script 'agi-VDAD_ALL_outbound.agi'. But why it doesn't work correctly it's unclear.
Does somebody have any ideas how to fix this issue?
Technical data and part of the logs of Asterisk and ViciDial are below.
Operation system: Centos 6.7 virtual server which was created by using technology of virtualization 'Vagrant'.
The version of Asterisk: 1.8.23.0-vici
The version of ViciDial: 2.10-473a
BUILD: 150210-0657
Used softphone: eyeBeam which interoperates with ViciDial as descripts below:
Softphone<------(sip)------->FreePBX<-------(iax2)------->ViciDial
# /etc/init.d/iptables status
iptables: Firewall is not running.
Asterisk's log (message-log):
[Jan 26 19:14:11] VERBOSE[6544] pbx.c: [Jan 26 19:14:11] > Channel Local/9380990971256@default-00000002;1 was answered.
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:1] Playback("Local/9380990971256@default-00000002;1", "sip-silence") in new stack
[Jan 26 19:14:11] VERBOSE[6557] file.c: [Jan 26 19:14:11] -- <Local/9380990971256@default-00000002;1> Playing 'sip-silence.gsm' (language 'en')
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:2] Wait("Local/9380990971256@default-00000002;1", "0.5") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:3] Set("IAX2/freepbx-dev-local-862", "answerTime=7") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:4] NoOp("IAX2/freepbx-dev-local-862", "answerTime is: 7") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:5] AGI("IAX2/freepbx-dev-local-862", "agi://127.0.0.1:4577/call_log") in new stack
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=100))
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- <IAX2/freepbx-dev-local-862>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:6] GotoIf("IAX2/freepbx-dev-local-862", "1?noAMD") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Goto (default,8368,9)
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:9] AGI("IAX2/freepbx-dev-local-862", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jan 26 19:14:13] VERBOSE[6557] res_agi.c: [Jan 26 19:14:13] -- <IAX2/freepbx-dev-local-862>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jan 26 19:14:13] VERBOSE[6557] pbx.c: [Jan 26 19:14:13] -- Executing [8368@default:10] AGI("IAX2/freepbx-dev-local-862", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack
[Jan 26 19:14:13] VERBOSE[6557] res_agi.c: [Jan 26 19:14:13] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jan 26 19:14:14] VERBOSE[6557] res_agi.c: [Jan 26 19:14:14] -- <IAX2/freepbx-dev-local-862>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jan 26 19:14:14] VERBOSE[6557] pbx.c: [Jan 26 19:14:14] -- Executing [8368@default:11] Hangup("IAX2/freepbx-dev-local-862", "") in new stack
[Jan 26 19:14:14] VERBOSE[6557] pbx.c: [Jan 26 19:14:14] == Spawn extension (default, 8368, 11) exited non-zero on 'IAX2/freepbx-dev-local-862'
The log of the script agi-VDAD_ALL_outbound.agi:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|callerID changed: V1261914040000069225
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- accountcode =
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- arg_1 = NORMAL-----LB
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callerid = 110031004100
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- calleridname = V1261914040000069225
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callington = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/freepbx-dev-local-862
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- context = default
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- language = en
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- priority = 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- threadid = 140389252900608
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1453828444.12
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- version = 1.8.23.0-vici
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|AGI Variables: |1453828444.12|IAX2/freepbx-dev-local-862|8368|IAX2|V1261914040000069225|V1261914040000069225|9|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |69225|2016-01-26 19:14:12|1.8.23.0|9|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|LLLLLLLLL LOCAL CHANNEL PRIORITY 4 LOGGING: (this is usually caused by carrier issues) LRERR 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='LRERR' where lead_id='69225' and status NOT IN('CBHOLD','CALLBK','CBHOLD','QCFAIL');|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR vicidial_list LRERR update: |1|1453828444.12|69225|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed,alt_dial,list_id,called_count) values('1453828444.12','69225','100','2016-01-26 19:14:12','1453828452','LRERR','','380990971256','VDAD','N','NONE','100','94')|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR : |69225|69225|insert to vicidial_log: 1453828444.12
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR VLE insert: |1|
|INSERT INTO vicidial_log_extended set uniqueid='1453828444.12',server_ip='127.0.0.1',call_date='2016-01-26 19:14:12',lead_id = '69225',caller_code='V1261914040000069225',custom_call_id='';|
Description of problem:
ViciDial does outgoing call to a subscriber.
Agent is online and associated with a campaing for which ViciDial does a current outgoing call. Other agents are not presented in ViciDial.
When a callee subscriber answered, ViciDial (Asterisk) should route the call to free agent.
But ViciDial (Asterisk) drops this call after 3 seconds.
During this time the agent stays to listen a music on hold (being in conference).
As I see the problem is in AGI-script 'agi-VDAD_ALL_outbound.agi'. But why it doesn't work correctly it's unclear.
Does somebody have any ideas how to fix this issue?
Technical data and part of the logs of Asterisk and ViciDial are below.
Operation system: Centos 6.7 virtual server which was created by using technology of virtualization 'Vagrant'.
The version of Asterisk: 1.8.23.0-vici
The version of ViciDial: 2.10-473a
BUILD: 150210-0657
Used softphone: eyeBeam which interoperates with ViciDial as descripts below:
Softphone<------(sip)------->FreePBX<-------(iax2)------->ViciDial
# /etc/init.d/iptables status
iptables: Firewall is not running.
Asterisk's log (message-log):
[Jan 26 19:14:11] VERBOSE[6544] pbx.c: [Jan 26 19:14:11] > Channel Local/9380990971256@default-00000002;1 was answered.
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:1] Playback("Local/9380990971256@default-00000002;1", "sip-silence") in new stack
[Jan 26 19:14:11] VERBOSE[6557] file.c: [Jan 26 19:14:11] -- <Local/9380990971256@default-00000002;1> Playing 'sip-silence.gsm' (language 'en')
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:2] Wait("Local/9380990971256@default-00000002;1", "0.5") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:3] Set("IAX2/freepbx-dev-local-862", "answerTime=7") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:4] NoOp("IAX2/freepbx-dev-local-862", "answerTime is: 7") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:5] AGI("IAX2/freepbx-dev-local-862", "agi://127.0.0.1:4577/call_log") in new stack
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=100))
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- <IAX2/freepbx-dev-local-862>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:6] GotoIf("IAX2/freepbx-dev-local-862", "1?noAMD") in new stack
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Goto (default,8368,9)
[Jan 26 19:14:11] VERBOSE[6557] pbx.c: [Jan 26 19:14:11] -- Executing [8368@default:9] AGI("IAX2/freepbx-dev-local-862", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack
[Jan 26 19:14:11] VERBOSE[6557] res_agi.c: [Jan 26 19:14:11] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jan 26 19:14:13] VERBOSE[6557] res_agi.c: [Jan 26 19:14:13] -- <IAX2/freepbx-dev-local-862>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jan 26 19:14:13] VERBOSE[6557] pbx.c: [Jan 26 19:14:13] -- Executing [8368@default:10] AGI("IAX2/freepbx-dev-local-862", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack
[Jan 26 19:14:13] VERBOSE[6557] res_agi.c: [Jan 26 19:14:13] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jan 26 19:14:14] VERBOSE[6557] res_agi.c: [Jan 26 19:14:14] -- <IAX2/freepbx-dev-local-862>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jan 26 19:14:14] VERBOSE[6557] pbx.c: [Jan 26 19:14:14] -- Executing [8368@default:11] Hangup("IAX2/freepbx-dev-local-862", "") in new stack
[Jan 26 19:14:14] VERBOSE[6557] pbx.c: [Jan 26 19:14:14] == Spawn extension (default, 8368, 11) exited non-zero on 'IAX2/freepbx-dev-local-862'
The log of the script agi-VDAD_ALL_outbound.agi:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|callerID changed: V1261914040000069225
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- accountcode =
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- arg_1 = NORMAL-----LB
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callerid = 110031004100
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- calleridname = V1261914040000069225
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- callington = 0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/freepbx-dev-local-862
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- context = default
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- language = en
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- priority = 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- threadid = 140389252900608
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1453828444.12
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi| -- version = 1.8.23.0-vici
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|AGI Variables: |1453828444.12|IAX2/freepbx-dev-local-862|8368|IAX2|V1261914040000069225|V1261914040000069225|9|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |69225|2016-01-26 19:14:12|1.8.23.0|9|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|LLLLLLLLL LOCAL CHANNEL PRIORITY 4 LOGGING: (this is usually caused by carrier issues) LRERR 9
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='LRERR' where lead_id='69225' and status NOT IN('CBHOLD','CALLBK','CBHOLD','QCFAIL');|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR vicidial_list LRERR update: |1|1453828444.12|69225|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed,alt_dial,list_id,called_count) values('1453828444.12','69225','100','2016-01-26 19:14:12','1453828452','LRERR','','380990971256','VDAD','N','NONE','100','94')|
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR : |69225|69225|insert to vicidial_log: 1453828444.12
2016-01-26 19:14:12|agi-VDAD_ALL_outbound.agi|-- LRERR VLE insert: |1|
|INSERT INTO vicidial_log_extended set uniqueid='1453828444.12',server_ip='127.0.0.1',call_date='2016-01-26 19:14:12',lead_id = '69225',caller_code='V1261914040000069225',custom_call_id='';|