vicidial.org

by **okli** » Mon Dec 08, 2008 10:58 pm

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?

by **mflorell** » Tue Dec 09, 2008 12:52 am

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

What Asterisk version?

by **okli** » Tue Dec 09, 2008 1:32 am

1.2.30.2 on both servers, A and B.

by **mflorell** » Tue Dec 09, 2008 6:24 pm

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.

by **okli** » Tue Dec 09, 2008 6:54 pm

Any hints where I could start troubleshooting this?

by **mflorell** » Tue Dec 09, 2008 10:11 pm

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

by **okli** » Tue Dec 09, 2008 11:33 pm

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. :roll:

Which script or part of vicidial is the first one pulling campaign callerID and sends it?

by **mflorell** » Wed Dec 10, 2008 1:08 pm

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

by **okli** » Wed Dec 10, 2008 4:47 pm

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.

by **mflorell** » Wed Dec 10, 2008 5:42 pm

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.

by **okli** » Wed Dec 10, 2008 6:51 pm

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.

by **mflorell** » Wed Dec 10, 2008 6:57 pm

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.

by **mflorell** » Wed Dec 10, 2008 7:42 pm

This has been fixed in trunk and branch204

Thanks again

by **okli** » Wed Dec 10, 2008 8:56 pm

Thank you Matt : )

vicidial.org

callerID not displayed in load balanced setup

callerID not displayed in load balanced setup

Who is online