收到某个MySQL服务器负载高于预警的报告,连接到该服务器后,首先查看负载情况:
[jss@BKmysql-03 ~]$ w
16:34:33 up 54 days, 4:22, 5 users, load average: 67.31, 70.10, 51.90
loadavg已经飙到双位数了,确实非常高,通过TOP查看进程的占用如下:
[jss@BKmysql-03 ~]$ top
top - 16:34:40 up 54 days, 4:22, 5 users, load average: 67.77, 70.15, 52.01
Tasks: 198 total, 3 running, 195 sleeping, 0 stopped, 0 zombie
Cpu(s): 1.4%us, 0.2%sy, 0.0%ni, 98.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 33554432k total, 32247564k used, 1306868k free, 426440k buffers
Swap: 49150856k total, 80k used, 49150776k free, 20735220k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
22646 mysql 15 0 9.9g 5.5g 7036 R 614.4 17.3 9267:32 mysqld
...................
...................
top - 16:35:08 up 54 days, 4:23, 5 users, load average: 70.47, 70.67, 52.77
Tasks: 205 total, 3 running, 202 sleeping, 0 stopped, 0 zombie
Cpu0 : 7.1%us, 1.4%sy, 0.0%ni, 91.0%id, 0.1%wa, 0.0%hi, 0.3%si, 0.1%st
Cpu1 : 1.0%us, 0.4%sy, 0.0%ni, 98.5%id, 0.1%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 0.5%us, 0.0%sy, 0.0%ni, 99.5%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 0.4%us, 0.0%sy, 0.0%ni, 99.6%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 0.4%us, 0.0%sy, 0.0%ni, 99.6%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 0.5%us, 0.0%sy, 0.0%ni, 99.5%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 0.4%us, 0.0%sy, 0.0%ni, 99.6%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu7 : 0.8%us, 0.0%sy, 0.0%ni, 99.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 33554432k total, 32254368k used, 1300064k free, 426440k buffers
Swap: 49150856k total, 80k used, 49150776k free, 20733516k cached
4 root RT -5 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
22646 mysql 16 0 9.9g 5.5g 7036 R 793.2 17.3 9271:10 mysqld
18558 mysql 17 0 66048 1120 952 S 0.4 0.0 0:00.01 mymon.sh
1 root 15 0 10348 684 576 S 0.0 0.0 0:00.51 init
2 root RT -5 0 0 0 S 0.0 0.0 0:01.76 migration/0
3 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
初始分析,CPU
上面的信息已经非常清晰的列出了最占资源的进程:mysqld,不过由于该机同时跑有多个MySQL实例,还需要进一步确认,最占资源的进程号是由哪个进程持有:
[jss@BKmysql-03 ~]$ ps -ef | grep 22646
jss 18584 18307 0 16:35 pts/5 00:00:00 grep 22646
mysql 22646 21712 12 Feb02 ? 6-10:32:03 /usr/local/mysql/bin/mysqld --defaults-file=/data/mysqldata/3307/my.cnf --basedir=/usr/local/mysql --datadir=/data/mysqldata/3307/data --plugin-dir=/usr/local/mysql/lib/plugin --log-error=/data/mysqldata/3307/mysql-error.log --open-files-limit=8192 --pid-file=/data/mysqldata/3307/mysql.pid --socket=/data/mysqldata/3307/mysql.sock --port=3307
进入mysql命令行模式连接到该实例,查看当前MySQL的进程列表,发现一堆Query状态进程正在处理:
mysql> show processlist;
+-----------+----------------------+----------------------+----------+---------+---------+------------------+-----------+
| Id | User | Host | db | Command | Time | State | Info |
+-----------+----------------------+----------------------+----------+---------+---------+------------------+-----------+
..............
..............
| 360359253 | apps_read | 192.168.31.55:37464 | apps | Query | 613 | Sending data | SELECT ......... |
| 360371212 | apps_read | 192.168.31.52:34632 | apps | Query | 575 | Sending data | SELECT ......... |
| 360371411 | apps_read | 192.168.31.59:4209 | apps | Query | 518 | Sending data | SELECT ......... |
| 360371805 | apps_read | 192.168.31.66:44717 | apps | Query | 595 | Sending data | SELECT ......... |
...............
...............
+-----------+----------------------+----------------------+----------+---------+---------+------------------+-----------+
527 rows in set (0.00 sec)
大部分进程均在执行同一条SQL语句:
SELECT q.* FROM ask_questions q WHERE q.object_id=????? AND q.status = 1 AND product_id=1 AND NOT EXISTS (SELECT a.id FROM ask_answers a WHERE a.question_id=q.id AND a.status = 4) ORDER BY q.create_date DESC LIMIT 0, 8
查看该语句执行计划:
mysql> use apps;
Database changed
mysql> explain SELECT q.* FROM ask_questions q WHERE q.object_id=????? AND q.status = 1 AND product_id=1 AND NOT EXISTS (SELECT a.id FROM ask_answers a WHERE a.question_id=q.id AND a.status = 4) ORDER BY q.create_date DESC LIMIT 0, 8;
+----+--------------------+-------+-------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+--------------------+-------+-------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
| 1 | PRIMARY | q | ref | ind_ask_questions_object_id | ind_ask_questions_object_id | 5 | const | 565 | Using where; Using filesort |
| 2 | DEPENDENT SUBQUERY | a | index | NULL | idx_data_id_stat | 10 | NULL | 159386 | Using where; Using index |
+----+--------------------+-------+-------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
2 rows in set (0.01 sec)
通过执行计划可以看出该语句子查询的执行计划相当的不乐观,通过idx_data_id_stat索引每次居然需要遍历近16w记录。我们知道索引扫描属于随机I/O,频繁并且大量的随机I/O性能显然是很糟糕的。
看看子查询表的索引情况:
mysql> show index from ask_answers;
+-------------+------------+---------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
+-------------+------------+---------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| ask_answers | 0 | PRIMARY | 1 | id | A | 144039 | NULL | NULL | | BTREE | | |
| ask_answers | 1 | ind_ask_answers_object_id | 1 | object_id | A | 5144 | NULL | NULL | YES | BTREE | | |
| ask_answers | 1 | idx_data_id_stat | 1 | create_date | A | 180 | NULL | NULL | YES | BTREE | | |
| ask_answers | 1 | idx_data_id_stat | 2 | question_id | A | 180 | NULL | NULL | | BTREE | | |
| ask_answers | 1 | idx_data_id_stat | 3 | status | A | 180 | NULL | NULL | | BTREE | | |
+-------------+------------+---------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
5 rows in set (0.00 sec)
强大呀,MySQL也有索引跳扫了吗,居然选择了idx_data_id_stat这项索引。
问了一下同事,原来是不久前根据慢查询的情况刚刚创建的,是为了优化查询时where create_date between ...的查询条件而创建,考虑到该查询同时需要过滤question_id和status,就创建了三列的复合索引。但是没想到给未附带create_date的查询语句造成了影响。
尽管该表并不大,十余万条记录,但每次查询都可能导致的十几万次随机读还是致使系统负载急速升高。
首要举措是删除这个不合理的索引:
mysql> alter table ask_answers drop index idx_data_id_stat;
Query OK, 0 rows affected (40.40 sec)
Records: 0 Duplicates: 0 Warnings: 0
查看执行计划,即使全表扫也会比走索引要快,因为全表扫多是顺序读:
mysql> explain SELECT q.* FROM ask_questions q WHERE q.object_id=????? AND q.status = 1 AND product_id=1 AND NOT EXISTS (SELECT a.id FROM ask_answers a WHERE a.question_id=q.id AND a.status = 4) ORDER BY q.create_date DESC LIMIT 0, 8 ;
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
| 1 | PRIMARY | q | ref | ind_ask_questions_object_id | ind_ask_questions_object_id | 5 | const | 565 | Using where; Using filesort |
| 2 | DEPENDENT SUBQUERY | a | ALL | NULL | NULL | NULL | NULL | 144039 | Using where |
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-------+--------+-----------------------------+
2 rows in set (0.00 sec)
然后再次show processlist时,基本上已经看不到Command列不等于Sleep的进程了:
mysql> show processlist;
+-----------+----------------------+----------------------+----------+---------+---------+------------------+-----------+
| Id | User | Host | db | Command | Time | State | Info |
+-----------+----------------------+----------------------+----------+---------+---------+------------------+-----------+
..............
..............
| 360310280 | apps_read | 192.168.31.58:64731 | apps | Sleep | 1 | | NULL |
| 360311110 | apps_read | 192.168.31.54:6988 | apps | Sleep | 1 | | NULL |
| 360311122 | apps_read | 192.168.31.58:64980 | apps | Sleep | 0 | | NULL |
..............
64 rows in set (0.36 sec)
进程数也大幅下降。
再次查看整机负载,已经在明显下降:
[mysql@BKmysql-03 3307]# w
16:46:05 up 54 days, 4:44, 4 users, load average: 18.72, 45.33, 55.43
USER TTY FROM LOGIN@ IDLE JCPU PCPU WHAT
jss pts/5 203.xx.xx.83 16:34 24.00s 0.13s 0.02s sshd: jss [priv]
jss pts/6 203.xx.xx.83 16:36 0.00s 0.05s 0.02s sshd: jss [priv]
[mysql@BKmysql-03 3307]# w
16:46:34 up 54 days, 4:44, 4 users, load average: 13.48, 41.53, 53.84
USER TTY FROM LOGIN@ IDLE JCPU PCPU WHAT
jss pts/5 203.xx.xx.83 16:34 10.00s 0.13s 0.02s sshd: jss [priv]
jss pts/6 203.xx.xx.83 16:36 0.00s 0.05s 0.02s sshd: jss [priv]
几分钟后,loadavg整机负载基本降至2-3,但是全表扫描也仍不理解,需要进一步优化。
考虑到该表除了上面这种查询形式外,还有基于create_date列的查询,因此决定创建两个索引,如下:
mysql> alter table ask_answers add index ind_create_date (create_date),add index ind_question_state (question_id,status);
Query OK, 0 rows affected (1.21 sec)
Records: 0 Duplicates: 0 Warnings: 0
没有了锁的竞争,这次创建索引操作执行也非常快,秒级完成。
再次查看执行计划:
mysql> explain SELECT q.* FROM ask_questions q WHERE q.object_id=????? AND q.status = 1 AND product_id=1 AND NOT EXISTS (SELECT a.id FROM ask_answers a WHERE a.question_id=q.id AND a.status = 4) ORDER BY q.create_date DESC LIMIT 0, 8 ;
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-----------------+------+-----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-----------------+------+-----------------------------+
| 1 | PRIMARY | q | ref | ind_ask_questions_object_id | ind_ask_questions_object_id | 5 | const | 565 | Using where; Using filesort |
| 2 | DEPENDENT SUBQUERY | a | ref | ind_question_state | ind_question_state | 5 | apps.q.id,const | 720 | Using index |
+----+--------------------+-------+------+-----------------------------+-----------------------------+---------+-----------------+------+-----------------------------+
2 rows in set (0.00 sec)
重新多次刷新show processlist已经完全看不到有正在执行的任务了。
此时,整机的负载也恢复到极低的水平:
[mysql@BKmysql-03 3307]# w
17:55:46 up 54 days, 5:43, 3 users, load average: 0.25, 0.09, 1.32
从70到0.x,数百倍的差距。对于MySQL数据库来说,一条坏SQL的确有可能拖死整个服务。
来自 “ ITPUB博客 ” ,链接:https://blog.itpub.net/30247732/viewspace-1655701/
,如需转载,请注明出处,否则将追究法律责任。