pt-query-digest (boîte à outils percona)

pt-query-digest peut analyser les informations liées aux requêtes MySQL via les journaux, la liste de processus et tcpdump. La syntaxe de base est la suivante :

pt-query-digest [OPTIONS] [FILES] [DSN]

pt-query-digest est un outil simple et facile à utiliser pour analyser les requêtes MySQL. Il peut analyser les requêtes de journal lent MySQL, de journal général et de journal binaire. (Les journaux binaires doivent d'abord être convertis en texte, via l'outil mysqlbinlog). Il fonctionne également avec SHOW PROCESSLIST et les données du protocole MySQL de tcpdump. Par défaut, l'outil indique quelle requête est la plus lente, il est donc très important de l'optimiser. Des rapports plus personnalisés peuvent être créés à l'aide de paramètres tels que --group-by, --filter et --embedded-attributes.

pt-query-digest a principalement les fonctions suivantes :

(1) Utilisez slow.log pour générer des informations statistiques :

pt-query-digest slow.log

(2) Analyser et générer des rapports à partir de la liste de processus :

pt-query-digest --processlist h=host1

( 3) Analysez les requêtes lentes via la capture de paquets tcppdump :

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

(4) Analysez les requêtes de journal lentes vers un autre hôte :

pt-query-digest --review h=host2 --no-report slow.log

Jetons un coup d'œil aux principaux paramètres :

--type par défaut sur slowlog, paramètre La valeur peut être défini sur binlog, genlog, slowlog, tcpdump, rawlog, etc.

--processlist Analyser la requête de journal complète de MySQL via processlist

--create-review-table Lorsque vous utilisez le paramètre --review pour afficher les résultats de l'analyse dans la table, il sera automatiquement exécuté s'il n'y a pas de table, créez.

--create-history-table Lorsque vous utilisez le paramètre --history pour afficher les résultats de l'analyse dans un tableau, il sera automatiquement créé s'il n'y a pas de tableau.

--filter correspond et filtre la requête lente d'entrée en fonction de la chaîne spécifiée, puis l'analyse

--limit limite le pourcentage ou le nombre de résultats de sortie. est le plus lent. Les 20 instructions sont émises. S'il est de 50 %, elles sont triées du plus grand au plus petit en fonction du temps de réponse total, et la sortie est coupée lorsque le total atteint 50 %.

--adresse du serveur MySQL hôte

--utilisateur nom d'utilisateur mysql

--mot de passe mot de passe de l'utilisateur mysql

--historique Enregistrez les résultats de l'analyse dans dans la table, les résultats de l'analyse seront plus détaillés. La prochaine fois que vous utiliserez --history, si la même instruction existe et que l'intervalle de temps de la requête est différent de celui de la table d'historique, elle sera enregistrée dans la table de données. peut interroger le même CHECKSUM Comparez les modifications historiques pour un certain type de requête.

--review Enregistrez les résultats de l'analyse dans la table. Cette analyse ne paramétre que les conditions de requête. Un type de requête concerne un enregistrement, ce qui est relativement simple. Lorsque --review sera utilisé la prochaine fois, si la même analyse d'instruction existe, elle ne sera pas enregistrée dans le tableau de données.

--type de sortie du résultat de l'analyse de sortie, la valeur peut être report (rapport d'analyse standard), slowlog (journal lent MySQL), json, json-anon, utilisez généralement le rapport pour une lecture plus facile.

--depuis l'heure à partir de laquelle démarrer l'analyse, la valeur est une chaîne, qui peut être un instant spécifié au format "aaaa-mm-jj [hh:mm:ss]", ou il peut s'agir d'une simple valeur de temps A : s (secondes), h (heures), m (minutes), d (jours), par exemple, 12h signifie que le comptage a commencé il y a 12 heures.

--jusqu'à la date limite, combiné avec --since peut analyser les requêtes lentes sur une période donnée.

Jetons un coup d'œil aux informations liées au rapport de sortie par défaut :

(1) Statistiques des données

# 2291.9s user time, 6.4s system time, 41.68M rss, 193.36M vsz
# Current date: Mon Jun 19 11:19:51 2017# Hostname: mxqmongodb2
# Files: /home/mysql/db3306/log/slowlog_343306.log
# Overall: 6.72M total, 140 unique, 16.12 QPS, 0.69x concurrency _________
# Time range: 2017-06-13T14:34:41 to 2017-06-18T10:22:04# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======# Exec time 287519s 1us 20s 43ms 148ms 339ms 214us
# Lock time 151259s 0 20s 23ms 144us 319ms 47us
# Rows sent 5.40M 0 1000 0.84 0.99 6.58 0.99# Rows examine 388.33M 0 3.72k 60.59 5.75 388.16 0.99# Query size 692.26M 6 799 108.02 202.40 69.96 80.10

Ce qui précède contient des informations Nom d'hôte, Requête globale, Requête unique, Période d'analyse Plage de temps, la partie Attribut est la même que la troisième partie, mettez-la dans la meilleure analyse

( 2) Résultats statistiques SQL de requête lente et statistiques de coûts

# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ================= ======= ====== ===== =========# 1 0x255C57D761A899A9 146053.6926 50.8% 75972 1.9225 2.93 UPDATE warehouse
# 2 0x813031B8BBC3B329 94038.9621 32.7% 242741 0.3874 0.23 COMMIT
# 3 0xA0352AA54FDD5DF2 10125.5055 3.5% 75892 0.1334 0.43 UPDATE order_line
# 4 0xE5E8C12332AD11C5 5660.5113 2.0% 75977 0.0745 0.83 SELECT district
# 5 0xBD195A4F9D50914F 3634.6219 1.3% 757760 0.0048 1.01 SELECT stock
# 6 0xF078A9E73D7A8520 3431.3527 1.2% 75874 0.0452 0.81 UPDATE district
# 7 0x9577D48F480A1260 2307.4342 0.8% 50255 0.0459 1.25 SELECT customer
# 8 0xFFDA79BA14F0A223 2158.4731 0.8% 75977 0.0284 0.54 SELECT customer warehouse
# 9 0x5E61FF668A8E8456 1838.4440 0.6% 1507614 0.0012 0.74 SELECT stock
# 10 0x10BEBFE721A275F6 1671.8274 0.6% 757751 0.0022 0.52 INSERT order_line
# 11 0x8B2716B5B486F6AA 1658.5984 0.6% 75871 0.0219 0.75 INSERT history
# 12 0xBF40A4C7016F2BAE 1504.7939 0.5% 758569 0.0020 0.77 SELECT item
# 13 0x37AEB73B59EFC119 1470.5951 0.5% 2838 0.5182 0.27 INSERT SELECT tpcc._stock_new tpcc.stock
# 15 0x26C4F579BF19956D 1030.4416 0.4% 1982 0.5199 0.28 INSERT SELECT tpcc.__stock_new tpcc.stock
# 22 0xD80B7970DBF2419C 493.0831 0.2% 947 0.5207 0.28 INSERT SELECT tpcc.__stock_new tpcc.stock
# 23 0xDE7EA4E363CAD006 488.2134 0.2% 943 0.5177 0.25 INSERT SELECT tpcc.__stock_new tpcc.stock
# 25 0x985B012461683472 470.6418 0.2% 907 0.5189 0.25 INSERT SELECT tpcc.__stock_new tpcc.stock
# MISC 0xMISC 9482.0467 3.3% 2182254 0.0043 0.0 <123 ITEMS>

Les informations comprennent la réponse : le temps de réponse total, le temps : la requête le temps total passé dans cette analyse. appels : nombre d'exécutions, c'est-à-dire le nombre total d'instructions de requête de ce type dans cette analyse. R/Call : Temps de réponse moyen par exécution. Élément : table d'opérations SQL.

(3) La troisième partie, les informations détaillées de chaque SQL

# Query 1: 1.14 QPS, 2.19x concurrency, ID 0x255C57D761A899A9 at byte 1782619576# This item is included in the report because it matches --limit.
# Scores: V/M = 2.93# Time range: 2017-06-13T14:34:42 to 2017-06-14T09:05:56# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======# Count 1 75972# Exec time 50 146054s 160us 20s 2s 7s 2s 1s
# Lock time 94 142872s 39us 20s 2s 7s 2s 992ms
# Rows sent 0 0 0 0 0 0 0 0# Rows examine 0 74.19k 1 1 1 1 0 1# Query size 0 4.05M 53 57 55.88 56.92 0.82 54.21# String:
# Hosts 127.0.0.1# Users root
# Query_time distribution
# 1us
# 10us
# 100us ######################
# 1ms ##
# 10ms ###
# 100ms ##################################
# 1s ################################################################
# 10s+ ##
# Tables
# SHOW TABLE STATUS LIKE 'warehouse'\G
# SHOW CREATE TABLE `warehouse`\G
UPDATE warehouse SET w_ytd = w_ytd + 3651 WHERE w_id = 4\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/select w_ytd = w_ytd + 3651 from warehouse where w_id = 4\G

Requête 1, qui est la requête la plus importante en termes de coût, la première ligne correspond aux en-têtes de colonnes du tableau. Le pourcentage est le pourcentage du total pour l'ensemble de l'analyse, et le total est la valeur réelle de la métrique spécifiée. Par exemple, dans ce cas, nous pouvons voir que la requête a été exécutée 75 972 fois, soit 50 % du total des requêtes dans le fichier. Les colonnes min, max et moy sont explicites. La colonne du 95e centile affiche le 95e centile ; 95 % des valeurs sont inférieures ou égales à cette valeur. L'écart type montre à quel point les valeurs sont regroupées. L'écart type et la médiane sont calculés à partir du 95e centile, en ignorant les valeurs les plus grandes et les plus petites.

