QueueMetrics > MySQL storage and Qloaderd/Uniloader

MySQL performance issues

<< < (2/3) > >>

WRP:
We increased the amount of CPU and memory resources available recently, but this was after we began having performance issues. From every measurement I can find, it appears as though only the CPU is being stressed.

The queries normally return within 100 ms, but as of late, they have been taking up to 50 seconds (with 10-15 of these similar queries sitting in the processlist all at the same time).

What do you suggest we do to further troubleshoot this issue? Are there system tests that we can run or MySQL optimizations worth considering? I'm normally able to get on the system when the CPU pegging is occurring, so running tests or taking measurements while the issue is occurring is not out of the question.

QueueMetrics:
Try optimizing  the queue_log table, with cluster index sorting based on the time_id field. This will take a while and has to be done when the system is down.

WRP:
Can you suggest the SQL syntax to achieve this?

QueueMetrics:
Try


--- Code: ---ALTER TABLE `queue_log` ORDER BY `time_id`
--- End code ---

tsolaaa:
So this is the last thing we tried and it was working since then.

However, as of this morning, we are hitting the problem again.

Running the MYSQL tuner script.


--- Code: ---[tr][td]-------- Performance Metrics -------------------------------------------------
[--] Up for: 3d 14h 11m 52s (1M q [3.673 qps], 100K conn, TX: 53B, RX: 183M)
[--] Reads / Writes: 58% / 42%
[--] Total buffers: 330.0M global + 34.6M per thread (130 max threads)
[OK] Maximum possible memory usage: 4.7G (60% of installed RAM)
[!!] Slow queries: 11% (134K/1M)
[!!] Highest connection usage: 97%  (127/130)
[OK] Key buffer size / total MyISAM indexes: 64.0M/50.9M
[OK] Key buffer hit rate: 100.0% (379M cached / 25K reads)
[OK] Query cache efficiency: 51.8% (128K cached / 247K selects)
[OK] Query cache prunes per day: 0
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 234 sorts)
[OK] Temporary tables created on disk: 1% (3K on disk / 209K total)
[OK] Thread cache hit rate: 99% (215 created / 100K connections)
[!!] Table cache hit rate: 0% (181 open / 160K opened)
[OK] Open file limit used: 10% (233/2K)
[OK] Table locks acquired immediately: 100% (278K immediate / 278K locks)[/sub]

--- End code ---

We are still getting a ton of slow queries that make the CPU max out.

I have checked with anyone logged into the machine, and no is is running any insane reports, etc.


Here is an example of the "show processlist;"


