Preface       Performance issues are what DBA most concerned thing.There're always a lot of SQL queries which maybe not using appropriated indexes cause bad perfoemance.Whenever that happens,we have to do some performance diagnosis immediately.In most scenarios,we will do that relies on slow log,but it's not enough or efficient I'm afraid.What's the better way then?Another tool of percona called "pt-query-digest" can solve these kind of issues.   Introduce       pt-query-digest is a tool focus on log analysis.It is supported to analyze slow log,general log,binlog and so on in different ways.You can also use it to analyze logs and simultaneously put these informations into tables on remote host(server) that you specified.That's really convenient and flexible for us DBA to work efficiently in performance tuning.
   Procedure   Usage 
1 Usage: pt-query-digest [OPTIONS] [FILES] [DSN]

 

Parameters introduce

SRE实战 互联网时代守护先锋，助力企业售后服务体系运筹帷幄！一键直达领取阿里云限量特价优惠。 
 1 --limit -- Limit the output conents by count(defualt 20) or percentage(default 50%).
 2 --type -- Indicate a type(default "slowlog",else value is "genlog","binlog","tcpdump",etc.) you want to anaylze.
 3 --processlist -- Analyze from "show processlist" result from specific host(need to input DSN).
 4 --create-history-table -- Create a table to record infomation if use "--history"(default "true").
 5 --create-review-table -- Create a table to record infomation if use "--review"(default "true").
 6 --history -- Save query metrics(such as query time) into a given table which can be checked incremental difference later.
 7 --review -- Save query classes into a given table for later review.It don't report same kind of class.
 8 --output -- Specify the format of query result(default "report").
 9 --since -- Give a specific time with time format of beginning.
10 --until -- Give a specific time with time format of end.
11 --group-by -- According to the atrribute of envents to group by(default "figerprint",else value is "tables"&"distill").
12 --order-by -- According to the atrribute of envents to sort by(default "Query_time:sum").

 

Examples   Make sure the slow log is enabled. 
 1 (root@localhost mysql3306.sock)[(none)]09:37:19>show variables like '%slow%';
 2 +---------------------------+----------+
 3 | Variable_name             | Value    |
 4 +---------------------------+----------+
 5 | log_slow_admin_statements | OFF      |
 6 | log_slow_slave_statements | ON       |
 7 | slow_launch_time          | 2        |
 8 | slow_query_log            | ON       |
 9 | slow_query_log_file       | slow.log |
10 +---------------------------+----------+
11 5 rows in set (0.00 sec)
12 
13 (root@localhost mysql3306.sock)[(none)]09:37:22>show variables like '%long_query_time%';
14 +-----------------+----------+
15 | Variable_name   | Value    |
16 +-----------------+----------+
17 | long_query_time | 1.000000 |
18 +-----------------+----------+
19 1 row in set (0.00 sec)
20 
21 (root@localhost mysql3306.sock)[(none)]09:37:25>show variables like '%log_output%';
22 +---------------+-------+
23 | Variable_name | Value |
24 +---------------+-------+
25 | log_output    | FILE  |
26 +---------------+-------+
27 1 row in set (0.00 sec)

 

Execute a slow query.

1 (root@localhost mysql3306.sock)[(none)]09:41:37>select sleep(60);
2 +-----------+
3 | sleep(60) |
4 +-----------+
5 |         0 |
6 +-----------+
7 1 row in set (1 min 0.01 sec)

 

Check slow log for information of above slow query.

1 [root@zlm2 09:43:12 /data/mysql/mysql3306/data]
2 #cat slow.log
3 
4 # Time: 2018-06-23T07:42:52.891778Z
5 # User@Host: root[root] @ localhost []  Id:     7
6 # Query_time: 60.001239  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 0
7 SET timestamp=1529739772;
8 select sleep(60);

 

Use pt-query-digest analyze slow log file for more details.

 1 [root@zlm2 09:42:24 ~]
 2 #pt-query-digest /data/mysql/mysql3306/data/slow.log
 3 
 4 # No events processed. -- Only if the slow query has finished,there will be a result of report.
 5 
 6 [root@zlm2 09:42:34 ~]
 7 #pt-query-digest /data/mysql/mysql3306/data/slow.log
 8 
 9 # 180ms user time, 0 system time, 25.59M rss, 221.68M vsz
