誰も教えてくれなかったMySQLの障害解析方法

  • 2568
    いいね
  • 2
    コメント
この記事は最終更新日から1年以上が経過しています。

それほどDBに詳しくないアプリエンジニアが何かトラブった時にすぐさま行動して問題把握できるようになる情報を列挙しておきます。

開発時、障害時の対処療法やちょっとした定期監視方法などを対象にしています。
抜本的な対策などはインフラエンジニアさんにお任せしたほうがいいと思います。

DBはいろんな意味でこわいんでできれば触りたくないです><

事前確認

MySQLサーバーのシステム設定値を確認しておく

以下のようにサーバーのシステム設定値を確認できます。

mysql> SHOW GLOBAL VARIABLES;

# ワイルドカード(%)を用いた絞り込み
mysql> SHOW GLOBAL VARIABLES LIKE 'performance_schema%'

MySQLサーバーのステータス値を確認しておく

以下のようにサーバーのステータス値を確認できます。

mysql> SHOW GLOBAL STATUS;

VARIABLESの時同様にLIKEやWHEREで絞込ができます。
なお性能に影響を与えてしまうので闇雲にこのコマンドを実行するのはやめましょう。

変数の説明はこちらにあります。

一部列挙しておきます。

変数 説明
Aborted_clients 接続を適切に閉じないままクライアントが終了したことが原因で中断した接続の数。
Aborted_connects MySQLサーバに接続しようとして失敗した回数。
Bytes_received すべてのクライアントから受信したバイト数。
Bytes_sent すべてのクライアントへ送信したバイト数。
Connections (成功/不成功に関わらず) MySQL サーバへの接続試行回数。
Delayed_errors エラー発生(duplicate key の可能性)により、INSERT DELAYED で書き込まれたレコードの数。
Innodb_buffer_pool_pages_free 空き容量
Innodb_data_pending_reads 現在の読み込み保留の数。
Innodb_data_pending_writes 現在の書き込み保留の数。
Innodb_data_read ここまでのデータの読み込み量 (単位:バイト)。
Innodb_rows_deleted InnoDB テーブルから削除したレコード数。
Innodb_rows_inserted InnoDB テーブルへの挿入レコード数。
Innodb_rows_read InnoDB テーブルからの読み込みレコード数。
Innodb_rows_updated InnoDB テーブルでの更新レコード数。
Qcache_hits クエリ キャッシュ ヒットの数。
Com_xxxx ステートメントのカウンタ値は、それぞれの xxx ステートメントを実行した回数を示す。(select他)

クエリキャッシュのヒット率

クエリキャッシュのヒット率は以下のように計算できます。

クエリキャッシュヒット率
 =キャッシュヒット数 / クエリ発行総数
 =キャッシュヒット数 / (キャッシュヒット数+キャッシュミス数)
 =Qcache_hits / ( Qcache_hit + Com_select) 
  
ヒット率が6割を下回るようであれば見直しをしたほうが良いかもしれません。

役立ちそうなコマンドの一覧

コマンド 説明
SHOW PROCESSLIST 接続されているスレッドの一覧
SHOW OPEN TABLES 現在オープンされているテーブルの一覧
SHOW PROCEDURE STATUS ストアドプロシージャの一覧
SHOW GRANTS ユーザー権限一覧
SHOW WARNINGS クエリで発生した警告一覧
SHOW ERRORS クエリで発生したエラー一覧

障害解析

実行したクエリのプロファイリング情報を表示する

プロファイリング情報収集を可にしたうえでコマンド実行するとクエリの実行時間などが詳細にわかります。

mysql> SET profiling=1;
mysql> SHOW PROFILE

SQLクエリログの出力と確認

何か自作のプログラムからSQLクエリを発行しているのであれば、そこで発行するSQLをprintするなどしてクエリのシンタックスに間違いがないか確認できます。

ただフレームワークを利用していたりするとprintを埋め込むことが難しいこともあるのでその場合には、MySQLのログから既に発行したクエリを確認するようにします。

mysql> SET GLOBAL general_log='on'

これでMySQLのデフォルトのデータディレクトリにログが出力されます。
ちなみにUbuntuだと/var/lib/mysqlになっています。

もし違ったとしても/etc/mysql/my.cnfを見ればdatadirという項目に書いてあります。

ちなみにログをファイルではなくMySQLのテーブルとして出力したい場合は以下のようにします。

mysql> SET GLOBAL log_output='table'

テーブル出力にした場合、mysqlデータベースのgeneral_logテーブルにログが出力されますので以下のように確認しましょう。

