A small hiccup when the system didn't respond and agents where complaining, the asterisk log showed this:
[Feb 13 11:09:17] WARNING[3332] chan_sip.c: Autodestruct on dialog '7ea53ead72a71b883ca7675c45100b09@<<Server IP>>:5060' with owner SIP/carrier_1-0000092f in place (Method: BYE). Rescheduling destruction for 10000 ms
aha, I've seen that before I though http://www.vicidial.org/VICIDIALforum/v ... =4&t=30297 but it was not exactly the same:
WARNING[2626]: chan_sip.c:4214 __sip_autodestruct: Autodestruct on dialog '0d42b9247c928cc90702775372e13c01@<<Server IP>>:5060' with owner SIP/ in place (Method: BYE). Rescheduling destruction for 10000 ms
the second time it happen it was a longer delay so I started investigate it more and found this in my /var/run/mysql/mysqld-slow.log (slow query logging):
- Code: Select all
# Time: 140213 11:09:17
# User@Host: cron[cron] @ [123.123.123.123]
# Query_time: 11.792559 Lock_time: 0.000187 Rows_sent: 1 Rows_examined: 431
use asterisk;
SET timestamp=1392286157;
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
# Time: 140213 11:09:31
# User@Host: cron[cron] @ [123.123.123.123]
# Query_time: 13.376370 Lock_time: 0.628954 Rows_sent: 1 Rows_examined: 433
SET timestamp=1392286171;
SELECT sum(pause_sec + wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and campaign_id IN('98') and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000;
# Time: 140213 11:09:41
# User@Host: cron[cron] @ [123.123.123.123]
# Query_time: 10.593508 Lock_time: 0.142008 Rows_sent: 1 Rows_examined: 435
SET timestamp=1392286181;
select avg(wait_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
(second time the problem occur the query took 231 seconds!!)
I knew I had run some report when it happen and the logs confirmed it:
123.123.123.2 - 6666 [13/Feb/2014:11:08:54 +0100] "GET /vicidial/AST_VDADstats.php HTTP/1.1" 200 24379 "http://123.123.123.123/vicidial/admin.php?ADD=999999" "Mozilla/5.0"
I tried that slow query and just removed ,vicidial_list
and voila:
- Code: Select all
mysql> SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
+--------------------------------------+
| sum(wait_sec + talk_sec + dispo_sec) |
+--------------------------------------+
| 1084 |
+--------------------------------------+
1 row in set (0.02 sec)
mysql> SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
+--------------------------------------+
| sum(wait_sec + talk_sec + dispo_sec) |
+--------------------------------------+
| 799945388 |
+--------------------------------------+
1 row in set (20.24 sec)
1012 times faster
and apparently this is how the query looked like before the change 2013-02-08 (140208-2033 - Added List select option)
now I noticed this text in the report page: "Lists: (optional, possibly slow)" no shit
if you look at the result from the query its very far off too!
So I did some tests:
build 140208-2033
list selection: --ALL--
- Code: Select all
/vicidial/AST_VDADstats.php.orig1?agent_hours=&DB=1&outbound_rate=&costformat=&print_calls=&query_date=2014-02-13&end_date=2014-02-14&group%5B%5D=98&list_ids%5B%5D=--ALL--&include_rollover=NO&bottom_graph=NO&carrier_stats=NO&report_display_type=TEXT&shift=ALL&SUBMIT=SUBMIT
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-14 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98') ;
Productivity Rating: 0
list selection: 997, 998
- Code: Select all
/vicidial/AST_VDADstats.php.orig1?agent_hours=&DB=1&outbound_rate=&costformat=&print_calls=&query_date=2014-02-13&end_date=2014-02-14&group%5B%5D=98&list_ids%5B%5D=997&list_ids%5B%5D=998&include_rollover=NO&bottom_graph=NO&carrier_stats=NO&report_display_type=TEXT&shift=ALL&SUBMIT=SUBMIT
select count(*) from vicidial_closer_log where call_date >= '2014-02-13 00:00:00' and call_date <= '2014-02-14 23:59:59' and campaign_id IN('') and list_id IN('997','998') and status NOT IN('DROP','XDROP','HXFER','QVMAIL','HOLDTO','LIVE','QUEUE');
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-14 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98') and vicidial_agent_log.lead_id=vicidial_list.lead_id and vicidial_list.list_id IN('997','998');
Productivity Rating: 1.9
no selected list selection
- Code: Select all
/vicidial/AST_VDADstats.php.orig1?agent_hours=&DB=1&outbound_rate=&costformat=&print_calls=&query_date=2014-02-13&end_date=2014-02-14&group%5B%5D=98&include_rollover=NO&bottom_graph=NO&carrier_stats=NO&report_display_type=TEXT&shift=ALL&SUBMIT=SUBMIT
select count(*) from vicidial_closer_log where call_date >= '2014-02-13 00:00:00' and call_date <= '2014-02-14 23:59:59' and campaign_id IN('') and status NOT IN('DROP','XDROP','HXFER','QVMAIL','HOLDTO','LIVE','QUEUE');
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-14 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98') ;
Productivity Rating: 0.11
build 140108-0730
no list selection because this was before that option
- Code: Select all
/vicidial/AST_VDADstats_r2067.php?agent_hours=&DB=1&outbound_rate=&costformat=&print_calls=&query_date=2014-02-13&end_date=2014-02-14&group%5B%5D=98&include_rollover=NO&bottom_graph=NO&carrier_stats=NO&report_display_type=TEXT&shift=ALL&SUBMIT=SUBMIT
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-14 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
Productivity Rating: 0.11
as you can see that the list selection queries is all wrong (look at the Productivity Rating value),
it will join with vicidial_list so only the number of leads will show and thus the productivity rating will be skyrocketing or the opposite when lists: --ALL-- is selected.
the query should left join instead to be able to grab all the data from vicidial_agent_log:
query without list selection:
SELECT * from vicidial_agent_log where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
-- 1084
bad query with list selection --ALL--
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
-- 799945388
bad query with list selection 997, 998:
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log,vicidial_list where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98') and vicidial_agent_log.lead_id=vicidial_list.lead_id and vicidial_list.list_id IN('997','998');
-- 63
good query with list selection:
SELECT sum(wait_sec + talk_sec + dispo_sec) from vicidial_agent_log
left join vicidial_list on vicidial_list.lead_id=vicidial_agent_log.lead_id
and list_id IN('997','998')
where event_time >= '2014-02-13 00:00:00' and event_time <= '2014-02-13 23:59:59' and pause_sec<65000 and wait_sec<65000 and talk_sec<65000 and dispo_sec<65000 and campaign_id IN('98');
-- 1084
I made a patch that changes the queries to left join and I posted it to the issue tracker: http://www.vicidial.org/VICIDIALmantis/view.php?id=741
With the patch the numbers are correct and the queries is fast, win win!