The
pt-query-digest command is a tool included in the Percona Toolkit project (formerly known as Maatkit). This command can read the queries from the slow query log, general query log, binary log (to be discussed later), and SHOW PROCESSLIST statement.
To use
pt-query-digest, Percona Toolkit needs to be installed. The package is included in several Linux distributions. The latest version can be downloaded from Percona's website as the .deb or .rpm package. It is compatible with all versions of MariaDB and MySQL starting from MySQL 5.0. It does not work on Windows and requires Perl.
Usually, we prefer to analyze the slow query log first because the queries it contains are likely to be problematic. This is what we will do in the next example. We have not discussed the slow log yet but it does not matter much. A user can just pass pt-query-digest, which is the name of the general query log, instead of the slow log. We will not discuss every single datum that is reported by pt-query-digest; we will comment the following example instead, highlighting the most important details.
As an example, we will just run the following:
root@this:~# pt-query-digest /usr/local/mysql/data/slow_query
Assuming that the slow_query file exists, the first part of the pt-query-digest output will look like the following:
# 460ms user time, 40ms system time, 27.54M rss, 110.14M vsz # Current date: Fri Jan 17 12:58:56 2014 # Hostname: this # Files: /usr/local/mysql/data/slow_query # Overall: 63 total, 23 unique, 0.00 QPS, 0.00x concurrency ______________ # Time range: 2014-01-09 09:14:22 to 2014-01-17 10:57:22 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 628s 391us 189s 10s 60s 30s 2ms # Lock time 157ms 0 139ms 2ms 366us 17ms 273us # Rows sent 1.86M 0 1.23M 30.29k 19.46 170.63k 0.99 # Rows examine 10.35M 0 3.70M 168.18k 245.21k 668.95k 36.69 # Query size 2.39k 11 92 38.78 84.10 22.19 33.28
We will generally be interested in the detailed statistics about the query's execution time, lock time, examined rows, and sent rows. For every data, we will consider the maximum, minimum, and average—the standard deviation will tell us how significant the average is. The total is also important, if it is compared to the 95% column. In our example, five percent of the queries take a huge amount of time. This tells us that a small number of queries definitely need to be optimized (if possible). In other cases, the comparison may suggest that most queries are poorly optimized. A good average with a low standard deviation is the ideal result.
The 95 percent ratio is not arbitrary; although in the example we have used the default value, it can be changed with the --limit option. We may want to start with the default value and, if necessary, again call pt-query-digest with a different limit to find out the ratio of queries that consumes most resources.
Then, we see a summarized query profile, shown as follows:
# Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ================== ============== ===== ======= ===== ============= # 1 0x9DEBB548615A0927 518.7809 82.6% 1679 86.4635 25.03 # 2 0xB4C4971837CA7647 72.6882 11.6% 6 72.6882 0.00 # 3 0xED8BDB15894993C6 10.6332 1.7% 5 10.6332 0.00 CALL test.rotate # MISC 0xMISC 26.1711 4.2% 55 0.4758 0.0 <20 ITEMS>
The pt-query-digest command shows the most problematic statements first, by default. In fact, in the preceding example, the first query appears to be dramatic; it has a huge response time and has been used several times.
The statements that are almost irrelevant (when compared to the most problematic ones) are grouped in the final row. Such statements are what statisticians call
outliers: the values that are not used to compute the average, because they do not represent whole set of values. The --outliers option defines the bound between the outliers and the other statements. This bound is based on the query time by default, but can also be based on other values. It also specifies the number of times a statement must appear to be excluded from the outliers.
Next, the single queries are reported. Let's take a look at the first one:
# Query 1: 0.00 QPS, 0.41x concurrency, ID 0x9DEBB548615A0927 at byte 11399 # This item is included in the report because it matches --limit. # Scores: V/M = 25.03 # Time range: 2014-01-14 15:06:35 to 15:27:39 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 9 6 # Exec time 82 519s 45s 189s 86s 184s 47s 83s # Lock time 1 2ms 249us 371us 289us 366us 40us 273us # Rows sent 0 0 0 0 0 0 0 0 # Rows examine 3 368.15k 0 200.48k 61.36k 192.13k 84.74k 0 # Query size 2 66 11 11 11 11 0 11 # String: # Databases test (5/83%), mysql (1/16%) # Hosts localhost # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s # 10s+ ################################################################ CALL test.pG