关于MySQL 通用查询日志和慢查询日志分析

短命女 2022-03-07 11:12 454阅读 0赞

# 关于MySQL 通用查询日志和慢查询日志分析  #

> （1）通用查询日志  
>        一、通用查询日志设置  
>        二、通用查询日志查看  
> （2）慢查询日志  
>           一、慢查询日志的设置  
>           二：slow log的日志相关参数详解  
>           三：如何在线安全的清空慢查询日志  
>           四：慢日志分析工具 mysqldumpslow和 mysqlsla介绍  
>           五：慢日志监控

**MySQL中的日志包括：错误日志、二进制日志、通用查询日志、慢查询日志等等。这里主要介绍下比较常用的两个功能：通用查询日志和慢查询日志。**

1）通用查询日志：记录建立的客户端连接和执行的语句。

2）慢查询日志：记录所有执行时间超过long\_query\_time秒的所有查询或者不使用索引的查询

**（1）通用查询日志**

** 一、通用查询日志设置**

在学习通用日志查询时，需要知道两个数据库中的常用命令：

1）show variables like '%version%';

> mysql> show variables like '%version%';  
> \+-------------------------+------------------------------+  
> | Variable\_name           | Value                        |  
> \+-------------------------+------------------------------+  
> | innodb\_version          | 5.7.19                       |  
> | protocol\_version        | 10                           |  
> | slave\_type\_conversions  |                              |  
> | tls\_version             | TLSv1,TLSv1.1                |  
> | version                 | 5.7.19                       |  
> | version\_comment         | MySQL Community Server (GPL) |  
> | version\_compile\_machine | x86\_64                       |  
> | version\_compile\_os      | macos10.12                   |  
> \+-------------------------+------------------------------+  
> 8 rows in set (0.01 sec)

上述命令，显示当前数据库中与版本号相关的东西。

2） show variables like '%general%';

可以查看，当前的通用日志查询是否开启，如果general\_log的值为ON则为开启，为OFF则为关闭（**默认情况下是关闭的**）。

3） show variables like '%log\_output%';

查看当前慢查询日志输出的格式，可以是FILE（存储在数数据库的数据文件中的hostname.log），也可以是TABLE（存储在数据库中的mysql.general\_log）

**二、通用查询日志查看**

问题：如何开启MySQL通用查询日志，以及如何设置要输出的通用日志输出格式呢？

> 开启通用日志查询： set global general\_log=on;
> 
> 关闭通用日志查询： set globalgeneral\_log=off;
> 
> 设置通用日志输出为表方式： set globallog\_output=’TABLE’;
> 
> 设置通用日志输出为文件方式： set globallog\_output=’FILE’;
> 
> 设置通用日志输出为表和文件方式：set global log\_output=’FILE,TABLE’;
> 
> （注意：上述命令只对当前生效，当MySQL重启失效，如果要永久生效，需要配置my.cnf）
> 
> **my.cnf文件的配置如下：**
> 
> general\_log=1  \#为1表示开启通用日志查询，值为0表示关闭通用日志查询
> 
> log\_output=FILE,TABLE\#设置通用日志的输出格式为文件和表

日志输出的效果图如下：

记录到mysql.general\_log表中的数据如下：

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70][]

**（2）慢查询日志**

**MySQL的慢查询日志是MySQL提供的一种日志记录，用来记录在MySQL中响应时间超过阈值的语句，具体指运行时间超过long\_query\_time值的SQL，则会被记录到慢查询日志中（日志可以写入文件或者数据库表，如果对性能要求高的话，建议写文件）。默认情况下，MySQL数据库是不开启慢查询日志的，long\_query\_time的默认值为10（即10秒，通常设置为1秒），即运行10秒以上的语句是慢查询语句。**

**一般来说，慢查询发生在大表（比如：一个表的数据量有几百万），且查询条件的字段没有建立索引，此时，要匹配查询条件的字段会进行全表扫描，耗时查过long\_query\_time，则为慢查询语句。**

**一、慢查询日志的设置**

**0、查询slow log的状态，如示例代码所示，则slow log已经开启。**

