vicidial.org

VICIDIAL astGUIclient discussion forum

Skip to content

Vicidial.org Home      Vicidial Forum      Vicidial Wiki      Vicidial Issue Tracker      astGUIclient Project Page


Call going to the wrong conference

All installation and configuration problems and questions

Moderators: gerski, enjay, williamconley, Op3r, Staydog, gardo, mflorell, MJCoate, mcargile, Kumba, Michael_N

Post a reply

Call going to the wrong conference

Postby ekaftan » Fri Oct 31, 2008 3:06 pm

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...
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Fri Oct 31, 2008 8:54 pm

vicidial.php version and build?
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Sat Nov 01, 2008 10:37 am

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.
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Sat Nov 01, 2008 6:32 pm

Asterisk version?

What is the loadavg when this happens?

Are you using remote agents at all?
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Sat Nov 01, 2008 7:56 pm

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...
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby ekaftan » Tue Nov 04, 2008 6:03 pm

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?
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Tue Nov 04, 2008 7:09 pm

Please post the agiout logfile output from the second call going into the existing agent's session.
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Tue Nov 04, 2008 8:13 pm

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?
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Wed Nov 05, 2008 7:58 pm

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
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Wed Nov 05, 2008 9:04 pm

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...
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Thu Nov 06, 2008 8:17 pm

I can't really tell why this would be happening, can you duplicate this happening on demand?
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby williamconley » Thu Nov 06, 2008 8:55 pm

Hm. Multi server setup. Does the manager realtime interface show the agents busy properly when they are busy? including the "closers"?
Vicidial Installation and Repair, plus Hosting and Colocation
Newest Product: Vicidial Agent Only Beep - Beta
http://www.PoundTeam.com # 352-269-0000 # 888-883-8488 # +44(203) 769-2294
williamconley
 
Posts: 20427
Joined: Wed Oct 31, 2007 4:17 pm
Location: Bartow, FL (In the boondocks)
Top

Postby ekaftan » Thu Nov 06, 2008 9:19 pm

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.
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby ekaftan » Thu Nov 06, 2008 9:20 pm

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.
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby williamconley » Thu Nov 06, 2008 9:28 pm

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.
Vicidial Installation and Repair, plus Hosting and Colocation
Newest Product: Vicidial Agent Only Beep - Beta
http://www.PoundTeam.com # 352-269-0000 # 888-883-8488 # +44(203) 769-2294
williamconley
 
Posts: 20427
Joined: Wed Oct 31, 2007 4:17 pm
Location: Bartow, FL (In the boondocks)
Top

Postby ekaftan » Thu Nov 06, 2008 10:05 pm

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....)
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby williamconley » Thu Nov 06, 2008 10:09 pm

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.
Vicidial Installation and Repair, plus Hosting and Colocation
Newest Product: Vicidial Agent Only Beep - Beta
http://www.PoundTeam.com # 352-269-0000 # 888-883-8488 # +44(203) 769-2294
williamconley
 
Posts: 20427
Joined: Wed Oct 31, 2007 4:17 pm
Location: Bartow, FL (In the boondocks)
Top

Postby ekaftan » Thu Nov 06, 2008 10:18 pm

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';|
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Fri Nov 07, 2008 12:47 am

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?
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Fri Nov 07, 2008 6:34 am

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...
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby ekaftan » Fri Nov 07, 2008 11:26 am

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?
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Fri Nov 07, 2008 7:05 pm

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.
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Fri Nov 07, 2008 7:14 pm

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...
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Fri Nov 07, 2008 7:42 pm

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.
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top

Postby ekaftan » Tue Nov 11, 2008 6:23 pm

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?
ekaftan
 
Posts: 126
Joined: Fri Nov 17, 2006 8:23 pm
Top

Postby mflorell » Tue Nov 11, 2008 6:53 pm

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.
mflorell
Site Admin
 
Posts: 18406
Joined: Wed Jun 07, 2006 2:45 pm
Location: Florida
Top
Post a reply

Return to Support

Who is online

Users browsing this forum: No registered users and 106 guests

Powered by phpBB® Forum Software © phpBB Group