vicidial.org

Using latest SVN. 2 servers load balanced- A and B, as per LOAD_BALANCING.TXT.
If server A uses server B to make the call, or vice versa, callerID from campaign setup is not displayed.
As far as I checked on our VoIP trunk it comes empty.

Here is FastAGI output when the agent is logged on server B, and call went through server A:

Code: Select all

2008-12-08 19:42:43|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++
2008-12-08 19:42:43|VDfastAGI|begin|Perl Environment Dump:
2008-12-08 19:42:43|VDfastAGI|begin|0|--debug
2008-12-08 19:42:43|VDfastAGI|begin|URL HVcauses: |PRI|NODEBUG|16||||
2008-12-08 19:42:43|VDfastAGI|begin|AGI Environment Dump:
2008-12-08 19:42:43|VDfastAGI|begin| -- accountcode =
2008-12-08 19:42:43|VDfastAGI|begin| -- callerid = unknown
2008-12-08 19:42:43|VDfastAGI|begin| -- calleridname = V1208194243001330695
2008-12-08 19:42:43|VDfastAGI|begin| -- callingani2 = 0
2008-12-08 19:42:43|VDfastAGI|begin| -- callingpres = 0
2008-12-08 19:42:43|VDfastAGI|begin| -- callingtns = 0
2008-12-08 19:42:43|VDfastAGI|begin| -- callington = 0
2008-12-08 19:42:43|VDfastAGI|begin| -- channel = Local/91778869XXXX@default-2ab4,2
2008-12-08 19:42:43|VDfastAGI|begin| -- context = default
2008-12-08 19:42:43|VDfastAGI|begin| -- dnid = unknown
2008-12-08 19:42:43|VDfastAGI|begin| -- enhanced = 0.0
2008-12-08 19:42:43|VDfastAGI|begin| -- extension = 91778869XXXX
2008-12-08 19:42:43|VDfastAGI|begin| -- language = en
2008-12-08 19:42:43|VDfastAGI|begin| -- network = yes
2008-12-08 19:42:43|VDfastAGI|begin| -- network_script = call_log
2008-12-08 19:42:43|VDfastAGI|begin| -- priority = 1
2008-12-08 19:42:43|VDfastAGI|begin| -- rdnis = unknown
2008-12-08 19:42:43|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log
2008-12-08 19:42:43|VDfastAGI|begin| -- type = Local
2008-12-08 19:42:43|VDfastAGI|begin| -- uniqueid = 1228794163.878463
2008-12-08 19:42:43|VDfastAGI|begin|AGI Variables: |1228794163.878463|Local/91778869XXXX@default-2ab4,2|91778869XXXX|Local|V1208194243001330695|
2008-12-08 19:42:43|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log|call_log|START|
2008-12-08 19:42:43|VDfastAGI|call_log|+++++ CALL LOG START : 2008-12-08 19:42:43
2008-12-08 19:42:43|VDfastAGI|call_log|EXTERNAL Client Phone: 1|91778869XXXX|
2008-12-08 19:42:43|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('1228794163.878463','Local/91778869XXXX@default-2ab4,2','EXTERNAL Client Phone','Local','10.17.17.3','91778869XXXX','914032745298','2008-12-08 19:42:43','1228794163','','','','','V1208194243001330695')|

Note -- callerid = unknown

action.launch:

Code: Select all

2008-12-08 19:42:43|/usr/share/astguiclient/AST_send_action_child.pl --SYSLOG --PATHlogs=%2Fvar%2Flog%2Fastguiclient --telnet_host=localhost --telnet_port=5038 --ASTmgrUSERNAME=cron --ASTmgrSECRET=XXXXXX --ASTmgrUSERNAMEsend=sendcron --man_id=1926646 --action=Originate --cmd_line_b=Exten%3A%208365 --cmd_line_c=Context%3A%20default --cmd_line_d=Channel%3A%20Local%2F91778869XXXX%40default --cmd_line_e=Priority%3A%201 --cmd_line_f=Callerid%3A%20V1208194243001330695 --cmd_line_g=Timeout%3A%2060000

asterisk CLI on server A:

Code: Select all

 -- Executing AGI("Local/91778869XXXX@default-e7c2,2", "agi://127.0.0.1:4577/call_log") in new stack
    -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
    -- Executing Dial("Local/91778869XXXX@default-e7c2,2", "IAX2/ys1/1778869XXXX|55|o") in new stack
    -- Called ys1/1778869XXXX
    -- Call accepted by 10.17.17.2 (format ulaw)
    -- Format for call is ulaw
    -- IAX2/ys1-5390 is proceeding passing it to Local/91778869XXXX@default-e7c2,2
    -- IAX2/ys1-5390 is making progress passing it to Local/91778869XXXX@default-e7c2,2

Happens both with 8365 and 8369 exten.

extensions.conf:

Server A:

Code: Select all