> mysql> show variables like '%slow%';  
> \+---------------------------+--------------------------------------------------------+  
> | Variable\_name             | Value                                                  |  
> \+---------------------------+--------------------------------------------------------+  
> | log\_slow\_admin\_statements | OFF                                                    |  
> | log\_slow\_slave\_statements | OFF                                                    |  
> | slow\_launch\_time          | 2                                                      |  
> **| slow\_query\_log            | ON                                                     |**  
> | slow\_query\_log\_file       | /usr/local/mysql/data/yaodeMacBook-Pro-slow.log |  
> \+---------------------------+--------------------------------------------------------+  
> 5 rows in set (0.00 sec)

如果没有开启慢查询日志有以下两种方法：

*   在配置文件\[mysqld\]中添加slow\_query\_log = ON和long\_query\_time = 1，然后重启MySQL即可生效。
 *    set global slow\_query\_log=1; 在线开启。如果MySQL发生重启，就会失效，如果要永久生效，就必选修改配置文件。

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70 1][]

1）slow\_query\_log\_file 的值是记录的慢查询日志到文件中（注意：默认名为主机名.log，慢查询日志是否写入指定文件中，需要指定慢查询的输出日志格式为文件，相关命令为：show variables like ‘%log\_output%’；去查看输出的格式）。

2）long\_query\_time 指定了慢查询的阈值，即如果执行语句的时间超过该阈值则为慢查询语句，默认值为10秒。

3）log\_queries\_not\_using\_indexes 如果值设置为ON，则会记录所有没有利用索引的查询（注意：如果只是将log\_queries\_not\_using\_indexes设置为ON，而将slow\_query\_log设置为OFF，此时该设置也不会生效，即该设置生效的前提是slow\_query\_log的值设置为ON），一般在性能调优的时候会暂时开启。

**2、设置慢查询开启的命令**

set global slow\_query\_log=1  
注：   
slow\_query\_log ON为开启，OFF为关闭   
slow\_query\_log\_file 为慢查询日志的存放地址

**3、查询并修改慢查询定义的时间为4ms**

show variables like 'long\_query\_time%'  
set global long\_query\_time=4  
**4、未使用索引的查询被记录到慢查询日志中。如果调优的话，建议开启这个选项。如果开启了这个参数，full index scan的sql也会被记录到慢查询日志中。**

show variables like 'log\_queries\_not\_using\_indexes'  
  
set global log\_queries\_not\_using\_indexes=1  
  
**5、查询慢查询记录总个数**

**问题：设置MySQL慢查询的输出日志格式为文件还是表，或者两者都有？**

通过命令：show variables like '%log\_output%';

通过log\_output的值可以查看到输出的格式，上面的值为TABLE。当然，我们也可以设置输出的格式为文本，或者同时记录文本和数据库表中，设置的命令如下：

\#慢查询日志输出到表中（即mysql.slow\_log）

set globallog\_output=’TABLE’;

\#慢查询日志仅输出到文本中(即：slow\_query\_log\_file指定的文件)

set global log\_output=’FILE’;

\#慢查询日志同时输出到文本和表中

set global log\_output=’FILE,TABLE’;

关于慢查询日志的表中的数据个文本中的数据格式分析：

慢查询的日志记录myql.slow\_log表中，格式如下：

> mysql> set global log\_output='TABLE,file';  
> Query OK, 0 rows affected (0.01 sec)
> 
> mysql> show variables like '%log\_output%';  
> \+---------------+------------+  
> | Variable\_name | Value      |  
> \+---------------+------------+  
> | log\_output    | FILE,TABLE |  
> \+---------------+------------+  
> 1 row in set (0.01 sec)
> 
> mysql> select \* from mysql.slow\_log;  
> Empty set (0.00 sec)
> 
> mysql> select sleep(10) as a, 1 as b;  
> \+---+---+  
> | a | b |  
> \+---+---+  
> | 0 | 1 |  
> \+---+---+  
> 1 row in set (10.00 sec)

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70 2][]

