慢查询日志会将查询过程中超出你设置的时间的查询记录下来,以便供开发者进行分析和优化。

1. 开启慢查询

1.1 查看当前设置

mysql> show variables like "%query%";

输出

+------------------------------+-----------------------------------------+
| Variable_name                | Value                                   |
+------------------------------+-----------------------------------------+
| binlog_rows_query_log_events | OFF                                     |
| ft_query_expansion_limit     | 20                                      |
| have_query_cache             | YES                                     |
| long_query_time              | 10.000000                               |
| query_alloc_block_size       | 8192                                    |
| query_cache_limit            | 1048576                                 |
| query_cache_min_res_unit     | 4096                                    |
| query_cache_size             | 16777216                                |
| query_cache_type             | OFF                                     |
| query_cache_wlock_invalidate | OFF                                     |
| query_prealloc_size          | 8192                                    |
| slow_query_log               | OFF                                     |
| slow_query_log_file          | /var/lib/mysql/lgj-Lenovo-G470-slow.log |
+------------------------------+-----------------------------------------+

三个参数

  • slow_query_log   ON/OFF ,使能开关
  • slow_query_log_file   慢查询日志目录和文件名称
  • long_query_time    超过该时间则进行记录,5.1之前只设置到秒,5.1开始支持毫秒。

注意,开启慢查询会影响性能,因此应当在某一段时间内开启,记录一段时间后关闭掉。

1.2 配置

lgj@lgj-Lenovo-G470:~/db-analysis$ whereis mysql
mysql: /usr/bin/mysql /usr/lib/mysql /etc/mysql /usr/local/mysql /usr/share/mysql /usr/share/man/man1/mysql.1.gz

我的配置文件在/etc/mysql目录下的my.cnf

配置

[mysqld]
port=3307
skip-grant-tables
!includedir /etc/mysql/conf.d/
!includedir /etc/mysql/mysql.conf.d/
#打开慢查询
slow_query_log = ON#设置超时时间为0,也就是记录所有的查询
long_query_time = 0

设置完后保存,重新启动mysql

service mysql  restart

重新查看参数,已经更改。

mysql> show variables like "%query%";
+------------------------------+-----------------------------------------+
| Variable_name                | Value                                   |
+------------------------------+-----------------------------------------+
| binlog_rows_query_log_events | OFF                                     |
| ft_query_expansion_limit     | 20                                      |
| have_query_cache             | YES                                     |
| long_query_time              | 0.000000                                |
| query_alloc_block_size       | 8192                                    |
| query_cache_limit            | 1048576                                 |
| query_cache_min_res_unit     | 4096                                    |
| query_cache_size             | 16777216                                |
| query_cache_type             | OFF                                     |
| query_cache_wlock_invalidate | OFF                                     |
| query_prealloc_size          | 8192                                    |
| slow_query_log               | ON                                      |
| slow_query_log_file          | /var/lib/mysql/lgj-Lenovo-G470-slow.log |
+------------------------------+-----------------------------------------+

1.3 查询

随便执行一条查询语句,然后查看慢查询日志。

/usr/sbin/mysqld, Version: 5.7.25-0ubuntu0.18.04.2 ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
/usr/sbin/mysqld, Version: 5.7.25-0ubuntu0.18.04.2-log ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
/usr/sbin/mysqld, Version: 5.7.25-0ubuntu0.18.04.2-log ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
;
# Time: 2019-02-27T14:07:42.841770Z
# User@Host: skip-grants user[lgj] @ localhost []  Id:     2
# Query_time: 0.016232  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1551276462;
;
# Time: 2019-02-27T14:07:51.774192Z
# User@Host: skip-grants user[lgj] @ localhost []  Id:     2
# Query_time: 0.000485  Lock_time: 0.000221 Rows_sent: 1  Rows_examined: 1
SET timestamp=1551276471;
select * from user;
# Time: 2019-02-27T14:07:55.839223Z
# User@Host: skip-grants user[lgj] @ localhost []  Id:     2
# Query_time: 0.000564  Lock_time: 0.000259 Rows_sent: 1  Rows_examined: 1
SET timestamp=1551276475;# 查询语句
select * from user;# 记录时间
# Time: 2019-02-27T14:08:07.404666Z
# User@Host: skip-grants user[lgj] @ localhost []  Id:     2#查询时间   锁表时间
# Query_time: 0.006318  Lock_time: 0.000435 Rows_sent: 13  Rows_examined: 1026
SET timestamp=1551276487;

从上面可以获知查询时间和锁表时间,但是如果文件比较大,查找时间最长的查询将会非常麻烦,需要使用相关的工具来进行分析。

《高性能mysql》推荐使用 qt-query-digest 工具

2. qt-query-digest的使用

