vicidial.org

Posted: **Tue Apr 05, 2011 5:36 am**

Goautodial - VERSION: 2.2.1-237, BUILD: 100510-2015
We have installed goautodial behind 2 IPBXs, each ipbx connected to a different provider.
Manual dialling thru both pbxs works.However, using the same campaign settings, ratio dial drops calls after 2secs thru one provider (P1) but works on the other (P2). On P1, the output of agiout.2011-04-05 looks like this :

2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|callerID changed: V0405112950000000090
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- accountcode =
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- callerid = 0000000000
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- calleridname = V0405112950000000090
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- channel = Local/0782120838@default-9daf,1
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- context = default
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- language = en
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- priority = 3
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- type = Local
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1301995791.63
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|AGI Variables: |1301995791.63|Local/0782120838@default-9daf,1|8368|Local|V0405112950000000090|V0405112950000000090|3|
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |90|2011-04-05 11:30:01|1.4.27.1-vici|3|
2011-04-05 11:30:01|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 3
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|callerID changed: V0405112950000000090
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- accountcode =
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- callerid = unknown
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- calleridname = V0405112950000000090
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- channel = Local/0782120838@default-9daf,1
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- context = default
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- language = en
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- priority = 4
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- type = Local
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1301995791.63
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|AGI Variables: |1301995791.63|Local/0782120838@default-9daf,1|8368|Local|V0405112950000000090|V0405112950000000090|4|
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |90|2011-04-05 11:30:03|1.4.27.1-vici|4|
2011-04-05 11:30:03|agi-VDAD_ALL_outbound.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 4

On P2 the output looks like this :

2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|callerID changed: V0405113744000000091
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- accountcode =
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- callerid = 0000000000
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- calleridname = V0405113744000000091
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- channel = SIP/lcr-00000015
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- context = default
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- language = en
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- priority = 3
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- type = SIP
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1301996264.69
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|AGI Variables: |1301996264.69|SIP/lcr-00000015|8368|SIP|V0405113744000000091|V0405113744000000091|3|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |91|2011-04-05 11:37:51|1.4.27.1-vici|3|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_live_agents where callerid='V0405113744000000091';|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where callerid='V0405113744000000091' and status IN('LIVE','XFER');|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|-- VDAD : |1|update of vac table: V0405113744000000091
|UPDATE vicidial_auto_calls set uniqueid='1301996264.69', channel='SIP/lcr-00000015',status='LIVE',stage='LIVE-0' where callerid='V0405113744000000091' order by call_time desc limit 1;|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='PU' where lead_id='91' and status NOT IN('CALLBK');|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|-- VDAD vicidial_list PU update: |1|1301996264.69|
2011-04-05 11:37:51|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) values('1301996264.69','91','801','2011-04-05 11:37:51','1301996271','QUEUE','1','0782120838','VDAD','N','NONE','8001')|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|-- VDAD : |91|91|insert to vicidial_log: 1301996264.69
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = '801' and call_time < "2011-04-05 11:37:44" and lead_id != '91';|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|-- VDAD get agent: |1|update of vla table: 801|10.18.10.61
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='91',uniqueid='1301996264.69', channel='SIP/lcr-00000015', call_server_ip='10.18.10.61', callerid='V0405113744000000091',comments='AUTO' where status = 'READY' and lead_id<1 and campaign_id='801' and last_update_time > '20110405113746' order by last_call_finish limit 1;|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where status IN('QUEUE','INCALL') and campaign_id='801' and callerid='V0405113744000000091' and channel='SIP/lcr-00000015' order by last_call_time limit 1;|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|-- VDAD XFER REMOTE: |1|update of vac table: V0405113744000000091
|UPDATE vicidial_auto_calls set status='XFER', stage='XFER-0' where callerid='V0405113744000000091';|
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|exiting the VDAD app, transferring call to 010*018*010*061*8600001
2011-04-05 11:37:51|agi-VDAD_ALL_outbound.agi|XXXXXXXXXX VDAD transferred: start|stop 2011-04-05 11:37:51|2011-04-05 11:37:51

Using P1, the call rings on my cell, i answer and its quiet, then it cuts after 2 secs. Of concern is the differences in the channels in the 2 extracts above.
The Master csv extracts are below.
Master.csv on P1

""V0405112950000000090" <0000000000>","0000000000","8368","default","Local/0782120838@default-9daf,1","","Hangup","","2011-04-05 11:29:51","2011-04-05 11:30:01","2011-04-05 11:30:04","13","3","ANSWERED","DOCUMENTATION","","1301995791.63",""
""V0405112950000000090" <0000000000>","0000000000","0782120838","default","Local/0782120838@default-9daf,2","SIP/lcr-00000013","Dial","SIP/lcr/0782120838||tTor","2011-04-05 11:29:51","2011-04-05 11:30:01","2011-04-05 11:30:04","13","3","ANSWERED","DOCUMENTATION","","1301995791.64",""