**可以看到，不管是表还是文件，都具体记录了：是那条语句导致慢查询（sql\_text），该慢查询语句的查询时间（query\_time），锁表时间（Lock\_time），以及扫描过的行数（rows\_examined）等信息。**

（**注意：**上述所有命令，如果都是通过MySQL的shell将参数设置进去，如果重启MySQL，所有设置好的参数将失效，如果想要永久的生效，需要将配置参数写入my.cnf文件中）。

**二：slow log的日志相关参数详解**

slow\_query\_log ：是否开启慢查询日志，1表示开启，0表示关闭。

log-slow-queries ：旧版（5.6以下版本）MySQL数据库慢查询日志存储路径。可以不设置该参数，系统则会默认给一个缺省的文件host\_name-slow.log

slow-query-log-file：新版（5.6及以上版本）MySQL数据库慢查询日志存储路径。可以不设置该参数，系统则会默认给一个缺省的文件host\_name-slow.log

long\_query\_time ：慢查询阈值，当查询时间多于设定的阈值时，记录日志。

log\_queries\_not\_using\_indexes：未使用索引的查询也被记录到慢查询日志中（可选项）。

log\_output：日志存储方式。log\_output='FILE'表示将日志存入文件，默认值是'FILE'。log\_output='TABLE'表示将日志存入数据库，这样日志信息就会被写入到mysql.slow\_log表中。MySQL数据库支持同时两种日志存储方式，配置的时候以逗号隔开即可，如：log\_output='FILE,TABLE'。日志记录到系统的专用日志表中，要比记录到文件耗费更多的系统资源，因此对于需要启用慢查询日志，又需要能够获得更高的系统性能，那么建议优先记录到文件。

**三：如何在线安全的清空慢查询日志**

*  停止slow log

>     mysql> set global slow_query_log=0;
>     Query OK, 0 rows affected (0.27 sec)
> 
>     mysql> show variables like '%slow%';
>     +---------------------+------------------------------------------+
>     | Variable_name       | Value                                    |
>     +---------------------+------------------------------------------+
>     | log_slow_queries    | OFF                                      |
>     | slow_launch_time    | 2                                        |
>     | slow_query_log      | OFF                                      |
>     | slow_query_log_file | /mysqllog/slow_log/slow_queries_3306.log |
>     +---------------------+------------------------------------------+
>     4 rows in set (0.00 sec)
>     #检查慢查询日志的状态

*  为慢查询日志重新设置path路径

>     mysql> set global slow_query_log_file='/mysqllog/slow_log/slow_queries_3306_new.log';
>     Query OK, 0 rows affected (0.03 sec)

*  开启慢查询日志，并设置long\_query\_time。

mysql> set global slow_query_log=1;
    Query OK, 0 rows affected (0.01 sec)
    mysql>set global long_query_time=1;
    
    
    #检查状态是否成功开启
    mysql> show variables like '%slow%';
    +---------------------+----------------------------------------------+
    | Variable_name       | Value                                        |
    +---------------------+----------------------------------------------+
    | log_slow_queries    | ON                                           |
    | slow_launch_time    | 2                                            |
    | slow_query_log      | ON                                           |
    | slow_query_log_file | /mysqllog/slow_log/slow_queries_3306_new.log |
    +---------------------+----------------------------------------------+
    4 rows in set (0.00 sec)
    
    检查slow sql 在新的日志文件中
    
    mysql> select sleep(10) as a, 1 as b;
    +---+---+
    | a | b |
    +---+---+
    | 0 | 1 |
    +---+---+
    1 row in set (10.00 sec)
    
    [mysql@xxx-xxx ~]$ more /mysqllog/slow_log/slow_queries_3306_new.log
    ......
    Time                 Id Command    Argument
    # Time: 140213  6:44:24
    # User@Host: root[root] @ localhost []
    # Query_time: 10.000365  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
    SET timestamp=1392273864;
    select sleep(10) as a, 1 as b;
    
    备份之前的慢查询日志
    mv /mysqllog/slow_log/slow_queries_3306.log /mysqlbackup/slow_log/slow_queries_3306.log.bak.20140213
    
    四：慢日志分析工具 介绍
    
    （1）mysqldumpslow 
    命令：
        -s 按照那种方式排序
        c：访问计数
        l：锁定时间
        r:返回记录
        al：平均锁定时间
        ar：平均访问记录数
        at：平均查询时间
    -t 是top n的意思，返回多少条数据。
    -g 可以跟上正则匹配模式，大小写不敏感。
    
    得到返回记录最多的20个sql
    mysqldumpslow -s r -t 20 sqlslow.log

