This does not tell me anything about your symptom. I doubt your problem is that you don't want this line to be in that file because it takes up too much room on the hard drive. I suspect you are talking about problems with the dialer (which you still haven't mentioned, but in your next post you are getting closer!)
Well, again: I'm getting a lot of aborted connection to vicidial db. I can't find anything about that on any of my web or dialer server's logs, however a lot of such aborts can be seen from DB's side. Further investigation showed that those aborts are caused by connections not properly closed. On top of that I've noticed, that vicidial makes several requests (I've seen 84 myself) in a single connection. Here is the example of aborted request:
- Code: Select all
1340666 Connect cron@192.168.9.15 as anonymous on asterisk
1340666 Query set autocommit=1
1340666 Query SELECT agi_output,local_gmt FROM servers where server_ip = 'X.X.X.X' (one of my IP addresses was here)
1340666 Query SELECT enable_queuemetrics_logging,queuemetrics_server_ip,queuemetrics_dbname,queuemetrics_login,queuemetrics_pass,queuemetrics_log_id,queuemetrics_eq_prepend,queuemetrics_pe_phone_append,did_agent_log,alt_log_server_ip,alt_log_dbname,alt_log_login,alt_log_pass,tables_use_alt_log_db,did_ra_extensions_enabled,queuemetrics_socket,queuemetrics_socket_url FROM system_settings
1340666 Query SELECT call_handle_method,agent_search_method,group_id,did_pattern,list_id,phone_code,campaign_id,user,user_unavailable_action,user_route_settings_ingroup,did_route,voicemail_ext,extension,exten_context,phone,server_ip FROM vicidial_inbound_dids where did_id = '126'
1340666 Query SELECT voicemail_dump_exten,ext_context,answer_transfer_agent,local_gmt,asterisk_version,max_vicidial_trunks FROM servers where server_ip = '68.233.253.217'
1340666 Query UPDATE vicidial_inbound_groups SET group_calldate='2013-11-07 08:48:38' where group_id='English'
1340666 Query SELECT call_time_id,after_hours_action,after_hours_message_filename,after_hours_exten,after_hours_voicemail,welcome_message_filename,moh_context,onhold_prompt_filename,prompt_interval,agent_alert_exten,agent_alert_delay,drop_call_seconds,drop_action,drop_exten,next_agent_call,voicemail_ext,queue_priority,drop_inbound_group,afterhours_xfer_group,play_place_in_line,play_estimate_hold_time,hold_time_option,hold_time_option_seconds,hold_time_option_exten,hold_time_option_voicemail,hold_time_option_xfer_group,hold_time_option_callback_filename,hold_time_option_callback_list_id,hold_recall_xfer_group,no_delay_call_route,play_welcome_message,no_agent_no_queue,no_agent_action,no_agent_action_value,extension_appended_cidname,uniqueid_status_display,uniqueid_status_prefix,hold_time_option_minimum,hold_time_option_press_filename,hold_time_option_callmenu,onhold_prompt_no_block,onhold_prompt_seconds,hold_time_option_no_block,hold_time_option_prompt_seconds,hold_time_second_option,hold_time_third_option,wait_hold_option_priority,wait_time_option,wait_time_second_option,wait_time_third_option,wait_time_option_seconds,wait_time_option_exten,wait_time_option_voicemail,wait_time_option_xfer_group,wait_time_option_callmenu,wait_time_option_callback_filename,wait_time_option_callback_list_id,wait_time_option_press_filename,wait_time_option_no_block,wait_time_option_prompt_seconds,active,calculate_estimated_hold_seconds,add_lead_url,eht_minimum_prompt_filename,eht_minimum_prompt_no_block,eht_minimum_prompt_seconds,on_hook_ring_time,ingroup_recording_override,ingroup_rec_filename,on_hook_cid,action_xfer_cid,drop_callmenu,after_hours_callmenu,max_calls_method,max_calls_count,max_calls_action FROM vicidial_inbound_groups where group_id = 'English'
1340666 Query SELECT ct_default_start,ct_default_stop,default_afterhours_filename_override ,ct_thursday_start,ct_thursday_stop,thursday_afterhours_filename_override ,ct_wednesday_start,ct_wednesday_stop,ct_holidays FROM vicidial_call_times where call_time_id = '24hours'
1340666 Query SELECT lead_id from vicidial_list where phone_number='4073017666' order by last_local_call_time desc limit 1
Increasing mysql timeouts did not help:
- Code: Select all
| interactive_timeout | 28800 |
| net_read_timeout | 60 |
| net_write_timeout | 120 |
| wait_timeout | 28800 |
Those aborted connections actually perform their requests (that's why I have no errors on client side), however do not close the connection properly.
The system that generates the amount of calls has very specific reasons for doing so. There is a constantly running script that monitors the system and makes the decisions of what should be dialed now. Access that script (it is one of the many screens available via "screen -list") and you can find out why this behavior occurs and trace that problem, likely to an unrelated process. Unrelated meaning "nothing to do with mysql having an error".
Thx for the suggestion, I've checked vdauto screen and it does not contain anything suspicious (errors, warnings or whatever). Here is the example of campaign debug while it's placing less calls, than it should place:
- Code: Select all
---------- ADAPT DEBUG
Campaign Debug: route72 - Route72 US 2013-11-07 10:59:13
Total leads in hopper right now: 1106
Adapt Debug: 2013-11-07 10:59:05
route72 hopper READY count: 1073
route72 agents LOGGED-IN count: 66
0 |route72|5|1073|9am-9pm|15|60|
TIME CALL CHECK: 13838396451383839941
CAMPAIGN DIFFERENTIAL: 66.2 23.1333333333333 (23.1333333333333 - 0)
CAMPAIGN ANSWERED STATUSES: route72|DROP,XDROP,CALLBK,CBHOLD,DEC,SALE,NI,NP,XFER,RQXFER,TIMEOT,AFTHRS,NANQUE,DropM,SALEFP,411,QCFAIL|
route72|1.20|2.47| |185 7491 2129| 0
LIVE CALLS: 102|SELECT count(*) from vicidial_auto_calls where campaign_id=route72
AGENT TIME STATS: 46021 511247 85401 89752|SELECT sum(pause_sec),sum(wait_sec),sum(talk_sec) - sum(dead_sec) as custtalk,sum(dispo_sec) + sum(dead_sec) as acw from vicidial_agent_log where event_time > 2013-11-07 00:00:01 and campaign_id=route72 and pause_sec < 65000 and wait_sec < 65000 and talk_sec < 65000 and dispo_sec < 65000 and dead_sec < 65000
AGENT CALLS: 5257|SELECT count(*) from vicidial_agent_log where event_time > 2013-11-07 00:00:01 and campaign_id=route72 and lead_id > 0
CAMPAIGN: route72 0
SETTINGS-
DIAL LEVEL: 2
DIAL METHOD: ADAPT_AVERAGE
AVAIL ONLY: N
DROP PERCENT: 48
MAX LEVEL: 2
SERVER TIME: 1059
LATE TARGET: 2100 (1041 left|1)
INTENSITY: 30
DLDIFF TARGET: 3
CURRENT STATS-
AVG AGENTS: 66.85
AGENTS: 66 ACTIVE: 48 CALC: 48 INCALL: 25 READY: 23
DL DIFFERENTIAL: 21.25 = (18.25 + 3)
DIAL LEVEL SUGGESTION-
PERCENT DIFF: 31.79
SUGGEST DL: 2.636 = (2 * (0.317875841436051 + 1) )
INTENSE DIFF: 41.32
INTENSE DL: 2.826 = (2 * (0.413238593866866 + 1) )
DIAL LEVEL OVER CAP! SETTING TO CAP: 2
DROP STATS-
TODAY DROPS: 7491 185 2.47%
ANSWER DROPS: 2129 8.69%
ONE HOUR DROPS: 4487/1229 52 1.16%
HALF HOUR DROPS: 2333/653 19 0.81%
FIVE MIN DROPS: 333/86 4 1.20%
ONE MIN DROPS: 36/6 2 5.56%
DIAL LEVEL UPDATED TO: 2 CONFIRM: 1
X.X.X.28 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.28: agents: 4 (READY: 1) dial_level: 2 (1|0|1) 3
ROUTE72 X.X.X.28: Calls to place: 6 (8 - 2 [0 + 2|5|0]) 14
CAMPAIGN DIFFERENTIAL: 26.7 8.4 (8.5 - 0.1)
LOCAL TRUNK SHORTAGE: 0|0 (14 - 300)
X.X.X.30 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.30: agents: 6 (READY: 1) dial_level: 2 (1|2|4) 3
ROUTE72 X.X.X.30: Calls to place: -12 (12 - 24 [0 + 24|5|0]) 34
CAMPAIGN DIFFERENTIAL: 23.2 6.15 (8 - 1.85)
LOCAL TRUNK SHORTAGE: 0|0 (22 - 300)
X.X.X.31 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.31: agents: 7 (READY: 2) dial_level: 2 (2|2|0) 3
ROUTE72 X.X.X.31: Calls to place: 6 (14 - 8 [0 + 8|5|0]) 14
CAMPAIGN DIFFERENTIAL: 67.3 16.55 (18.9 - 2.35)
LOCAL TRUNK SHORTAGE: 0|0 (14 - 300)
X.X.X.32 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.32: agents: 19 (READY: 7) dial_level: 2 (7|9|0) 3
ROUTE72 X.X.X.32: Calls to place: 4 (38 - 34 [0 + 34|5|0]) 38
CAMPAIGN DIFFERENTIAL: 67.25 16.3 (18.55 - 2.25)
LOCAL TRUNK SHORTAGE: 0|0 (38 - 300)
X.X.X.33 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.33: agents: 3 (READY: 0) dial_level: 2 (0|0|1) 3
ROUTE72 X.X.X.33: Calls to place: 4 (6 - 2 [0 + 2|5|0]) 6
CAMPAIGN DIFFERENTIAL: 67.1 16.1 (18.75 - 2.65)
LOCAL TRUNK SHORTAGE: 0|0 (6 - 300)
X.X.X.34 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.34: agents: 12 (READY: 6) dial_level: 2 (6|3|2) 3
ROUTE72 X.X.X.34: Calls to place: 17 (24 - 7 [0 + 7|4|0]) 26
CAMPAIGN DIFFERENTIAL: 66.85 18.25 (19.15 - 0.9)
LOCAL TRUNK SHORTAGE: 0|0 (26 - 300)
X.X.X.35 Debug: 2013-11-07 10:59:01
ROUTE72 X.X.X.35: agents: 12 (READY: 4) dial_level: 2 (4|5|0) 3
ROUTE72 X.X.X.35: Calls to place: 1 (24 - 23 [0 + 23|5|0]) 25
CAMPAIGN DIFFERENTIAL: 67.35 16.8 (18.55 - 1.75)
LOCAL TRUNK SHORTAGE: 0|0 (25 - 300)
Inbound Debug: English 2013-11-07 10:58:42
ANSWERED STATUSES: English|DROP,XDROP,CALLBK,CBHOLD,DEC,SALE,NI,NP,XFER,RQXFER,TIMEOT,AFTHRS,NANQUE,DropM,SALEFP,411,QCFAIL|
DAILY STATS|4|70|0|11 IN-GROUP: English CALLS: 1082 ANSWER: 1004 DROPS: 49
Stat1: 978 Stat2: 995 Hold: 4413.50|2019.75|833.00
Dial level on my real time screen always shows the maximum allowed in the campaign settings, however seems that it has no connection to what is really dialed there. I've also checked asterisk and DB at this moment - no errors or stuck requests there too.
And based on your comments, you are saying that these aborts happened in the stock vicidial mysql configuration as well? Or "it had problems" not specifically THIS problem?
Yes, it has aborts on the default config too. Stock config was slow I've tried it some time ago.