Master.csv on P2

""V0405113744000000091" <0000000000>","0000000000","0782120838","default","Local/0782120838@default-1ed7,2","SIP/lcr-00000015","Dial","SIP/lcr/0782120838||tTor","2011-04-05 11:37:44","2011-04-05 11:37:51","2011-04-05 11:37:51","7","0","ANSWERED","DOCUMENTATION","","1301996264.70",""

Please advice, seems this is also happening with a Vicidial install.

Posted: **Tue Apr 05, 2011 3:49 pm**

do you know the software and rule set of the 2nd provider and how it may differ from the first?

consider adding a valid callerid to the call

see if you can acquire sip debug information of the answered call and see how they differ.

there is a Reason the channel is remaining "local". Either no sound or something has not quite finished.

Posted: **Wed Apr 06, 2011 4:21 am**

Pls Note - to circumnavigate the rule about not posting URLS, i have changed to [at], replaced : with ;. Thank you

Regarding the software rule of each provider i am still to get more infor about that.

Callerid is set to 000000 in goautodial settings for both scenarios though it gets re-written on each respective pbx P1 and P2. Even on the cellphone the callerid for each provider shows.
I have managed to get the sip debug messages. After comparing the debug messages on P1 (dropping) and P2(working), the following is an extract of where there are differences
P1 (dropping) - extract

[Apr 6 09:39:44] -- <Local/0782120838[at]default-73b7,1> Playing 'sip-silence' (language 'en')
[Apr 6 09:39:44] WARNING[1466]: file.c:1292 waitstream_core: Unexpected control subclass '-1'
[Apr 6 09:39:44] -- Executing [8368[at]default:2] AGI("Local/0782120838[at]default-73b7,1", "agi;//127.0.0.1:4577/call_log") in new stack
[Apr 6 09:39:44] -- AGI Script agi;//127.0.0.1:4577/call_log completed, returning 0
[Apr 6 09:39:44] -- Executing [8368[at]default:3] AGI("Local/0782120838[at]default-73b7,1", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Apr 6 09:39:44] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Apr 6 09:39:45] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Apr 6 09:39:45] -- Executing [8368[at]default:4] AGI("Local/0782120838[at]default-73b7,1", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Apr 6 09:39:45] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Apr 6 09:39:46] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Apr 6 09:39:46] -- Executing [8368[at]default:5] Hangup("Local/0782120838[at]default-73b7,1", "") in new stack
[Apr 6 09:39:46] == Spawn extension (default, 8368, 5) exited non-zero on 'Local/0782120838[at]default-73b7,1'
[Apr 6 09:39:46] -- Executing [h[at]default:1] DeadAGI("Local/0782120838[at]default-73b7,1", "agi;//127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Apr 6 09:39:46] -- AGI Script agi;//127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0

P2 (working) - extract

[Apr 6 09:48:17] -- Executing [8368[at]default:1] Playback("Local/0782120838[at]default-e39c,1", "sip-silence") in new stack
[Apr 6 09:48:17] -- <Local/0782120838[at]default-e39c,1> Playing 'sip-silence' (language 'en')
[Apr 6 09:48:17] WARNING[3508]: file.c:1292 waitstream_core: Unexpected control subclass '-1'
[Apr 6 09:48:17] -- Executing [h[at]default:1] DeadAGI("Local/0782120838[at]default-e39c,2", "agi;//127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----0") in new stack
[Apr 6 09:48:17] -- AGI Script agi;//127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----0 completed, returning 0
[Apr 6 09:48:17] == Spawn extension (default, 0782120838, 2) exited non-zero on 'Local/0782120838[at]default-e39c,2'
[Apr 6 09:48:17] -- Executing [8368[at]default:2] AGI("SIP/lcr-00000029", "agi;//127.0.0.1:4577/call_log") in new stack
[Apr 6 09:48:17] -- AGI Script agi;//127.0.0.1:4577/call_log completed, returning 0
[Apr 6 09:48:17] -- Executing [8368[at]default:3] AGI("SIP/lcr-00000029", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack

i cant post full debug messages because of the rule about not posting URLS etc

Posted: **Mon Apr 11, 2011 6:08 am**

it would appear that there are differences in the call handling between the two machines. one is completely answering the call and has sound in both directions, whereas the other doesn't quite complete (which leaves the call as a "Local" call when it his the 8368 script ...).

the 8368 script rejects local calls (they should not be "local" when they reach this script's 2nd line). Line 1 begins transmitting sound on an answered channel ... another process will immediately (if sound begins transmitting) convert that channel from Local to something like "SIP/lcr-00000029". If that doesn't happen, vicidial will fail.

So how are the two machines different? Asterisk Version? One behind a firewall (possibly causing one-way or No sound)?

vicidial.org

Ratio Dial method dropping calls after 2 secs

Ratio Dial method dropping calls after 2 secs