> Count: 414  Time=3.51s (1454s)  Lock=0.0s (0s)  Rows=2194.9（9097604）, root\[root\]@localhost  
>   select \* from mysql.general\_log
> 
> Count:414            语句出现了414次；
> 
> Time=3.51s（1454）  执行最长时间为3.51s，累计总耗费时间1454s；
> 
> Lock=0.0s（0）           等待锁最长时间为0s，累计等待锁耗费时间为0s；
> 
> Rows=2194.9（9097604） 发送给客户端最多的行数为2194.9，累计发送给客户端的函数为90976404

具体命令如下：

bogon:~ a6$ sudo mysqldumpslow -s r -t 20 /usr/local/mysql/data/yaodeMacBook-Pro-slow.log;

> Password:
> 
> Reading mysql slow query log from /usr/local/mysql/data/yaodeMacBook-Pro-slow.log  
> Count: 2  Time=0.03s (0s)  Lock=0.00s (0s)  Rows=1575.0 (3150), root\[root\]@localhost  
>   select \* from tk\_question\_ls
> 
> Count: 2  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=5.5 (11), root\[root\]@localhost  
>   select \* from tk\_question\_ls limit N
> 
> Count: 1  Time=0.00s (0s)  Lock=0.02s (0s)  Rows=10.0 (10), root\[root\]@localhost  
>   select \* from mysql.general\_log
> 
> Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=5.0 (5), root\[root\]@localhost  
>   select distinct difficulty from tk\_question\_ls
> 
> Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=4.0 (4), root\[root\]@localhost  
>   select \* from product
> 
> Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=1.0 (1), root\[root\]@localhost  
>   select \* from  tk\_question\_ls limit N
> 
> Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), root\[root\]@localhost  
>   select \* from one\_and\_two\_kn\_accumulate\_stars
> 
> Died at /usr/local/mysql/bin/mysqldumpslow line 161, <> chunk 9.

得到平均访问次数最多的20条sql

mysqldumpslow -s ar -t 20 sqlslow.log  
  
得到平均访问次数最多,并且里面含有ttt字符的20条sql

mysqldumpslow -s ar -t 20 -g "ttt" sqldlow.log  
  
注：   
1、如果出现 -bash: mysqldumpslow: command not found 错误，请执行

ln -s /usr/local/mysql/bin/mysqldumpslow /usr/bin  
  
2、如果出现如下错误，Died at /usr/bin/mysqldumpslow line 161, <> chunk 405659.说明你要分析的sql日志太大了，请拆分后再分析

拆分的命令为：

**tail -100000 mysql-slow.log>mysql-slow.20180725.log**

**（注意：mysqldumpslow脚本是用perl语言写的，具体mysqldumpslow的用法后期再讲）**

**问题：实际在学习过程中，如何得知设置的慢查询是有效的？**

很简单，我们可以手动产生一条慢查询语句，比如，如果我们的慢查询log\_query\_time的值设置为5 s，则我们可以执行如下语句：

select  sleep(10);

该条语句即是慢查询语句，之后，便可以在相应的日志输出文件或表中去查看是否有该条语句。

**（2）慢查询分析工具mysqlsla**

