ようへいの日々精進XP

よかろうもん

WEB+DB PRESS Vol.116 を読んだ (2) 〜 特集 1: トラブルシューティング (第 3 章データベース)〜

tl;dr

WEB+DB PRESS Vol.116 の記事を読んでみたメモです.

gihyo.jp

読みながら気になる単語や内容をマインドマップにまとめていきたいと思います. 今回は「特集 1: トラブルシューティング」の「第 3 章データベース」を読みました.

マインドマップ

f:id:inokara:20200426172540p:plain

メモ

ただ, 何となく

眺めていた top コマンドだけど, 以下のように見ることでボトルネックの特定が捗ることが判りました.

  • us (ユーザープロセス: カーネル以外) の使用時間 -> テーブルスキャン, スロークエリ
  • sy (システムプロセス: カーネル) の使用時間 -> データの書き込みやダンプ中, iowait の発生

mysqldumpslow

こんなコマンド

知らなかった. すいません.

$ mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

Parse and summarize the MySQL slow query log. Options are

  --verbose    verbose
  --debug      debug
  --help       write this text to standard output

  -v           verbose
  -d           debug
  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default
                al: average lock time
                ar: average rows sent
                at: average query time
                 c: count
                 l: lock time
                 r: rows sent
                 t: query time
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the top n queries
  -a           don't abstract all numbers to N and strings to 'S'
  -n NUM       abstract numbers with at least n digits within names
  -g PATTERN   grep: only consider stmts that include this string
  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),
               default is '*', i.e. match all
  -i NAME      name of server instance (if using mysql.server startup script)
  -l           don't subtract lock time from total time

ちょっと試してみる.

MySQL サーバーの用意

Docker でシュッと用意します.

$ docker run -i -t --name mysql -p 3306:3306 -e MYSQL_ROOT_PASSWORD=mysql -d mysql:latest \
 --slow-query-log=true \
 --slow-query-log-file=/tmp/slow.log \
 --long-query-time=1

スローログは /tmp/slow.log に出力するようにして, 1 秒以上のクエリは記録するようにします.

ログを吐きつつ mysqldumpslow を実行してみる

以下のようにクエリを断続的に投げつつ, mysqldumpslow を実行してみます.

#!/usr/bin/env bash

while true
do
  docker exec -t -i mysql mysql -uroot -pmysql -hlocalhost --execute="SELECT SLEEP($(($RANDOM % 10)));"
  sleep 2
done

SELECT SLEEP(N) しか投げていないので, 以下のようにちょっと寂しいけど, mysqldumpslow の出力を確認することが出来ました.

$ docker exec -t -i mysql mysqldumpslow -s c /tmp/slow.log

Reading mysql slow query log from /tmp/slow.log
Count: 61  Time=4.94s (301s)  Lock=0.00s (0s)  Rows=1.0 (61), root[root]@localhost
  SELECT SLEEP(N)

シンプルに件数をカウントする -s c オプションの実行結果です.

以上

なかなかデータベースのパフォーマンスチューニングとかに携わる機会はありませんが, とても奥深く且つ, 日頃から手を動かしておく必要があるなあと思った次第です。