Page 1 of 1
Call going to the wrong conference
Posted:
Fri Oct 31, 2008 3:06 pmby ekaftan
I have a customer that is using Vicidial for an incoming credit check callcenter. The have two groups, one inbound and one backoffice group. Inbound agents get calls and sometimes the system need further info and they have to transfer the call to the backoffice group. Once or twice a day, the call gets transfered to a backoffice agent thats already talking to a customer.
I have found nothing wrong with how the system is setup and I am really stumped.
Where should I start looking?
thanks...
Posted:
Fri Oct 31, 2008 8:54 pmby mflorell
vicidial.php version and build?
Posted:
Sat Nov 01, 2008 10:37 amby ekaftan
mflorell wrote:vicidial.php version and build?
When problem started, 2.0.4. I've now upgraded up to RC5 and it still happens.
vicidial.php is now 2.0.4-152
thanks.
Posted:
Sat Nov 01, 2008 6:32 pmby mflorell
Asterisk version?
What is the loadavg when this happens?
Are you using remote agents at all?
Posted:
Sat Nov 01, 2008 7:56 pmby ekaftan
mflorell wrote:Asterisk version?
What is the loadavg when this happens?
Are you using remote agents at all?
Fairly low load average. Does not seem to relate. No remote agents. Asterisk 1.2.24.
One thing, its a two server setup. Each server has one incoming E1. Only one server has the SIP phones for the users.
I modified the diaplan today to redirect the calls via IAX to the server where the SIP phones register and call only there the inbound agi (it used to be that the agi was called on each server and the call transfered to the conference using the IP*IP* extensions) After this change the problem has not recurred, but call load on weekends is so low, we never had two calls at the same time today...
Posted:
Tue Nov 04, 2008 6:03 pmby ekaftan
No improvement rerouting calls via IAX. It still reocurred today.
A call came in at 15:32 and it ot assigned to an agent. That agent was still talking and another call was transfered to the same agent.
There was no queue and load average was 0.11.
I cant find anything wrong on agiout.....
Which script resets vicidial_live_agents and set the agent on READY or CLOSER?
Posted:
Tue Nov 04, 2008 7:09 pmby mflorell
Please post the agiout logfile output from the second call going into the existing agent's session.
Posted:
Tue Nov 04, 2008 8:13 pmby ekaftan
I am collecting the log... It looks like a race condition... several calls were being transferred at that same time. At least 4 logs stepping each other...
This is the call that ended up in the wrong agent:
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------99
9-----1-----Garant
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callerid = 53623704
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- channel = IAX2/d2-15999
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- dnid = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- type = IAX2
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830966.290526
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830966.290526|IAX2/d2-15999|7797|IAX2|Closer|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:36:0
7
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |53623704|SELECT lead_id from vicidial_list where
phone_number='53623704' order by modify_date limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5688181|SELECT lead_id from vicidial_list where ph
one_number='53623704' order by modify_date limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_al
low_inbound='Y';|5688181|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173607005688181
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqu
eid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','5688181'
,'1225830966.290526','Y1104173607005688181','IAX2/d2-15999','1','53623704','2008-11-04 17:36:07','IN','LIVE-0')|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch,
status,phone_code,phone_number,user,processed) values('5688181','FrontIN','2008-11-04 17:36:07','1225830967','QUEUE','1',
'53623704','VDCL','N')|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL : |5688181|insert to vicidial_closer_log
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign
_id = 'FrontIN' and call_time < "2008-11-04 17:36:07" and lead_id != '5688181';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='5688181',uniqueid='1225830966.290526', channel='IAX2/d2-15999',
callerid='Y1104173607005688181', call_server_ip='170.100.99.15' where status IN('CLOSER','READY') and campaign_id IN('Tes
tFO','TestBO','Mesa','Garant') and closer_campaigns LIKE "% FrontIN %" and last_update_time > '20081104173602' order by l
ast_call_finish limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173607005688181' and channel='I
AX2/d2-15999' order by last_call_time limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173607005688181
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y1104173607005688181';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |0E0|5688181|16610280
|UPDATE vicidial_xfer_log set closer='16610280' where lead_id = '5688181' order by call_date desc limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5688181
|UPDATE vicidial_closer_log set user='16610280' where lead_id='5688181' order by call_date desc limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041736078605019|170*100*099*015*78605019|IAX2/d
2-15999|insert to vicidial_manager
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280'
and group_id='FrontIN';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |52|16610280|FrontIN|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5688181|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5688181' and call_date='2008-11-04 17:36:07';|
Then this last line also mentions 17:36:07 as date/time:
2008-11-04 17:36:16|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:36:07|2008-11-04 17:36:16
Should I post the entire 17:36 minute?
Posted:
Wed Nov 05, 2008 7:58 pmby mflorell
Can you post the other 4 calls that sent to this agent?
The ones that all had this line:
exiting VDAD app, transferring call to 170*100*099*015*8605019
Posted:
Wed Nov 05, 2008 9:04 pmby ekaftan
This agent had over 70 call yesterday. I am posting the last 4, including the one with the conference problem.
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------99
9-----1-----Garant
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- callerid = 412232825
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- channel = Zap/18-1
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- dnid = 7777
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- type = Zap
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830347.290277
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830347.290277|Zap/18-1|7797|Zap|Closer|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:25:4
8
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |412232825|SELECT lead_id from vicidial_list where
phone_number='412232825' order by modify_date limit 1;|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5681240|SELECT lead_id from vicidial_list where ph
one_number='412232825' order by modify_date limit 1;|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_al
low_inbound='Y';|5681240|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104172548005681240
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqu
eid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','5681240'
,'1225830347.290277','Y1104172548005681240','Zap/18-1','1','412232825','2008-11-04 17:25:48','IN','LIVE-0')|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch,
status,phone_code,phone_number,user,processed) values('5681240','FrontIN','2008-11-04 17:25:48','1225830348','QUEUE','1',
'412232825','VDCL','N')|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDCL : |5681240|insert to vicidial_closer_log
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign
_id = 'FrontIN' and call_time < "2008-11-04 17:25:48" and lead_id != '5681240';|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104172548005681240' and channel='Z
ap/18-1' order by last_call_time limit 1;|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104172548005681240
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5681240|16610280
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5681240
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041725488605019|170*100*099*015*78605019|Zap/18
-1|insert to vicidial_manager
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280'
and group_id='FrontIN';|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |48|16610280|FrontIN|
2008-11-04 17:25:48|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5681240|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5681240' and call_date='2008-11-04 17:25:48';|
2008-11-04 17:25:57|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:25:48|2008-11-04 17:25:57
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------99
9-----1-----Garant
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- callerid = 22220956
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- channel = IAX2/d2-12775
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- dnid = unknown
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- type = IAX2
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830443.290331
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830443.290331|IAX2/d2-12775|7797|IAX2|Closer|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:27:2
4
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |22220956|SELECT lead_id from vicidial_list where
phone_number='22220956' order by modify_date limit 1;|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5682378|SELECT lead_id from vicidial_list where ph
one_number='22220956' order by modify_date limit 1;|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_al
low_inbound='Y';|5682378|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104172724005682378
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqu
eid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','5682378'
,'1225830443.290331','Y1104172724005682378','IAX2/d2-12775','1','22220956','2008-11-04 17:27:24','IN','LIVE-0')|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch,
status,phone_code,phone_number,user,processed) values('5682378','FrontIN','2008-11-04 17:27:24','1225830444','QUEUE','1',
'22220956','VDCL','N')|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDCL : |5682378|insert to vicidial_closer_log
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign
_id = 'FrontIN' and call_time < "2008-11-04 17:27:24" and lead_id != '5682378';|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104172724005682378' and channel='I
AX2/d2-12775' order by last_call_time limit 1;|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104172724005682378
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5682378|16610280
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5682378
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041727248605019|170*100*099*015*78605019|IAX2/d
2-12775|insert to vicidial_manager
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280'
and group_id='FrontIN';|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |49|16610280|FrontIN|
2008-11-04 17:27:24|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5682378|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5682378' and call_date='2008-11-04 17:27:24';|
2008-11-04 17:27:33|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:27:24|2008-11-04 17:27:33
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------99
9-----1-----Garant
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- callerid = 23133738
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- channel = Zap/29-1
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- dnid = 7777
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- type = Zap
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830618.290421
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830618.290421|Zap/29-1|7797|Zap|Closer|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:30:1
9
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |23133738|SELECT lead_id from vicidial_list where
phone_number='23133738' order by modify_date limit 1;|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5682073|SELECT lead_id from vicidial_list where ph
one_number='23133738' order by modify_date limit 1;|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_allow_inbound='Y';|5682073|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173019005682073
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqu
eid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','5682073'
,'1225830618.290421','Y1104173019005682073','Zap/29-1','1','23133738','2008-11-04 17:30:19','IN','LIVE-0')|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch,
status,phone_code,phone_number,user,processed) values('5682073','FrontIN','2008-11-04 17:30:19','1225830619','QUEUE','1',
'23133738','VDCL','N')|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDCL : |5682073|insert to vicidial_closer_log
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign
_id = 'FrontIN' and call_time < "2008-11-04 17:30:19" and lead_id != '5682073';|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173019005682073' and channel='Z
ap/29-1' order by last_call_time limit 1;|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173019005682073
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5682073|16610280
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5682073
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041730198605019|170*100*099*015*78605019|Zap/29
-1|insert to vicidial_manager
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280'
and group_id='FrontIN';|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |50|16610280|FrontIN|
2008-11-04 17:30:19|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5682073|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5682073' and call_date='2008-11-04 17:30:19';|
2008-11-04 17:30:28|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:30:19|2008-11-04 17:30:28
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------99
9-----1-----Garant
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- callerid = 412223817
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- channel = IAX2/d2-1283
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- dnid = unknown
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- type = IAX2
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830864.290483
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830864.290483|IAX2/d2-1283|7797|IAX2|Closer|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:34:2
5
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |412223817|SELECT lead_id from vicidial_list where
phone_number='412223817' order by modify_date limit 1;|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5682904|SELECT lead_id from vicidial_list where ph
one_number='412223817' order by modify_date limit 1;|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_al
low_inbound='Y';|5682904|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173425005682904
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqu
eid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','5682904'
,'1225830864.290483','Y1104173425005682904','IAX2/d2-1283','1','412223817','2008-11-04 17:34:25','IN','LIVE-0')|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch,
status,phone_code,phone_number,user,processed) values('5682904','FrontIN','2008-11-04 17:34:25','1225830865','QUEUE','1',
'412223817','VDCL','N')|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDCL : |5682904|insert to vicidial_closer_log
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign
_id = 'FrontIN' and call_time < "2008-11-04 17:34:25" and lead_id != '5682904';|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173425005682904' and channel='I
AX2/d2-1283' order by last_call_time limit 1;|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173425005682904
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5682904|16610280
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5682904
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041734258605019|170*100*099*015*78605019|IAX2/d
2-1283|insert to vicidial_manager
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280'
and group_id='FrontIN';|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |51|16610280|FrontIN|
2008-11-04 17:34:25|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5682904|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5682904' and call_date='2008-11-04 17:34:25';|
2008-11-04 17:34:34|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:34:25|2008-11-04 17:34:34
Thanks...
Posted:
Thu Nov 06, 2008 8:17 pmby mflorell
I can't really tell why this would be happening, can you duplicate this happening on demand?
Posted:
Thu Nov 06, 2008 8:55 pmby williamconley
Hm. Multi server setup. Does the manager realtime interface show the agents busy properly when they are busy? including the "closers"?
Posted:
Thu Nov 06, 2008 9:19 pmby ekaftan
mflorell wrote:I can't really tell why this would be happening, can you duplicate this happening on demand?
Nopes. I cannot duplicate. It happens only once or twice a day. Always only to one agent and always in the middle of the day. Never when somebody is looking.
Posted:
Thu Nov 06, 2008 9:20 pmby ekaftan
williamconley wrote:Hm. Multi server setup. Does the manager realtime interface show the agents busy properly when they are busy? including the "closers"?
All agents are connected to only one server. Calls get routied incoming to both servers, but all end up in only one. I had call load balanced but some transfers failed so I moved all to one server.
Sometimes the interface will show agents paused when still on an active call, but never as free.
Posted:
Thu Nov 06, 2008 9:28 pmby williamconley
OK, it seems you may have altered your system from your original post while attempting to resolve this issue. is this the "persistent" issue troubling you:
A call came in at 15:32 and it ot assigned to an agent. That agent was still talking and another call was transfered to the same agent.
?
if so, when that call came in and was assigned to a busy agent, was that agent the original recipient of this call or was this agent a closer to whom this call was transferred by the original agent?
Trying to get a "grip" on the present issue.
Posted:
Thu Nov 06, 2008 10:05 pmby ekaftan
williamconley wrote:OK, it seems you may have altered your system from your original post while attempting to resolve this issue. is this the "persistent" issue troubling you:
A call came in at 15:32 and it ot assigned to an agent. That agent was still talking and another call was transfered to the same agent.
?
if so, when that call came in and was assigned to a busy agent, was that agent the original recipient of this call or was this agent a closer to whom this call was transferred by the original agent?
Trying to get a "grip" on the present issue.
Agent on conference 8605019 was still talking to customer on call that came in at 17:34:25 when another call, coming in at 17:36:07 was transferred to her.
(I thought I had found some smoking gun on Fastagilog but I guess it was not....)
Posted:
Thu Nov 06, 2008 10:09 pmby williamconley
Ok, now define "was transferred to her". Was this a fresh "unanswered" call or a transfer to her from another agent? (closer transfer, blind transfer)
have to ask.
Posted:
Thu Nov 06, 2008 10:18 pmby ekaftan
Ok. I found it. Another call came in at 17:36:10 (3 seconds after the one on 17:36:07) and that also got transferred to agent on conference 8605019... both logs step on each other. I will post the whole log for completness...
Race condition? Mysql bug?
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------9
99-----1-----Garant
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callerid = 53623704
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- channel = IAX2/d2-15999
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- dnid = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- type = IAX2
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830966.290526
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830966.290526|IAX2/d2-15999|7797|IAX2|Closer|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:36:
07
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |53623704|SELECT lead_id from vicidial_list where
phone_number='53623704' order by modify_date limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5688181|SELECT lead_id from vicidial_list where p
hone_number='53623704' order by modify_date limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------9
99-----1-----Garant
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- callerid = 26354780
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- channel = Zap/9-1
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- dnid = 7777
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- type = Zap
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830968.290527
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830968.290527|Zap/9-1|7797|Zap|Closer|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:36:
10
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |26354780|SELECT lead_id from vicidial_list where
phone_number='26354780' order by modify_date limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5681635|SELECT lead_id from vicidial_list where p
hone_number='26354780' order by modify_date limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|Perl Environment Dump:
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|0|CIDLOOKUPRC-----LB-----FrontIN-----3427797-----Closer-----park----------9
99-----1-----Garant
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- accountcode =
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- callerid = 27321438
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- calleridname = unknown
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- callingani2 = 0
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- callingpres = 3
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- callingtns = 0
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- callington = 33
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- channel = IAX2/d2-13355
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- context = inboundvicidial
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- dnid = unknown
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- enhanced = 0.0
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- extension = 7797
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- language = cl
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- priority = 4
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- rdnis = unknown
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- request = agi-VDAD_ALL_inbound.agi
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- type = IAX2
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi| -- uniqueid = 1225830970.290528
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|AGI Variables: |1225830970.290528|IAX2/d2-13355|7797|IAX2|Closer|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|+++++ INBOUND CALL VDCL STARTED : |FrontIN|Closer-3427797|2008-11-04 17:36:
11
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list search |27321438|SELECT lead_id from vicidial_list where
phone_number='27321438' order by modify_date limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|VDAD vicidial_list found |5683112|SELECT lead_id from vicidial_list where p
hone_number='27321438' order by modify_date limit 1;|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_a
llow_inbound='Y';|5681032|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173604005681032
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniqueid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','568103
2','1225830963.290525','Y1104173604005681032','Zap/8-1','1','26647857','2008-11-04 17:36:04','IN','LIVE-0')|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch
,status,phone_code,phone_number,user,processed) values('5681032','FrontIN','2008-11-04 17:36:04','1225830964','QUEUE','1
','26647857','VDCL','N')|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDCL : |5681032|insert to vicidial_closer_log
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaig
n_id = 'FrontIN' and call_time < "2008-11-04 17:36:04" and lead_id != '5681032';|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='5681032',uniqueid='1225830963.290525', channel='Zap/8-1', calle
rid='Y1104173604005681032', call_server_ip='170.100.99.15' where status IN('CLOSER','READY') and campaign_id IN('TestFO'
,'TestBO','Mesa','Garant') and closer_campaigns LIKE "% FrontIN %" and last_update_time > '20081104173559' order by last
_call_finish limit 1;|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173604005681032' and channel=
'Zap/8-1' order by last_call_time limit 1;|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173604005681032
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y1104173604005681032';|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5681032|7886209
|UPDATE vicidial_xfer_log set closer='7886209' where lead_id = '5681032' order by call_date desc limit 1;|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5681032
|UPDATE vicidial_closer_log set user='7886209' where lead_id='5681032' order by call_date desc limit 1;|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041736048605005|170*100*099*015*78605005|Zap/8
-1|insert to vicidial_manager
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605005
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='7886209'
and group_id='FrontIN';|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |152|7886209|FrontIN|
2008-11-04 17:36:04|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5681032|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5681032' and call_date='2008-11-04 17:36:04';|
2008-11-04 17:36:13|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:36:04|2008-11-04 17:36:13
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_a
llow_inbound='Y';|5688181|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173607005688181
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniq
ueid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','568818
1','1225830966.290526','Y1104173607005688181','IAX2/d2-15999','1','53623704','2008-11-04 17:36:07','IN','LIVE-0')|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch
,status,phone_code,phone_number,user,processed) values('5688181','FrontIN','2008-11-04 17:36:07','1225830967','QUEUE','1
','53623704','VDCL','N')|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL : |5688181|insert to vicidial_closer_log
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaig
n_id = 'FrontIN' and call_time < "2008-11-04 17:36:07" and lead_id != '5688181';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='5688181',uniqueid='1225830966.290526', channel='IAX2/d2-15999',
callerid='Y1104173607005688181', call_server_ip='170.100.99.15' where status IN('CLOSER','READY') and campaign_id IN('T
estFO','TestBO','Mesa','Garant') and closer_campaigns LIKE "% FrontIN %" and last_update_time > '20081104173602' order b
y last_call_finish limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173607005688181' and channel=
'IAX2/d2-15999' order by last_call_time limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173607005688181
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y1104173607005688181';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |0E0|5688181|16610280
|UPDATE vicidial_xfer_log set closer='16610280' where lead_id = '5688181' order by call_date desc limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5688181
|UPDATE vicidial_closer_log set user='16610280' where lead_id='5688181' order by call_date desc limit 1;|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041736078605019|170*100*099*015*78605019|IAX2/
d2-15999|insert to vicidial_manager
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280
' and group_id='FrontIN';|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |52|16610280|FrontIN|
2008-11-04 17:36:07|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5688181|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5688181' and call_date='2008-11-04 17:36:07';|
2008-11-04 17:36:16|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:36:07|2008-11-04 17:36:16
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_a
llow_inbound='Y';|5681635|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173610005681635
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniq
ueid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','568163
5','1225830968.290527','Y1104173610005681635','Zap/9-1','1','26354780','2008-11-04 17:36:10','IN','LIVE-0')|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch
,status,phone_code,phone_number,user,processed) values('5681635','FrontIN','2008-11-04 17:36:10','1225830970','QUEUE','1
','26354780','VDCL','N')|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDCL : |5681635|insert to vicidial_closer_log
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaig
n_id = 'FrontIN' and call_time < "2008-11-04 17:36:10" and lead_id != '5681635';|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='5681635',uniqueid='1225830968.290527', channel='Zap/9-1', calle
rid='Y1104173610005681635', call_server_ip='170.100.99.15' where status IN('CLOSER','READY') and campaign_id IN('TestFO'
,'TestBO','Mesa','Garant') and closer_campaigns LIKE "% FrontIN %" and last_update_time > '20081104173605' order by last
_call_finish limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173610005681635' and channel=
'Zap/9-1' order by last_call_time limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173610005681635
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y1104173610005681635';|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5681635|16610280
|UPDATE vicidial_xfer_log set closer='16610280' where lead_id = '5681635' order by call_date desc limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5681635
|UPDATE vicidial_closer_log set user='16610280' where lead_id='5681635' order by call_date desc limit 1;|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041736108605019|170*100*099*015*78605019|Zap/9
-1|insert to vicidial_manager
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605019
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='16610280
' and group_id='FrontIN';|
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |53|16610280|FrontIN|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||SELECT campaign_id FROM vicidial_campaigns where active='Y' and campaign_a
llow_inbound='Y';|5683112|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|callerID changed: Y1104173611005683112
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_auto_calls (server_ip,campaign_id,status,lead_id,uniq
ueid,callerid,channel,phone_code,phone_number,call_time,call_type,stage) values('170.100.99.15','FrontIN','LIVE','568311
2','1225830970.290528','Y1104173611005683112','IAX2/d2-13355','1','27321438','2008-11-04 17:36:11','IN','LIVE-0')|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||INSERT INTO vicidial_closer_log (lead_id,campaign_id,call_date,start_epoch
,status,phone_code,phone_number,user,processed) values('5683112','FrontIN','2008-11-04 17:36:11','1225830971','QUEUE','1
','27321438','VDCL','N')|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDCL : |5683112|insert to vicidial_closer_log
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaig
n_id = 'FrontIN' and call_time < "2008-11-04 17:36:11" and lead_id != '5683112';|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDAD get agent: |30|0|1|1|update of vla table: FrontIN|
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='5683112',uniqueid='1225830970.290528', channel='IAX2/d2-13355',
callerid='Y1104173611005683112', call_server_ip='170.100.99.15' where status IN('CLOSER','READY') and campaign_id IN('T
estFO','TestBO','Mesa','Garant') and closer_campaigns LIKE "% FrontIN %" and last_update_time > '20081104173606' order b
y last_call_finish limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where
status = 'QUEUE' and campaign_id IN('TestFO','TestBO','Mesa','Garant') and callerid='Y1104173611005683112' and channel=
'IAX2/d2-13355' order by last_call_time limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDCL XFER REMOTE: |1|update of vac table: Y1104173611005683112
|UPDATE vicidial_auto_calls set status='CLOSER', stage='CLOSER-0' where callerid='Y1104173611005683112';|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDXL vicidial_xfer_log update: |1|5683112|15509343
|UPDATE vicidial_xfer_log set closer='15509343' where lead_id = '5683112' order by call_date desc limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- closer log : |1|update of vcl table: 5683112
|UPDATE vicidial_closer_log set user='15509343' where lead_id='5683112' order by call_date desc limit 1;|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDCL agent alert: |VH11041736118605009|170*100*099*015*78605009|IAX2/
d2-13355|insert to vicidial_manager
2008-11-04 17:36:10|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5681635|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5681635' and call_date='2008-11-04 17:36:10';|
2008-11-04 17:36:19|agi-VDAD_ALL_inbound.agi|XXXXX VDAD transferred: start|stop 2008-11-04 17:36:10|2008-11-04 17:36:19
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|exiting VDAD app, transferring call to 170*100*099*015*8605009
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi||SELECT calls_today from vicidial_inbound_group_agents WHERE user='15509343
' and group_id='FrontIN';|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDLIA agent calls: |64|15509343|FrontIN|
2008-11-04 17:36:11|agi-VDAD_ALL_inbound.agi|-- VDCL vcl update: |1|5683112|
|UPDATE vicidial_closer_log set queue_seconds='0' where lead_id = '5683112' and call_date='2008-11-04 17:36:11';|
Posted:
Fri Nov 07, 2008 12:47 amby mflorell
Could you possibly try setting your Next Agent Call setting for your inbound group to inbound_group_rank or fewest_calls for tomorrow to see if you can duplicate this problem with one of those methods?
Posted:
Fri Nov 07, 2008 6:34 amby ekaftan
mflorell wrote:Could you possibly try setting your Next Agent Call setting for your inbound group to inbound_group_rank or fewest_calls for tomorrow to see if you can duplicate this problem with one of those methods?
I changed it to fewest_calls. I'll report during the day...
Posted:
Fri Nov 07, 2008 11:26 amby ekaftan
ekaftan wrote:mflorell wrote:Could you possibly try setting your Next Agent Call setting for your inbound group to inbound_group_rank or fewest_calls for tomorrow to see if you can duplicate this problem with one of those methods?
I changed it to fewest_calls. I'll report during the day...
No change. It already happened today...
Any possible fix?
Posted:
Fri Nov 07, 2008 7:05 pmby mflorell
Well, I have tried and I cannot duplicate the problem which makes it a bit difficult to find the reason it's happening. Also, I do not have any clients that I know of that are experiencing this issue either.
There are a few things that have changed recently in SVN trunk that I might backport to 2.0.4 branch. If I can do that over the weekend I will send you the code or a link to the code.
Posted:
Fri Nov 07, 2008 7:14 pmby ekaftan
mflorell wrote:Well, I have tried and I cannot duplicate the problem which makes it a bit difficult to find the reason it's happening. Also, I do not have any clients that I know of that are experiencing this issue either.
There are a few things that have changed recently in SVN trunk that I might backport to 2.0.4 branch. If I can do that over the weekend I will send you the code or a link to the code.
Nice, thanks.
ps:
I am pretty sure whats failing it the UPDATE that sets the agent as QUEUE, or the SELECT that comes after that that gets the conference to send the call to.
Two calls at just the right time call two agi-VDAD_ALL_inbound and thus two UPDATEs and then two SELECTs that both get the same agent's conference number.
Maybe its just that mysql is not transaction friendly enough or the SELECT after the UPDATE is not specific enough to get the right row...
I have not been able to think of a better way to code it though...
Posted:
Fri Nov 07, 2008 7:42 pmby mflorell
I recently added a ton of MySQL debugging to SVN trunk trying to figure out what was going on with a client system. It ended up being a horrible InnoDB setup that had all sorts of errors in it, but the code is now in there and it is able to log every single MySQL query used by the agent interface and the AGI scripts. This along with MySQL bin-log should allow you to see in excruciating detail exactly what is going on with the database queries on your system.
The only thing I can think of that could cause this is somehow an old AJAX request that sends the READY status for the agent is executed after the call gets sent to the agent.
From the output it is clear that the updates are being executed, and in MySQL with MyISAM tables it will do a full table lock when updating so that's not the problem.
I have an idea of something to try, I will post after I have tested it to make sure it doesn't cause more harm than good.
Posted:
Tue Nov 11, 2008 6:23 pmby ekaftan
mflorell wrote:I have an idea of something to try, I will post after I have tested it to make sure it doesn't cause more harm than good.
Thanks. Any updates?
Posted:
Tue Nov 11, 2008 6:53 pmby mflorell
Sorry about that, been quite busy. I did commit the change to SVN branches/agc_2.0.4 and I will post a link to the changed file later when I have more time.