Jetons un coup d'œil à l'utilisation régulière :

1 : Analyser les journaux lents

Rapport par défaut

[root@mxqmongodb2 bin]# ./pt-query-digest /home/mysql/db3306/log/slowlog_343306.log >/home/sa/slowlog_343306.log

Divisez-le selon le temps. Généralement, nous analyserons le journal lent d'une journée :

[root@mxqmongodb2 bin]# ./pt-query-digest --since=24h /home/mysql/db3306/log/slowlog_343306.log >/home/sa/slowlog_343306_24.log

而且我们可以设置过滤条天通过--filter参数，更好生成我们想要的报表。

例如只查询select：--filter '$event->{arg} =~ m/^select/i'，只查询某个用户：--filter '($event->{user} || "") =~ m/^dba/i' ，全表扫描等：--filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' 

2：保存分析结果到表文件：

[root@mxqmongodb2 bin]# ./pt-query-digest --user=root --password=123456 --port=3306 --review h=172.16.16.35,D=test,t=query_report /home/mysql/db3306/log/slowlog_343306.log

 

看一下结果样式

mysql> select * from query_report limit 1\G*************************** 1. row ***************************checksum: 1206612749604517366fingerprint: insert into order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, ol_amount, ol_dist_info) values(?+)
sample: INSERT INTO order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, ol_amount, ol_dist_info) VALUES (3730, 6, 10, 1, 6657, 10, 8, 62.41910171508789, 'N3F5fAhga7U51tlXr8AEgZdi')
first_seen: 2017-06-13 14:34:42last_seen: 2017-06-14 09:05:54reviewed_by: NULL
reviewed_on: NULL
comments: NULL1 row in set (0.00 sec)

 

3：分析binlog（要先使用mysqlbinlog将binlog转换）

[root@mxqmongodb2 log]# mysqlbinlog mysql-bin.000012 >/home/sa/mysql-bin_000012.log
[root@mxqmongodb2 bin]# ./pt-query-digest --type=binlog /home/sa/mysql-bin_000012.log >/home/sa/mysql-bin_000012_report.log

 

这个测试的时候还是有点小迷茫的，因为打印的结果并不是我要的，难道是因为我的binlog格式是ROW？保留下来，后面在测试。

4：分析general log

加上--type=genlog 即可，没有验证。。。。。。

5：tcpdump抓包分析

我们先要开启压力测试：

[root@mxqmongodb2 tpcc-mysql]# ./tpcc_start -h127.0.0.1 -P3306 -d tpcc -u root -p123456 -w 10 -c 10 -r 10 -l 3000

 

连续测试三十分钟，提供我们的抓取数据：

[root@mxqmongodb2 log]# tcpdump -s 65535 -x -nn -q -tttt -i any -c 10000 port 3306 >/home/sa/mysql.tcp.txt
[root@mxqmongodb2 bin]# ./pt-query-digest --type=tcpdump /home/sa/mysql.tcp.txt >/home/sa/mysql.tcp_repot.txt

 

看一下效果：

[root@mxqmongodb2 sa]# cat mysql.tcp_repot.txt
 
# 4.2s user time, 50ms system time, 27.65M rss, 179.15M vsz
# Current date: Tue Jun 20 17:08:40 2017# Hostname: mxqmongodb2
# Files: /home/sa/mysql.tcp.txt
# Overall: 155 total, 3 unique, 9.76 QPS, 4.52x concurrency ______________
# Time range: 2017-06-20 17:06:19.850032 to 17:06:35.731291# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======# Exec time 72s 63us 2s 463ms 1s 352ms 393ms
# Rows affecte 25 0 15 0.16 0.99 1.18 0# Query size 956 6 30 6.17 5.75 1.85 5.75# Warning coun 1 0 1 0.01 0 0.08 0
 # Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============= ===== ====== ===== =========# 1 0x813031B8BBC3B329 69.9077 97.4% 153 0.4569 0.25 COMMIT
# MISC 0xMISC 1.8904 2.6% 2 0.9452 0.0 <2 ITEMS>
 # Query 1: 9.63 QPS, 4.40x concurrency, ID 0x813031B8BBC3B329 at byte 10100332# This item is included in the report because it matches --limit.
# Scores: V/M = 0.25# Time range: 2017-06-20 17:06:19.850032 to 17:06:35.731291# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======# Count 98 153# Exec time 97 70s 63us 2s 457ms 1s 336ms 393ms
# Rows affecte 100 25 0 15 0.16 0.99 1.19 0# Query size 96 918 6 6 6 6 0 6# Warning coun 100 1 0 1 0.01 0 0.08 0# String:
# Hosts 127.0.0.1# Query_time distribution
# 1us
# 10us #
# 100us ####
# 1ms #
# 10ms #
# 100ms ################################################################
# 1s ##########
# 10s+commit\G

 

Ce qui précède est le contenu détaillé de. pour plus d'informations, suivez d'autres articles connexes sur le site Web de PHP en chinois!