vicidial.org

VICIDIAL astGUIclient discussion forum
http://forum.eflo.net/VICIDIALforum/

[SOLVED] Auto calls with DAHDI and LB not working

http://forum.eflo.net/VICIDIALforum/viewtopic.php?f=4&t=37528

Page 1 of 1

[SOLVED] Auto calls with DAHDI and LB not working

PostPosted: Tue Aug 01, 2017 10:15 am
by airflux
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.

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

PostPosted: Wed Aug 02, 2017 5:18 am
by airflux
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?

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

PostPosted: Wed Aug 02, 2017 7:18 am
by mflorell
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!

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

PostPosted: Wed Aug 02, 2017 12:21 pm
by airflux
Thank you Matt for Vicidial :)
All times are UTC - 5 hours
Page 1 of 1
Powered by phpBB® Forum Software © phpBB Group
http://www.phpbb.com/