Setup Details:
GoAutoDial CE 2.0
ViciDial Version:2.2.1-237 BUILD: 100510-2015
Kernel:Linux 2.6.18-194.8.1.el5.goPAE
OS: CentOS release 5.5 (Final)
We have a multiple server load balanced setup consisting of 4 servers. The load balancing was achieved following the Load_Balanced.txt document.All the servers have same version and OS as stated above in the setup details.All the machines have asterisk servers and on one we have the MySql database and the GUI.
We created an outbound broadcast campaign and were able to successfully outdial calls with no issues howsoever.The load balancing was perfect as the calls were distributed as desired.The problem is with the reporting.
On observing the Export calls report, the status of the call which was picked and listened to is shown as "QUEUE" and the call_length is shown as "NULL" when the call length was 16 seconds when checked manually.
See this:
- Code: Select all
call_date phone_number status user full_name campaign_id vendor_lead_code source_id list_id gmt_offset_now phone_code phone_number title first_name middle_initial last_name address1 address2 address3 city state province postal_code country_code gender date_of_birth alt_phone email security_phrase comments length_in_sec user_group alt_dial rank owner lead_id list_name list_description status_name
2011-02-11 14:57:08 XXX0666909 QUEUE VDAD Outbound Auto Dial 222 100002 10001 610 -6.00 1 XXX0666909 0000-00-00 NONE 0 56766 610 610 Lead To Be Called
If we see the record for this particular phone in the Database:
- Code: Select all
mysql> select * from vicidial_log where list_id = '610';
| uniqueid | lead_id | list_id | campaign_id | call_date | start_epoch | end_epoch | length_in_sec | status | phone_code | phone_number | user | comments | processed | user_group | term_reason | alt_dial |
+--------------+---------+---------+-------------+---------------------+-------------+------------+---------------+--------+-
| 1297416602.8 | 56767 | 610 | 222 | 2011-02-11 15:00:11 | 1297416611 | NULL | NULL | QUEUE | 1 | XXX0666909 | VDAD | NULL | N | NULL | NONE | NONE |
+--------------+---------+---------+-------------+---------------------+-------------+------------+---------------+--------+------------+--------------+------+----------+-----------+------------+-------------+----------+
Notice that the unique_id for this phone is 1297416602.8
In this scenario,On observing the agi debug logs we saw that the phone was dialled via say Server 1 and the prompt was played on Server 2. During this process of transferring the call over IAX, the phone was asssigned a new unique id on the second server and eventually the statistics for this were not persisted in the database as the unique id changed.
See the following agi debug logs:
Server 1 agi debug logs:
- Code: Select all
Executing [919560666909@default:1] AGI("Local/91XXX666909@default-c74a,2", "agi://127.0.0.1:4577/call_log") in new stack
[Feb 11 15:00:02] AGI Tx >> agi_network: yes
[Feb 11 15:00:02] AGI Tx >> agi_network_script: call_log
[Feb 11 15:00:02] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Feb 11 15:00:02] AGI Tx >> agi_channel: Local/91XXX666909@default-c74a,2
[Feb 11 15:00:02] AGI Tx >> agi_language: en
[Feb 11 15:00:02] AGI Tx >> agi_type: Local
[Feb 11 15:00:02] AGI Tx >> agi_uniqueid: 1297416602.9
[Feb 11 15:00:02] AGI Tx >> agi_callerid: 0000000000
[Feb 11 15:00:02] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:02] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:02] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:02] AGI Tx >> agi_callington: 0
[Feb 11 15:00:02] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:02] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:02] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:02] AGI Tx >> agi_context: default
[Feb 11 15:00:02] AGI Tx >> agi_extension: 91XXX666909
[Feb 11 15:00:02] AGI Tx >> agi_priority: 1
[Feb 11 15:00:02] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:02] AGI Tx >> agi_accountcode:
[Feb 11 15:00:02] AGI Tx >>
[Feb 11 15:00:02] -- AGI Script agi://127.0.0.1:4577/call_log completed, ret urning 0
[Feb 11 15:00:02] -- Executing [91XXX666909@default:2] Dial("Local/91956066 6909@default-c74a,2", "DAHDI/g1/0XXX666909|30|o") in new stack
[Feb 11 15:00:02] -- Requested transfer capability: 0x00 - SPEECH
[Feb 11 15:00:02] -- Called g1/0XXX666909
[Feb 11 15:00:02] -- DAHDI/1-1 is proceeding passing it to Local/91XXX666909@default-c74a,2
[Feb 11 15:00:02] -- DAHDI/1-1 is making progress passing it to Local/91XXX666909@default-c74a,2
[Feb 11 15:00:06] == Parsing '/etc/asterisk/manager.conf': [Feb 11 15:00:06] F ound
[Feb 11 15:00:06] == Manager 'sendcron' logged on from 127.0.0.1
[Feb 11 15:00:06] == Manager 'sendcron' logged off from 127.0.0.1
[Feb 11 15:00:06] -- DAHDI/1-1 is ringing
[Feb 11 15:00:11] -- DAHDI/1-1 answered Local/91XXX666909@default-c74a,2
[Feb 11 15:00:11] > Channel Local/91XXX666909@default-c74a,1 was answere d.
[Feb 11 15:00:11] == Manager 'sendcron' logged off from 127.0.0.1
[Feb 11 15:00:11] -- Executing [8368@default:1] Playback("Local/91XXX666909 @default-c74a,1", "sip-silence") in new stack
[Feb 11 15:00:11] -- <Local/91XXX666909@default-c74a,1> Playing 'sip-silenc e' (language 'en')
[Feb 11 15:00:11] WARNING[10585]: file.c:1292 waitstream_core: Unexpected contro l subclass '-1'
[Feb 11 15:00:11] -- Executing [h@default:1] DeadAGI("Local/91XXX666909@def ault-c74a,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-- ---ANSWER-----9-----0") in new stack
[Feb 11 15:00:11] AGI Tx >> agi_network: yes
[Feb 11 15:00:11] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODE BUG-----16-----ANSWER-----9-----0
[Feb 11 15:00:11] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses --PRI-----NODEBUG-----16-----ANSWER-----9-----0
[Feb 11 15:00:11] AGI Tx >> agi_channel: Local/91XXX666909@default-c74a,2
[Feb 11 15:00:11] AGI Tx >> agi_language: en
[Feb 11 15:00:11] AGI Tx >> agi_type: Local
[Feb 11 15:00:11] AGI Tx >> agi_uniqueid: 1297416602.9
[Feb 11 15:00:11] AGI Tx >> agi_callerid: 0000000000
[Feb 11 15:00:11] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:11] AGI Tx >> agi_callington: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:11] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:11] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:11] AGI Tx >> agi_context: default
[Feb 11 15:00:11] AGI Tx >> agi_extension: h
[Feb 11 15:00:11] AGI Tx >> agi_priority: 1
[Feb 11 15:00:11] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:11] AGI Tx >> agi_accountcode:
[Feb 11 15:00:11] AGI Tx >>
[Feb 11 15:00:11] -- Executing [8368@default:2] AGI("DAHDI/1-1", "agi://127. 0.0.1:4577/call_log") in new stack
[Feb 11 15:00:11] AGI Tx >> agi_network: yes
[Feb 11 15:00:11] AGI Tx >> agi_network_script: call_log
[Feb 11 15:00:11] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Feb 11 15:00:11] AGI Tx >> agi_channel: DAHDI/1-1
[Feb 11 15:00:11] AGI Tx >> agi_language: en
[Feb 11 15:00:11] AGI Tx >> agi_type: DAHDI
[Feb 11 15:00:11] AGI Tx >> agi_uniqueid: 1297416602.8---------------->THE UNIQUE ID OF THE PHONE IN MYSQL
[Feb 11 15:00:11] AGI Tx >> agi_callerid: 0000000000
[Feb 11 15:00:11] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:11] AGI Tx >> agi_callington: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:11] AGI Tx >> agi_dnid: 66042200
[Feb 11 15:00:11] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:11] AGI Tx >> agi_context: default
[Feb 11 15:00:11] AGI Tx >> agi_extension: 8368
[Feb 11 15:00:11] AGI Tx >> agi_priority: 2
[Feb 11 15:00:11] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:11] AGI Tx >> agi_accountcode:
[Feb 11 15:00:11] AGI Tx >>
[Feb 11 15:00:11] -- AGI Script agi://127.0.0.1:4577/call_log completed, ret urning 0
[Feb 11 15:00:11] -- Executing [8368@default:3] AGI("DAHDI/1-1", "agi-VDAD_A LL_outbound.agi|NORMAL-----LB") in new stack
[Feb 11 15:00:11] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI -----NODEBUG-----16-----ANSWER-----9-----0 completed, returning 0
[Feb 11 15:00:11] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ ALL_outbound.agi
[Feb 11 15:00:11] AGI Tx >> agi_request: agi-VDAD_ALL_outbound.agi
[Feb 11 15:00:11] AGI Tx >> agi_channel: DAHDI/1-1
[Feb 11 15:00:11] AGI Tx >> agi_language: en
[Feb 11 15:00:11] AGI Tx >> agi_type: DAHDI
[Feb 11 15:00:11] AGI Tx >> agi_uniqueid: 1297416602.8
[Feb 11 15:00:11] AGI Tx >> agi_callerid: 0000000000
[Feb 11 15:00:11] == Spawn extension (default, 91XXXX666909, 2) exited non-zer o on 'Local/919560666909@default-c74a,2'
[Feb 11 15:00:11] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:11] AGI Tx >> agi_callington: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:11] AGI Tx >> agi_dnid: 66042200
[Feb 11 15:00:11] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:11] AGI Tx >> agi_context: default
[Feb 11 15:00:11] AGI Tx >> agi_extension: 8368
[Feb 11 15:00:11] AGI Tx >> agi_priority: 3
[Feb 11 15:00:11] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:11] AGI Tx >> agi_accountcode:
[Feb 11 15:00:11] AGI Tx >>
[Feb 11 15:00:11] AGI Rx << SET CALLERID V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> 200 result=1
[Feb 11 15:00:11] AGI Rx << CHANNEL STATUS DAHDI/1-1
[Feb 11 15:00:11] AGI Tx >> 200 result=6
[Feb 11 15:00:11] AGI Rx << SET CALLERID "V0211150002000056767 <9560666909>"
[Feb 11 15:00:11] AGI Tx >> 200 result=1
[Feb 11 15:00:11] AGI Rx << SET CONTEXT default
[Feb 11 15:00:11] AGI Tx >> 200 result=0
[Feb 11 15:00:11] AGI Rx << SET EXTENSION 192*168*005*005*8368
[Feb 11 15:00:11] AGI Tx >> 200 result=0
[Feb 11 15:00:11] ERROR[10585]: utils.c:966 ast_carefulwrite: write() returned e rror: Broken pipe
[Feb 11 15:00:11] AGI Rx << SET PRIORITY 1
[Feb 11 15:00:11] AGI Tx >> 200 result=0
[Feb 11 15:00:11] ERROR[10585]: utils.c:966 ast_carefulwrite: write() returned e rror: Broken pipe
[Feb 11 15:00:11] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returni ng 0
[Feb 11 15:00:11] -- Executing [192*168*005*005*8368@default:1] Dial("DAHDI/ 1-1", "IAX2/vici3:test@192.168.5.5:4569/8368|55|oT") in new stack
[Feb 11 15:00:11] -- Called vici3:test@192.168.5.5:4569/8368
[Feb 11 15:00:11] -- Call accepted by 192.168.5.5 (format ulaw)
[Feb 11 15:00:11] -- Format for call is ulaw
[Feb 11 15:00:11] -- IAX2/vici4-1361 answered DAHDI/1-1
[Feb 11 15:00:27] == Refreshing DNS lookups.
[Feb 11 15:00:27] -- Executing [h@default:1] DeadAGI("DAHDI/1-1", "agi://127 .0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----16-----16" ) in new stack
[Feb 11 15:00:27] WARNING[10585]: res_agi.c:2203 deadagi_exec: Running DeadAGI o n a live channel will cause problems, please use AGI
[Feb 11 15:00:27] AGI Tx >> agi_network: yes
[Feb 11 15:00:27] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODE BUG-----16-----ANSWER-----16-----16
[Feb 11 15:00:27] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses --PRI-----NODEBUG-----16-----ANSWER-----16-----16
[Feb 11 15:00:27] AGI Tx >> agi_channel: DAHDI/1-1
[Feb 11 15:00:27] AGI Tx >> agi_language: en
[Feb 11 15:00:27] AGI Tx >> agi_type: DAHDI
[Feb 11 15:00:27] AGI Tx >> agi_uniqueid: 1297416602.8
[Feb 11 15:00:27] AGI Tx >> agi_callerid: xxxx666909
[Feb 11 15:00:27] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:27] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:27] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:27] AGI Tx >> agi_callington: 0
[Feb 11 15:00:27] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:27] AGI Tx >> agi_dnid: 66042200
[Feb 11 15:00:27] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:27] AGI Tx >> agi_context: default
[Feb 11 15:00:27] AGI Tx >> agi_extension: h
[Feb 11 15:00:27] AGI Tx >> agi_priority: 1
[Feb 11 15:00:27] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:27] AGI Tx >> agi_accountcode:
[Feb 11 15:00:27] AGI Tx >>
[Feb 11 15:00:27] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI -----NODEBUG-----16-----ANSWER-----16-----16 completed, returning 0
[Feb 11 15:00:27] -- Hungup 'IAX2/vici4-1361'
[Feb 11 15:00:27] == Spawn extension (default, 192*168*005*005*8368, 1) exited non-zero on 'DAHDI/1-1'
[Feb 11 15:00:27] -- Hungup 'DAHDI/1-1'
Server 2 agi debug logs:
- Code: Select all
[Feb 11 15:00:11] -- Accepting AUTHENTICATED call from 192.168.5.4:
> requested format = ulaw,
> requested prefs = (ulaw|gsm),
> actual format = ulaw,
> host prefs = (ulaw),
> priority = mine
[Feb 11 15:00:11] -- Executing [8368@default:1] Playback("IAX2/vici3-3243", "sip-silence") in new stack
[Feb 11 15:00:11] -- <IAX2/vici3-3243> Playing 'sip-silence' (language 'en')
[Feb 11 15:00:11] -- Executing [8368@default:2] AGI("IAX2/vici3-3243", "agi://127.0.0.1:4577/call_log") in new stack
[Feb 11 15:00:11] AGI Tx >> agi_network: yes
[Feb 11 15:00:11] AGI Tx >> agi_network_script: call_log
[Feb 11 15:00:11] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Feb 11 15:00:11] AGI Tx >> agi_channel: IAX2/vici3-3243
[Feb 11 15:00:11] AGI Tx >> agi_language: en
[Feb 11 15:00:11] AGI Tx >> agi_type: IAX2
[Feb 11 15:00:11] AGI Tx >> agi_uniqueid: 1297416611.2------------------>NEW UNIQUE_ID ASSIGNED TO THE PHONE
[Feb 11 15:00:11] AGI Tx >> agi_callerid: XXXX666909
[Feb 11 15:00:11] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:11] AGI Tx >> agi_callington: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:11] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:11] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:11] AGI Tx >> agi_context: default
[Feb 11 15:00:11] AGI Tx >> agi_extension: 8368
[Feb 11 15:00:11] AGI Tx >> agi_priority: 2
[Feb 11 15:00:11] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:11] AGI Tx >> agi_accountcode: IAXvici3
[Feb 11 15:00:11] AGI Tx >>
[Feb 11 15:00:11] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Feb 11 15:00:11] -- Executing [8368@default:3] AGI("IAX2/vici3-3243", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Feb 11 15:00:11] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Feb 11 15:00:11] AGI Tx >> agi_request: agi-VDAD_ALL_outbound.agi
[Feb 11 15:00:11] AGI Tx >> agi_channel: IAX2/vici3-3243
[Feb 11 15:00:11] AGI Tx >> agi_language: en
[Feb 11 15:00:11] AGI Tx >> agi_type: IAX2
[Feb 11 15:00:11] AGI Tx >> agi_uniqueid: 1297416611.2
[Feb 11 15:00:11] AGI Tx >> agi_callerid: XXXX666909
[Feb 11 15:00:11] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:11] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:11] AGI Tx >> agi_callington: 0
[Feb 11 15:00:11] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:11] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:11] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:11] AGI Tx >> agi_context: default
[Feb 11 15:00:11] AGI Tx >> agi_extension: 8368
[Feb 11 15:00:11] AGI Tx >> agi_priority: 3
[Feb 11 15:00:11] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:11] AGI Tx >> agi_accountcode: IAXvici3
[Feb 11 15:00:11] AGI Tx >>
[Feb 11 15:00:12] AGI Rx << SET CALLERID V0211150002000056767
[Feb 11 15:00:12] AGI Tx >> 200 result=1
[Feb 11 15:00:12] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Feb 11 15:00:12] -- Executing [8368@default:4] AGI("IAX2/vici3-3243", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Feb 11 15:00:12] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Feb 11 15:00:12] AGI Tx >> agi_request: agi-VDAD_ALL_outbound.agi
[Feb 11 15:00:12] AGI Tx >> agi_channel: IAX2/vici3-3243
[Feb 11 15:00:12] AGI Tx >> agi_language: en
[Feb 11 15:00:12] AGI Tx >> agi_type: IAX2
[Feb 11 15:00:12] AGI Tx >> agi_uniqueid: 1297416611.2
[Feb 11 15:00:12] AGI Tx >> agi_callerid: unknown
[Feb 11 15:00:12] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:12] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:12] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:12] AGI Tx >> agi_callington: 0
[Feb 11 15:00:12] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:12] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:12] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:12] AGI Tx >> agi_context: default
[Feb 11 15:00:12] AGI Tx >> agi_extension: 8368
[Feb 11 15:00:12] AGI Tx >> agi_priority: 4
[Feb 11 15:00:12] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:12] AGI Tx >> agi_accountcode: IAXvici3
[Feb 11 15:00:12] AGI Tx >>
[Feb 11 15:00:12] AGI Rx << SET CALLERID V0211150002000056767
[Feb 11 15:00:12] AGI Tx >> 200 result=1
[Feb 11 15:00:12] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Feb 11 15:00:12] -- Executing [8368@default:5] Playback("IAX2/vici3-3243", "welcome_tofrenzo_the_best_way_english") in new stack
[Feb 11 15:00:12] -- <IAX2/vici3-3243> Playing 'welcome_tofrenzo_the_best_way_english' (language 'en')
[Feb 11 15:00:27] -- Executing [8368@default:6] Hangup("IAX2/vici3-3243", "") in new stack
[Feb 11 15:00:27] == Spawn extension (default, 8368, 6) exited non-zero on 'IAX2/vici3-3243'
[Feb 11 15:00:27] -- Executing [h@default:1] DeadAGI("IAX2/vici3-3243", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Feb 11 15:00:27] AGI Tx >> agi_network: yes
[Feb 11 15:00:27] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Feb 11 15:00:27] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Feb 11 15:00:27] AGI Tx >> agi_channel: IAX2/vici3-3243
[Feb 11 15:00:27] AGI Tx >> agi_language: en
[Feb 11 15:00:27] AGI Tx >> agi_type: IAX2
[Feb 11 15:00:27] AGI Tx >> agi_uniqueid: 1297416611.2
[Feb 11 15:00:27] AGI Tx >> agi_callerid: unknown
[Feb 11 15:00:27] AGI Tx >> agi_calleridname: V0211150002000056767
[Feb 11 15:00:27] AGI Tx >> agi_callingpres: 0
[Feb 11 15:00:27] AGI Tx >> agi_callingani2: 0
[Feb 11 15:00:27] AGI Tx >> agi_callington: 0
[Feb 11 15:00:27] AGI Tx >> agi_callingtns: 0
[Feb 11 15:00:27] AGI Tx >> agi_dnid: unknown
[Feb 11 15:00:27] AGI Tx >> agi_rdnis: unknown
[Feb 11 15:00:27] AGI Tx >> agi_context: default
[Feb 11 15:00:27] AGI Tx >> agi_extension: h
[Feb 11 15:00:27] AGI Tx >> agi_priority: 1
[Feb 11 15:00:27] AGI Tx >> agi_enhanced: 0.0
[Feb 11 15:00:27] AGI Tx >> agi_accountcode: IAXvici3
[Feb 11 15:00:27] AGI Tx >>
[Feb 11 15:00:27] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[Feb 11 15:00:27] -- Hungup 'IAX2/vici3-3243'
Here are the agiout logs for both servers:
Server 1 agiout log:
- Code: Select all
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |56766|2011-02-11 14:57:08|1.4.27.1-vici|3|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_live_agents where callerid='V0211145701000056766';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where callerid='V0211145701000056766' and status IN('LIVE','XFER');|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|-- VDAD : |1|update of vac table: V0211145701000056766
|UPDATE vicidial_auto_calls set uniqueid='1297416421.4', channel='DAHDI/1-1',status='LIVE',stage='LIVE-0' where callerid='V0211145701000056766' order by call_time desc limit 1;|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='PU' where lead_id='56766' and status NOT IN('CALLBK');|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|-- VDAD vicidial_list PU update: |1|1297416421.4|
2011-02-11 14:57:08|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('1297416421.4','56766','222','2011-02-11 14:57:08','1297416428','QUEUE','1','9560666909','VDAD','N','NONE','610')|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|-- VDAD : |56766|56766|insert to vicidial_log: 1297416421.4
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = '222' and call_time < "2011-02-11 14:57:01" and lead_id != '56766';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi||SELECT count(*) FROM vicidial_live_agents where campaign_id = '222' and last_update_time > '20110211145703';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi||CONCURRENT TRANSFERS AUTO SETTING: 2 (8)|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|-- VDAD get agent: |1|update of vla table: 222|192.168.5.4
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='56766',uniqueid='1297416421.4', channel='DAHDI/1-1', call_server_ip='192.168.5.4', callerid='V0211145701000056766',comments='AUTO' where status = 'READY' and lead_id<1 and campaign_id='222' and last_update_time > '20110211145703' order by random_id limit 1;|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where status IN('QUEUE','INCALL') and campaign_id='222' and callerid='V0211145701000056766' and channel='DAHDI/1-1' order by last_call_time limit 1;|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|-- VDAD XFER REMOTE: |1|update of vac table: V0211145701000056766
|UPDATE vicidial_auto_calls set status='XFER', stage='XFER-0' where callerid='V0211145701000056766';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|callerID changed: "V0211145701000056766" <9560666909>
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|exiting the VDAD app, transferring call to 192*168*005*005*8368
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|XXXXXXXXXX VDAD transferred: start|stop 2011-02-11 14:57:08|2011-02-11 14:57:08
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|callerID changed: V0211150002000056767
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- accountcode =
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- callerid = 0000000000
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- calleridname = V0211150002000056767
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- channel = DAHDI/1-1
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- context = default
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- dnid = 66042200
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- language = en
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- priority = 3
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- type = DAHDI
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1297416602.8
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|AGI Variables: |1297416602.8|DAHDI/1-1|8368|DAHDI|V0211150002000056767|V0211150002000056767|3|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |56767|2011-02-11 15:00:11|1.4.27.1-vici|3|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_live_agents where callerid='V0211150002000056767';|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|0|SELECT count(*) FROM vicidial_auto_calls where callerid='V0211150002000056767' and status IN('LIVE','XFER');|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|-- VDAD : |1|update of vac table: V0211150002000056767
|UPDATE vicidial_auto_calls set uniqueid='1297416602.8', channel='DAHDI/1-1',status='LIVE',stage='LIVE-0' where callerid='V0211150002000056767' order by call_time desc limit 1;|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi||UPDATE vicidial_list set status='PU' where lead_id='56767' and status NOT IN('CALLBK');|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|-- VDAD vicidial_list PU update: |1|1297416602.8|
2011-02-11 15:00:11|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('1297416602.8','56767','222','2011-02-11 15:00:11','1297416611','QUEUE','1','9560666909','VDAD','N','NONE','610')|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|-- VDAD : |56767|56767|insert to vicidial_log: 1297416602.8
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = '222' and call_time < "2011-02-11 15:00:02" and lead_id != '56767';|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi||SELECT count(*) FROM vicidial_live_agents where campaign_id = '222' and last_update_time > '20110211150006';|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi||CONCURRENT TRANSFERS AUTO SETTING: 2 (8)|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|-- VDAD get agent: |1|update of vla table: 222|192.168.5.4
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='56767',uniqueid='1297416602.8', channel='DAHDI/1-1', call_server_ip='192.168.5.4', callerid='V0211150002000056767',comments='AUTO' where status = 'READY' and lead_id<1 and campaign_id='222' and last_update_time > '20110211150006' order by random_id limit 1;|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where status IN('QUEUE','INCALL') and campaign_id='222' and callerid='V0211150002000056767' and channel='DAHDI/1-1' order by last_call_time limit 1;|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|-- VDAD XFER REMOTE: |1|update of vac table: V0211150002000056767
|UPDATE vicidial_auto_calls set status='XFER', stage='XFER-0' where callerid='V0211150002000056767';|
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|callerID changed: "V0211150002000056767" <9560666909>
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|exiting the VDAD app, transferring call to 192*168*005*005*8368
2011-02-11 15:00:11|agi-VDAD_ALL_outbound.agi|XXXXXXXXXX VDAD transferred: start|stop 2011-02-11 15:00:11|2011-02-11 15:00:11
Server 2 agiout log:
- Code: Select all
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|+++++ VDAD START PSEUDO DUPLICATE: EXITING- 3
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|sound file passed as ||
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|callerID changed: V0211130702000056762
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- accountcode = IAXvici2
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- callerid = unknown
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- calleridname = V0211130702000056762
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/vici2-1625
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- context = default
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- language = en
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- priority = 4
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1297409838.0
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|AGI Variables: |1297409838.0|IAX2/vici2-1625|8368|IAX2|V0211130702000056762|V0211130702000056762|4|
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |56762|2011-02-11 13:07:18|1.4.27.1-vici|4|
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|1|SELECT count(*) FROM vicidial_live_agents where callerid='V0211130702000056762';|
2011-02-11 13:07:18|agi-VDAD_ALL_outbound.agi|+++++ VDAD START PSEUDO DUPLICATE: EXITING- 4
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|sound file passed as ||
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|callerID changed: V0211145701000056766
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- accountcode = IAXvici3
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callerid = 9560666909
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- calleridname = V0211145701000056766
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/vici3-3701
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- context = default
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- language = en
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- priority = 3
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1297416428.1
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|AGI Variables: |1297416428.1|IAX2/vici3-3701|8368|IAX2|V0211145701000056766|V0211145701000056766|3|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |56766|2011-02-11 14:57:08|1.4.27.1-vici|3|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|1|SELECT count(*) FROM vicidial_live_agents where callerid='V0211145701000056766';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|+++++ VDAD START PSEUDO DUPLICATE: EXITING- 3
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|sound file passed as ||
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|callerID changed: V0211145701000056766
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- accountcode = IAXvici3
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callerid = unknown
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- calleridname = V0211145701000056766
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/vici3-3701
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- context = default
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- language = en
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- priority = 4
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1297416428.1
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|AGI Variables: |1297416428.1|IAX2/vici3-3701|8368|IAX2|V0211145701000056766|V0211145701000056766|4|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|+++++ VDAD START : |56766|2011-02-11 14:57:08|1.4.27.1-vici|4|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|1|SELECT count(*) FROM vicidial_live_agents where callerid='V0211145701000056766';|
2011-02-11 14:57:08|agi-VDAD_ALL_outbound.agi|+++++ VDAD START PSEUDO DUPLICATE: EXITING- 4
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|Perl Environment Dump:
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|0|NORMAL-----LB
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|sound file passed as ||
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|callerID changed: V0211150002000056767
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- accountcode = IAXvici3
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- callerid = 9560666909
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- calleridname = V0211150002000056767
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- callington = 0
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- channel = IAX2/vici3-3243
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- context = default
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- extension = 8368
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- language = en
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- priority = 3
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- type = IAX2
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1297416611.2
2011-02-11 15:00:12|agi-VDAD_ALL_outbound.agi|AGI Variables: |1297416611.2|IAX2/vici3-3243|8368|IAX2|V0211150002000056767|V0211150002000056767|3|
Are we missing something here or have others faced this issue while working with load balanced setup? Please suggest.
We also tried with the latest SVN/Trunk agi-VDAD_ALL_outbound.agi but the issue persists.