....
; dial a long distance outbound number
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,2,Dial(${TRUNK}/${EXTEN:1},55,o)
exten => _91NXXNXXXXXX,3,Hangup
....
; dial a long distance outbound number
exten => _1NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _1NXXNXXXXXX,2,Dial(${TRUNK}/${EXTEN},55,o)
exten => _1NXXNXXXXXX,3,Hangup
....
exten => _010*017*017*003*.,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*004*.,1,Dial(${TRUNKIAX2}/${EXTEN:16},55,o)
exten => _010*017*017*003*8600XXX,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*003*8600XXX*.,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*003*78600XXX,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*003*78600XXX*.,1,Goto(default,${EXTEN:16},1)
exten => _8600XXX*.,1,AGI(agi-VDADfixCXFER.agi)
exten => _78600XXX*.,1,AGI(agi-VDADfixCXFER.agi)
....
; VICIDIAL_auto_dialer transfer script:
exten => 8365,1,Playback(sip-silence)
exten => 8365,2,AGI(agi://127.0.0.1:4577/call_log)
exten => 8365,3,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----SO)
exten => 8365,4,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----SO)
exten => 8365,5,Hangup
.....
; VICIDIAL_auto_dialer transfer script AMD with Load Balanced:
exten => 8369,1,Playback(sip-silence)
exten => 8369,2,AGI(agi://127.0.0.1:4577/call_log)
exten => 8369,3,AMD(2000|2000|1000|5000|120|50|4|256)
exten => 8369,4,AGI(VD_amd.agi,${EXTEN})
exten => 8369,5,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
exten => 8369,6,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
exten => 8369,7,Hangup

Server B:

Code: Select all

....
exten => _010*017*017*003*.,1,Dial(${TRUNKIAX1}/${EXTEN:16},55,o)
exten => _010*017*017*004*.,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*004*8600XXX,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*004*8600XXX*.,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*004*78600XXX,1,Goto(default,${EXTEN:16},1)
exten => _010*017*017*004*78600XXX*.,1,Goto(default,${EXTEN:16},1)
exten => _8600XXX*.,1,AGI(agi-VDADfixCXFER.agi)
exten => _78600XXX*.,1,AGI(agi-VDADfixCXFER.agi)
....

If agent is on server A, and call goes through the same server campaign callerID is properly displayed. Same applies for server B.
Did I miss something, or it's a bug?

I have not seen this issue on any of our production systems.

What Asterisk version?

1.2.30.2 on both servers, A and B.

We have set up many multi-server systems using 1.2.30.2 and have never had an issue with this. We could do a full system check of your setup, but it would be at our regular hourly rate.

Any hints where I could start troubleshooting this?

Looking at the active Asterisk CLI call flow on each system with full logging turned on while duplicating the issue.

Thanks.
I've done that already, callerID everywhere shows up as unknown or null:

CLI from server A, agent is on B:

Code: Select all

 -- Executing AGI("Local/91778869XXXX@default-97d8,2", "agi://127.0.0.1:4577/call_log") in new stack
AGI Tx >> agi_network_script: call_log
AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
AGI Tx >> agi_channel: Local/91778869XXXX@default-97d8,2
AGI Tx >> agi_language: en
AGI Tx >> agi_type: Local
AGI Tx >> agi_uniqueid: 1228881210.41
AGI Tx >> agi_callerid: unknown
AGI Tx >> agi_calleridname: V1209195330001330632
AGI Tx >> agi_callingpres: 0
AGI Tx >> agi_callingani2: 0
AGI Tx >> agi_callington: 0
AGI Tx >> agi_callingtns: 0
AGI Tx >> agi_dnid: unknown
AGI Tx >> agi_rdnis: unknown
AGI Tx >> agi_context: default
AGI Tx >> agi_extension: 91778869XXXX
AGI Tx >> agi_priority: 1
AGI Tx >> agi_enhanced: 0.0
AGI Tx >> agi_accountcode:
AGI Tx >>
    -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
    -- Executing Dial("Local/91778869XXXX@default-97d8,2", "IAX2/ys1/1778869XXXX|55|o") in new stack
    -- Called ys1/1778869XXXX
    -- Call accepted by 10.17.17.2 (format ulaw)
    -- Format for call is ulaw

FASTagiout:

Code: Select all

2008-12-09 19:53:30|VDfastAGI|begin|+++++++++++++++++ FastAGI Start ++++++++++++++++++++++++++++++++++++++++
2008-12-09 19:53:30|VDfastAGI|begin|Perl Environment Dump:
2008-12-09 19:53:30|VDfastAGI|begin|0|--debug
2008-12-09 19:53:30|VDfastAGI|begin|AGI Environment Dump:
2008-12-09 19:53:30|VDfastAGI|begin| -- accountcode =
2008-12-09 19:53:30|VDfastAGI|begin| -- callerid = unknown
2008-12-09 19:53:30|VDfastAGI|begin| -- calleridname = V1209195330001330632
2008-12-09 19:53:30|VDfastAGI|begin| -- callingani2 = 0
2008-12-09 19:53:30|VDfastAGI|begin| -- callingpres = 0
2008-12-09 19:53:30|VDfastAGI|begin| -- callingtns = 0
2008-12-09 19:53:30|VDfastAGI|begin| -- callington = 0
2008-12-09 19:53:30|VDfastAGI|begin| -- channel = Local/91778869XXXX@default-97d8,2
2008-12-09 19:53:30|VDfastAGI|begin| -- context = default
2008-12-09 19:53:30|VDfastAGI|begin| -- dnid = unknown
2008-12-09 19:53:30|VDfastAGI|begin| -- enhanced = 0.0
2008-12-09 19:53:30|VDfastAGI|begin| -- extension = 91778869XXXX
2008-12-09 19:53:30|VDfastAGI|begin| -- language = en
2008-12-09 19:53:30|VDfastAGI|begin| -- network = yes
2008-12-09 19:53:30|VDfastAGI|begin| -- network_script = call_log
2008-12-09 19:53:30|VDfastAGI|begin| -- priority = 1
2008-12-09 19:53:30|VDfastAGI|begin| -- rdnis = unknown
2008-12-09 19:53:30|VDfastAGI|begin| -- request = agi://127.0.0.1:4577/call_log
2008-12-09 19:53:30|VDfastAGI|begin| -- type = Local
2008-12-09 19:53:30|VDfastAGI|begin| -- uniqueid = 1228881210.41
2008-12-09 19:53:30|VDfastAGI|begin|AGI Variables: |1228881210.41|Local/91778869XXXX@default-97d8,2|91778869XXXX|Local|V1209195330001330632|
2008-12-09 19:53:30|VDfastAGI|call_log|Process to run: |agi://127.0.0.1:4577/call_log|call_log|START|
2008-12-09 19:53:30|VDfastAGI|call_log|+++++ CALL LOG START : 2008-12-09 19:53:30
2008-12-09 19:53:30|VDfastAGI|call_log|EXTERNAL Client Phone: 1|91778869XXXX|
2008-12-09 19:53:30|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('1228881210.41','Local/91778869XXXX@default-97d8,2','EXTERNAL Client Phone','Local','10.17.17.3','91778869XXXX','8368','2008-12-09 19:53:30','1228881210','','','','','V1209195330001330632')|

action.full:

Code: Select all

2008-12-09 19:53:30|1989977|0|1|
Action: Originate
Exten: 8368
Context: default
Channel: Local/91778869XXXX@default
Priority: 1
Callerid: V1209195330001330632
Timeout: 60000

|
2008-12-09 19:53:36|1989977|1|||
2008-12-09 19:53:41|1989977|2|||

<callerID num> is missing after V1209195330001330632

On manual calls I see "Callerid: "M1209195855001330633" <888308XXXX>"

and so on. Campaign callerID is not anywhere in all log files nor in CLI.

I am really puzzled where else to look.
Which script or part of vicidial is the first one pulling campaign callerID and sends it?

Both the AST_VDauto_dial and the FILL script grab and send the callerID number from the campaign settings.

AST_VDauto_dial_FILL.pl

The statement which pulls campaign callerID uses

line 299:

Code: Select all

$DBIPcampaigncid[$camp_CIPct] =   "$aryA[2]"

$DBIPcampaigncid is not used anywhere alse in script.

Later on in script a wrong variable, not populated anywhere is used instead- $DBfill_campaigncid:

line 708:

Code: Select all

if (length($DBfill_campaigncid[$camp_CIPct]) > 6) {$CCID = "$DBfill_campaigncid[$camp_CIPct]";   $CCID_on++;}

It should be

Code: Select all

if (length($DBIPcampaigncid[$camp_CIPct]) > 6) {$CCID = "$DBIPcampaigncid[$camp_CIPct]";   $CCID_on++;}

I am waiting agents to go on break and test if this was all.
Thanks for the hints.

Thanks for looking into this, let me know if that fixes your problem.

You will have to kill the autoFILL screen session to let it start up again.

That was it, problem solved. Thanks again, this was really serious issue for us.

I checked AST_VDauto_dial_FILL.pl in latest trunk and in 2.0.4.1.rc5- they both are using the incorrect variable.

BTW are you aware MANTIS doesn't work? It's been inaccessible for a week or more.

Forbidden

You don't have permission to access /VICIDIALmantis on this server.

Additionally, a 404 Not Found error was encountered while trying to use an ErrorDocument to handle the request.

Thanks for posting this fix. Now I'm confused as to why we have not seen this issue at our multi-server sites. I will try to post and test a fix later tonight for both branch and trunk.

As for Mantis, there was an attack on the site through an expliot in Mantis, we just have not had the time to test the upgrade and put it live.

This has been fixed in trunk and branch204

Thanks again

Thank you Matt : )