vicidial.org

by **airflux** » Tue Aug 01, 2017 10:15 am

Hi guy, I need a guru that helps me.. any help will be appreciated

I'm going crazy with auto calls over PRI (dahdi) that doesn't works, auto calls over VOIP trunk and manual calls over PRI and VOIP works fine as always. I got a 7 server cluster with asterisk 11.25.1-vici, SVN version 2796: 1 db, 2 www, 4 dialers, load balance active.

Using dahdi on auto calls, called number receives the call and answer it normally, Vicidial "knows" about this answer but doesn't route it to the agent (READY) that see on the agent screen "Calls in queue: 1" for some second before the called number (customer) hangup.

I think that FastAGI_log.pl creates the problem, but I can't find the cause. Comparing dialplan output of working (voip trunk) and not working version (dahdi trunk) the are 2 differences in the not working version:
1) AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTCAMP)) is missing on the extension 8368 (default call routing with lb).
2) <DAHDI/i1/340XXXXXXX-13>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 4, returns 4 and not 0 as "no error"

When /usr/share/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi is launched, there are no CAMPCUST in channel variables, then the agi script can't find the right server to send the call. But I'm not sure about that.

Dialplan output of working version (voip trunk)

Code: Select all: [Aug 1 15:10:29] -- Executing [9999340XXXXXXX@default:1] NoOp("Local/9999340XXXXXXX@default-00000001;2", "AUTO") in new stack [Aug 1 15:10:29] -- Executing [9999340XXXXXXX@default:2] AGI("Local/9999340XXXXXXX@default-00000001;2", "agi://127.0.0.1:4577/call_log") in new stack [Aug 1 15:10:29] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTCAMP)) [Aug 1 15:10:29] -- <Local/9999340XXXXXXX@default-00000001;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0 [Aug 1 15:10:29] -- Executing [9999340XXXXXXX@default:3] Dial("Local/9999340XXXXXXX@default-00000001;2", "SIP/voiptrunk/340XXXXXXX,,To") in new stack [Aug 1 15:10:29] == Using SIP RTP CoS mark 5 [Aug 1 15:10:29] -- Called SIP/voiptrunk/340XXXXXXX [Aug 1 15:10:32] -- SIP/voiptrunk-00000002 is ringing [Aug 1 15:10:35] -- SIP/voiptrunk-00000002 answered Local/9999340XXXXXXX@default-00000001;2 [Aug 1 15:10:35] > Channel Local/9999340XXXXXXX@default-00000001;1 was answered [Aug 1 15:10:35] -- Executing [h@default:1] AGI("Local/9999340XXXXXXX@default-00000001;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----6-----0") in new stack [Aug 1 15:10:35] -- Executing [8368@default:1] Playback("SIP/voiptrunk-00000002", "sip-silence") in new stack [Aug 1 15:10:35] -- <SIP/voiptrunk-00000002> Playing 'sip-silence.gsm' (language 'it') [Aug 1 15:10:35] -- Executing [8368@default:2] AGI("SIP/voiptrunk-00000002", "agi://127.0.0.1:4577/call_log") in new stack [Aug 1 15:10:35] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTCAMP)) [Aug 1 15:10:35] -- <SIP/voiptrunk-00000002>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0 [Aug 1 15:10:35] -- Executing [8368@default:3] AGI("SIP/voiptrunk-00000002", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack [Aug 1 15:10:35] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi [Aug 1 15:10:35] -- <SIP/voiptrunk-00000002>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0 [Aug 1 15:10:35] -- Executing [172*016*072*052*8600053@default:1] Dial("SIP/voiptrunk-00000002", "IAX2/vicit5:CENSORED@172.16.72.52:4569/8600053,55,oT") in new stack [Aug 1 15:10:35] -- Called IAX2/vicit5:CENSORED@172.16.72.52:4569/8600053 [Aug 1 15:10:35] -- Call accepted by 172.16.72.52 (format ulaw) [Aug 1 15:10:35] -- Format for call is (ulaw) [Aug 1 15:10:35] -- IAX2/vicit6-11986 answered SIP/voiptrunk-00000002 [Aug 1 15:10:36] -- <Local/9999340XXXXXXX@default-00000001;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----6-----0 completed, returning 0

Dialplan output of not working version (dahdi trunk)

Code: Select all: [Aug 1 15:52:02] -- Executing [9999340XXXXXXX@default:1] NoOp("Local/9999340XXXXXXX@default-00000001;2", "AUTO") in new stack [Aug 1 15:52:02] -- Executing [9999340XXXXXXX@default:2] AGI("Local/9999340XXXXXXX@default-00000001;2", "agi://127.0.0.1:4577/call_log") in new stack [Aug 1 15:52:02] -- AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTCAMP)) [Aug 1 15:52:02] -- <Local/9999340XXXXXXX@default-00000001;2>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0 [Aug 1 15:52:02] -- Executing [9999340XXXXXXX@default:3] Dial("Local/9999340XXXXXXX@default-00000001;2", "DAHDI/g11/340XXXXXXX,,To") in new stack [Aug 1 15:52:02] -- Requested transfer capability: 0x00 - SPEECH [Aug 1 15:52:02] -- Called DAHDI/g11/340XXXXXXX [Aug 1 15:52:05] -- DAHDI/i1/340XXXXXXX-2 is ringing [Aug 1 15:52:05] -- DAHDI/i1/340XXXXXXX-2 is making progress passing it to Local/9999340XXXXXXX@default-00000001;2 [Aug 1 15:52:10] -- DAHDI/i1/340XXXXXXX-2 answered Local/9999340XXXXXXX@default-00000001;2 [Aug 1 15:52:10] > Channel Local/9999340XXXXXXX@default-00000001;1 was answered [Aug 1 15:52:10] -- Executing [8368@default:1] Playback("Local/9999340XXXXXXX@default-00000001;1", "sip-silence") in new stack [Aug 1 15:52:10] -- <Local/9999340XXXXXXX@default-00000001;1> Playing 'sip-silence.gsm' (language 'en') [Aug 1 15:52:10] -- Executing [8368@default:2] AGI("Local/9999340XXXXXXX@default-00000001;1", "agi://127.0.0.1:4577/call_log") in new stack [Aug 1 15:52:10] -- <Local/9999340XXXXXXX@default-00000001;1>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0 [Aug 1 15:52:10] -- Executing [8368@default:3] AGI("Local/9999340XXXXXXX@default-00000001;1", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack [Aug 1 15:52:10] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi [Aug 1 15:52:10] -- Executing [h@default:1] AGI("Local/9999340XXXXXXX@default-00000001;2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----8-----0") in new stack [Aug 1 15:52:11] == Manager 'sendcron' logged off from 127.0.0.1 [Aug 1 15:52:11] -- <Local/9999340XXXXXXX@default-00000001;2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----8-----0 completed, returning 0 [Aug 1 15:52:11] == Spawn extension (default, 9999340XXXXXXX, 3) exited non-zero on 'Local/9999340XXXXXXX@default-00000001;2' [Aug 1 15:52:11] -- <DAHDI/i1/340XXXXXXX-2>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0 [Aug 1 15:52:11] -- Executing [8368@default:4] AGI("DAHDI/i1/340XXXXXXX-2", "agi-VDAD_ALL_outbound.agi,NORMAL-----LB") in new stack [Aug 1 15:52:11] -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi [Aug 1 15:52:21] -- <DAHDI/i1/340XXXXXXX-2>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 4 [Aug 1 15:52:21] == Spawn extension (default, 8368, 4) exited non-zero on 'DAHDI/i1/340XXXXXXX-2' [Aug 1 15:52:21] -- Executing [h@default:1] AGI("DAHDI/i1/340XXXXXXX-2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack [Aug 1 15:52:21] -- <DAHDI/i1/340XXXXXXX-2>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0--------------- completed, returning 0 [Aug 1 15:52:21] -- Hungup 'DAHDI/i1/340XXXXXXX-2'

DAHDI trunk carrier setup on server vicit3 (172.16.72.46)
exten => _9999[03][1-9]XXXXX.,1,NoOp(AUTO)
same => n,AGI(agi://127.0.0.1:4577/call_log)
same => n,Dial(DAHDI/g11/${EXTEN:4},,To)
same => n,Hangup()

VOIP trunk carrier setup on server vicit5 (172.16.72.50)
exten => _9999[03][1-9]XXXXX.,1,NoOp(AUTO)
same => n,AGI(agi://127.0.0.1:4577/call_log)
same => n,Dial(SIP/voiptrunk/${EXTEN:4},,To)
same => n,Hangup

Agent with phone pc001 is connected on vicit6 (172.16.72.52)
Called phone number: 340XXXXXXX

FASTagiout log here of not working version

Code: Select all: 2017-08-01 15:54:02|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++ 2017-08-01 15:54:02|VDfastAGI|begin|Perl Environment Dump: 2017-08-01 15:54:02|VDfastAGI|begin|0|--debug 2017-08-01 15:54:02|VDfastAGI|begin|URL HVcauses: |PRI|NODEBUG|16|ANSWER|6|6| 2017-08-01 15:54:02|VDfastAGI|begin|AGI Environment Dump: 2017-08-01 15:54:02|VDfastAGI|begin| -- accountcode = 2017-08-01 15:54:02|VDfastAGI|begin| -- callerid = 0863XXXXXX 2017-08-01 15:54:02|VDfastAGI|begin| -- calleridname = V8011554020000006019 2017-08-01 15:54:02|VDfastAGI|begin| -- callingani2 = 0 2017-08-01 15:54:02|VDfastAGI|begin| -- callingpres = 0 2017-08-01 15:54:02|VDfastAGI|begin| -- callingtns = 0 2017-08-01 15:54:02|VDfastAGI|begin| -- callington = 0 2017-08-01 15:54:02|VDfastAGI|begin| -- channel = Local/9999340XXXXXXX@default-00000002;2 2017-08-01 15:54:02|VDfastAGI|begin| -- context = default 2017-08-01 15:54:02|VDfastAGI|begin| -- dnid = unknown 2017-08-01 15:54:02|VDfastAGI|begin| -- enhanced = 0.0 2017-08-01 15:54:02|VDfastAGI|begin| -- extension = 9999340XXXXXXX 2017-08-01 15:54:02|VDfastAGI|begin| -- language = en 2017-08-01 15:54:02|VDfastAGI|begin| -- network = yes 2017-08-01 15:54:02|VDfastAGI|begin| -- network_script = call_log 2017-08-01 15:54:02|VDfastAGI|begin| -- priority = 2 2017-08-01 15:54:02|VDfastAGI|begin| -- rdnis = unknown 2017-08-01 15:54:02|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log 2017-08-01 15:54:02|VDfastAGI|begin| -- threadid = 140473295861504 2017-08-01 15:54:02|VDfastAGI|begin| -- type = Local 2017-08-01 15:54:02|VDfastAGI|begin| -- uniqueid = 1501595642.7 2017-08-01 15:54:02|VDfastAGI|begin| -- version = 11.25.1-vici 2017-08-01 15:54:02|VDfastAGI|begin|AGI Variables: |1501595642.7|Local/9999340XXXXXXX@default-00000002;2|9999340XXXXXXX|Local|V8011554020000006019| 2017-08-01 15:54:02|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log|call_log|START| 2017-08-01 15:54:02|VDfastAGI|call_log|+++++ CALL LOG START : 2017-08-01 15:54:02 2017-08-01 15:54:02|VDfastAGI|call_log|Local Channel Line: 0|9999340XXXXXXX| 2017-08-01 15:54:02|VDfastAGI|call_log||CAMPCUST: T_ULL|V8011554020000006019| 2017-08-01 15:54:02|VDfastAGI|call_log||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('1501595642.7','Local/9999340XXXXXXX@default-00000002;2','Local Channel Line','Local','172.16.72.46','9999340XXXXXXX','9999340XXXXXXX','2017-08-01 15:54:02','1501595642','','','','','V8011554020000006019')| 2017-08-01 15:54:12|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++ 2017-08-01 15:54:12|VDfastAGI|begin|Perl Environment Dump: 2017-08-01 15:54:12|VDfastAGI|begin|0|--debug 2017-08-01 15:54:12|VDfastAGI|begin|URL HVcauses: |PRI|NODEBUG|16|ANSWER|8|8| 2017-08-01 15:54:12|VDfastAGI|begin|AGI Environment Dump: 2017-08-01 15:54:12|VDfastAGI|begin| -- accountcode = 2017-08-01 15:54:12|VDfastAGI|begin| -- callerid = unknown 2017-08-01 15:54:12|VDfastAGI|begin| -- calleridname = unknown 2017-08-01 15:54:12|VDfastAGI|begin| -- callingani2 = 0 2017-08-01 15:54:12|VDfastAGI|begin| -- callingpres = 35 2017-08-01 15:54:12|VDfastAGI|begin| -- callingtns = 0 2017-08-01 15:54:12|VDfastAGI|begin| -- callington = 0 2017-08-01 15:54:12|VDfastAGI|begin| -- channel = DAHDI/i1/-4 2017-08-01 15:54:12|VDfastAGI|begin| -- context = default 2017-08-01 15:54:12|VDfastAGI|begin| -- dnid = 8635098 2017-08-01 15:54:12|VDfastAGI|begin| -- enhanced = 0.0 2017-08-01 15:54:12|VDfastAGI|begin| -- extension = h 2017-08-01 15:54:12|VDfastAGI|begin| -- language = it 2017-08-01 15:54:12|VDfastAGI|begin| -- network = yes 2017-08-01 15:54:12|VDfastAGI|begin| -- network_script = call_log--HVcauses--PRI-----NODEBUG-----16--------------- 2017-08-01 15:54:12|VDfastAGI|begin| -- priority = 1 2017-08-01 15:54:12|VDfastAGI|begin| -- rdnis = unknown 2017-08-01 15:54:12|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- 2017-08-01 15:54:12|VDfastAGI|begin| -- threadid = 140473300039424 2017-08-01 15:54:12|VDfastAGI|begin| -- type = DAHDI 2017-08-01 15:54:12|VDfastAGI|begin| -- uniqueid = 1501595652.9 2017-08-01 15:54:12|VDfastAGI|begin| -- version = 11.25.1-vici 2017-08-01 15:54:12|VDfastAGI|begin|AGI Variables: |1501595652.9|DAHDI/i1/-4|h|DAHDI|unknown| 2017-08-01 15:54:12|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------|call_log|END| 2017-08-01 15:54:12|VDfastAGI|call_log||CALL HUNG UP| 2017-08-01 15:54:12|VDfastAGI|call_log|URL HVcauses: |PRI|NODEBUG|16|||0| 2017-08-01 15:54:12|VDfastAGI|call_log||1501595652.9|1501595652|DAHDI/i1/-4|| 2017-08-01 15:54:12|VDfastAGI|call_log||UPDATE call_log set end_time='2017-08-01 15:54:12',end_epoch='1501595652',length_in_sec=0,length_in_min=' 0.00',channel='DAHDI/i1/-4' where uniqueid='1501595652.9'| 2017-08-01 15:54:12|VDfastAGI|call_log|QUERY done: start time = 1501595652 | sec: 0 | min: 0.00 |1 2017-08-01 15:54:12|VDfastAGI|call_log||DELETE from live_inbound where uniqueid IN('1501595652.9','1501595652.9') and server_ip='172.16.72.46'| 2017-08-01 15:54:12|VDfastAGI|call_log|+++++ CALL LOG HUNGUP: |1501595652.9|DAHDI/i1/-4|h|2017-08-01 15:54:12|min: 0.00| 2017-08-01 15:54:12|VDfastAGI|call_log|DEBUG: NODEBUG 2017-08-01 15:54:12|VDfastAGI|call_log|VD_hangup : unknown DAHDI/i1/-4 1 0 2017-08-01 15:54:12|VDfastAGI|call_log||SELECT lead_id,callerid,campaign_id,alt_dial,stage,UNIX_TIMESTAMP(call_time),uniqueid,status,call_time,phone_code,phone_number,queue_position,server_ip FROM vicidial_auto_calls where uniqueid = '1501595652.9' or callerid = 'unknown' limit 1;| 2017-08-01 15:54:12|VDfastAGI|call_log|VD hangup: no VDAC record found: 1501595652.9 unknown 2017-08-01 15:54:14|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++ 2017-08-01 15:54:14|VDfastAGI|begin|Perl Environment Dump: 2017-08-01 15:54:14|VDfastAGI|begin|0|--debug 2017-08-01 15:54:14|VDfastAGI|begin|URL HVcauses: |PRI|NODEBUG|16|ANSWER|12|12| 2017-08-01 15:54:14|VDfastAGI|begin|AGI Environment Dump: 2017-08-01 15:54:14|VDfastAGI|begin| -- accountcode = 2017-08-01 15:54:14|VDfastAGI|begin| -- callerid = 0863XXXXXX 2017-08-01 15:54:14|VDfastAGI|begin| -- calleridname = V8011554020000006019 2017-08-01 15:54:14|VDfastAGI|begin| -- callingani2 = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- callingpres = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- callingtns = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- callington = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- channel = Local/9999340XXXXXXX@default-00000002;2 2017-08-01 15:54:14|VDfastAGI|begin| -- context = default 2017-08-01 15:54:14|VDfastAGI|begin| -- dnid = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- enhanced = 0.0 2017-08-01 15:54:14|VDfastAGI|begin| -- extension = h 2017-08-01 15:54:14|VDfastAGI|begin| -- language = en 2017-08-01 15:54:14|VDfastAGI|begin| -- network = yes 2017-08-01 15:54:14|VDfastAGI|begin| -- network_script = call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----12-----0 2017-08-01 15:54:14|VDfastAGI|begin| -- priority = 1 2017-08-01 15:54:14|VDfastAGI|begin| -- rdnis = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----12-----0 2017-08-01 15:54:14|VDfastAGI|begin| -- threadid = 140473295861504 2017-08-01 15:54:14|VDfastAGI|begin| -- type = Local 2017-08-01 15:54:14|VDfastAGI|begin| -- uniqueid = 1501595642.7 2017-08-01 15:54:14|VDfastAGI|begin| -- version = 11.25.1-vici 2017-08-01 15:54:14|VDfastAGI|begin|AGI Variables: |1501595642.7|Local/9999340XXXXXXX@default-00000002;2|h|Local|V8011554020000006019| 2017-08-01 15:54:14|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----12-----0|call_log|END| 2017-08-01 15:54:14|VDfastAGI|call_log||CALL HUNG UP| 2017-08-01 15:54:14|VDfastAGI|call_log|URL HVcauses: |PRI|NODEBUG|16|ANSWER|12|12| 2017-08-01 15:54:14|VDfastAGI|call_log|1|SELECT sip_hangup_cause,sip_hangup_reason FROM vicidial_dial_log where lead_id='6019' and server_ip='172.16.72.46' and caller_code='V8011554020000006019' order by call_date desc limit 1;|0|| 2017-08-01 15:54:14|VDfastAGI|call_log||INSERT IGNORE INTO vicidial_carrier_log set uniqueid='1501595642.7',call_date='2017-08-01 15:54:14',server_ip='172.16.72.46',lead_id='6019',hangup_cause='16',dialstatus='ANSWER',channel='Local/9999340XXXXXXX@default-00000002;2',dial_time='12',answered_time='0',sip_hangup_cause='0',sip_hangup_reason='',caller_code='V8011554020000006019';| 2017-08-01 15:54:14|VDfastAGI|call_log|-- CARRIER LOG insert: |1|6019|16|0|| 2017-08-01 15:54:14|VDfastAGI|call_log||1501595642.7|1501595642|Local/9999340XXXXXXX@default-00000002;2|0| 2017-08-01 15:54:14|VDfastAGI|call_log||UPDATE call_log set end_time='2017-08-01 15:54:14',end_epoch='1501595654',length_in_sec=12,length_in_min=' 0.20',channel='Local/9999340XXXXXXX@default-00000002;2' where uniqueid='1501595642.7'| 2017-08-01 15:54:14|VDfastAGI|call_log|QUERY done: start time = 1501595642 | sec: 12 | min: 0.20 |1 2017-08-01 15:54:14|VDfastAGI|call_log||DELETE from live_inbound where uniqueid IN('1501595642.7','1501595642.7') and server_ip='172.16.72.46'| 2017-08-01 15:54:14|VDfastAGI|call_log|+++++ CALL LOG HUNGUP: |1501595642.7|Local/9999340XXXXXXX@default-00000002;2|h|2017-08-01 15:54:14|min: 0.20| 2017-08-01 15:54:14|VDfastAGI|call_log|DEBUG: NODEBUG 2017-08-01 15:54:14|VDfastAGI|call_log|VD_hangup : V8011554020000006019 Local/9999340XXXXXXX@default-00000002;2 1 6019 2017-08-01 15:54:14|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++ 2017-08-01 15:54:14|VDfastAGI|begin|Perl Environment Dump: 2017-08-01 15:54:14|VDfastAGI|begin|0|--debug 2017-08-01 15:54:14|VDfastAGI|begin|AGI Environment Dump: 2017-08-01 15:54:14|VDfastAGI|begin| -- accountcode = 2017-08-01 15:54:14|VDfastAGI|begin| -- callerid = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- calleridname = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- callingani2 = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- callingpres = 35 2017-08-01 15:54:14|VDfastAGI|begin| -- callingtns = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- callington = 0 2017-08-01 15:54:14|VDfastAGI|begin| -- channel = DAHDI/i1/340XXXXXXX-3 2017-08-01 15:54:14|VDfastAGI|begin| -- context = default 2017-08-01 15:54:14|VDfastAGI|begin| -- dnid = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- enhanced = 0.0 2017-08-01 15:54:14|VDfastAGI|begin| -- extension = 8368 2017-08-01 15:54:14|VDfastAGI|begin| -- language = it 2017-08-01 15:54:14|VDfastAGI|begin| -- network = yes 2017-08-01 15:54:14|VDfastAGI|begin| -- network_script = call_log 2017-08-01 15:54:14|VDfastAGI|begin| -- priority = 2 2017-08-01 15:54:14|VDfastAGI|begin| -- rdnis = unknown 2017-08-01 15:54:14|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log 2017-08-01 15:54:14|VDfastAGI|begin| -- threadid = 140473300039424 2017-08-01 15:54:14|VDfastAGI|begin| -- type = DAHDI 2017-08-01 15:54:14|VDfastAGI|begin| -- uniqueid = 1501595642.6 2017-08-01 15:54:14|VDfastAGI|begin| -- version = 11.25.1-vici 2017-08-01 15:54:14|VDfastAGI|begin|AGI Variables: |1501595642.6|DAHDI/i1/340XXXXXXX-3|8368|DAHDI|unknown| 2017-08-01 15:54:14|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log|call_log|START| 2017-08-01 15:54:14|VDfastAGI|call_log|+++++ CALL LOG START : 2017-08-01 15:54:14 2017-08-01 15:54:14|VDfastAGI|call_log|Zap Trunk Line: 0|i1/340XXXXXXX-3| 2017-08-01 15:54:14|VDfastAGI|call_log||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('1501595642.6','DAHDI/i1/340XXXXXXX-3','Zap Trunk Line','DAHDI','172.16.72.46','8368','8368','2017-08-01 15:54:14','1501595654','','','','','unknown')| 2017-08-01 15:54:14|VDfastAGI|call_log|0||SELECT result FROM vicidial_cpd_log where callerid='V8011554020000006019' and result NOT IN('Voice','Unknown','???','') order by cpd_id desc limit 1;| 2017-08-01 15:54:14|VDfastAGI|call_log|-- VD_hangup Local DEBUG: |PRI|V8011554020000006019|ANSWER|16|0|| 2017-08-01 15:54:14|VDfastAGI|call_log|+++++ VDAD START LOCAL CHANNEL: EXITING- 1 2017-08-01 15:54:19|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++ 2017-08-01 15:54:19|VDfastAGI|begin|Perl Environment Dump: 2017-08-01 15:54:19|VDfastAGI|begin|0|--debug 2017-08-01 15:54:19|VDfastAGI|begin|URL HVcauses: |PRI|NODEBUG|16|||0| 2017-08-01 15:54:19|VDfastAGI|begin|AGI Environment Dump: 2017-08-01 15:54:19|VDfastAGI|begin| -- accountcode = 2017-08-01 15:54:19|VDfastAGI|begin| -- callerid = unknown 2017-08-01 15:54:19|VDfastAGI|begin| -- calleridname = unknown 2017-08-01 15:54:19|VDfastAGI|begin| -- callingani2 = 0 2017-08-01 15:54:19|VDfastAGI|begin| -- callingpres = 35 2017-08-01 15:54:19|VDfastAGI|begin| -- callingtns = 0 2017-08-01 15:54:19|VDfastAGI|begin| -- callington = 0 2017-08-01 15:54:19|VDfastAGI|begin| -- channel = DAHDI/i1/340XXXXXXX-3 2017-08-01 15:54:19|VDfastAGI|begin| -- context = default 2017-08-01 15:54:19|VDfastAGI|begin| -- dnid = unknown 2017-08-01 15:54:19|VDfastAGI|begin| -- enhanced = 0.0 2017-08-01 15:54:19|VDfastAGI|begin| -- extension = h 2017-08-01 15:54:19|VDfastAGI|begin| -- language = it 2017-08-01 15:54:19|VDfastAGI|begin| -- network = yes 2017-08-01 15:54:19|VDfastAGI|begin| -- network_script = call_log--HVcauses--PRI-----NODEBUG-----16--------------- 2017-08-01 15:54:19|VDfastAGI|begin| -- priority = 1 2017-08-01 15:54:19|VDfastAGI|begin| -- rdnis = unknown 2017-08-01 15:54:19|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- 2017-08-01 15:54:19|VDfastAGI|begin| -- threadid = 140473300039424 2017-08-01 15:54:19|VDfastAGI|begin| -- type = DAHDI 2017-08-01 15:54:19|VDfastAGI|begin| -- uniqueid = 1501595642.6 2017-08-01 15:54:19|VDfastAGI|begin| -- version = 11.25.1-vici 2017-08-01 15:54:19|VDfastAGI|begin|AGI Variables: |1501595642.6|DAHDI/i1/340XXXXXXX-3|h|DAHDI|unknown| 2017-08-01 15:54:19|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------|call_log|END| 2017-08-01 15:54:19|VDfastAGI|call_log||CALL HUNG UP| 2017-08-01 15:54:19|VDfastAGI|call_log|URL HVcauses: |PRI|NODEBUG|16|||0| 2017-08-01 15:54:19|VDfastAGI|call_log||1501595642.6|1501595654|DAHDI/i1/340XXXXXXX-3|0| 2017-08-01 15:54:19|VDfastAGI|call_log||UPDATE call_log set end_time='2017-08-01 15:54:19',end_epoch='1501595659',length_in_sec=5,length_in_min=' 0.08',channel='DAHDI/i1/340XXXXXXX-3' where uniqueid='1501595642.6'| 2017-08-01 15:54:19|VDfastAGI|call_log|QUERY done: start time = 1501595654 | sec: 5 | min: 0.08 |1 2017-08-01 15:54:19|VDfastAGI|call_log||DELETE from live_inbound where uniqueid IN('1501595642.6','1501595642.6') and server_ip='172.16.72.46'| 2017-08-01 15:54:19|VDfastAGI|call_log|+++++ CALL LOG HUNGUP: |1501595642.6|DAHDI/i1/340XXXXXXX-3|h|2017-08-01 15:54:19|min: 0.08| 2017-08-01 15:54:19|VDfastAGI|call_log|DEBUG: NODEBUG 2017-08-01 15:54:19|VDfastAGI|call_log|VD_hangup : unknown DAHDI/i1/340XXXXXXX-3 1 0 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT lead_id,callerid,campaign_id,alt_dial,stage,UNIX_TIMESTAMP(call_time),uniqueid,status,call_time,phone_code,phone_number,queue_position,server_ip FROM vicidial_auto_calls where uniqueid = '1501595642.6' or callerid = 'unknown' limit 1;| 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT channel from parked_channels where channel_group='unknown';| 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT channel,server_ip from parked_channels_recent where channel_group='unknown' and park_end_time > "2017-08-01 13:54:19" order by park_end_time desc limit 1;| 2017-08-01 15:54:19|VDfastAGI|call_log|-- VDAC record deleted: |1| |0|1501595642.6|1501595642.6|unknown|unknown|LIVE|DAHDI/i1/340XXXXXXX-3(172.16.72.46)|(172.16.72.46)|(0|0)| 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT start_epoch,status,user,term_reason,comments FROM vicidial_log FORCE INDEX(lead_id) where lead_id = '0' and uniqueid LIKE "1501595642%" limit 1;| 2017-08-01 15:54:19|VDfastAGI|call_log|no VDL record found: 1501595642.6 unknown 0 1501595642.6 1501595642.6 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT start_epoch,status,closecallid,user,term_reason,length_in_sec,queue_seconds,comments FROM vicidial_closer_log where lead_id = '0' and call_date > "2017-08-01 09:54:19" order by closecallid desc limit 1;| 2017-08-01 15:54:19|VDfastAGI|call_log|no VDL or VDCL record found: 1501595642.6 unknown 0 1501595642.6 1501595642.6 |1|unknown| 2017-08-01 15:54:19|VDfastAGI|call_log||SELECT auto_alt_dial,auto_alt_dial_statuses,use_internal_dnc,use_campaign_dnc,use_other_campaign_dnc FROM vicidial_campaigns where campaign_id='';|

The strange part on agi output is the DAHDI channel, sometimes is DAHDI/i1/-4, sometime DAHDI/i1/340XXXXXXX-3.

by **airflux** » Wed Aug 02, 2017 5:18 am

I've just found the solution in onother post: http://www.vicidial.org/VICIDIALforum/viewtopic.php?f=4&t=34419&p=118563&hilit=dahdi#p119324
The problem is caused by the missing callerid in the Dial, but I don't understand why appens.

Add the bold row in carrier config:
exten => _91X.,1,AGI(agi://127.0.0.1:4577/call_log);
exten => _91X.,n,Set(_Missing_CLID1=${CALLERID(all)});
exten => _91X.,n,Dial(${ogtrunk}/0${EXTEN:2},,tToR)
exten => _91X.,n,Hangup()

Add the bold row in extension.conf or create a new one:
exten => 8368,1,Playback(sip-silence)
exten => 8368,n,Set(CALLERID(all)=${Missing_CLID1});
exten => 8368,n,AGI(agi://127.0.0.1:4577/call_log)
exten => 8368,n,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
exten => 8368,n,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
exten => 8368,n,Hangup()

That adds the callerid like you can see:
Executing [8368@default:2] Set("DAHDI/i1/340XXXXXXX-3c", "CALLERID(all)="V8021201110000006022" <0863XXXXX>") in new stack
then VDAD_ALL_outbound.agi stopped returning "error 4"
<DAHDI/i1/340XXXXXXX-3c>AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
because call_log agi script now execute the second
AGI Script Executing Application: (EXEC) Options: (Set(_CAMPCUST=TESTCAMP))
that was missing before that.

I hope this will help someone else.

Matt, this is something that can be fixed on Vicidial or is not a problem, maybe can be something related to a bad configuration?

by **mflorell** » Wed Aug 02, 2017 7:18 am

For about the last year we've noticed that some equipment at some carriers has the ability to overwrite the CID on phone calls on Asterisk servers by using messaging that for some reason Asterisk cannot be set to ignore. We never have gotten any explanations from the affected carriers of why this happens, and many of the CIDs that the calls are changed to make no sense at all, like "Phone Call <12>", just strange and useless information. So, my guess is that something similar is happening on your system.

Although, you seem to have found a very simple workaround for this that we've missed, so very good to you! We will have to give your method a try with some of our other affected clients, so thank you very much!

by **airflux** » Wed Aug 02, 2017 12:21 pm

Thank you Matt for Vicidial

vicidial.org

[SOLVED] Auto calls with DAHDI and LB not working

[SOLVED] Auto calls with DAHDI and LB not working

Re: Auto calls with DAHDI and LB problem - FastAGI_log.pl?

Re: [SOLVED] Auto calls with DAHDI and LB not working

Re: [SOLVED] Auto calls with DAHDI and LB not working

Who is online