Percona-tookit學習筆記(三)

  • 2019 年 10 月 4 日
  • 筆記

pt-query-digest

功能:

    根據一些規則分析查詢語句,對可能的問題提出建議

說明:

    pt-query-digest可以從普通MySQL日誌,慢查詢日誌以及二進位日誌中分析查詢,甚至可以從SHOW PROCESSLIST和MySQL協議的tcpdump中進行分析,如果沒有指定文件,它從標準輸入流(STDIN)中讀取數據。

整體概要(Overall)

示例:

# pt-query-digest/usr/local/mariadb/var/node2-slow.log > /root/mysql-slow.log

# 這個部分是一個大致的概要資訊(類似loadrunner給出的概要資訊),通過它可以對當前MySQL的查詢性能做一個初步的評估,比如各個指標的最大值(max),平# 均值(min),95%分布值,中位數(median),標準偏差(stddev)。這些指標有查詢的執行時間(Exec time),鎖佔用的時間(Lock time),MySQL執行器需要# 檢查的行數(Rowsexamine),最後返回給客戶端的行數(Rows sent),查詢的大小。

# 290ms user time, 20ms system time, 26.31Mrss, 215.15M vsz  # Current date: Mon May  9 14:18:13 2016  # Hostname: localhost.localdomain  # Files: /data/mysql/localhost-slow.log  # Overall: 17 total, 4 unique,0.00 QPS, 0.00x concurrency _______________  整體概要資訊  # 上一行的含義:17個操作,4個語句,QPS太低了,所以顯示為0  # Time range: 2016-04-10 19:57:45 to2016-04-29 14:27:38  # Attribute          total     min    max     avg     95% stddev  median  # ============     ======= ======= ======= ======= ============== =======  # Exec time          2751s     27s   938s    162s    464s   223s     60s  # Lock time            2ms    43us  434us   120us   424us  124us    53us  # Rows sent         81.79k      47 20.74k   4.81k  20.37k  7.99k  329.68  # Rows examine     345.13k      47 75.68k  20.30k  72.41k 30.48k  329.68  # Query size         2.34k      25    881     141  284.79 212.96   38.53

下面是查詢的摘要資訊(Profile)

這個部分對所有」重要」的查詢(通常是比較慢的查詢)做了個一覽表:

每個查詢都有一個Query ID,這個ID通過Hash計算出來的。pt-query-digest是根據這個所謂的Fingerprint來group by的。

# Profile  # Rank Query ID           Response time   Calls R/Call   V/M  Item  # ==== ================== ==================== ======== ===== ===========  #   1 0x1F830B61B2FB68F0 2238.7287 81.4%    8 279.8411 28... SELECT ecs_goods  #    2 0x1FADF8A6BD46B153  244.0573 8.9%     4  61.0143 0.00 SELECT create_sn admin_user agent_sn  #   3 0xB1A36F5B279696D1 241.4298  8.8%     4 60.3574  0.00 SELECT ecs_goods  # MISC 0xMISC               26.8954  1.0%    1  26.8954   0.0 <1 ITEMS>

如下圖:

Rank            整個分析中該「語句」的排名,一般也就是性能最差的。

Response time   「語句」的響應時間以及整體佔比情況。

Calls           該「語句」的執行次數。

R/Call          每次執行的平均響應時間【ResponseTime/Calls】。

V/M             響應時間的差異平均對比率。

Item            顯示了其他2個佔比較低而不值得單獨顯示的查詢的統計數據。

下面是每條SQL的詳細報告

這個部分會列出Profile表中每個查詢的詳細資訊:

