深夜2時の PagerDuty の悪夢
時刻は深夜2時、電話の呼び出し音が鳴り響きます。モニタリングダッシュボードを見ると、プライマリデータベースの CPU 使用率が 95% に急上昇しています。Web アプリケーションは 504 Gateway Timeout で動かなくなっています。最初の本能的な反応は、パニックに陥ってスケールアップすることかもしれません。インスタンスの RAM を増やしたり、より高スペックな RDS ティアにアップグレードしたりすることです。しかし、ハードウェアが本当の解決策になることは稀です。通常、この混乱の原因は、インデックスなしで 1,000 万行をスキャンしようとしている 1 つの不正な SQL クエリです。
MySQL は非常に優れた働きをしますが、黙って耐える性質もあります。たとえそのクエリが 15 秒かかり、最も重要なテーブルをロックしてしまったとしても、送られてくるひどいクエリを忠実に実行しようとします。これらのパフォーマンスキラーを捕まえるには、スロークエリログ (Slow Query Log) が必要です。
このログは、データベースのドライブレコーダーのようなものだと考えてください。特定の制限時間を超えたクエリや、インデックスを完全に無視したクエリをすべて記録します。これがないと、コードのどの部分がシステムを遅延させているのかを推測するしかありません。
有効化：ダウンタイムなしでスイッチを入れる
設定を変更するために本番環境のデータベースを再起動することはできません。再起動するとバッファプールがクリアされ、アクティブな接続が切断されてしまいます。これは多くの場合、スロークエリそのものよりも悪影響を及ぼします。幸いなことに、MySQL ではグローバル変数を使用して、実行時にログの切り替えが可能です。
現在のステータスの確認
まずは、すでにログが有効になっているかどうかを確認しましょう。MySQL シェルに入り、以下を実行します。
SHOW VARIABLES LIKE '%slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';もし slow_query_log が OFF であれば、データベースは実質的に目隠し状態で運用されていることになります。再起動せずにすぐに有効化するには、以下のコマンドを使用します。
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL slow_query_log_file = '/var/log/mysql/mysql-slow.log';
SET GLOBAL long_query_time = 1.0;私は通常、ベースラインとしてしきい値を 1.0 秒に設定します。秒間 5,000 リクエスト以上を処理するトラフィックの多い API の場合は、これを 0.1 秒または 0.2 秒に絞ることもあります。これにより、「マイクロボトルネック」が大規模な障害に発展する前にキャッチできます。
設定を永続化する
実行時の変更は、サーバーが再起動すると消えてしまいます。これらの設定を永続的にするには、設定ファイル（通常は /etc/mysql/my.cnf）を更新します。[mysqld] ブロックの下に以下の行を追加します。
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 1.0
log_queries_not_using_indexes = 1
min_examined_row_limit = 100log_queries_not_using_indexes の使用には注意が必要です。レガシーコードを含む大規模なデータベースでは、数分で数ギガバイトのログが生成される可能性があります。min_examined_row_limit = 100 はセーフティネットとして機能し、インデックスを必要としない小さな無害なテーブルがログに記録されないようにします。
設定：ノイズの中からシグナルを見つけ出す
ログは読みやすくて初めて役に立ちます。すべてのクエリを記録すると、CPU の問題がディスク I/O の問題にすり替わるだけです。パフォーマンスチューニングとは、ノイズの中から重要なシグナルを見つけ出す作業です。
しきい値の戦略
5 分間の特定のデバッグ作業でない限り、本番環境で long_query_time を 0 に設定してはいけません。負荷の高いサーバーでは、ディスク容量がいっぱいになり、ルートパーティションがクラッシュする可能性があります。まずは 2 秒から始めましょう。ログが空のままでアプリが重いと感じる場合は、1 秒、次に 0.5 秒へと下げていきます。
誤検知のフィルタリング
バックアップ中など、サーバーが他の処理で忙しかったためにクエリが遅くなることがあります。min_examined_row_limit を使用することで、そのような「運の悪い」クエリを無視できます。客観的に重いクエリ、つまり何千行ものデータにアクセスしたクエリだけに集中できます。
ファイル vs テーブル
MySQL はログを FILE または TABLE に保存できます。TABLE への保存は SQL を使ってログを分析できる利点がありますが、データベースエンジンに大きなオーバーヘッドを加えます。本番環境では、常に FILE を使用してください。その方が高速であり、外部ツールを使用してデータベースのリソースを消費せずに解析できます。
分析：データの解読
生のログは見づらいものです。1 つのエントリは以下のようになります。
# Time: 2023-10-27T14:15:01.123456Z
# Query_time: 8.452100 Lock_time: 0.000123 Rows_sent: 5 Rows_examined: 1200000
SELECT * FROM transactions WHERE user_id = 999 ORDER BY created_at DESC;これが決定的な証拠（スモーキング・ガン）です。わずか 5 件のレコードを見つけるために 8.4 秒かかり、120 万行をスキャンしています。明らかに user_id にインデックスが必要です。
プロのツールセット
これらのファイルを手動で読まないでください。mysqldumpslow を使ってデータを集計しましょう。類似のクエリをグループ化してくれるので、どのクエリが累積で最も大きな遅延を引き起こしているかを確認できます。
# 合計実行時間でソートし、ワースト10件を表示
mysqldumpslow -s t -t 10 /var/log/mysql/mysql-slow.logより詳細な洞察が必要な場合は、Percona Toolkit の pt-query-digest を使用してください。これは DBA にとってのゴールドスタンダードです。詳細なヒストグラムを提供し、1 日のどの時間帯にデータベースの負荷が最も高いかを特定します。
最終的な解決策：EXPLAIN
問題のあるクエリを見つけたら、EXPLAIN を付けて実行してください。これにより、MySQL がそのクエリをどのように実行する計画なのかを正確に知ることができます。もし type: ALL と表示されていれば、それはフルテーブルスキャンを意味します。データベースはディスク上のすべての行を読み取っています。適切なインデックスを追加するだけで、その 8 秒かかっていたクエリが 10 ミリ秒に短縮されることもよくあります。
データベースのチューニングは一度きりの作業ではありません。適切なしきい値を設定してスロークエリログを稼働させ続けましょう。それは早期警戒システムとなり、ボトルネックが深夜 2 時の電話に変わる前に修正するのに役立ちます。