2.1 安装

  • 创建目录: mkdir db-analysis && cd db-analysis
  • 下载 pt-query-digest: curl -LO https://percona.com/get/pt-query-digest
  • 设置执行权限:chmod +x pt-query-digest
  • 将慢查询日志的文件复制到当前的目录下
  • 执行分析:  ./pt-query-digest lgj-Lenovo-G470-slow.log

结果

# 220ms user time, 10ms system time, 33.67M rss, 90.27M vsz
# Current date: Wed Feb 27 22:55:05 2019
# Hostname: lgj-Lenovo-G470
# Files: lgj-Lenovo-G470-slow.log
# Overall: 9 total, 7 unique, 0.24 QPS, 0.00x concurrency ________________
# Time range: 2019-02-27T14:07:29 to 2019-02-27T14:08:07
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          185ms   225us   122ms    21ms   122ms    37ms     6ms
# Lock time            2ms       0   485us   186us   467us   166us   159us
# Rows sent             50       0      13    5.56   12.54    5.25    0.99
# Rows examine       2.03k       0   1.00k  230.44 1012.63  419.72    0.99
# Query size           198      11      32      22   31.70    7.35   17.65

# Profile
# Rank Query ID                          Response time Calls R/Call V/M
# ==== ================================= ============= ===== ====== =====
#    1 0x751417D45B8E80EE5CBA2034458B...  0.1223 66.1%     1 0.1223  0.00 SHOW DATABASES
#    2 0xA11944C87A6A5C16FB38455BF703...  0.0320 17.3%     1 0.0320  0.00 SELECT
#    3 0x898255B1BE4F8C3044AE35A18286...  0.0155  8.4%     1 0.0155  0.00 ADMIN INIT DB
#    4 0xE77769C62EF669AA7DD5F6760F2D...  0.0134  7.3%     2 0.0067  0.00 SHOW VARIABLES
# MISC 0xMISC                             0.0018  1.0%     4 0.0004   0.0 <3 ITEMS>

# Query 1: 0 QPS, 0x concurrency, ID 0x751417D45B8E80EE5CBA2034458B5BC9 at byte 1471
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-02-27T14:07:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11       1
# Exec time     66   122ms   122ms   122ms   122ms   122ms       0   122ms
# Lock time      6   110us   110us   110us   110us   110us       0   110us
# Rows sent     20      10      10      10      10      10       0      10
# Rows examine   0      10      10      10      10      10       0      10
# Query size     7      14      14      14      14      14       0      14
# String:
# Databases    microblog
# Hosts        localhost
# Users        skip-grants user
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  ################################################################
#    1s
#  10s+
show databases\G

# Query 2: 0 QPS, 0x concurrency, ID 0xA11944C87A6A5C16FB38455BF7035609 at byte 1008
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-02-27T14:07:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11       1
# Exec time     17    32ms    32ms    32ms    32ms    32ms       0    32ms
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      2       1       1       1       1       1       0       1
# Rows examine   0       0       0       0       0       0       0       0
# Query size     8      17      17      17      17      17       0      17
# String:
# Hosts        localhost
# Users        skip-grants user
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ################################################################
# 100ms
#    1s
#  10s+
# EXPLAIN /*!50100 PARTITIONS*/
SELECT DATABASE()\G

# Query 3: 0 QPS, 0x concurrency, ID 0x898255B1BE4F8C3044AE35A182869033 at byte 1225
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-02-27T14:07:42
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         11       1
# Exec time      8    15ms    15ms    15ms    15ms    15ms       0    15ms
# Lock time      0       0       0       0       0       0       0       0
# Rows sent      0       0       0       0       0       0       0       0
# Rows examine   0       0       0       0       0       0       0       0
# Query size    15      30      30      30      30      30       0      30
# String:
# Databases    microblog
# Hosts        localhost
# Users        skip-grants user
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ################################################################
# 100ms
#    1s
#  10s+
administrator command: Init DB\G

# Query 4: 0.05 QPS, 0.00x concurrency, ID 0xE77769C62EF669AA7DD5F6760F2D2EBB at byte 775
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2019-02-27T14:07:30 to 2019-02-27T14:08:07
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         22       2
# Exec time      7    13ms     6ms     7ms     7ms     7ms   559us     7ms
# Lock time     54   920us   435us   485us   460us   485us    35us   460us
# Rows sent     52      26      13      13      13      13       0      13
# Rows examine  98   2.00k   1.00k   1.00k   1.00k   1.00k       0   1.00k
# Query size    29      58      29      29      29      29       0      29
# String:
# Databases    microblog
# Hosts        localhost
# Users        skip-grants user
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms  ################################################################
#  10ms
# 100ms
#    1s
#  10s+
show variables like "%query%"\G

