tcpdumpとmk-query-digestでMySQLのクエリ解析

Maatkitmk-query-digestで定期的なMySQLのクエリ解析をやってみたのでメモ
※今はPERCONA Toolkitになっちゃったみたいですがそっちはまだ試してません!

参考にしたサイト

同じような記事はいっぱいあるので細かいところは書きません。
Maatkitについてはこのあたり

tcpdumpとmk-query-digestの組合せについてはこのあたり

あとはperldoc mk-query-digest


解析結果のこと

DBに結果を突っ込むこともできるのですが、いったんはテキストレポートをWEBで見るようにしています。
結果で見ているところはこのあたり

総レスポンスタイムごと並べたサマリ
# Profile
# Rank Query ID  Response time Calls R/Call Apdx V/M   EXPLAIN   Item
# ==== ========= ============= ===== ====== ==== ===== ========= ========
#    1 0xF851186 21.6800 22.7% 47123 0.0005 1.00  0.16 c         SELECT blog
#    2 0x7FBC4FF 10.2069 10.7%  6213 0.0016 1.00  0.31 c         SELECT user
#    3 0x5D51E5F  9.2891  9.7% 13219 0.0007 1.00  0.00           ADMIN CONNECT
#    4 0xD4FFE0A  7.4837  7.8%   178 0.0420 0.99  0.92 TF>rerere SELECT friend user
#    5 0xB3738BF  7.4329  7.8%     7 1.0618 0.71  0.01 TF>rr     SELECT t count

だいたいこんな感じです

  • Response:処理時間の合計
  • Time:処理時間の合計の比率
  • Calls:実行回数
  • R/Call:平均処理時間
  • Adpx:クエリの評価(1に近いほうがいい)
  • EXPLAIN:EXPLAINのサマリ(TFは「Using temporary; Using filesort」、などなど)
  • Item:簡略化されたクエリ
各クエリの詳細

ズラーッと並ぶのですが、例えば5番目のやつだけ抜き出し

# Query 5: 0.15 QPS, 0.15x concurrency, ID 0xB3738BF at byte 249830102
# This item is included in the report because it matches --limit.
# Scores: Apdex = 0.71 [1.0]*, V/M = 0.01
# EXPLAIN sparkline: TF>rr
# Query_time sparkline: |     _^ |
# Time range: 2011-12-09 04:XX:XX.XXXXXX to 04:XX:XX.XXXXXX
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0       7
# Exec time      7      7s   939ms      1s      1s      1s    93ms      1s
# Rows affecte   0       0       0       0       0       0       0       0
# Query size     0   4.96k     725     725     725     725       0     725
# Warning coun   0       0       0       0       0       0       0       0
# String:
# Databases    user
# Errors       none
# Hosts        192.168.1.11 (2/28%), 192.168.1.12 (1/14%)... 2 more
# Users        test
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  #########################
#    1s  ################################################################
#  10s+
# Review information
#    first_seen: 2011-12-08 04:XX:XX
#     last_seen: 2011-12-08 04:XX:XX
#   reviewed_by:
#   reviewed_on:
#      comments:
# Tables
#    SHOW TABLE ...
# EXPLAIN /*!50100 PARTITIONS*/
SELECT t.id, c.count as cnt, ...<省略>
WHERE t.create_time < 1323370560 ... ORDER BY cnt DESC LIMIT 51, 5\G
# *************************** 1. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: t
#    partitions: NULL
#          type: ref
# possible_keys: PRIMARY,AAA_idx,BBB_idx,create_unixtime_idx
#           key: delete_flg_idx
#       key_len: 1
#           ref: const
#          rows: 911
#         Extra: Using where; Using temporary; Using filesort
# *************************** 2. row ***************************
#            id: 1
#   select_type: SIMPLE
#         table: c
#    partitions: NULL
#          type: ref
# possible_keys: CCC_idx
#           key: CCC_idx
#       key_len: 4
#           ref: user.t.DDD_id
#          rows: 1
#         Extra:

クエリに関する情報、サンプルクエリ、EXPLAIN結果などが並んでいます。
※中身はテキトウに変えてあります


解析元のソースは基本的にスローログかtcpdumpのキャプチャ結果になると思いますが(--typeオプションの項を参照)、MySQL触らずに全クエリ解析ができるのでとりあえずtcpdumpを使っています。。


参考サイトからちょっとだけ変えてるところ

tcpdumpの結果をテキスト形式でファイル出力してる例が多いのですが

tcpdump -i eth0 port 3306 -s 65535 -x -nn -q -tttt -l > /tmp/mysql.txt
mk-query-digest --type tcpdump /tmp/mysql.txt

pcap形式のほうがファイルが小さくなっていいと思うのだけどどうなんだろう

tcpdump -i eth0 port 3306 -s 65535 -w /tmp/mysql.pcap
tcpdump -s 65535 -x -nn -q -tttt -l -r /tmp/mysql.pcap | mk-query-digest --type tcpdump

ファイルサイズが1/3強くらいになります。


あとEXPLAINの結果があると便利なので、オプションはいったんこんな感じにしてます。

DSN="h=${host},u=${db_user},p=${db_password}"

/usr/sbin/tcpdump -s 65535  -x -nn -q -tttt -l -r /tmp/mysql.pcap 2>/dev/null | \
  mk-query-digest --type tcpdump --limit 50 --explain $DSN \

実際に各サーバ上で実行するバッチ

#!/bin/sh
HOSTNAME=`hostname`
DATE=`date +%Y%m%d`

PCAP_FILE=/tmp/${HOSTNAME}_${DATE}.pcap
PCAP_TIME=60
PCAP_IFACE=eth0

QD_FILE=/tmp/${HOSTNAME}_${DATE}.txt
QD_LIMIT=50
QD_DSN="h=127.0.0.1,u=<USERNAME>,p=<PASSWORD>"
QD_UPLOAD_URL=http://192.168.1.10/local/upload/qd/$HOSTNAME/


# MySQLトラフィックをtcpdumpしてpcap形式で保存
sudo /usr/sbin/tcpdump -i $PCAP_IFACE port 3306 -s 65535 -w $PCAP_FILE 2>/dev/null &
pid=$!
sleep $PCAP_TIME
sudo kill $pid

# mk-query-digestでプロファイリング
/usr/sbin/tcpdump -s 65535  -x -nn -q -tttt -l -r $PCAP_FILE 2>/dev/null | \
  mk-query-digest --type tcpdump --limit $QD_LIMIT --explain $QD_DSN \
  > $QD_FILE

# WEBDAVで管理サーバにアップ
curl -X MKCOL $QD_UPLOAD_URL
curl -T $QD_FILE $QD_UPLOAD_URL
sudo /bin/rm $PCAP_FILE $QD_FILE


お馬鹿クエリ撲滅したい(;´Д`)ハァハァ