mysql> USE mysql
mysql> SELECT * FROM general_log\G

末尾に\Gをつけると1行づつの表示にしてくれるのでカラム数が多い場合でも見やすいです。

ログの必要がなくなったらoffにしましょう。

mysql> SET GLOBAL general_log='off'

なお常に有効にしたい場合、my.cnfで設定しておきましょう。

ちなみにSET GLOBALをつけるにはroot権限が必要ですが、無停止で設定できます。
my.cnfに設定する場合には再起動が必要です。

SQLクエリのデバッグ

わかりやすいシンタックスエラーならばまだしも、クエリ実行できるけれども結果が正しくない場合には、ちょっと大変です。
そんな場合にはクエリ自体をより詳細に見てデバッグします。

まず、あやしそうなクエリに目をつけたらそれを詳細に情報表示させます。

mysql> EXPLAIN EXTENDED <SQLクエリ>\G

この結果をみて各レコードの最後にwarningという文字を見つけたらそれを深堀りしてみます。

mysql> show warnings\G

このshow warningsでは、入力したクエリそのものではなく、最適化した後の実際に実行されるクエリを表示してくれます。

ちなみにshow warningsを打つのが面倒であれば以下のようにして常にenableにすることもできます。

mysql> \W

データの更新ミスを疑う

SQLは合っていてもデータ自体が壊れている場合もあります。
そんな場合にはクエリをいくら解析しても問題点はわかりません。

こういった問題はデータが壊れたタイミングでは問題が発覚せず、そのデータを利用しようとするときに初めて発覚するので結構やっかいです。

特にUPDATEやDELETEがおかしい場合には一旦SELECTで置き換えてみて対象データが正しくリストアップされているか確認しましょう。
WHERE条件などは同じままにするのがポイントです。

UPDATEやDELETE時の行数とSELECTした時の行数が正しいことを確認してみるとなにか見つかるかもしれません。

mysql> <UPDATEかDELETE文> 
Query OK, 10 rows affected
mysql> <SELECT文>
10 rows in set (0.00 sec)

レコードの重複を見破る

よくある問題の1つはユニークであるはずの値が重複してしまうことです。

カラムをユニークに設定していなかったという凡ミスもありえますので確認して問題あれば対処しましょう。

mysql> ALTER TABLE <テーブル名> ADD UNIQUE(<カラム名>)

スロークエリを発見する

間違ってはいないが、時間がかかっているクエリはシステムのパフォーマンスを低下させる原因です。
まずはこのようなスロークエリを見つけてクエリの見直しをかけてやる必要があります。

以下を設定すると一定時間以上かかっているクエリのログを出力できます。

# 5秒以上かかっているクエリをログ出力
mysql> SET GLOBAL slow_query_log=ON
mysql> SET GLOBAL slow_query_log_file=/var/lib/mysql/mysql-slow.log
mysql> SET GLOBAL long_query_time=5

なお0秒指定すると全クエリが記録されて負荷がかかるので大きめに指定しましょう。

なおログファイルを遅い順に並べて見たい場合には以下を使うと便利です。

$ mysqldumpslow -s t /var/lib/mysql/mysql-slow.log

mysqldumpslowを使えば、ソートの他に特定パターンのクエリのみに絞ったりもできますので詳しくはmanで調べてみましょう。

スロークエリを事前に撲滅する

スロークエリはログから確認できますが、できれば事前に防いでおきたいものです。

スロークエリは大抵インデックスが上手く効いてなかったり、扱う行数が不必要に大きかったりすることが原因なのでそれがわかれば事前に対処できます。

基本に忠実にEXPLAINで確認しますが、typeとrowsを特によく見ましょう。

mysql> EXPLAIN EXTENDED <SQL文>\G
*********************** 1. row ***********************
・・・
  type: index
・・・
  rows: 2000
・・・
*********************** 2. row ***********************
・・・
  type: index_subquery
・・・
  rows: 300
・・・

上記のような場合、最大2000x300行分調べられてしまうのでもっと対象行を減らせないかSQL文を見直しましょう。

インデックスがそもそもないのであれば対象カラムにインデックスを追加しておきましょう。

mysql> ALTER TABLE <テーブル名> ADD INDEX(<カラム名>)

なお、必ずしもEXPLAINの情報だけが正しいとは限らないので、最終的には実行時間で判断するほうが良いです。