MySql开启慢查询日志并使用pt-query-digest 分析的更多相关文章

  1. MySQL 开启慢查询日志

    1.1 简介 开启慢查询日志,可以让MySQL记录下查询超过指定时间的语句,通过定位分析性能的瓶颈,才能更好的优化数据库系统的性能. 1.2 登录数据库查看 [root@localhost lib]# ...

  2. MySQL开启慢查询日志时报Errcode: 13 的解决方法

    开启慢查询日志时会出现(Errcode: 13 - Permission denied)文件找不到的错误,但文件明明是存在的并且有读写的权限. mysql> set global slow_qu ...

  3. MySQL 开启慢查询日志与普通日志

    一.开启满查询日志 1.查看慢查询日志 SHOW VARIABLES LIKE '%slow%'; 2.开启慢查询日志 set GLOBAL slow_query_log =on; 3.设置慢查询日志 ...

  4. mysql开启慢查询日志及查询--windows

    MySQL慢查询配置 1. 慢查询有什么用? 它能记录下所有执行超过long_query_time时间的SQL语句, 帮你找到执行慢的SQL, 方便我们对这些SQL进行优化. 2. 如何开启慢查询? ...

  5. MYSQL开启慢查询日志实施

    查看当前服务器是否开启慢查询:1.快速办法,运行sql语句show VARIABLES like "%slow%" 2.直接去my.conf中查看.my.conf中的配置(放在[m ...

  6. 操作3 mongodb和mysql 开启慢查询日志 ,以及mongodb从配置文件启动

    1. mongodb从配置文件启动 创建配置文件:/usr/local/mongodb/etc/mongodb.conf 配置文件的内容为: #Directory and relavent set d ...

  7. mysql开启慢查询日志

    5.1版本之前,在 my.cnf添加如下信息, long_query_time=1 log_slow_queries=/data/mysql/slow.log 5.1版本之后,在 my.cnf添加如下 ...

  8. Mysql: 开启慢查询日志[ERROR] unknown variable &#39;log-slow-queries&#39;处理办法

    参考: http://www.dataguru.cn/thread-305503-1-1.html # slow query log qjp 20160921 # mysql5.6版本以上,取消了参数 ...

  9. mysql开启慢查询日志以及查看(转载自网络)

    转载自http://database.51cto.com/art/201309/410314_1.htm

随机推荐

  1. 用GitHub Pages搭了个静态博客

    经过周末两天折腾,终于在GitHub Pages上用Hugo搭了个静态博客. 链接:https://xusiwei.github.io/ @ruanyf 曾经在博客里提到过"喜欢写Blog的 ...

  2. 分享google的技能的11个级别,大家看看自己到哪个级别了?

    you are unfamiliar with the subject area. you can read / understand the most fundamental aspects of ...

  3. atitit.常用编程语言的性能比较 c c++ java

    atitit.常用编程语言的性能比较 c c++ java 选择一个什么样的程序问题进行这样的测试呢?这是一个很关键的问题,也最容易影响测试的公平性.另外的,对于每种语言,各自的优势都是不同的 #-- ...

  4. hdu 4454 Stealing a Cake

    简单的计算几何: 可以把0-2*pi分成几千份,然后找出最小的: 也可以用三分: #include<cstdio> #include<cmath> #include<al ...

  5. AngularJS中的控制器示例_2

    <!doctype html> <html ng-app="myApp"> <head> <script src="C:\\Us ...

  6. ORACLE11G RAC 施加以分离不同的实例.TAF

    有套POS制 现在应用大量的,大量的数据,! 年前的交易在一定程度上的统计分析影响了额外的应用程序. 这两种应用分别OLTP和OLAP. 其实很多本项目具有的应用要求双方.  看了很多近期的其他系统, ...

  7. could not resolve host: github.com 问题解决办法

    向github提交代码时出现问题,如图: 代码push失败,提示could not resolve host: github.com     解决办法:   1.打开终端,输入:ping github ...

  8. 使用window.btoa和window.atob来进行Base64编码和解码

      方法描述 WindowBase64.atob() 函数用来解码一个已经被base-64编码过的数据. WindowBase64.btoa() 函数 将ascii字符串或二进制数据转换成一个base ...

  9. 【MySQL】 清除等待连接

    由于MySQL突然新增了很多连接,超出了my.cnf所设置的最大连接数,MySQL服务无法访问,这里通过Shell脚本来删掉Sleep连接 方式1 清除连接进程 #!/bin/bash #------ ...

  10. 缺少的文件是 ..\packages\Microsoft.Net.Compilers.1.0.0\build\Microsoft.Net.Compilers.props。

    报错信息: 严重性 代码 说明 项目级别 文件 行 禁止显示状态 工具错误 这台计算机上缺少此项目引用的 NuGet 程序包.使用“NuGet 程序包还原”可下载这些程序包.有关更多信息,请参见 ht ...