--- Code: ---mysql> show processlist;
+--------+--------------+---------------------+--------------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| Id     | User         | Host                | db           | Command | Time | State        | Info                                                                                                 |
+--------+--------------+---------------------+--------------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| 101270 | queuemetrics | localhost:40641     | queuemetrics | Query   |  132 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101271 | queuemetrics | localhost:40642     | queuemetrics | Query   |  129 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101272 | queuemetrics | localhost:40643     | queuemetrics | Query   |  127 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101274 | queuemetrics | localhost:40644     | queuemetrics | Query   |  126 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101275 | queuemetrics | localhost:40645     | queuemetrics | Query   |  126 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101276 | queuemetrics | localhost:40646     | queuemetrics | Query   |  124 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101277 | queuemetrics | localhost:40647     | queuemetrics | Query   |  116 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101278 | queuemetrics | localhost:40648     | queuemetrics | Query   |  116 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101279 | queuemetrics | localhost:40649     | queuemetrics | Query   |  114 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101280 | queuemetrics | localhost:40650     | queuemetrics | Query   |  103 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101281 | queuemetrics | localhost:40651     | queuemetrics | Query   |  102 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101282 | queuemetrics | localhost:40652     | queuemetrics | Query   |   94 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101284 | queuemetrics | localhost:40653     | queuemetrics | Query   |   83 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101285 | queuemetrics | localhost:40654     | queuemetrics | Query   |   82 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101286 | queuemetrics | localhost:40655     | queuemetrics | Query   |   80 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101287 | queuemetrics | localhost:40656     | queuemetrics | Query   |   82 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101289 | queuemetrics | localhost:40657     | queuemetrics | Query   |   80 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101290 | queuemetrics | localhost:40658     | queuemetrics | Query   |   80 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101291 | queuemetrics | localhost:40659     | queuemetrics | Query   |   77 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101292 | queuemetrics | localhost:40660     | queuemetrics | Query   |   69 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101293 | queuemetrics | localhost:40661     | queuemetrics | Query   |   69 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101294 | queuemetrics | localhost:40662     | queuemetrics | Query   |   68 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101295 | queuemetrics | localhost:40663     | queuemetrics | Query   |   61 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101297 | queuemetrics | 64.207.128.55:41921 | queuemetrics | Sleep   |    5 |              | NULL                                                                                                 |
| 101298 | queuemetrics | localhost:53878     | queuemetrics | Query   |   47 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101299 | queuemetrics | localhost:53879     | queuemetrics | Query   |   44 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101301 | queuemetrics | localhost:53880     | queuemetrics | Query   |   40 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101302 | queuemetrics | localhost:53881     | queuemetrics | Query   |   39 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101303 | queuemetrics | localhost:53882     | queuemetrics | Query   |   39 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101304 | queuemetrics | localhost:53883     | queuemetrics | Query   |   36 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101305 | queuemetrics | localhost:53884     | queuemetrics | Query   |   28 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101306 | queuemetrics | localhost:53885     | queuemetrics | Query   |   25 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101307 | queuemetrics | localhost:53886     | queuemetrics | Query   |   25 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101308 | queuemetrics | localhost:53887     | queuemetrics | Query   |   19 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101309 | queuemetrics | localhost:53888     | queuemetrics | Query   |   16 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101310 | queuemetrics | localhost:53889     | queuemetrics | Query   |   11 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101311 | queuemetrics | localhost:53890     | queuemetrics | Query   |    6 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101312 | queuemetrics | localhost:53891     | queuemetrics | Query   |    6 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101313 | queuemetrics | localhost:53892     | queuemetrics | Query   |    5 | Sending data | SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue |
| 101314 | root         | localhost           | queuemetrics | Query   |    0 | NULL         | show processlist                                                                                     |
+--------+--------------+---------------------+--------------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
40 rows in set (0.00 sec)

--- End code ---



Also, here is some of the slow query logs


--- Code: ---

