Permalink
Switch branches/tags
Nothing to show
Find file Copy path
Fetching contributors…
Cannot retrieve contributors at this time
172 lines (129 sloc) 5.87 KB

mysql の状態をみるコマンド集。

query log

/etc/my.cnf

log=/var/log/mysql/mysql_query.log

ファイルを作っておく必要がある

$ sudo mkdir /var/log/mysql
$ sudo touch /var/log/mysql/mysql_query.log
$ sudo chown -R mysql /var/log/mysql

/etc/init.d/mysqld #やらなくても出る気がするけどな

- $exec   --datadir="$datadir" --socket="$socketfile" \
+ $exec --log --datadir="$datadir" --socket="$socketfile" \

cf. http://itchronicle.com/2012/10/20/63

slow log

/etc/my.cnf

slow_query_log      = 1
slow_query_log_file = /var/lib/mysql/slow.log
long_query_time     = 0.1
log-queries-not-using-indexes

/var/lib/mysql/slow.log を見る. log-queries-not-using-indexes で index 使ってないやつがスロークエリとして出る。

mysqldumpslow

mysqldumpslow を使ってレポートを出す. クエリの発行回数、平均時間(トータル時間)が見れる。-s c でカウント順、-s at で平均時間順、-s t でトータル時間順、-s ar で取得した平均行数順、-s r でトータル行数順にソートできる。

$ sudo mysqldumpslow -s t /var/lib/mysql/slow.log
Count: 665  Time=0.06s (40s)  Lock=0.00s (0s)  Rows=100.0 (66500), isucon[isucon]@localhost
  SELECT * FROM memos WHERE is_private=N ORDER BY created_at DESC, id DESC LIMIT N OFFSET N

Count: 1232  Time=0.02s (25s)  Lock=0.00s (0s)  Rows=110.3 (135858), isucon[isucon]@localhost
  SELECT id, content, is_private, created_at, updated_at FROM memos WHERE user=N  ORDER BY created_at

Count: 1227  Time=0.02s (23s)  Lock=0.00s (0s)  Rows=1.0 (1227), isucon[isucon]@localhost
  SELECT count(*) AS c FROM memos WHERE is_private=N

クエリ時間は短いが、クエリ数が多いやつなどもあるので、1度 long_query_time = 0 にして mysqldumpslow で全クエリを対象に集計してみて、そのあとは 0.1 と log-queries-not-using-indexes で tail -F しておくとよさそう。

mysql の内部状態

See 06.mysql_tmc.md

show processlist

これを数回~数十回叩いてみて、 よく出ているクエリは、遅かったり量が多かったりする「チューニング候補」になる。

show full processlist;

showprocesslist.sh 定期実行するスクリプト cf. http://treeapps.hatenablog.com/entry/20120124/p1

#!/bin/sh
interval=$1
# インターバルの単位は秒で初期値は1秒
test -z $interval && interval=1
watch -n $interval --differences "mysql -uroot -Dtest --table -Be 'show processlist;'"

pt-query-digest

ブログ見てるとこれを使ってる人が多いみたい

インストール

sudo yum localinstall -y http://percona.com/get/percona-toolkit.rpm

long_query_time = 0 にして全クエリを出力した slow log にかけてみる

$ pt-query-digest slow.log
# 35.5s user time, 40ms system time, 24.99M rss, 208.00M vsz
# Current date: Sun Sep 14 01:19:01 2014
# Hostname: xxxxxx
# Files: slow.log
# Overall: 154.58k total, 15 unique, 2.53k QPS, 1.97x concurrency ________
# Time range: 2014-09-14 01:00:00 to 01:01:01
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time           120s     2us   123ms   775us   113us     5ms    63us
# Lock time             3s       0   309us    19us    31us    10us    19us
# Rows sent        419.98k       0     208    2.78    0.99   14.68    0.99
# Rows examine     180.24M       0  62.90k   1.19k    0.99   6.93k    0.99
# Query size         5.89M      14     617   39.96   38.53   16.99   38.53

# Profile
# Rank Query ID           Response time Calls  R/Call V/M   Item
# ==== ================== ============= ====== ====== ===== ============
#    1 0x4517399CB130EF84 53.0195 44.2%   1249 0.0424  0.01 SELECT memos
#    2 0x4B4B34854741F958 25.4719 21.2%   1263 0.0202  0.00 SELECT memos
#    3 0x08E3E2CA950A9030 22.0707 18.4%   1249 0.0177  0.00 SELECT memos
#    4 0x8ED61FE2C1C9A2A1  8.6435  7.2% 126383 0.0001  0.00 SELECT users
#    5 0x402E13A51340C830  4.8808  4.1%    220 0.0222  0.00 SELECT memos
# MISC 0xMISC              5.8524  4.9%  24219 0.0002   0.0 <10 ITEMS>

# Query 1: 20.48 QPS, 0.87x concurrency, ID 0x4517399CB130EF84 at byte 26212620
# Scores: V/M = 0.01
# Time range: 2014-09-14 01:00:00 to 01:01:01
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0    1249
# Exec time     44     53s    19ms   123ms    42ms    82ms    23ms    28ms
# Lock time      1    44ms    18us   309us    35us    60us    14us    30us
# Rows sent     29 121.97k     100     100     100     100       0     100
# Rows examine  32  58.81M  41.88k  62.90k  48.21k  62.55k   7.64k  42.34k
# Query size     1 108.35k      82      95   88.83   92.72    6.28   92.72
# String:
# Hosts        localhost
# Users        isucon
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms  ################################################################
# 100ms  #
#    1s
#  10s+
# Tables
#    SHOW TABLE STATUS LIKE 'memos'\G
#    SHOW CREATE TABLE `memos`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT * FROM memos WHERE is_private=0 ORDER BY created_at DESC, id DESC LIMIT 100 OFFSET 18900\G

... 以下デフォルトではトップ5まで

tcpdump から集計をとることもできるけど、ISUCON では使わないかな。

sudo tcpdump -i bond0 -s 65535 -x -nn -q -tttt 'port 3306' > tcpdump.out 2> /dev/null

(ローカルホスト通信の場合)

sudo tcpdump -i lo -s 65535 -x -nn -q -tttt 'port 3306' > tcpdump.out 2> /dev/null
pt-query-digest --type=tcpdump tcpdump.out > pt.out

みれるものは同じ