1

This is my first time posting here. I am new to MySQL and trying to learn it as fast as possible but this issue is causing a problem to production and need to reach out for help.

This server is running Suse linux and has a MariaDB 5.5.46. We have been having a huge spike in threads on this active server and I have been digging into this for a little while. I have used Jet Profiler to get a more visual idea of what is going on while looking into this matter and a few days ago I saw this spike live on the server shooting up to 600 threads for about 2 minutes. Thanks to that i have isolated a query that even in the CLI is taking 45 to 57 sec to complete.

This is the offending query that i have pulled out of the Jet Profiler. it is coming from a web site pulling a list off the source for an external person to view the contents. The active server that it is pulling from is phone system.

SELECT CONCAT( DATE(call_date),'<br/>', TIME(call_date) ) as DateTime
    , vlog.campaign_id AS Campaign
    , CONCAT(emp.full_name,' [',vlog.user,']') AS 'Rep'
    , CONCAT(lead.first_name,' ',lead.last_name) as 'Name'
    , CONCAT(lead.state,'/',lead.city) AS 'State-City'  , lead.lead_id
    , vlog.status as CallSts
    , lead.status as LeadSts
    , vlog.phone_number AS 'Phone'
    , timediff(end_time,start_time) as 'Length'
    , location
FROM
    vicidial_log as vlog 
    LEFT JOIN recording_log as rlog  ON vlog.uniqueid = rlog.vicidial_id
    LEFT JOIN vicidial_list as lead  ON vlog.lead_id = lead.lead_id 
    LEFT JOIN vicidial_users as emp  ON emp.user      = rlog.user
WHERE
    date(vlog.call_date) <= '2016-03-11'
    AND vlog.status <> 'INCALL'
    AND vlog.length_in_sec > 10
    AND vlog.campaign_id like 'AG%' 
    AND location IS NOT NULL
   AND rlog.end_time IS NOT NULL

Here is the EXPLAIN addition.

+----+-------------+-------+--------+----------------------+-------------+---------+---------------------------+---------+---------------------------------------------------------------------+
| ID | select_type | table |  type  |    possible_keys     |     key     | key_len |            ref            |  rows   |                               Extra                                 |
+----+-------------+-------+--------+----------------------+-------------+---------+---------------------------+---------+---------------------------------------------------------------------+
|  1 | SIMPLE      | rlog  | range  | filename,vicidial_id | vicidial_id |      63 | NULL                      | 1040870 | Using index condition; Using where; Using temporary; Using filesort |
|  1 | SIMPLE      | vlog  | eq_ref | PRIMARY              | PRIMARY     |      62 | asterisk.rlog.vicidial_id |       1 | Using where                                                         |
|  1 | SIMPLE      | lead  | eq_ref | PRIMARY              | PRIMARY     |       4 | asterisk.vlog.lead_id     |       1 |                                                                     |
|  1 | SIMPLE      | emp   | eq_ref | user                 | user        |      62 | asterisk.rlog.user        |       1 | Using where                                                         |
+----+-------------+-------+--------+----------------------+-------------+---------+---------------------------+---------+---------------------------------------------------------------------+

migrated from serverfault.com Mar 15 '16 at 20:18

This question came from our site for system and network administrators.

  • At least the LEFT join on recording_log and vicidial_users are wrong, it's actually Inner joins (which table is location coming from?). – dnoeth Mar 15 '16 at 20:54
  • Adapted the query to use the INNER for this part of the query and it still took 47.85 sec. I will track down the table that the inner join is using and report back. – dreedy Mar 15 '16 at 21:13
  • 1
    Please provide SHOW CREATE TABLE. – Rick James Mar 15 '16 at 22:05
  • What tables are location and end_time in? Change the query to add aliases in front of them. – Rick James Mar 15 '16 at 22:06
  • On what portion would you like me to show the Create table ? – dreedy Mar 16 '16 at 19:58
1

It looks like indexes are not properly used.

You have 6 WHERE (AND) clauses, each of them should be analyzed from an index selection perspective :

clause 1: DATE(vlog.call_date) <= '2016-03-11'

This one won't be a good candidate because:

  1. you cast your call_date with a DATE() function, making any index on this column totally unusable.
  2. a call_date lower than a recent date would not filter a lot of records anyway since most of the calls would likely be in the range

clause 2: vlog.status <> 'INCALL'

A not equal clause won't be able to use any status based index as far as I can tell.

clause 3: vlog.length_in_sec > 10

