BlackChen'site

MySql 慢查询查看分析

最近需优化其他项目, 需要分析MySql慢查询日志. 以下为记录.

MySQL开启慢查询记录

配置参数

slow_query_log 慢查询开启状态
slow_query_log_file 慢查询日志存放的位置(这个目录需要MySQL的运行帐号的可写权限,一般设置为MySQL的数据存放目录)
long_query_time 查询超过多少秒才记录

查看开启状态

show variables like 'slow_query%';

show variables like 'long_query_time';

配置方式

全局变量设置

mysql> set global slow_query_log='ON'; 
mysql> set global slow_query_log_file='/usr/local/mysql/data/slow_2.log';
mysql> set global long_query_time=2;

配置文件配置

在配置文件:my.cnf中,在[mysqld]下的下方加入

[mysqld]
slow_query_log = ON
slow_query_log_file = /usr/local/mysql/data/slow.log
long_query_time = 1

重启mysql
service mysqld restart

慢sql分析

使用工具: pt-query-digest

下载

curl -LO https://percona.com/get/pt-query-digest
chmod +x pt-query-digest

使用

  1. 直接分析慢查询文件:
    pt-query-digest slow.log > slow_report.log

  2. 分析最近12小时内的查询:
    pt-query-digest --since=12h slow.log > slow_report_12hour.log

  3. 分析指定时间范围内的查询:

pt-query-digest slow.log --since '2014-04-17 09:30:00' --until '2014-04-17 10:00:00'> > slow_report_sometime.log

分析结果:


# 7.3s user time, 190ms system time, 27.73M rss, 4.11G vsz
# Current date: Mon Oct 14 15:47:48 2019
# Hostname: BlackChenMacBook-Pro.local
# Files: Robot-5422-slow.log
# Overall: 2.73k total, 20 unique, 0.02 QPS, 0.04x concurrency ___________
# Time range: 2019-10-12T15:50:46 to 2019-10-14T06:39:03
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          5852s      1s    258s      2s      3s     10s      1s
# Lock time            72s    24us   658ms    27ms   163ms    69ms    69us
# Rows sent        153.51M       0  16.49M  57.62k    0.99 845.83k    0.99
# Rows examine       5.94G       0  16.49M   2.23M   6.61M   3.00M 211.82k
# Query size       728.14k      54   1.32k  273.32   1.20k  239.63  174.84

# Profile
# Rank Query ID                      Response time   Calls R/Call   V/M   
# ==== ============================= =============== ===== ======== ===== 
#    1 0x499FA9423A7FCBCB49191F40... 1563.1490 26.7%   664   2.3541  0.03 SELECT robot_location
#    2 0xA004FAB8800139F62E486DE7... 1103.1562 18.8%   925   1.1926  0.02 SELECT robot_serve_log
#    3 0xCF841360E860BFCFC9ACF8F7...  913.3547 15.6%   735   1.2427  0.03 SELECT robot_serve_log
#    4 0xE3C753C2F267B2D767A347A2...  511.6249  8.7%     8  63.9531 11... SELECT robot_request
#    5 0x6B1885CD08FD04295E78F773...  507.3592  8.7%     2 253.6796  0.18 SELECT robot_request
#    6 0x4E8FB23B15F2C2B74B7CA805...  488.3607  8.3%   140   3.4883  0.01 SELECT robot_location
#    7 0x3AED577126A6800370A57441...  206.4373  3.5%     1 206.4373  0.00 SELECT robot_exception
#    8 0xBD7E2258BB4DFC057C52F84E...  188.9859  3.2%     2  94.4930  0.27 SELECT robot_running_record
#    9 0x3568682324628CA4011445CA...  177.1153  3.0%   133   1.3317  0.05 INSERT robot_running_record
#   10 0xFD9C9335A35C4ACBAC889B61...   67.0709  1.1%    58   1.1564  0.02 SELECT robot_serve_log
#   12 0xD587E79058219B88C6BC1DD4...   23.8074  0.4%    18   1.3226  0.03 UPDATE robot_running
#   13 0x3D25AAF867B71CF280377CBD...   22.4495  0.4%    14   1.6035  0.05 SELECT robot_serve_log
#   14 0xFAA66BA6EF72B13079552C67...   17.2053  0.3%    14   1.2290  0.05 INSERT robot_running_record
# MISC 0xMISC                          62.3830  1.1%    14   4.4559   0.0 <7 ITEMS>

# Query 1: 0.00 QPS, 0.01x concurrency, ID 0x499FA9423A7FCBCB49191F40F033E79E at byte 51928895
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.03
# Time range: 2019-10-12T15:50:46 to 2019-10-14T06:33:54
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         24     664
# Exec time     26   1563s      2s      6s      2s      2s   256ms      2s
# Lock time      0   133ms    57us    35ms   199us   273us     1ms   119us
# Rows sent      0     196       0       1    0.30    0.99    0.45       0
# Rows examine  75   4.48G   6.92M   6.92M   6.92M   6.61M       0   6.61M
# Query size    26 192.59k     297     297     297     297       0     297
# String:
# Hosts        172.16.54.23 (524/78%), 172.16.54.22 (140/21%)
# Users        robot
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s  ################################################################
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'robot_location'\G
#    SHOW CREATE TABLE `robot_location`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT
         
        location_id, robot_code, grid_x, grid_y, create_time, mall_id, building_id, floor_id
     
        from robot_location
        where location_id = (
          SELECT
          max(location_id)
          FROM robot_location
          where robot_code = 'HX-00055'
        )\G
        
...

各列说明:

Column        Meaning
============  ==========================================================
Rank          The query's rank within the entire set of queries analyzed
Query ID      The query's fingerprint
Response time The total response time, and percentage of overall total
Calls         The number of times this query was executed
R/Call        The mean response time per execution
V/M           The Variance-to-mean ratio of response time
Item          The distilled query

参考:
pt-query-digest查询日志分析工具
官方文档

评论