10 # Current date: Sat Jun 23 09:43:28 2018
11 # Hostname: zlm2
12 # Files: /data/mysql/mysql3306/data/slow.log
13 # Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
14 # Time range: all events occurred at 2018-06-23T07:42:52
15 # Attribute          total     min     max     avg     95%  stddev  median
16 # ============     ======= ======= ======= ======= ======= ======= =======
17 # Exec time            60s     60s     60s     60s     60s       0     60s
18 # Lock time              0       0       0       0       0       0       0
19 # Rows sent              1       1       1       1       1       0       1
20 # Rows examine           0       0       0       0       0       0       0
21 # Query size            16      16      16      16      16       0      16
22 
23 # Profile
24 # Rank Query ID           Response time  Calls R/Call  V/M   Item
25 # ==== ================== ============== ===== ======= ===== ======
26 #    1 0xF9A57DD5A41825CA 60.0012 100.0%     1 60.0012  0.00 SELECT
27 
28 # Query 1: 0 QPS, 0x concurrency, ID 0xF9A57DD5A41825CA at byte 0 ________
29 # This item is included in the report because it matches --limit.
30 # Scores: V/M = 0.00
31 # Time range: all events occurred at 2018-06-23T07:42:52
32 # Attribute    pct   total     min     max     avg     95%  stddev  median
33 # ============ === ======= ======= ======= ======= ======= ======= =======
34 # Count        100       1
35 # Exec time    100     60s     60s     60s     60s     60s       0     60s
36 # Lock time      0       0       0       0       0       0       0       0
37 # Rows sent    100       1       1       1       1       1       0       1
38 # Rows examine   0       0       0       0       0       0       0       0
39 # Query size   100      16      16      16      16      16       0      16
40 # String:
41 # Hosts        localhost
42 # Users        root
43 # Query_time distribution
44 #   1us
45 #  10us
46 # 100us
47 #   1ms
48 #  10ms
49 # 100ms
50 #    1s
51 #  10s+  ################################################################
52 # EXPLAIN /*!50100 PARTITIONS*/
53 select sleep(60)\G
54 
55 ###All the meaning of above is self-explanatory,you can check official document for details.###

 

Other expamples   1.Analyze general log. 
1 pt-query-digest --type=genlog /path/zlm2.log > report1.log

 

2.Analyze binlog.

1 mysqlbinlog -vv --base64-output=decode-rows /path/mysql-bin.000010 > mysql-bin000010.sql
2 pt-query-digest --type=binlog /path/mysql-bin000001.sql > report2.log

 

3.Analyze rawlog(It's a general txt file which contains SQL statement).

1 echo "select sleep(10);">rawlog.log pt-query-digest --type=rawlog rawlog.log > report3.log

 

4.Analyze processlist(DSN is indispensable).

1 pt-query-digest --processlist h=192.168.1.101,P=3306,u=repl,p=repl4slave > report4.log -- If connection failed,it will try every second.

 

5.Analyze tcpdump.

1 tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > tcpdump.log
2 pt-query-digest --type=tcpdump tcpdump.log > report5.log

 

6.Analyze slow log since last 24 hours.

1 pt-query-digest --since=24h slow.log > report6.log

 

7.Analyze slow log since time until time.

1 pt-query-digest --since '2018-06-23 08:30:00' --until '2018-06-23 10:30:00' slow.log > report7.log

 

8.Analyze slow log into view table("query_review" table will be created if not specify "-t") of remote host.

1 pt-query-digest --review h=192.168.1.102,P=3306,u=repl,p=repl4slave,D=zlm,t=query_review slow.log > report8.log

 

9.Analyze slow log into history table("query_history" table will be created like above) of remote host.

1 pt-query-digest --review h=192.168.1.102,P=3306,u=repl,p=repl4slave,D=zlm,t=query_history slow.log > report9.log

 

Summay
  • There're still some advanced useages I've not demonstrated such as "--group-by","--order-by" and "--filter",etc.
  • pt-query-digest is extraordinarily useful when doing performance diagnosis by different ways.
  • It's recommended to analyze logs on another node(maybe slave) instead of master to reduce consumption of CPU,Memory,IO,etc.
  • pt-query-digest can help you to find out the specific slow quries.Afterwards you can use MySQL profiling("set profiling=1;" then "show profiles;") to survey the perticular resources which are tremendously consumed.

 

扫码关注我们
微信号：SRE实战
拒绝背锅 运筹帷幄