I can imagine most of the calls would last more than 10s, so an numerical index based on this column would probably not filter many records, if ever defined. May depend on actual recorded data though.

clause 4: vlog.campaign_id like 'AG%'

I like this one. A string based index would filter on the compaigns stating with these two characters. If text were equally distributed upon alphabetical letters — LIKE clause being case insensitive — you would have a 26x26=612 factor filter. It's less probable, but I would at least say a 100 factor, which is kind of a good start.

You'd still have to add the index on that column if not existing, and also make sure you would launch the query with at least 2 letters, to be efficient.

clause 5: location IS NOT NULL

Nullable columns can be indexed and filtered on null values, but they are arguably very common values that would not filter a lot of records. I would preferably follow the clause 4 lead.

clause 6: rlog.end_time IS NOT NULL

Same as clause 5.

To summarize, I would add an index on compaign_id and see what happens.

Hope that helps.

  • 26*26=676. 52*52 is what you wanted if the collation is ..._ci. But your final conclusion (100 factor) is actually pretty correct for the most common 2-letter pair of a non-evenly-distibuted list. – Rick James Mar 15 '16 at 22:21
  • What kind of key should i add to the campaign_id index ? – dreedy Mar 16 '16 at 19:55
  • A standard one-column key with the following syntax : ALTER TABLE vlog ADD INDEX (campaign_id). – Tom Desp Mar 16 '16 at 20:02
  • I added an index to the corresponding table that the relation of vlog was using and it helped. it brought the query down to 33.69 secs. It seems like we are moving in the right direction. – dreedy Mar 16 '16 at 20:51
  • Indexing has definitely helped. I indexed server columns until i hit a 0.01 sec time. And now i am working on minimizing this. So far i have found that the biggest index that changes the time of the query from 48 ish sec to 4.26 sec is length_in_sec column. This is after i have removed all indexes and flushed the cache. – dreedy Mar 17 '16 at 20:47
1

Do not use LEFT except when you expect it to do something. In your case, AND rlog.end_time IS NOT NULL effectively turns the LEFT JOIN into JOIN. I can't tell about the others, but it could matter to the performance.

Each of the columns here might be useful as an index. Add 4 single-column indexes in order to give the Optimizer some choices. Hopefully it will pick the most selective.

    vlog.call_date < '2016-03-12'  -- note the changes
AND vlog.status <> 'INCALL'
AND vlog.length_in_sec > 10
AND vlog.campaign_id like 'AG%' 

Once you see from EXPLAIN which index it picks, make a 4-column composite index starting with that column. (If location is also in that table, include it, too.) The hope here is that ICP will kick in for the index scan and be more efficient than just a single-column index.

62-byte ids??? Please provide SHOW CREATE TABLE so I can criticize your keys.

It says "using temporary, using filesort", yet I see nothing in the query that necessitates such. Are you sure that query and that EXPLAIN go together?

  • I love the 'Hopefully it will pick the most selective' part! As a matter of fact, MySQL has been surprisingly worse than expected in my experience, as far as index selection is concerned. – Tom Desp Mar 16 '16 at 14:03
  • LOL. That particular pattern is especially bad. 5.7 has improvements, and may do better on this "toss a 4-sided coin" optimization problem. – Rick James Mar 16 '16 at 18:57
0

When a query take so much time, it often means that the database is executing a linear table scan rather than an indexed access.

However, to help you, I need more data. You had to use EXPLAIN and PROFILING to extract the required informations.

EXPLAIN is simple to grasp: it print how the query planner intends to run your query. Execute EXPLAIN <your query here> and report back the output.

PROFILING is a little more complex. To use it, you had to:

  • enable profiling via SET profiling=1
  • execute your query
  • list the profiled queries (with their IDs) using SHOW profiles
  • print detailed information executing SHOW profile FOR query <query_id>

Execute these commands and report back the output.

  • I have add the EXPLAIN portion in the original part. I Will have to add the second portion tomorrow morning. Thank you for the help. – dreedy Mar 15 '16 at 20:52
  • I have tried setting profiling as you have suggested but i come up with an issue.It seems that the database does not have profiling enabled. – dreedy Mar 16 '16 at 19:49
  • I have grabbed a tool set from Percona and run the pt-query-digest. This has given me some results back. Would that be helpfully. – dreedy Mar 16 '16 at 19:53
  • Can you EXPLAIN removing the AND rlog.end_time IS NOT NULL clause? – shodanshok Mar 17 '16 at 8:37

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.