慢查询日志

1、慢查询日志介绍

慢查询日志是什么？

1.MySQL的慢查询日志是MySQL提供的一种日志记录，它用来记录在MySQL中响应时间超过阀值的语句，具体指运行时间超过long_query_time值的SQL，则会被记录到慢查询日志中。
2.long_query_time的默认值为10，意思是运行10秒以上的SQL语句会被记录下来
3.由他来查看哪些SQL超出了我们的最大忍耐时间值，比如一条sql执行超过5秒钟，我们就算慢SQL，希望能收集超过5秒的sql，结合之前explain进行全面分析。

2、慢查询日志开启

怎么玩？

说明：

1.默认情况下，MySQL数据库没有开启慢查询日志，需要我们手动来设置这个参数。
2.当然，如果不是调优需要的话，一般不建议启动该参数，因为开启慢查询日志会或多或少带来一定的性能影响。慢查询日志支持将日志记录写入文件

查看是否开启及如何开启

1.查看慢查询日志是否开启：

• 默认情况下slow_query_log的值为OFF，表示慢查询日志是禁用的
• 可以通过设置slow_query_log的值来开启
• 通过SHOW VARIABLES LIKE '%slow_query_log%';查看 mysql 的慢查询日志是否开启

mysql> SHOW VARIABLES LIKE '%slow_query_log%';
+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| slow_query_log      | OFF                           |
| slow_query_log_file | /var/lib/mysql/Heygo-slow.log |
+---------------------+-------------------------------+
2 rows in set (0.00 sec)

2.如何开启开启慢查询日志：

• set global slow_query_log = 1;开启慢查询日志
• 使用set global slow_query_log=1开启了慢查询日志只对当前数据库生效，如果MySQL重启后则会失效。

mysql> set global slow_query_log = 1;
Query OK, 0 rows affected (0.07 sec)

mysql> SHOW VARIABLES LIKE '%slow_query_log%';
+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| slow_query_log      | ON                            |
| slow_query_log_file | /var/lib/mysql/Heygo-slow.log |
+---------------------+-------------------------------+
2 rows in set (0.00 sec)

3.如果要永久生效，就必须修改配置文件my.cnf（其它系统变量也是如此）

• 修改my.cnf文件，[mysqld]下增加或修改参数：slow_query_log和slow_query_log_file后，然后重启MySQL服务器。
• 也即将如下两行配置进my.cnf文件

[mysqld]
slow_query_log =1
slow_query_log_file=/var/lib/mysql/Heygo-slow.log

• 关于慢查询的参数slow_query_log_file，它指定慢查询日志文件的存放路径，系统默认会给一个缺省的文件host_name-slow.log（如果没有指定参数slow_query_log_file的话）

---

那么开启慢查询日志后，什么样的SQL参会记录到慢查询里面？

• 这个是由参数long_query_time控制，默认情况下long_query_time的值为10秒，命令：SHOW VARIABLES LIKE 'long_query_time%';查看慢 SQL 的阈值

mysql> SHOW VARIABLES LIKE 'long_query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.01 sec)

• 可以使用命令修改，也可以在my.cnf参数里面修改。
• 假如运行时间正好等于long_query_time的情况，并不会被记录下来。也就是说，在mysql源码里是判断大于long_query_time，而非大于等于。

3、慢查询日志示例

案例讲解

1.查看慢 SQL 的阈值时间，默认阈值时间为 10s

mysql> SHOW VARIABLES LIKE 'long_query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

2.设置慢 SQL 的阈值时间，我们将其设置为 3s

mysql> set global long_query_time=3;
Query OK, 0 rows affected (0.00 sec)

3.为什么设置后阈值时间没变？

• 需要重新连接或者新开一个回话才能看到修改值。
• 查看全局的 long_query_time 值：show global variables like 'long_query_time';发现已经生效

mysql> set global long_query_time=3;
Query OK, 0 rows affected (0.00 sec)

mysql> SHOW VARIABLES LIKE 'long_query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

mysql> show global variables like 'long_query_time';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 3.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

4.记录慢 SQL 以供后续分析

• 怼个 select sleep(4); 超过 3s ，肯定会被记录到日志中

mysql> select sleep(4); 
+----------+
| sleep(4) |
+----------+
|        0 |
+----------+
1 row in set (4.00 sec)

• 慢查询日志文件在 /var/lib/mysql/ 下，后缀为 -slow.log

[root@Heygo mysql]# cd /var/lib/mysql/
[root@Heygo mysql]# ls -l
总用量 176156
-rw-rw----. 1 mysql mysql       56 8月   3 19:08 auto.cnf
drwx------. 2 mysql mysql     4096 8月   5 10:36 db01
-rw-rw----. 1 mysql mysql     7289 8月   3 22:38 Heygo.err
-rw-rw----. 1 mysql mysql      371 8月   5 12:58 Heygo-slow.log
-rw-rw----. 1 mysql mysql 79691776 8月   5 10:36 ibdata1
-rw-rw----. 1 mysql mysql 50331648 8月   5 10:36 ib_logfile0
-rw-rw----. 1 mysql mysql 50331648 8月   3 19:08 ib_logfile1
drwx------. 2 mysql mysql     4096 8月   3 19:08 mysql
srwxrwxrwx. 1 mysql mysql        0 8月   3 22:38 mysql.sock
drwx------. 2 mysql mysql     4096 8月   3 19:08 performance_schema

• 查看慢查询日志中的内容

[root@Heygo mysql]# cat Heygo-slow.log 
/usr/sbin/mysqld, Version: 5.6.49 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 200805 12:58:01
# User@Host: root[root] @ localhost []  Id:    11
# Query_time: 4.000424  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
SET timestamp=1596603481;
select sleep(4);

5.查询当前系统中有多少条慢查询记录：show global status like '%Slow_queries%';

mysql> show global status like '%Slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 1     |
+---------------+-------+
1 row in set (0.00 sec)

---

配置版的慢查询日志

在 /etc/my.cnf 文件的 [mysqld] 节点下配置

slow_query_log=1；
slow_query_log_file=/var/lib/mysql/Heygo-slow.log 
long_query_time=3；
log_output=FILE

日志分析命令 mysqldumpslow

1.mysqldumpslow是什么？
在生产环境中，如果要手工分析日志，查找、分析SQL，显然是个体力活，MySQL提供了日志分析工具mysqldumpslow。
2.查看 mysqldumpslow的帮助信息

[root@Heygo mysql]# 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 lock time
                ar: average rows sent
                at: average query time
                 c: count
                 l: lock time
                 r: rows sent
                 t: query time  
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the 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 script)
  -l           don't subtract lock time from total time

3.mysqldumpshow 参数解释

• s：是表示按何种方式排序
• c：访问次数
• l：锁定时间
• r：返回记录
• t：查询时间
• al：平均锁定时间
• ar：平均返回记录数
• at：平均查询时间
• t：即为返回前面多少条的数据
• g：后边搭配一个正则匹配模式，大小写不敏感的

---

常用参数手册

• 得到返回记录集最多的10个SQL

mysqldumpslow -s r -t 10 /var/lib/mysql/Heygo-slow.log

• 得到访问次数最多的10个SQL

mysqldumpslow -s c- t 10/var/lib/mysql/Heygo-slow.log

• 得到按照时间排序的前10条里面含有左连接的查询语句

mysqldumpslow -s t -t 10 -g "left join" /var/lib/mysql/Heygo-slow.log

• 另外建议在使用这些命令时结合 | 和more使用，否则有可能出现爆屏情况

mysqldumpslow -s r -t 10 /var/lib/mysql/Heygo-slow.log | more