MySQL slow query pt-query-digest analysis of slow query log

1. Introduction

pt-query-digest is a tool for analyzing MySQL slow queries. It can analyze binlog, general log, slowlog, or MySQL protocol data captured by SHOWPROCESSLIST or tcpdump. The analysis results can be output to a file. The analysis process is to first parameterize the query statement conditions, then group and count the parameterized queries, and calculate the execution time, number of times, proportion, etc. of each query. The analysis results can be used to identify problems and optimize them.

2. Install pt-query-digest

1. Download page: https://www.percona.com/doc/percona-toolkit/2.2/installation.html

2. Perl modules

yum install -y perl-CPAN perl-Time-HiRes

3. Installation steps

Method 1: rpm installation

cd /usr/local/src
wget percona.com/get/percona-toolkit.rpm
yum install -y percona-toolkit.rpm

The tool installation directory is: /usr/bin

Method 2: Source code installation

cd /usr/local/src
wget percona.com/get/percona-toolkit.tar.gz
tar zxf percona-toolkit.tar.gz
cd percona-toolkit-2.2.19
perl Makefile.PL PREFIX=/usr/local/percona-toolkit
make && make install

The tool installation directory is: /usr/local/percona-toolkit/bin

4. Introduction to the usage of each tool (details: https://www.percona.com/doc/percona-toolkit/2.2/index.html)

(1) Slow query log analysis and statistics

pt-query-digest /usr/local/mysql/data/slow.log

(2) Server Summary

pt-summary

(3) Server disk monitoring

pt-diskstats

(4)MySQL service status summary

pt-mysql-summary -- --user=root --password=root

pt-query-digest syntax and important options

1. pt-query-digest [OPTIONS] [FILES] [DSN]
2. --create-review-table When the --review parameter is used to output the analysis results to a table, it will be created automatically if it does not exist.
3. --create-history-table When the --history parameter is used to output the analysis results to a table, it will be created automatically if the table does not exist.
4. --filter matches and filters the input slow query according to the specified string before analyzing it
5. --limit limits the percentage or number of output results. The default value is 20, which means that the 20 slowest statements are output. If it is 50%, they are sorted from large to small according to the proportion of total response time, and the output ends when the total reaches 50%.
6. --host mysql server address
7. --user mysql username
8. --password mysql user password
9. --history saves the analysis results to the table. The analysis results are relatively detailed. The next time you use --history, if the same statement exists and the time interval of the query is different from that in the history table, it will be recorded in the data table. You can compare the historical changes of a certain type of query by querying the same CHECKSUM.
10. --review saves the analysis results to the table. This analysis is just parameterizing the query conditions, one record for one type of query, which is relatively simple. The next time you use --review, if the same statement analysis exists, it will not be recorded in the data table.
11. --output The output type of the analysis results. The values ​​can be report (standard analysis report), slowlog (MySQL slow log), json, or json-anon. Report is generally used for easier reading.
12. --since The time to start the analysis. The value is a string. It can be a specified time point in the format of "yyyy-mm-dd [hh:mm:ss]" or a simple time value: s (seconds), h (hours), m (minutes), d (days). For example, 12h means that the statistics start from 12 hours ago.
13. --until deadline, combined with --since, can analyze slow queries over a period of time.
    

4. Analyze the output results of pt-query-digest

Part I: Overall statistical results

Overall: How many queries are there in total

Time range: The time range for query execution

unique: the number of unique queries, that is, the total number of different queries after parameterizing the query conditions

total: total min: minimum max: maximum avg: average

95%: Arrange all the values ​​from small to large, and the number at 95% is generally the most valuable for reference.

median: median, arrange all the values ​​from small to large, the position is in the middle

# The tool performs log analysis of user time, system time, physical memory usage, and virtual memory usage. # 340ms user time, 140ms system time, 23.99M rss, 203.11M vsz
# Tool execution time# Current date: Fri Nov 25 02:37:18 2016
# Hostname where the analysis tool is running# Hostname: localhost.localdomain
# Files: slow.log
# Overall: 2 total, 2 unique, 0.01 QPS, 0.01x concurrency ________________
# Time range for logging # Time range: 2016-11-22 06:06:18 to 06:11:40
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Statement execution time# Exec time 3s 640ms 2s 1s 2s 999ms 1s
# Lock time # Lock time 1ms 0 1ms 723us 1ms 1ms 723us
# Number of rows sent to the client # Rows sent 5 1 4 2.50 4 2.12 2.50
# Select statement scans rows # Rows examine 186.17k 0 186.17k 93.09k 186.17k 131.64k 93.09k
# Number of characters in the query# Query size 455 15 440 227.50 440 300.52 227.50

Part 2: Query group statistics results

Rank: The ranking of all statements, sorted by query time in descending order by default, specified by --order-by

Query ID: statement ID (remove extra spaces and text characters, and calculate the hash value)

Response: total response time

time: The total time proportion of this query in this analysis

calls: the number of executions, that is, how many query statements of this type are there in this analysis

R/Call: average response time per execution

V/M: Ratio of response time variability-to-mean

Item: Query object

# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ==================== ============= ====== ====== =================
# 1 0xF9A57DD5A41825CA 2.0529 76.2% 1 2.0529 0.00 SELECT
# 2 0x4194D8F83F4F9365 0.6401 23.8% 1 0.6401 0.00 SELECT wx_member_base

Part 3: Detailed statistics for each query

From the detailed statistical results of the query below, the top table lists the statistics of each item such as execution number, maximum, minimum, average, 95%, etc.

ID: The query ID number, corresponding to the Query ID in the above figure

Databases: database name

Users: The number of times each user executes (percentage)

Query_time distribution: query time distribution. The length reflects the interval ratio. In this example, the number of queries between 1s-10s is twice that of queries over 10s.

Tables: Tables involved in the query

Explain: SQL Statement

# Query 1: 0 QPS, 0x concurrency, ID 0xF9A57DD5A41825CA at byte 802 ______
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2016-11-22 06:11:40
# Attribute pct total min max avg 95% stddev median
# ============ === ======== ======== ======== ======== ======= ======= ======== =======
# Count 50 1
# Exec time 76 2s 2s 2s 2s 2s 0 2s
# Lock time 0 0 0 0 0 0 0 0
# Rows sent 20 1 1 1 1 1 0 1
# Rows examine 0 0 0 0 0 0 0 0
# Query size 3 15 15 15 15 15 0 15
# String:
# Databases test
# Hosts 192.168.8.1
# Users mysql
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################################################
# 10s+
# EXPLAIN /*!50100 PARTITIONS*/
select sleep(2)\G

5. Usage Examples

1. Analyze the slow query file directly:

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

2. Analyze the queries in the last 12 hours:

pt-query-digest --since=12h slow.log > slow_report2.log

3. Analyze queries within a specified time range:

pt-query-digest slow.log --since '2017-01-07 09:30:00' --until '2017-01-07 10:00:00' >> slow_report3.log

4. Analysis refers to slow queries containing select statements

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

5. Slow query for a certain user

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

6. Query all slow queries with full table scan or full join

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

7. Save the query to the query_review table

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

8. Save the query to the query_history table

pt-query-digest --user=root –password=abc123 --review h=localhost,D=test,t=query_history --create-review-table slow.log_0001
pt-query-digest --user=root –password=abc123 --review h=localhost,D=test,t=query_history --create-review-table slow.log_0002

9. Capture mysql's TCP protocol data through tcpdump and then analyze it

tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt
pt-query-digest --type tcpdump mysql.tcp.txt> slow_report9.log

10. Analyze binlog

mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest --type=binlog mysql-bin000093.sql > slow_report10.log

11. Analyze general log

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

Summarize

The above is the full content of this article. I hope that the content of this article can bring some help to your study or work. If you have any questions, you can leave a message to communicate. Thank you for your support of 123WORDPRESS.COM.