スロークエリは状況によりますが以下のように対処するのがオススメです。

  • インデックスを適切に使う、マルチカラムインデックスも可能ならつかう
  • 返す行数を極力減らす、必要なカラムだけを参照する
  • サブクエリをJOINなどに書き換える

障害発生時のMySQLサーバーの再起動確認

サーバーがクラッシュしたら、MySQLが再起動したのかどうか確認してみます。
MySQLの再起動絡みで障害(マスタとスレーブの同期など)が発生することがあるからです。

エラーログで再起動したかどうかを確認したり、mysqlの状態変数を見ることでも確認できます。

mysql> SHOW GLOBAL STATUS LIKE 'uptime';

この時表示されるUptime値によって再起動と障害に因果関係があるのか判断できます。

再起動と障害に因果関係がある場合には、再起動直前のエラーログを眺めてみてなにか情報がないかを確認します。
エラーログ出力は必ず有効にしておきましょう。

あるクエリ実行後に妙なシグナルがあったりするかもしれません。
もしクエリが問題なのであればそれをチェックしてみます。

またRAM不足でクラッシュすることもありますが、その場合はインフラ屋さんに相談してみましょう。

ロックの待ち行列に注意する

テーブルへの同時アクセスを実現するためにロックが使われます。
このロックが原因で実行が極端に遅くなることが有ります。

他のスレッドがテーブルをロックし、ロック解除待ちをしてしまう状況です。

ずっとロックしているかどうかを調べるためには以下を実施します。

mysql> SHOW PROCESSLIST\G
*********************** 1. row ***********************
・・・
Time: 55
State: Locked
・・・

ここで表示されるState項目にLockedとあればロックされている証拠です。
Timeはクエリの実行時間つまりどれだけの間ロックしているかを表します。

あるところで長い間ロックが発生していたらまた別のところできっと Sleepしているところも見つかるでしょう。
Sleepはロック解除待ちをしている部分です。

なお、INFORMATION_SCHEMA.PROCESSLISTの中身をSELECTすればSHOW PROCESSLISTと同様の結果を得られます。

トランザクションのautocommit無効に注意

トランザクションを使う場合には、トランザクション間でロックをしあうデッドロック状態も起こりえますので注意しましょう。

いちばん問題なのはautocommit=0として自動でコミットされないようにすることです。

これは便利では有りますが、もしトランザクションの最後にCOMMITまたはROLLBACKを忘れてしまったらその後ずっとロックされたままになってしまいます。

もしトランザクションを使っていてautocommit=0としていてロック待ち問題が発生したのであれば、COMMITやROLLBACKし忘れがないかチェックしましょう。

ハードウェア的な問題解析

ハードウェアは問題が発覚したらプロにお任せしましょう。

メモリの問題

ハードウェア故障以外でメモリで問題になるのはメモリ容量不足です。

MySQLで使っているメモリ量を調べてみて容量が逼迫しているか監視してみましょう。

この記事この記事にメモリ使用量を算出するSQLが載っています

そもそも物理的に容量が足りていないのか、設定で余計に制限しているのかの切り分けが重要です。
後者の場合には、インフラエンジニアの方と相談して設定変更も検討しましょう。

そもそもMySQLでは、クエリキャッシュがメモリ使用量増大の原因になっていることも有ります。

クエリキャッシュのステータスは以下のように確認できます。

mysql> SHOW STATUS LIKE 'Qcache%';

あまり使うものではありませんがキャッシュを削除したい場合はこちら。

mysql> RESET QUERY CACHE;

そもそもクエリキャッシュが問題となっているようであれば、my.cnfのキャッシュの設定を見なおしておきましょう。 

query_cache_sizeやquery_cache_limitなどが適切かどうか確認するといいと思います。

ディスクの問題

使い続けているとメモリだけではなくディスク容量の問題にもぶち当たります。

まずはログファイル容量を確認して問題がないか確認します。

$ ls -hal /var/log/mysqld-*

またはmysqldがテンポラリーテーブルを掴みっぱなしの場合もあります。
そういった場合には再起動をかけてみるのもひとつの手となります。

テーブル自体の容量が肥大化していっている場合もある。

その場合には最適化してみると多少改善されることもある。
なお以下コマンドはテーブルをロックするため注意が必要。

mysql> OPTIMIZE TABLE hisory_log;

余談

まぁコマンド打つのもいいけどMUNINとかNAGIOSとかNew Relicとか入れて、MySQLにかぎらず障害監視を簡単にできるのが一番いいですね

そうすれば、

  • グラフがあって傾向とかわかりやすいし
  • ノウハウも属人化しないし
  • 何より楽

ですしね。