目录

慢查询日志

慢查询介绍

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

慢查询日志开启

说明:

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

查看是否开启及如何开启

  • 查看慢查询日志是否开启:

  • 默认情况下slow_query_log的值为OFF,表示慢查询日志是禁用的

  • 可以通过设置slow_query_log的值来开启

  • 通过SHOW VARIABLES LIKE '%slow_query_log%';查看 mysql 的慢查询日志是否开启

    1
    2
    3
    4
    5
    6
    7
    8
    
    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)
    
  • 开启慢查询日志

    • set global slow_query_log = 1;开启慢查询日志

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

       1
       2
       3
       4
       5
       6
       7
       8
       9
      10
      11
      
      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)
      
  • 永久生效

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

    • 修改my.cnf文件,[mysqld]下增加或修改参数:slow_query_log和slow_query_log_file后,然后重启MySQL服务器。
    • 也即将如下两行配置进my.cnf文件
    1
    2
    3
    4
    5
    
    [mysqld]
    slow_query_log =1
    slow_query_log_file=/var/lib/mysql/Heygo-slow.log
    long_query_time=3;
    log_output=FILE
    
    • 关于慢查询的参数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 的阈值

    1
    2
    3
    4
    5
    6
    7
    
    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,而非大于等于。

慢查询日志示例

  • 查看慢 SQL 的阈值时间,默认阈值时间为 10s

    1
    2
    3
    4
    5
    6
    7
    
    mysql> SHOW VARIABLES LIKE 'long_query_time%';
    +-----------------+-----------+
    | Variable_name   | Value     |
    +-----------------+-----------+
    | long_query_time | 10.000000 |
    +-----------------+-----------+
    1 row in set (0.00 sec)
    
  • 设置慢 SQL 的阈值时间,我们将其设置为 3s

    1
    2
    
    mysql> set global long_query_time=3;
    Query OK, 0 rows affected (0.00 sec)
    
  • 为什么设置后阈值时间没变?

    • 需要重新连接或者新开一个回话才能看到修改值。

    • 查看全局的 long_query_time 值:show global variables like 'long_query_time';发现已经生效

       1
       2
       3
       4
       5
       6
       7
       8
       9
      10
      11
      12
      13
      14
      15
      16
      17
      18
      
      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)
      
  • 记录慢 SQL 以供后续分析

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

      1
      2
      3
      4
      5
      6
      7
      
      mysql> select sleep(4); 
      +----------+
      | sleep(4) |
      +----------+
      |        0 |
      +----------+
      1 row in set (4.00 sec)
      
    • 慢查询日志文件在 /var/lib/mysql/ 下,后缀为 -slow.log

       1
       2
       3
       4
       5
       6
       7
       8
       9
      10
      11
      12
      13
      
      [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
      
    • 查看慢查询日志中的内容

      1
      2
      3
      4
      5
      6
      7
      8
      9
      
      [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);
      
  • 查询当前系统中有多少条慢查询记录:show global status like '%Slow_queries%';

    1
    2
    3
    4
    5
    6
    7
    
    mysql> show global status like '%Slow_queries%';
    +---------------+-------+
    | Variable_name | Value |
    +---------------+-------+
    | Slow_queries  | 1     |
    +---------------+-------+
    1 row in set (0.00 sec)
    

慢查询日志分析

mysqldumpslow是什么?

在生产环境中,如果要手工分析日志,查找、分析SQL,显然是个体力活,MySQL提供了日志分析工具mysqldumpslow。

查看 mysqldumpslow的帮助信息

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
[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

mysqldumpshow 参数解释

  1. s:是表示按何种方式排序
  2. c:访问次数
  3. l:锁定时间
  4. r:返回记录
  5. t:查询时间
  6. al:平均锁定时间
  7. ar:平均返回记录数
  8. at:平均查询时间
  9. t:即为返回前面多少条的数据
  10. g:后边搭配一个正则匹配模式,大小写不敏感的

常用参数手册

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

    1
    
    mysqldumpslow -s r -t 10 /var/lib/mysql/Heygo-slow.log
    
  2. 得到访问次数最多的10个SQL

    1
    
    mysqldumpslow -s c- t 10/var/lib/mysql/Heygo-slow.log
    
  3. 得到按照时间排序的前10条里面含有左连接的查询语句

    1
    
    mysqldumpslow -s t -t 10 -g "left join" /var/lib/mysql/Heygo-slow.log
    
  4. 另外建议在使用这些命令时结合 | 和more使用,否则有可能出现爆屏情况

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