Hi,
I have a query which appears in the slow logs.
The query is a simple order by id query:
SELECT news_id,news_title FROM news ORDER BY news_id DESC LIMIT 25
Explain:
explain SELECT news_id,news_title FROM news ORDER BY news_id DESC LIMIT 25;
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
| 1 | SIMPLE | news | index | NULL | PRIMARY | 4 | NULL | 179016 | |
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
1 row in set (0.00 sec)
I’ve tried “FORCE INDEX(PRIMARY)” but nothing changed:
explain SELECT news_id,news_title FROM news FORCE INDEX(PRIMARY) ORDER BY news_id DESC LIMIT 25;
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
| 1 | SIMPLE | news | index | NULL | PRIMARY | 4 | NULL | 179016 | |
±—±------------±------±------±--------------±------- -±--------±-----±-------±------+
1 row in set (0.00 sec)
This is a MyISAM table and news_id is primary key for the table.
How can i optimise this query?
vgatto
April 8, 2009, 3:13pm
2
According to your explain, MySQL is using an index scan to evaluate your query. However, if you have --log-queries-not-using-indexes enabled, queries which use index scans will be written to the slow query log regardless of their execution time. Have you tried running this query from the command line client? I’m guessing it takes under a tenth of second to execute.
Yes, you’re right.
I’m trying to find out what causing mysql to use 190% CPU sometimes. So I’ve enabled “log-queries-not-using-indexes”.
januzi
April 8, 2009, 3:34pm
4
This is the only one query in the query log ?
No. But this is the most used/logged query.
And this ones appears sometimes:
SELECT news_id,news_title,news_hit FROM news ORDER BY news_date DESC LIMIT 0, 25;
SELECT news_id,news_title,news_position,news_hit,news_cat,news_date FROM news WHERE DATE(news_date) = CURDATE() ORDER BY
news_date ASC LIMIT 0, 50;
SELECT news_id,news_title,news_summary,news_image_small FROM news WHERE news_cat=‘7’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
SELECT news_id,news_title,news_image,news_summary FROM news WHERE (news_position=‘2’ or news_position=‘6’) and news_cat=‘1’ ORDER BY news_date DESC LIMIT 12;
SELECT * FROM comments WHERE com_status=‘0’ ORDER BY com_date;
I’m working on each query. But I’m not sure if slow queries does this.
This is a heavy load news site. MySQL is the only service on the server. (2.4 GHz Xeon CPU, 2GB RAM)
I can’t give any slow query right now because there isn’t. Slow queries only appears during busy hours. And MySQL CPU usage stays between 100-190%.
januzi
April 8, 2009, 4:20pm
6
explain SELECT news_id,news_title,news_position,news_hit,news_cat,news_date FROM news WHERE DATE(news_date) = CURDATE() ORDER BY
news_date ASC LIMIT 0, 50;
explain SELECT news_id,news_title,news_summary,news_image_small FROM news WHERE news_cat=‘7’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
explain SELECT news_id,news_title,news_image,news_summary FROM news WHERE (news_position=‘2’ or news_position=‘6’) and news_cat=‘1’ ORDER BY news_date DESC LIMIT 12;
I think that query with DATE(news_date) is the worst. Explain should show fullscan.
Yes. I mean the query with CURDATE() function does full scan. But that query is only used on a few pages rarely visited.
mysql> explain SELECT news_id,news_title,news_position,news_hit,news_cat,news_date FROM news WHERE DATE(news_date) = CURDATE() ORDER BY
→ news_date ASC LIMIT 0, 50;
±—±------------±------±------±--------------±------- —±--------±-----±-------±------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±------±--------------±------- —±--------±-----±-------±------------+
| 1 | SIMPLE | news | index | NULL | news_date | 8 | NULL | 179101 | Using where |
±—±------------±------±------±--------------±------- —±--------±-----±-------±------------+
1 row in set (0.00 sec)
mysql> explain SELECT news_id,news_title,news_summary,news_image_small FROM news WHERE news_cat=‘7’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
±—±------------±------±------------±----------------- ------±-----------------------±--------±-----±-----±— ------------------------------------------------------------ ------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±------------±----------------- ------±-----------------------±--------±-----±-----±— ------------------------------------------------------------ ------+
| 1 | SIMPLE | news | index_merge | news_position,news_cat | news_cat,news_position | 1,1 | NULL | 651 | Using intersect(news_cat,news_position); Using where; Using filesort |
±—±------------±------±------------±----------------- ------±-----------------------±--------±-----±-----±— ------------------------------------------------------------ ------+
1 row in set (0.00 sec)
mysql> explain SELECT news_id,news_title,news_image,news_summary FROM news WHERE (news_position=‘2’ or news_position=‘6’) and news_cat=‘1’ ORDER BY news_date DESC LIMIT 12;
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
| 1 | SIMPLE | news | ref | news_position,news_cat | news_cat | 1 | const | 49552 | Using where; Using filesort |
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
1 row in set (0.00 sec)
januzi
April 8, 2009, 5:02pm
8
Try
explain SELECT news_id,news_title,news_image,news_summary FROM news WHERE (news_position=‘2’ and news_cat = ‘1’ ) or ( news_position=‘6’ and news_cat=‘1’ ) ORDER BY news_date DESC LIMIT 12;
So, the most common query is SELECT news_id,news_title,news_hit FROM news ORDER BY news_date DESC LIMIT 0, 25; ?
Edit:
Please, copy news table (structure) into news_tmp.
Add some records (100 should do it) and then check it with:
explain SELECT news_id,news_title,news_summary,news_image_small FROM news_tmp WHERE news_cat=‘7’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
Create index with two columns: news_cat + news_position, optimize table and check it again. (remember to use valid news_cat and news_position)
Before new index:
explain SELECT news_id,news_title,news_summary,news_image_small FROM news_tmp WHERE news_cat=‘1’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
±—±------------±---------±------------±-------------- ---------±-----------------------±--------±-----±-----± ------------------------------------------------------------ ---------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±---------±------------±-------------- ---------±-----------------------±--------±-----±-----± ------------------------------------------------------------ ---------+
| 1 | SIMPLE | news_tmp | index_merge | news_position,news_cat | news_position,news_cat | 1,1 | NULL | 3 | Using intersect(news_position,news_cat); Using where; Using filesort |
±—±------------±---------±------------±-------------- ---------±-----------------------±--------±-----±-----± ------------------------------------------------------------ ---------+
1 row in set (0.00 sec)
After adding new index (cat_position):
explain SELECT news_id,news_title,news_summary,news_image_small FROM news_tmp WHERE news_cat=‘1’ and news_position=‘7’ ORDER BY news_date DESC LIMIT 1;
±—±------------±---------±-----±--------------------- ---------------±-------------±--------±------------±---- -±----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±---------±-----±--------------------- ---------------±-------------±--------±------------±---- -±----------------------------+
| 1 | SIMPLE | news_tmp | ref | news_position,news_cat,cat_position | cat_position | 2 | const,const | 2 | Using where; Using filesort |
±—±------------±---------±-----±--------------------- ---------------±-------------±--------±------------±---- -±----------------------------+
1 row in set (0.00 sec)
Now these queries also appears in slow log:
SELECT news_id,news_title,news_date FROM news WHERE news_cat=‘1’ ORDER BY news_date DESC LIMIT 5;
explain SELECT news_id,news_title,news_date FROM news WHERE news_cat=‘1’ ORDER BY news_date DESC LIMIT 5;
±—±------------±------±-----±--------------±-------- -±--------±------±------±----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±--------------±-------- -±--------±------±------±----------------------------+
| 1 | SIMPLE | news | ref | news_cat | news_cat | 1 | const | 46664 | Using where; Using filesort |
±—±------------±------±-----±--------------±-------- -±--------±------±------±----------------------------+
1 row in set (0.00 sec)
SELECT news_id,news_title,news_image,news_summary FROM news WHERE news_position=‘2’ ORDER BY news_date DESC LIMIT 12;
explain SELECT news_id,news_title,news_image,news_summary FROM news WHERE news_position=‘2’ ORDER BY news_date DESC LIMIT 12;
±—±------------±------±-----±--------------±-------- ------±--------±------±------±-------------------------- --+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±--------------±-------- ------±--------±------±------±-------------------------- --+
| 1 | SIMPLE | news | ref | news_position | news_position | 1 | const | 34438 | Using where; Using filesort |
±—±------------±------±-----±--------------±-------- ------±--------±------±------±-------------------------- --+
1 row in set (0.19 sec)
SELECT news_id,news_title,news_image_small,news_summary FROM news WHERE news_position IN (8,3,7) and news_cat=‘1’ ORDER BY
news_date DESC LIMIT 0, 2;
explain SELECT news_id,news_title,news_image_small,news_summary FROM news WHERE news_position IN (8,3,7) and news_cat=‘1’ ORDER BY
→ news_date DESC LIMIT 0, 2;
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
| 1 | SIMPLE | news | ref | news_position,news_cat | news_cat | 1 | const | 46665 | Using where; Using filesort |
±—±------------±------±-----±-----------------------+ ----------±--------±------±------±---------------------- ------+
1 row in set (0.09 sec)
januzi
April 9, 2009, 5:44am
11
Ok, add that new index to the news table.
Did You think about splitting news table into two separate tables ? First with 25 rows - the newest data, second with rest of the data.
I’ve added new index, cat_position.
Now there are 5 indexes:
PRIMARY (news_id)
news_position
news_cat
news_date
cat_position (news_cat, news_position)
Yes I did think about splitting news table into two seperate tables. First one for current day and other for rest of the news. But I couldn’t figure out how can I implement new structure to the site. How to move records between two tables? How to build home page and other pages? etc… I’m still looking for an example but couldn’t find one yet.
Thank you so much.
MySQL still use 170-180% CPU sometimes with no slow log. This was the only one:
SELECT news_id,news_title,news_position FROM news WHERE news_cat=‘5’ ORDER BY news_date DESC LIMIT 6;
explain SELECT news_id,news_title,news_position FROM news WHERE news_cat=‘5’ ORDER BY news_date DESC LIMIT 6;
±—±------------±------±-----±----------------------± -------------±--------±------±------±------------------- ---------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
±—±------------±------±-----±----------------------± -------------±--------±------±------±------------------- ---------+
| 1 | SIMPLE | news | ref | news_cat,cat_position | cat_position | 1 | const | 18169 | Using where; Using filesort |
±—±------------±------±-----±----------------------± -------------±--------±------±------±------------------- ---------+
1 row in set (0.00 sec)
januzi
April 9, 2009, 6:42am
14
Could You paste “show status” ? Skip variables with value = 0
show status;
±----------------------------------±-------------+
| Variable_name | Value |
±----------------------------------±-------------+
| Aborted_clients | 2 |
| Aborted_connects | 2 |
| Bytes_received | 1596 |
| Bytes_sent | 22046 |
| Com_change_db | 1 |
| Com_show_databases | 1 |
| Com_show_fields | 27 |
| Com_show_status | 1 |
| Com_show_tables | 1 |
| Compression | OFF |
| Connections | 862868 |
| Created_tmp_files | 46901 |
| Created_tmp_tables | 3 |
| Flush_commands | 1 |
| Handler_read_rnd_next | 32 |
| Handler_write | 161 |
| Key_blocks_unused | 107350 |
| Key_blocks_used | 11411 |
| Key_read_requests | 54226934 |
| Key_reads | 16980 |
| Key_write_requests | 219634 |
| Key_writes | 7345 |
| Last_query_cost | 21555.899000 |
| Max_used_connections | 380 |
| Open_files | 232 |
| Open_tables | 186 |
| Qcache_free_blocks | 494 |
| Qcache_free_memory | 130821696 |
| Qcache_hits | 3378511 |
| Qcache_inserts | 407703 |
| Qcache_not_cached | 100424 |
| Qcache_queries_in_cache | 928 |
| Qcache_total_blocks | 2393 |
| Questions | 6740807 |
| Rpl_status | NULL |
| Slave_running | OFF |
| Ssl_session_cache_mode | NONE |
| Table_locks_immediate | 843738 |
| Table_locks_waited | 35763 |
| Threads_cached | 4 |
| Threads_connected | 8 |
| Threads_created | 13860 |
| Threads_running | 3 |
| Uptime | 55618 |
±----------------------------------±-------------+
251 rows in set (0.00 sec)
januzi
April 9, 2009, 8:11am
16
Please run:
Show processlist
and paste output of the “top” with maximal cpu usage
I couldn’t catch a busy time, but this shows 113 % CPU usage:
top - 17:02:26 up 58 days, 13:39, 2 users, load average: 0.58, 0.55, 0.62
Tasks: 70 total, 1 running, 69 sleeping, 0 stopped, 0 zombie
Cpu(s): 27.9%us, 28.5%sy, 0.0%ni, 41.6%id, 0.8%wa, 0.2%hi, 1.0%si, 0.0%st
Mem: 2076468k total, 1304408k used, 772060k free, 203136k buffers
Swap: 1951888k total, 0k used, 1951888k free, 843996k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3049 mysql 15 0 409m 113m 4720 S 113 5.6 217:00.85 mysqld
21761 root 15 0 2228 1120 856 R 0 0.1 0:00.19 top
1 root 15 0 1948 644 552 S 0 0.0 0:03.44 init
2 root RT 0 0 0 0 S 0 0.0 0:00.00 migration/0
3 root 34 19 0 0 0 S 0 0.0 0:00.00 ksoftirqd/0
4 root RT 0 0 0 0 S 0 0.0 0:00.00 migration/1
5 root 34 19 0 0 0 S 0 0.0 0:00.00 ksoftirqd/1
6 root 10 -5 0 0 0 S 0 0.0 0:00.14 events/0
7 root 10 -5 0 0 0 S 0 0.0 0:00.01 events/1
8 root 10 -5 0 0 0 S 0 0.0 0:01.03 khelper
9 root 10 -5 0 0 0 S 0 0.0 0:00.00 kthread
13 root 14 -5 0 0 0 S 0 0.0 0:00.10 kblockd/0
14 root 10 -5 0 0 0 S 0 0.0 0:00.28 kblockd/1
15 root 17 -5 0 0 0 S 0 0.0 0:00.00 kacpid
105 root 11 -5 0 0 0 S 0 0.0 0:00.00 kseriod
145 root 18 -5 0 0 0 S 0 0.0 0:00.00 kswapd0
146 root 18 -5 0 0 0 S 0 0.0 0:00.00 aio/0
147 root 19 -5 0 0 0 S 0 0.0 0:00.00 aio/1
292 root 15 0 0 0 0 S 0 0.0 0:00.04 kirqd
617 root 10 -5 0 0 0 S 0 0.0 0:00.00 khubd
780 root 12 -5 0 0 0 S 0 0.0 0:00.00 scsi_eh_0
794 root 11 -5 0 0 0 S 0 0.0 0:00.00 scsi_eh_1
show processlist;
±--------±-----±--------------------±-----±--------±-- —±-------------±---------------------------------------- ------------------------------------------------------------ -+
| Id | User | Host | db | Command | Time | State | Info |
±--------±-----±--------------------±-----±--------±-- —±-------------±---------------------------------------- ------------------------------------------------------------ -+
| 1029605 | root | localhost | gg | Query | 0 | NULL | show processlist |
| 1042170 | gg | 212.175.22.32:50384 | gg | Query | 1 | Sending data | SELECT news_id,news_title,news_position,news_hit,news_cat,news_date FROM news WHERE DATE(news_date) |
| 1042171 | gg | 212.175.22.32:50385 | gg | Sleep | 2 | | NULL |
| 1042198 | gg | 212.175.22.32:38002 | gg | Sleep | 1 | | NULL |
| 1042202 | gg | 212.175.22.32:38006 | gg | Query | 1 | Locked | UPDATE news SET news_hit=‘216’ WHERE news_id=‘182212’ |
| 1042204 | gg | 212.175.22.32:38008 | gg | Sleep | 1 | | NULL |
| 1042209 | gg | 212.175.22.32:38013 | gg | Query | 1 | Locked | SELECT news_id,news_position,news_title,news_hit,news_date FROM news WHERE news_date BETWEEN concat( |
| 1042210 | gg | 212.175.22.32:38014 | gg | Sleep | 1 | | NULL |
±--------±-----±--------------------±-----±--------±-- —±-------------±---------------------------------------- ------------------------------------------------------------ -+
8 rows in set (0.00 sec)
januzi
April 9, 2009, 12:40pm
18
Hmmm … does cpu usage rise with hdd i/o ?
Could You check Your raid status (if there is a raid) ?
Does hdd run in dma mode ?
Could You run “optimize table news” and “analyze table news” ?
There is no RAID.
I couldn’t find out dma status:
hdparm -i /dev/sda
/dev/sda:
HDIO_GET_IDENTITY failed: Invalid argument
hdparm -I /dev/sda
/dev/sda:
HDIO_DRIVE_CMD(identify) failed: Invalid argument
I’ve runned optimize/analyze many times.
januzi
April 12, 2009, 7:52am
20
Please check:
explain SELECT news_id,news_title,news_hit FROM news where news_date in ( $xxx ) ORDER BY news_date DESC LIMIT 0, 25;
where $xxx is list of the dates eg: $xxx = “‘2009-04-01’, ‘2009-04-02’, ‘2009-04-03’” ;
There is a limit of the length of the query, but I think that You will be able to put two months in that list. This should limit amount of the rows.