vicidial.org

I'm currently experiencing an issue with autodialing a campaign. The agent logs in and successfully connects to the conference. Once we resume, the system dials out, but there is no sound on the callee's phone, no information appears on the agent screen, and the CLI seems to indicate that it's calling VD_hangup.agi. The callee's phone shows that the call is still connected, despite the hangup. One thing to note is that all is fine when the campaign is set to manual dial... problem is just when autodialing.

I'm using....
asterisk-1.2.12.1
libpri-1.2.3
zaptel-1.2.11
Sangoma A102 dual-T1/PRI

CLI Output:
-- Zap/1-1 is ringing
-- Zap/1-1 answered Local/917173304813@default-b78d,2
> Channel Local/917173304813@default-b78d,1 was answered.
== Manager 'sendcron' logged off from 127.0.0.1
-- Executing AGI("Local/917173304813@default-b78d,1", "call_log.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
== Spawn extension (default, 917173304813, 2) exited non-zero on 'Local/917173304813@default-b78d,2'
-- Executing DeadAGI("Local/917173304813@default-b78d,2", "call_log.agi|h") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
-- AGI Script call_log.agi completed, returning 0
-- Executing AGI("Zap/1-1", "agi-VDADtransfer.agi|8365") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDADtransfer.agi
-- AGI Script call_log.agi completed, returning 0
-- Executing DeadAGI("Local/917173304813@default-b78d,2", "VD_hangup.agi|PRI-----NODEBUG-----16-----ANSWER-----11-----0") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/VD_hangup.agi
-- AGI Script VD_hangup.agi completed, returning 0
== Parsing '/etc/asterisk/manager.conf': Found
== Manager 'sendcron' logged on from 127.0.0.1
-- Hungup 'Zap/pseudo-828683085'
== Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/phonetest-0968a2b0'
-- Executing DeadAGI("SIP/phonetest-0968a2b0", "call_log.agi|h") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
-- AGI Script call_log.agi completed, returning 0
-- Executing DeadAGI("SIP/phonetest-0968a2b0", "VD_hangup.agi|PRI-----NODEBUG-----16---------------") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/VD_hangup.agi
-- AGI Script VD_hangup.agi completed, returning 0
== Manager 'sendcron' logged off from 127.0.0.1
-- Channel 0/1, span 1 got hangup request
== Spawn extension (default, 8365, 2) exited non-zero on 'Zap/1-1'
-- Executing DeadAGI("Zap/1-1", "call_log.agi|h") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
-- AGI Script call_log.agi completed, returning 0
-- Executing DeadAGI("Zap/1-1", "VD_hangup.agi|PRI-----NODEBUG-----16---------------") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/VD_hangup.agi
-- AGI Script VD_hangup.agi completed, returning 0
-- Hungup 'Zap/1-1'

type screen -r to check if you have screen running.

What is the loadavg when this happens?

Can you post some output from /var/log/astguiclient/agiout.2006-XX-XX from when this happens?

screen -r output:
2762.ASTupdate (Detached)
2719.ASTsend (Detached)
2480.ASTVDadapt (Detached)
2757.ASTVDauto (Detached)
2766.ASTVDremote (Detached)
2713.ASTlisten (Detached)

load average never goes above 0.07

Here's a chunk of the agiout file during the described failure...

2006-11-21 16:19:28|call_log.agi|AGI Environment Dump:
2006-11-21 16:19:28|call_log.agi| -- accountcode =
2006-11-21 16:19:28|call_log.agi| -- callerid = unknown
2006-11-21 16:19:28|call_log.agi| -- calleridname = S0611211617028600051
2006-11-21 16:19:28|call_log.agi| -- callingani2 = 0
2006-11-21 16:19:28|call_log.agi| -- callingpres = 0
2006-11-21 16:19:28|call_log.agi| -- callingtns = 0
2006-11-21 16:19:28|call_log.agi| -- callington = 0
2006-11-21 16:19:28|call_log.agi| -- channel = SIP/phonetest-09680300
2006-11-21 16:19:28|call_log.agi| -- context = default
2006-11-21 16:19:28|call_log.agi| -- dnid = unknown
2006-11-21 16:19:28|call_log.agi| -- enhanced = 0.0
2006-11-21 16:19:28|call_log.agi| -- extension = h
2006-11-21 16:19:28|call_log.agi| -- language = en
2006-11-21 16:19:28|call_log.agi| -- priority = 1
2006-11-21 16:19:28|call_log.agi| -- rdnis = unknown
2006-11-21 16:19:28|call_log.agi| -- request = call_log.agi
2006-11-21 16:19:28|call_log.agi| -- type = SIP
2006-11-21 16:19:28|call_log.agi| -- uniqueid = 1164143822.88
2006-11-21 16:19:28|call_log.agi|AGI Variables: |1164143822.88|SIP/phonetest-09680300|h|SIP|S0611211617028600051|
2006-11-21 16:19:28|call_log.agi||CALL HUNG UP|
2006-11-21 16:19:28|call_log.agi||DELETE from live_inbound where uniqueid='1164143822.88' and server_ip='10.10.11.30'|
2006-11-21 16:19:28|call_log.agi|+++++ CALL LOG HUNGUP: |1164143822.88|SIP/phonetest-09680300|h|2006-11-21 16:19:28|min: |
2006-11-21 16:19:28|VD_hangup.agi|Perl Environment Dump:
2006-11-21 16:19:28|VD_hangup.agi|0|PRI-----NODEBUG-----16---------------
2006-11-21 16:19:28|VD_hangup.agi|AGI Environment Dump:
2006-11-21 16:19:28|VD_hangup.agi| -- accountcode =
2006-11-21 16:19:28|VD_hangup.agi| -- callerid = unknown
2006-11-21 16:19:28|VD_hangup.agi| -- calleridname = S0611211617028600051
2006-11-21 16:19:28|VD_hangup.agi| -- callingani2 = 0
2006-11-21 16:19:28|VD_hangup.agi| -- callingpres = 0
2006-11-21 16:19:28|VD_hangup.agi| -- callingtns = 0
2006-11-21 16:19:28|VD_hangup.agi| -- callington = 0
2006-11-21 16:19:28|VD_hangup.agi| -- channel = SIP/phonetest-09680300
2006-11-21 16:19:28|VD_hangup.agi| -- context = default
2006-11-21 16:19:28|VD_hangup.agi| -- dnid = unknown
2006-11-21 16:19:28|VD_hangup.agi| -- enhanced = 0.0
2006-11-21 16:19:28|VD_hangup.agi| -- extension = h
2006-11-21 16:19:28|VD_hangup.agi| -- language = en
2006-11-21 16:19:28|VD_hangup.agi| -- priority = 2
2006-11-21 16:19:28|VD_hangup.agi| -- rdnis = unknown
2006-11-21 16:19:28|VD_hangup.agi| -- request = VD_hangup.agi
2006-11-21 16:19:28|VD_hangup.agi| -- type = SIP
2006-11-21 16:19:28|VD_hangup.agi| -- uniqueid = 1164143822.88
2006-11-21 16:19:28|VD_hangup.agi|AGI Variables: |1164143822.88|SIP/phonetest-09680300|h|SIP|S0611211617028600051|
2006-11-21 16:19:28|VD_hangup.agi|DEBUG: NODEBUG
2006-11-21 16:19:28|VD_hangup.agi|VD_hangup : S0611211617028600051 SIP/phonetest-09680300 2 28600051
2006-11-21 16:19:28|VD_hangup.agi||SELECT lead_id,callerid FROM vicidial_auto_calls where uniqueid = '1164143822.88' limit 1;|
2006-11-21 16:19:28|VD_hangup.agi|VD hangup: no VDAC record found: 1164143822.88 S0611211617028600051

Any agiout file fouput from the closer AGI script?

There are no closer files in the log directory.

Could this possibly be an extensions.conf issue?

What AGI script are you using to send calls to agents for inbound?

I actually have nothing set up for inbound... it's currently set up for outbound only, so I skipped anything tagged as "inbound" in the scratch_install document. Should I add them back in?

What about your transfer AGI script, any output in agiout from that when you have problems?

This may be more helpful....

2006-11-22 7:41:32|call_log.agi|Perl Environment Dump:2006-11-22 7:41:32|call_log.agi|0|83652006-11-22 7:41:32|call_log.agi|AGI Environment Dump:2006-11-22 7:41:32|call_log.agi| -- accountcode =2006-11-22 7:41:32|call_log.agi| -- callerid = 48478272002006-11-22 7:41:32|call_log.agi| -- calleridname = V11220740560000000032006-11-22 7:41:32|call_log.agi| -- callingani2 = 02006-11-22 7:41:32|call_log.agi| -- callingpres = 02006-11-22 7:41:32|call_log.agi| -- callingtns = 02006-11-22 7:41:32|call_log.agi| -- callington = 02006-11-22 7:41:32|call_log.agi| -- channel = Local/917173304813@default-3efa,12006-11-22 7:41:32|call_log.agi| -- context = default2006-11-22 7:41:32|call_log.agi| -- dnid = unknown2006-11-22 7:41:32|call_log.agi| -- enhanced = 0.02006-11-22 7:41:32|call_log.agi| -- extension = 83652006-11-22 7:41:32|call_log.agi| -- language = en2006-11-22 7:41:32|call_log.agi| -- priority = 12006-11-22 7:41:32|call_log.agi| -- rdnis = unknown2006-11-22 7:41:32|call_log.agi| -- request = call_log.agi2006-11-22 7:41:32|call_log.agi| -- type = Local2006-11-22 7:41:32|call_log.agi| -- uniqueid = 1164199256.982006-11-22 7:41:32|call_log.agi|AGI Variables: |1164199256.98|Local/917173304813@default-3efa,1|8365|Local|V1122074056000000003|2006-11-22 7:41:32|call_log.agi|+++++ CALL LOG START : 2006-11-22 7:41:322006-11-22 7:41:32|call_log.agi||INSERT INTO call_log (uniqueid,channel,channel_group,type,server_ip,extension,number_dialed,start_time,start_epoch,end_time,end_epoch,length_in_sec,length_in_min,caller_code) values('1164199256.98','Local/917173304813@default-3efa,1','','Local','10.10.11.30','8365','','2006-11-22 7:41:32','1164199292','','','','','V1122074056000000003')|
2006-11-22 7:41:32|call_log.agi|AGI Environment Dump:2006-11-22 7:41:32|call_log.agi| -- accountcode =2006-11-22 7:41:32|call_log.agi| -- callerid = 48478272002006-11-22 7:41:32|call_log.agi| -- calleridname = V11220740560000000032006-11-22 7:41:32|call_log.agi| -- callingani2 = 02006-11-22 7:41:32|call_log.agi| -- callingpres = 02006-11-22 7:41:32|call_log.agi| -- callingtns = 02006-11-22 7:41:32|call_log.agi| -- callington = 02006-11-22 7:41:32|call_log.agi| -- channel = Local/917173304813@default-3efa,22006-11-22 7:41:32|call_log.agi| -- context = default2006-11-22 7:41:32|call_log.agi| -- dnid = unknown2006-11-22 7:41:32|call_log.agi| -- enhanced = 0.02006-11-22 7:41:32|call_log.agi| -- extension = h2006-11-22 7:41:32|call_log.agi| -- language = en2006-11-22 7:41:32|call_log.agi| -- priority = 12006-11-22 7:41:32|call_log.agi| -- rdnis = unknown2006-11-22 7:41:32|call_log.agi| -- request = call_log.agi2006-11-22 7:41:32|call_log.agi| -- type = Local2006-11-22 7:41:32|call_log.agi| -- uniqueid = 1164199256.992006-11-22 7:41:32|call_log.agi|AGI Variables: |1164199256.99|Local/917173304813@default-3efa,2|h|Local|V1122074056000000003|2006-11-22 7:41:32|call_log.agi||CALL HUNG UP|2006-11-22 7:41:32|call_log.agi||1164199256.9900000|1164199256|2006-11-22 7:41:32|call_log.agi|QUERY done: start time = 1164199256 | sec: 36 | min: 0.60 |2006-11-22 7:41:32|call_log.agi||UPDATE call_log set end_time='2006-11-22 7:41:32',end_epoch='1164199292',length_in_sec=36,length_in_min=' 0.60' where uniqueid='1164199256.99'|2006-11-22 7:41:32|call_log.agi||DELETE from live_inbound where uniqueid='1164199256.99' and server_ip='10.10.11.30'|
2006-11-22 7:41:32|call_log.agi|+++++ CALL LOG HUNGUP: |1164199256.99|Local/917173304813@default-3efa,2|h|2006-11-22 7:41:32|min: 0.60|
2006-11-22 7:41:32|agi-VDADtransfer.agi|Perl Environment Dump:
2006-11-22 7:41:32|agi-VDADtransfer.agi|0|8365
2006-11-22 7:41:32|agi-VDADtransfer.agi|callerID changed: V1122074056000000003
2006-11-22 7:41:32|agi-VDADtransfer.agi|AGI Environment Dump:
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- accountcode =
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- callerid = 4847827200
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- calleridname = V1122074056000000003
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- callingani2 = 0
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- callingpres = 0
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- callingtns = 0
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- callington = 0
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- channel = Zap/1-1
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- context = default
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- dnid = unknown
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- enhanced = 0.0
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- extension = 8365
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- language = en
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- priority = 2
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- rdnis = unknown
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- type = Zap
2006-11-22 7:41:32|agi-VDADtransfer.agi| -- uniqueid = 1164199256.98
2006-11-22 7:41:32|agi-VDADtransfer.agi|AGI Variables: |1164199256.98|Zap/1-1|8365|Zap|V1122074056000000003|V1122074056000000003|2|
2006-11-22 7:41:32|agi-VDADtransfer.agi|+++++ VDAD START : |3|2006-11-22 7:41:32|1.2.12.1|2|
2006-11-22 7:41:32|agi-VDADtransfer.agi|-- VDAD : |1|update of vac table: V1122074056000000003
|UPDATE vicidial_auto_calls set uniqueid='1164199256.98', channel='Zap/1-1',status='LIVE' where callerid='V1122074056000000003' order by call_time desc limit 1;|
2006-11-22 7:41:32|agi-VDADtransfer.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed) values('1164199256.98','3','9999','2006-11-22 7:41:32','1164199292','QUEUE','1','7173304813','VDAD','N')|
2006-11-22 7:41:32|agi-VDADtransfer.agi|-- VDAD : |3|3|insert to vicidial_log: 1164199256.982006-11-22 7:41:32|VD_hangup.agi|Perl Environment Dump:
2006-11-22 7:41:32|VD_hangup.agi|0|PRI-----NODEBUG-----16-----ANSWER-----36-----0
2006-11-22 7:41:32|VD_hangup.agi|AGI Environment Dump:
2006-11-22 7:41:32|VD_hangup.agi| -- accountcode =2006-11-22 7:41:32|VD_hangup.agi| -- callerid = 48478272002006-11-22 7:41:32|VD_hangup.agi| -- calleridname = V1122074056000000003
2006-11-22 7:41:32|VD_hangup.agi| -- callingani2 = 0
2006-11-22 7:41:32|VD_hangup.agi| -- callingpres = 0
2006-11-22 7:41:32|VD_hangup.agi| -- callingtns = 0
2006-11-22 7:41:32|VD_hangup.agi| -- callington = 0
2006-11-22 7:41:32|VD_hangup.agi| -- channel = Local/917173304813@default-3efa,2
2006-11-22 7:41:32|VD_hangup.agi| -- context = default
2006-11-22 7:41:32|VD_hangup.agi| -- dnid = unknown
2006-11-22 7:41:32|VD_hangup.agi| -- enhanced = 0.0
2006-11-22 7:41:32|VD_hangup.agi| -- extension = h
2006-11-22 7:41:32|VD_hangup.agi| -- language = en
2006-11-22 7:41:32|VD_hangup.agi| -- priority = 2
2006-11-22 7:41:32|VD_hangup.agi| -- rdnis = unknown
2006-11-22 7:41:32|VD_hangup.agi| -- request = VD_hangup.agi
2006-11-22 7:41:32|VD_hangup.agi| -- type = Local
2006-11-22 7:41:32|VD_hangup.agi| -- uniqueid = 1164199256.99
2006-11-22 7:41:32|VD_hangup.agi|AGI Variables: |1164199256.99|Local/917173304813@default-3efa,2|h|Local|V1122074056000000003|
2006-11-22 7:41:32|VD_hangup.agi|DEBUG: NODEBUG
2006-11-22 7:41:32|VD_hangup.agi|VD_hangup : V1122074056000000003 Local/917173304813@default-3efa,2 2 3
2006-11-22 7:41:32|VD_hangup.agi|-- VDhangup Local DEBUG: |PRI|V1122074056000000003|ANSWER|16|
2006-11-22 7:41:32|VD_hangup.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 2

What version of asterisk-perl module are you using?

asterisk-perl-0.09

doesn't work with VICIDIAL, you need to use 0.08 as specified in the SCRATCH_INSTALL.