[root@qm log]# tail -f mysqld.slow.log
# Time: 110718 14:29:07
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 146  Lock_time: 0  Rows_sent: 30578  Rows_examined: 2136443
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , 'q-301'  , '3011'  , '3010'  , '3005'  , '3006'  , 'none'  , '3003'  , '3004'  , '3009'  , '3008' )   ORDER BY time_id ASC , unique_row_count ASC;
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 22
INSERT INTO temp_union_556553 SELECT id_coda , nome_coda ,  LCASE(composizione_coda) AS composizione_coda,  LCASE(agenti_membri) AS agenti_membri ,  LCASE(agenti_spilloff_1) AS agenti_spilloff_1 ,  LCASE(agenti_spilloff_2) AS agenti_spilloff_2 , wrapuptime , announcement_duration , visibility_key , q_direction , sl_calls_y , sl_calls_r , sl_ag_calls_y , sl_ag_calls_r , sl_ag_wait_y , sl_ag_wait_r , sl_ag_pause_y , sl_ag_pause_r , sl_waittime_y , sl_waittime_r , sl_talktime_y , sl_talktime_r  FROM code_possibili WHERE   composizione_coda IN ( '3003', '3004', '3005', '3006', '3008', '3009', '3010', '3011', 'q-301',  'dummy-close-list' );
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 10  Rows_examined: 10
SELECT * FROM temp_union_556553;
# Time: 110718 14:29:11
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 148  Lock_time: 0  Rows_sent: 1125  Rows_examined: 2136443
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , '3000'  , 'none'  , 'q-300' )   ORDER BY time_id ASC , unique_row_count ASC;
# Time: 110718 14:29:13
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 3  Rows_examined: 3
SELECT * FROM temp_union_567841;
# Time: 110718 14:29:14
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 141  Lock_time: 0  Rows_sent: 30585  Rows_examined: 2136454
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , 'q-301'  , '3011'  , '3010'  , '3005'  , '3006'  , 'none'  , '3003'  , '3004'  , '3009'  , '3008' )   ORDER BY time_id ASC , unique_row_count ASC;
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 22
INSERT INTO temp_union_687716 SELECT id_coda , nome_coda ,  LCASE(composizione_coda) AS composizione_coda,  LCASE(agenti_membri) AS agenti_membri ,  LCASE(agenti_spilloff_1) AS agenti_spilloff_1 ,  LCASE(agenti_spilloff_2) AS agenti_spilloff_2 , wrapuptime , announcement_duration , visibility_key , q_direction , sl_calls_y , sl_calls_r , sl_ag_calls_y , sl_ag_calls_r , sl_ag_wait_y , sl_ag_wait_r , sl_ag_pause_y , sl_ag_pause_r , sl_waittime_y , sl_waittime_r , sl_talktime_y , sl_talktime_r  FROM code_possibili WHERE   composizione_coda IN ( '3003', '3004', '3005', '3006', '3008', '3009', '3010', '3011', 'q-301',  'dummy-close-list' );
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 10  Rows_examined: 10
SELECT * FROM temp_union_687716;
# Time: 110718 14:29:20
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 142  Lock_time: 0  Rows_sent: 1131  Rows_examined: 2136459
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , '3000'  , 'none'  , 'q-300' )   ORDER BY time_id ASC , unique_row_count ASC;
# Time: 110718 14:29:24
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 143  Lock_time: 0  Rows_sent: 1135  Rows_examined: 2136473
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , '3000'  , 'none'  , 'q-300' )   ORDER BY time_id ASC , unique_row_count ASC;
# Time: 110718 14:29:33
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 152  Lock_time: 0  Rows_sent: 30598  Rows_examined: 2136473
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , 'q-301'  , '3011'  , '3010'  , '3005'  , '3006'  , 'none'  , '3003'  , '3004'  , '3009'  , '3008' )   ORDER BY time_id ASC , unique_row_count ASC;
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 22
INSERT INTO temp_union_266575 SELECT id_coda , nome_coda ,  LCASE(composizione_coda) AS composizione_coda,  LCASE(agenti_membri) AS agenti_membri ,  LCASE(agenti_spilloff_1) AS agenti_spilloff_1 ,  LCASE(agenti_spilloff_2) AS agenti_spilloff_2 , wrapuptime , announcement_duration , visibility_key , q_direction , sl_calls_y , sl_calls_r , sl_ag_calls_y , sl_ag_calls_r , sl_ag_wait_y , sl_ag_wait_r , sl_ag_pause_y , sl_ag_pause_r , sl_waittime_y , sl_waittime_r , sl_talktime_y , sl_talktime_r  FROM code_possibili WHERE   composizione_coda IN ( '3003', '3004', '3005', '3006', '3008', '3009', '3010', '3011', 'q-301',  'dummy-close-list' );
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 10  Rows_examined: 10
SELECT * FROM temp_union_266575;
# Time: 110718 14:29:34
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 3  Rows_examined: 3
SELECT * FROM temp_union_155538;
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 154  Lock_time: 0  Rows_sent: 30598  Rows_examined: 2136471
SELECT time_id , call_id , queue , agent , verb , data1 , data2 , data3 , data4 , data5   FROM queue_log  WHERE  partition ='P001' AND        (time_id >= '1310972400' AND time_id<='1577869260')     AND queue IN ( '', 'NONE'  , 'q-301'  , '3011'  , '3010'  , '3005'  , '3006'  , 'none'  , '3003'  , '3004'  , '3009'  , '3008' )   ORDER BY time_id ASC , unique_row_count ASC;
# Time: 110718 14:29:35
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 22
INSERT INTO temp_union_813568 SELECT id_coda , nome_coda ,  LCASE(composizione_coda) AS composizione_coda,  LCASE(agenti_membri) AS agenti_membri ,  LCASE(agenti_spilloff_1) AS agenti_spilloff_1 ,  LCASE(agenti_spilloff_2) AS agenti_spilloff_2 , wrapuptime , announcement_duration , visibility_key , q_direction , sl_calls_y , sl_calls_r , sl_ag_calls_y , sl_ag_calls_r , sl_ag_wait_y , sl_ag_wait_r , sl_ag_pause_y , sl_ag_pause_r , sl_waittime_y , sl_waittime_r , sl_talktime_y , sl_talktime_r  FROM code_possibili WHERE   composizione_coda IN ( '3003', '3004', '3005', '3006', '3008', '3009', '3010', '3011', 'q-301',  'dummy-close-list' );
# User@Host: queuemetrics[queuemetrics] @ localhost [127.0.0.1]
# Query_time: 0  Lock_time: 0  Rows_sent: 10  Rows_examined: 10
SELECT * FROM temp_union_813568;
# Time: 110718 14:29:30



--- End code ---

Navigation

[0] Message Index

[#] Next page

[*] Previous page

Go to full version