MySQL トラブルシューティング その2[MySQLログ]

MySQLのログについて適当に。

エラーログ
もっとも参照する情報であるログファイル。
なにかトラブルに遭遇した場合、ほとんどの出来事はエラーログに記録されていることでしょう。
エラーログは特に指定していなかった場合、データディレクトリ内にホスト名.errというファイル名で生成されています。
基本的にエラーメッセージそのものが問題点を表しているのでその部分を確認すればいいのです。

エラーログの中には「ERROR 2」のようにエラー番号がのっている時があります。。
この時MySQLに付属しているperrorコマンドを使うと、エラーコードの意味を表示してくれます。

perror 2
OS error code   2:  No such file or directory

スロークエリログ
クエリの実行に時間がかかった時に記録されるログです。
データディレクトリにホスト名-slow.logというファイル名で生成されます。
大量のスロークエリログを解析するには、mysqldumpslowコマンドを利用すると便利です。

mysqldumpslowはMySQLに付属しているツール。
出力したスロークエリログを読み込みます。

mysqldumpslow -s t -t 5 /tmp/slow_query.log > /tmp/slow_result.log
Reading mysql slow query log from /tmp/slow_query.log

出力したslow_log

Count: 52251  Time=2.94s (153533s)  Lock=0.00s (6s)  Rows=1.9 (101255), test[test]@localhost
  SELECT N
  FROM   `test_t`
  WHERE  `p_id` = 'S'

Count: 7598  Time=8.91s (67661s)  Lock=0.00s (1s)  Rows=5135.6 (39020315), test[test]@localhost
  SELECT `un_id`, `m_time` FROM `a_ra` WHERE `p_id` = 'S'
   
Count: 769  Time=0.02s (16s)  Lock=0.00s (0s)  Rows=5.0 (4096), test[test]@localhost
  SELECT u_id, title, name FROM item, author WHERE
  title LIKE 'S' AND u_item = u_hav ORDER BY u_id ASC LIMIT N

このような形式で出力できる。

Count	何回そのSQL文が実行されたのか
Time	最初の数字が平均実行時間で、カッコ内の数字がトータルの実行時間。

今回は「合計実行時間順に10件表示する」というオプションを指定して出力しました。
これで出力したログのSQL文を上から順に修正していけば、ボトルネックの解消ができるはずです。

他にもさまざまな便利なオプションが存在します。

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

スロークエリログは、my.cnfで設定したlong_query_timeの値より実行に時間がかかっているSQL文をすべて記録することができます。
この値を0にすると全てのSQL文を出力対象にすることも可能だが、サーバの過負荷につながるので開発機などで数十秒だけ0にして検証するなどの使い方が望ましいです。