# Query 1: 0.00 QPS, 0.00x concurrency, ID0x1F830B61B2FB68F0 at byte 0 __  # This item is included in the reportbecause it matches --limit.  # Scores: V/M = 286.15  # Time range: 2016-04-10 19:57:45 to2016-04-26 12:51:19  # Attribute    pct  total     min     max    avg     95%  stddev median  # ============ === ======= ======= ============== ======= ======= =======  # Count         47       8  # Exec time     81  2239s     40s    938s   280s    918s    283s   285s  # Lock time     16  345us    43us    44us   43us    42us       0   42us  # Rows sent      3  2.47k      47     489 316.38  487.09  113.03 329.68  # Rows examine   0  2.47k      47     489 316.38  487.09  113.03 329.68  # Query size     8    200      25      25     25      25       0     25  # String:  # Databases    b2b  # Hosts        116.228.235.114  # Users        b2b (5/62%), b2b_user (3/37%)  # Query_time distribution  #  1us  # 10us  # 100us  #  1ms  # 10ms  # 100ms  #   1s  # 10s+  ################################################################  # Tables  #   SHOW TABLE STATUS FROM `b2b` LIKE 'ecs_goods'G  #   SHOW CREATE TABLE `b2b`.`ecs_goods`G  # EXPLAIN /*!50100 PARTITIONS*/  SELECT * FROM `ecs_goods`G  # Query 2: 0.25 QPS, 15.25x concurrency, ID0x1FADF8A6BD46B153 at byte 4730  # This item is included in the reportbecause it matches --limit.  # Scores: V/M = 0.00  # Time range: 2016-04-28 15:17:28 to15:17:44  # Attribute    pct  total     min     max    avg     95%  stddev median  # ============ === ======= ======= ============== ======= ======= =======  # Count         23       4  # Exec time      8   244s     61s     61s    61s     60s       0    60s  # Lock time     62    1ms   193us   434us  318us   424us   112us  424us  # Rows sent     94 77.67k  16.33k  20.74k 19.42k  20.37k   1.81k 20.37k  # Rows examine  86 297.44k 71.27k  75.68k  74.36k 72.41k   1.49k  72.41k  # Query size    48  1.13k     290     290    290     290       0    290  # String:  # Databases    KF_Mobile  # Hosts        116.228.235.114  # Users        KF_Mobile_user  # Query_time distribution  #  1us  # 10us  # 100us  #  1ms  # 10ms  # 100ms  #   1s  # 10s+ ################################################################  # Tables  #   SHOW TABLE STATUS FROM `KF_Mobile` LIKE 'create_sn'G  #   SHOW CREATE TABLE `KF_Mobile`.`create_sn`G  #   SHOW TABLE STATUS FROM `KF_Mobile` LIKE 'admin_user'G  #   SHOW CREATE TABLE `KF_Mobile`.`admin_user`G  #   SHOW TABLE STATUS FROM `KF_Mobile` LIKE 'agent_sn'G  #   SHOW CREATE TABLE `KF_Mobile`.`agent_sn`G  # EXPLAIN /*!50100 PARTITIONS*/  #select * from (   select distincts.*,u.OEM_name,u.admin_account,IFNULL(i.active_state,'00') AS state fromcreate_sn s left   joinadmin_user u on s.agent_id=u.agent_id left join agent_sn i on i.sn_num=s.sn_num   ##)n   ##WHERE n.agent_id='84872355' order byn.create_date desc 84872355G  # Query 3: 0.00 QPS, 0.00x concurrency, ID0xB1A36F5B279696D1 at byte 6896  # This item is included in the reportbecause it matches --limit.  # Scores: V/M = 0.00  # Time range: 2016-04-25 19:13:19 to2016-04-29 14:27:38  # Attribute    pct  total     min     max    avg     95%  stddev median  # ============ === ======= ======= ============== ======= ======= =======  # Count         23       4  # Exec time      8   241s     60s     60s    60s     60s       0    60s  # Lock time     12  263us    53us   100us   65us    98us    19us   54us  # Rows sent      1  1.26k     322     326 323.75  313.99       0 313.99  # Rows examine   0  1.26k     322     326 323.75  313.99       0 313.99  # Query size     6    156      39      39     39      39       0     39  # String:  # Databases    b2b  # Hosts        116.228.235.114  # Users        b2b (2/50%), b2b_user (2/50%)  # Query_time distribution  #  1us  #  10us  # 100us  #  1ms  # 10ms  # 100ms  #   1s  # 10s+ ################################################################  # Tables  #   SHOW TABLE STATUS FROM `b2b` LIKE 'ecs_goods'G  #   SHOW CREATE TABLE `b2b`.`ecs_goods`G  # EXPLAIN /*!50100 PARTITIONS*/  SELECT * FROM `ecs_goods` LIMIT 0, 1000

另外,可以從tcpdump中分析:

因為慢日誌方式需要重新連接,而生產環境重啟中間件是非常昂貴的操作。

所以在資料庫伺服器上抓包分析也是一種不錯的選擇。

pt-query-digest對於抓包有一定的格式。(-x -nn -q -tttt)  -s:源埠  -c:抓包的數量

操作步驟:

1、抓包      tcpdump-s 65535 -x -nn -q -tttt -i any -c 100000 port 3306 > mysql.tcp.dmp  2、分析      pt-query-digest--limit 20 --type tcpdump mysql.tcp.dmp

還有一些其他方法,沒仔細搞過,貼一下吧:

1、從PROCESSLIST中查詢某個MySQL中最慢的查詢:

pt-query-digest -processlisth=host1 【操作失敗,不知道原因】

2、從一台機器上講slow log保存到另外一台機器上待稍後詳細分析:

pt-query-digest --reviewh=host2 --no-report /usr/local/mariadb/var/node2-slow.log  建議:當slow log很大的時候最好還是將日誌文件移到其他機器上進行分析。

還可以跟一些過濾條件。詳見官方文檔:http://www.percona.com/doc/percona-toolkit/2.2/pt-query-digest.html

另外結合一些第三方工具還能生成相應的報表,可以參考這裡:

http://biancheng.dnbcw.info/mysql/433514.html

http://blog.csdn.net/seteor/article/details/24017913

Tags: