mysql5.1.40.jrp_pt-query-digest分析mysql查询日志

[root@hank-yoon log]# pt-query-digest slowq.log

# 200ms user time, 10ms system time, 24.39M rss, 205.12M vsz

# Current date: Thu Dec 17 15:32:04 2015

# Hostname: hank-yoon.com

# Files: slowq.log

# Overall: 8 total, 2 unique, 0.00 QPS, 0.00x concurrency ________________

# Time range: 2015-12-17 05:00:09 to 15:30:01

# Attribute          total     min     max     avg     95%  stddev  median

# ============     ======= ======= ======= ======= ======= ======= =======

# Exec time            15s      1s      7s      2s      7s      2s      1s

# Lock time            1ms    85us   251us   175us   247us    49us   194us

# Rows sent        213.24k       4 213.21k  26.65k 211.82k  70.05k    3.89

# Rows examine       2.40M 213.21k 320.55k 306.93k 312.96k  33.45k 312.96k

# Rows affecte           0       0       0       0       0       0       0

# Bytes sent        19.42M   1.44k  19.41M   2.43M  19.33M   6.39M   1.39k

# Query size         6.46k     768     836  827.50  833.10   25.62  833.10

1、Overall: 8 total  总共查询8条

2、2 unique：  唯一查询数量，对查询条件过滤后，总共有多少个不同的查询，一共有2个

3、Time range: 2015-12-17 05:00:09 to 15:30:01    时间范围，从几点开始到几点的查询

4、total：总计    min：最小  max：最大   avg：平均   95%：将所有值从小到大排列，位于95%的那个数

stddev：标准偏差   median：中位数，位置位于中间那个数

5、Exec time：执行时间

6、Lock time：锁时间

7、Rows sent：最后返回给客户端的行数，查询大小

8、Rows affecte：发送改变的行数

9、Rows examine：执行器需要检查的行数大小

10、Query size：查询语句的字符数

# Profile

# Rank Query ID           Response time Calls R/Call V/M   Item

# ==== ================== ============= ===== ====== ===== ===============

#    1 0x50EF20421A671146  7.4117 50.7%     7 1.0588  0.00 SELECT erp_order erp_order_option wms_order_sync jx_region

#    2 0x9B9DD48242D6C02D  7.2176 49.3%     1 7.2176  0.00 SELECT jx_erp_goods_ware

1、Rank：整个分析中语句排名，性能最差的

2、Response time：语句响应时间及整体占比情况

3、Calls：执行次数

4、R/Call：每次执行的平均响应时间

5、V/M：响应时间的差异平均对比率

# Query 1: 0.00 QPS,      --QPS：每秒查询数

0.00x concurrency,        --concurrency：该查询的近似并发值

ID 0x50EF20421A671146     --16进制查询的指纹，去掉了多余的空格和文本字符，转换成小写，使用--filter可以进行过滤

at byte 5592              --查询语句在日志文件中的偏移量，不一定精确，根据偏移量在日志文件中查询tail -c +5592 slowq.log |head

# This item is included in the report because it matches --limit.

# Scores: V/M = 0.00

# Time range: 2015-12-17 05:24:01 to 15:30:01

# Attribute    pct   total     min     max     avg     95%  stddev  median

--PCT：指的是执行语句占概要报告中的百分比，占有87%，一共执行了7次

# ============ === ======= ======= ======= ======= ======= ======= =======

# Count         87       7

# Exec time     50      7s      1s      1s      1s      1s    35ms      1s

# Lock time     93     1ms   142us   251us   188us   247us    38us   185us

# Rows sent      0      28       4       4       4       4       0       4

# Rows examine  91   2.19M 320.15k 320.55k 320.32k 312.96k       0 312.96k

# Rows affecte   0       0       0       0       0       0       0       0

# Bytes sent     0  10.10k   1.44k   1.44k   1.44k   1.44k       0   1.44k

# Query size    88   5.71k     836     836     836     836       0     836

# String:

# Databases    yoon        --数据库名

# Hosts

# Last errno   0

# Users        zhu_yoon    --执行语句用户

# Query_time distribution

#   1us

#  10us

# 100us

#   1ms

#  10ms

# 100ms

#    1s  ################################################################

#  10s+

# Tables

#    SHOW TABLE STATUS FROM `yoon` LIKE 'erp_order'\G

#    SHOW CREATE TABLE `yoon`.`erp_order`\G

#    SHOW TABLE STATUS FROM `yoon` LIKE 'erp_order_option'\G

#    SHOW CREATE TABLE `yoon`.`erp_order_option`\G

#    SHOW TABLE STATUS FROM `yoon` LIKE 'wms_order_sync'\G

#    SHOW CREATE TABLE `yoon`.`wms_order_sync`\G

#    SHOW TABLE STATUS FROM `yoon` LIKE 'jx_region'\G

#    SHOW CREATE TABLE `yoon`.`jx_region`\G

# EXPLAIN /*!50100 PARTITIONS*/

SELECT eo.pay_status,(CASE WHEN eo.order_amount >0 THEN (eo.order_amount- eo.platform_discount) ELSE eo.order_amount END) codValue,eo.invoice_no,eo.consignee realName,eo.tel phone,eo.mobile,eo.zipcode postCode,eoo.auto_weight totalWeight,eoo.packages totalNumber,

jrp.region_name province,jrc.region_name city,IFNULL(jrd.region_name,eo.district_name)  county,eo.address address,eo.order_id OrderId

FROM erp_order eo

JOIN erp_order_option eoo ON eo.order_id=eoo.order_id

JOIN wms_order_sync wos ON wos.OrderId=eo.order_id

LEFT JOIN jx_region jrp ON jrp.region_id=eo.province_id

LEFT JOIN jx_region jrc ON jrc.region_id=eo.city_id

LEFT JOIN jx_region jrd ON jrd.region_id=eo.district_id WHERE wos.IsValid=0 AND wos.DealFlag=0

and eo.ware_id=5

AND eo.shipping_id=93

GROUP BY eo.order_id  ORDER BY eoo.sendtime DESC LIMIT 20\G

(1)直接分析慢查询文件:

pt-query-digest  slowq.log > slow_report.log

(2)分析最近12小时内的查询：

pt-query-digest  --since=12h  slowq.log > slow_report.log

(3)分析指定时间范围内的查询：

pt-query-digest slowq.log --since '2015-04-17 09:30:00' --until '2015-04-17 10:00:00'> > slow_report.log

(4)分析指含有select语句的慢查询

pt-query-digest--filter '$event->{fingerprint} =~ m/^select/i' slowq.log> slow_report.log

(5) 针对某个用户的慢查询

pt-query-digest--filter '($event->{user} || "") =~ m/^root/i' slowq.log> slow_report.log

(6) 查询所有所有的全表扫描或full join的慢查询

pt-query-digest--filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' slowq.log > slow_report.log

(7)把查询保存到query_review表

pt-query-digest  --user=root --password=abc123 --review  h=localhost,D=test,t=query_review--create-review-table  slowq.log

(8)把查询保存到query_history表

pt-query-digest  --user=root --password=abc123 --review  h=localhost,D=test,t=query_ history--create-review-table  slowq.log

pt-query-digest  --user=root --password=abc123--review  h=localhost,D=test,t=query_history--create-review-table  slowq.log

(9)通过tcpdump抓取mysql的tcp协议数据，然后再分析

tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.txt

pt-query-digest --type tcpdump mysql.txt> slow_report.log

(10)分析binlog

mysqlbinlog mysql-bin.000077 > mysql-bin000077.sql

pt-query-digest  --type=binlog  mysql-bin000077.sql > slow_report.log

(11)分析general log

pt-query-digest  --type=genlog  localhost.log > slow_report.log