如何利用 MySQL 攻破数据库效能瓶颈？_日志
作者 | 阿文
责编 | 郭芮
今天和大家分享一下 MySQL 的慢日志。
在实际工作中，我面对很多使用者会经常碰到一个问题，那就是在使用 MySQL时，执行一条语句需要很长时间返回，这是为什么呢？当你在使用 MySQL 中，当发现一些效能问题的时，比如执行一个语句要很长时间才返回结果，我们称之为慢查询，一般来说，发生慢查询的原因有：
通常情况下，在业务上线之前，会在测试环境里面，把 MySQL的慢查询开启，也就是把 longquerytime 设定为 0，这样确保每一条语句都被记录到慢日志中去，具体的配置可以参考下文。
MySQL 的慢查询日志是MySQL提供的一种日志记录，它是用来记录在MySQL中响应时间超过阀值的语句。系统预设情况下，MySQL 并不启动慢查询日志，需要我们手动来设定这个引数，当然，如果不是调优需要的话，一般不建议启动该引数，因为开启慢查询日志会或多或少带来一定的效能影响。
慢查询日志支援将日志记录写入档案，也支援将日志记录写入数据库表。
慢查询配置
预设情况下slowquerylog的值为OFF，表示慢查询日志是禁用的，可以通过设定slowquerylog的值来开启，如下所示：
mysql> show variables like '%slow_query_log%'
-> ;
+---------------------+-------------------------------+
| Variable_name |Value |
+---------------------+-------------------------------+
|slow_query_log | OFF |
| slow_query_log_file |/var/lib/mysql/mysql-slow.log |
+---------------------+-------------------------------+
2 rows inset (0.00 sec)
mysql> setglobalslow_query_log= 1;
Query OK, 0rows affected(0.00sec)
mysql> show variables like '%slow_query_log%';
+---------------------+-------------------------------+
| Variable_name |Value |
+---------------------+-------------------------------+
|slow_query_log | ON |
| slow_query_log_file |/var/lib/mysql/mysql-slow.log |
+---------------------+-------------------------------+
2 rows inset (0.00 sec)
使用set global slowquerylog=1开启了慢查询日志只对当前数据库生效，如果MySQL重启后则会失效。如果要永久生效，就必须修改配置档案my.cnf（其它系统变数也是如此）。
[[email protected] ~]# vim /etc/my.cnf
slow_query_log= 1
slow_query_log_file=/var/lib/mysql/mysql-slow.log
引数说明：
那么开启了慢查询日志后，什么样的SQL才会记录到慢查询日志里面呢？ 是否会被写入到慢日志是由引数longquerytime控制，预设情况下longquerytime的值为10秒，可以使用命令修改，也可以在my.cnf引数里面修改。关于执行时间正好等于longquerytime的情况，并不会被记录下来。也就是说，在MySQL源代码里是判断大于longquerytime，而非大于等于。从MySQL 5.1开始，longquerytime开始以微秒记录SQL语句执行时间，之前仅用秒为单位记录。如果记录到表里面，只会记录整数部分，不会记录微秒部分。
检视long_time 值，预设是 10 秒。
mysql> show variables like '%long_query_time%';
+-----------------+-----------+
| Variable_name |Value |
+-----------------+-----------+
|long_query_time | 10.000000 |
+-----------------+-----------+
1row inset ( 0. 00sec)
设定值，例如这里设定为 5 秒：
mysql> setgloballong_query_time= 5;
Query OK, 0rows affected ( 0.00sec)
mysql> show variables like'%long_query_time%';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| long_query_time | 10.000000|
+-----------------+-----------+
1row inset( 0.01sec)
如上所示，修改了变数longquerytime，但是查询变数longquerytime的值还是10。
使用命令 set global longquerytime=5修改后，需要重新连线或新开一个会话才能看到修改值。因为通过用show variables like 'longquerytime'检视是当前会话的变数值。
也可以不用重新连线会话，而是用 show global variables like 'longquerytime'; 如下所示：
mysql> show global variables like 'long_query_time';
+-----------------+----------+
| Variable_name |Value |
+-----------------+----------+
|long_query_time | 5.000000 |
+-----------------+----------+
1row inset ( 0. 00sec)
我们设定longquerytime的值为2：
mysql> setgloballong_query_time= 2;
Query OK, 0rows affected ( 0.00sec)
mysql> show globalvariables like'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 2.000000|
+-----------------+----------+
1row inset( 0.00sec)
然后执行一条超时5秒的语句（需要重新连线MySQL）：
[[email protected] ~] # mysql -u root -p
Enter password:
Welcome to the MySQL monitor. Commands endwith; or g.
Your MySQL connection id is 4
Server version: 5.7.21-log MySQL Community Server (GPL)
Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.
Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.
Type ' help;' or 'h' for help. Type'c'toclearthe currentinputstatement.
mysql> showvariableslike'long_query_time';
+ -----------------+----------+
| Variable_name | Value |
+ -----------------+----------+
| long_query_time | 2.000000 |
+ -----------------+----------+
1 row in set( 0.02sec)
mysql> selectsleep( 5)
-> ;
+ ----------+
| sleep(5) |
+ ----------+
| 0 |
+ ----------+
1 row in set( 5.01sec)
[[email protected] ~]# cat /var/lib/mysql/mysql-slow. log
/usr/sbin/mysqld, Version: 5.7.21(MySQL Community Server(GPL)). started with:
Tcp port: 3306Unix socket: /var/lib/mysql/mysql.sock
TimeId Command Argument
/usr/sbin/mysqld, Version: 5.7.21- log(MySQL Community Server(GPL)). started with:
Tcp port: 0Unix socket: /var/lib/mysql/mysql.sock
TimeId Command Argument
# Time: 2018-02-09T06: 59: 47.782111Z
# [email protected]: root[root] @ localhost [] Id: 4
# Query_time: 5.000252Lock_time: 0.000000Rows_sent: 1Rows_examined: 0
SETtimestamp= 1518159587;
selectsleep( 5);
logoutput 引数是指定日志的储存方式。logoutput='FILE'表示将日志存入档案，预设值是'FILE'。log_output='TABLE'表示将日志存入数据库，这样日志资讯就会被写入到mysql.slowlog表中。MySQL数据库支援同时两种日志储存方式，配置的时候以逗号隔开即可，如：logoutput='FILE,TABLE'。日志记录到系统的专用日志表中，要比记录到档案耗费更多的系统资源，因此对于需要启用慢查询日志，又需要能够获得更高的系统效能，那么建议优先记录到档案。
mysql> show variables like '%log_output%';
+---------------+-------+
| Variable_name |Value |
+---------------+-------+
|log_output | FILE |
+---------------+-------+
1row inset ( 0. 01sec)
设定为表：
mysql> set global log_output= 'TABLE';
Query OK, 0rows affected ( 0.00sec)
mysql> show variables like '%log_output%';
+ ---------------+-------+
| Variable_name | Value |
+ ---------------+-------+
| log_output | TABLE |
+ ---------------+-------+
1row inset ( 0.00sec)
mysql> selectsleep( 5);
+ ----------+
| sleep( 5) |
+ ----------+
| 0|
+ ----------+
1row inset ( 5.00sec)
执行 select * from mysql.slowlog; 观察慢查询日志里每类语句的输出，其中querytime表示query语句的执行时间，单位是为秒，lock time是锁定的时间，rowssent是query语句执行返回的记录数，而rowsexamined则是优化器估算的扫描行数，querytime、rowsexamined、rowssent 三个值可以大致衡量一条查询的成本，特别留意 rowsexamined 字段是否与预期一致。
系统变数log-queries-not-using-indexes：未使用索引的查询也被记录到慢查询日志中（可选项）。如果调优的话，建议开启这个选项。另外，开启了这个引数，其实使用full index scan的sql也会被记录到慢查询日志。
mysql> show variables like'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF|
+-------------------------------+-------+
1row inset( 0.00sec)
mysql> setgloballog_queries_not_using_indexes= 1;
Query OK, 0rows affected ( 0.00sec)
mysql> show variables like'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON|
+-------------------------------+-------+
1row inset( 0.00sec)
mysql>
系统变数logslowadmin_statements表示是否将慢管理语句例如ANALYZE TABLE和ALTER TABLE等记入慢查询日志：
mysql> show variables like'log_slow_admin_statements';
+---------------------------+-------+
| Variable_name | Value |
+---------------------------+-------+
| log_slow_admin_statements | OFF|
+---------------------------+-------+
1row inset( 0.00sec)
mysql>
mysql> setgloballog_slow_admin_statements= 1;
Query OK, 0rows affected ( 0.01sec)
mysql> show variables like'log_slow_admin_statements';
+---------------------------+-------+
| Variable_name | Value |
+---------------------------+-------+
| log_slow_admin_statements | ON|
+---------------------------+-------+
1row inset( 0.00sec)
查询有多少条慢日志，可以使用系统变数：
mysql> show global statuslike '%slow_queries%';
+ ---------------+-------+
| Variable_name | Value |
+ ---------------+-------+
| Slow_queries | 2|
+ ---------------+-------+
1row inset ( 0.01sec)
日志分析工具mysqldumpslow
MySQL 自带了一个检视慢日志的工具 mysqldumpslow，执行mysqldumpslow --help 可以检视其相关引数和说明：
[[email protected] ~] # mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
Parse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default
al: average locktime
ar: average rowssent
at: average querytime
c: count
l: locktime
r: rowssent
t: querytime
-r reversethe sortorder(largest lastinstead offirst)
-t NUMjust showthe top n queries
-a don 't abstract all numbers to N and strings to 'S '
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '* ', i.e. match all
-i NAME name of server instance (if using mysql.server startup )
-l don't subtract locktimefromtotal time
例如，得到返回记录集最多的10个SQL：
mysqldumpslow -s r -t 10/mysql/mysql_slow. log
得到访问次数最多的10个SQL：
mysqldumpslow -s c -t 10/mysql/mysql_slow. log
通过以上方式我们可以配置和发现慢 SQL，那么在发现慢 SQL 语句之后，我们可以通过对数据库进行优化来提升 SQL 的执行速度，比如加索引或修改该应用的实现方式等。
华为最强自研 NPU 问世，麒麟 810 测评远超骁龙系列！
