慢查询日志

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_logslow_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
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 218,640评论 6 507
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 93,254评论 3 395
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 165,011评论 0 355
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,755评论 1 294
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,774评论 6 392
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,610评论 1 305
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,352评论 3 418
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,257评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,717评论 1 315
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,894评论 3 336
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,021评论 1 350
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,735评论 5 346
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,354评论 3 330
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,936评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,054评论 1 270
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,224评论 3 371
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,974评论 2 355

推荐阅读更多精彩内容