**       慢查询分析工具还有mysqlsla，mysqlsla是hackmysql.com推出的一款MySQL的日志分析工具，功能非常强大. 数据报表,非常有利于分析慢查询的原因, 包括执行频率, 数据量, 查询消耗等。**（参考[https://www.cnblogs.com/skymyyang/p/7239010.html][https_www.cnblogs.com_skymyyang_p_7239010.html]）

本文针对MySQL数据库服务器查询逐渐变慢的问题， 进行分析，并提出相应的解决办法，具体的分析解决办法如下：会经常发现开发人员查一下没用索引的语句或者没有limit n的语句，这些没语句会对数据库造成很大的影...

**五：慢查询监控**

针对MySQL数据库服务器查询逐渐变慢的问题， 进行分析，并提出相应的解决办法，具体的分析解决办法如下：

会经常发现开发人员查一下没用索引的语句或者没有limit n的语句，这些没语句会对数据库造成很大的影响，例如一个几千万条记录的大表要全部扫描，或者是不停的做filesort，对数据库和服务器造成io影响等。这是镜像库上面的情况。

**而到了线上库，除了出现没有索引的语句，没有用limit的语句，还多了一个情况,mysql连接数过多的问题。说到这里，先来看看以前我们的监控做法 **

> **1. 部署zabbix等开源分布式监控系统，获取每天的数据库的io，cpu，连接数   
> 2. 部署每周性能统计，包含数据增加量，iostat，vmstat，datasize的情况   
> 3. Mysql slowlog收集，列出top 10**

以前以为做了这些监控已经是很完美了，现在部署了mysql节点进程监控之后，才发现很多弊端

> **第一种做法的弊端: zabbix太庞大，而且不是在mysql内部做的监控，很多数据不是非常准备，现在一般都是用来查阅历史的数据情况   
> 第二种做法的弊端：因为是每周只跑一次，很多情况没法发现和报警   
> 第三种做法的弊端: 当节点的slowlog非常多的时候，top10就变得没意义了，而且很多时候会给出那些是一定要跑的定期任务语句给你。。参考的价值不大 **

那么我们怎么来解决和查询这些问题呢

**对于排查问题找出性能瓶颈来说，最容易发现并解决的问题就是MYSQL的慢查询以及没有得用索引的查询。 **  
OK，开始找出mysql中执行起来不“爽”的SQL语句吧。

最后总结一下节点监控的好处

>   
> 1． 轻量级的监控，而且是实时的，还可以根据实际的情况来定制和修改   
> 2． 设置了过滤程序，可以对那些一定要跑的语句进行过滤   
> 3． 及时发现那些没有用索引，或者是不合法的查询，虽然这很耗时去处理那些慢语句，但这样可以避免数据库挂掉，还是值得的   
> 4. 在数据库出现连接数过多的时候，程序会自动保存当前数据库的processlist，DBA进行原因查找的时候这可是利器  
> 5. 使用mysqlbinlog 来分析的时候，可以得到明确的数据库状态异常的时间段

有些人会建义我们来做mysql配置文件设置，如下

> 调节tmp\_table\_size 的时候发现另外一些参数   
> Qcache\_queries\_in\_cache 在缓存中已注册的查询数目   
> Qcache\_inserts 被加入到缓存中的查询数目   
> Qcache\_hits 缓存采样数数目   
> Qcache\_lowmem\_prunes 因为缺少内存而被从缓存中删除的查询数目   
> Qcache\_not\_cached 没有被缓存的查询数目 (不能被缓存的，或由于 QUERY\_CACHE\_TYPE)   
> Qcache\_free\_memory 查询缓存的空闲内存总数   
> Qcache\_free\_blocks 查询缓存中的空闲内存块的数目   
> Qcache\_total\_blocks 查询缓存中的块的总数目   
> Qcache\_free\_memory 可以缓存一些常用的查询,如果是常用的sql会被装载到内存。那样会增加数据库访问速度

参考：https://blog.csdn.net/sunyuhua\_keyboard/article/details/81204020  
           https://blog.csdn.net/timchen525/article/details/75268151    
           https://www.cnblogs.com/qmfsun/p/4844472.html

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70]: /images/20220307/33e7f9632f564d41bc1f75a74a69dcd0.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70 1]: /images/20220307/590b39dd5f1d4548935b1a56507df0bd.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2hlbGxveGlhb3poZQ_size_16_color_FFFFFF_t_70 2]: /images/20220307/4ed56c3d018340e4becc94c3b8c4f7e5.png
[https_www.cnblogs.com_skymyyang_p_7239010.html]: https://www.cnblogs.com/skymyyang/p/7239010.html