MySQLスロークエリログの設定と読み方:mysqldumpslowで分析

black flat screen computer monitor SQL

スロークエリログは、決めた秒数(long_query_time)より時間がかかった SQL をファイルに書き出す機能です。初期状態では無効なので、まず有効にします。再起動せずに今すぐ始めるなら、次の2行を実行します。

SET GLOBAL slow_query_log  = 'ON';
SET GLOBAL long_query_time = 1;   -- 1秒を超えたSQLを記録する

-- 記録先のファイルを確かめる
SHOW VARIABLES LIKE 'slow_query_log_file';

たまったログは mysqldumpslow -s t -t 5 <ログファイル> で、合計時間が長い SQL の上位5つにまとめて読みます。この記事では、再起動しても消えない設定のしかた、ログの各項目の読み方、mysqldumpslow の使い方を MySQL 8.0 で説明します。

このシナリオで考える

本記事では、ECサイトの注文管理システムを想定します。ordersテーブルに数百万行のデータがあり、特定のクエリが「なぜか重い」という状況を例に使います。

CREATE TABLE orders (
  id         BIGINT        PRIMARY KEY AUTO_INCREMENT,
  user_id    INT           NOT NULL,
  status     VARCHAR(20)   NOT NULL,
  total      DECIMAL(10,2) NOT NULL,
  created_at DATETIME      NOT NULL
);

このテーブルへの検索のどれかが遅い、という想定です。スロークエリログを有効にすると、遅い SQL がファイルにたまっていきます。

スロークエリログの有効化と設定

有効にする方法は、設定ファイル(my.cnf)に書く方法と、SET GLOBAL でその場で変える方法の2つです。主な設定項目は次のとおりです。

変数名 意味 おすすめの値
slow_query_log スロークエリログの有効/無効 1(有効)
slow_query_log_file ログファイルの出力先パス /var/log/mysql/slow.log
long_query_time 記録するクエリの閾値(秒)。デフォルトは10 1〜2
log_queries_not_using_indexes インデックスを使わないクエリも記録する 1(調査時に有効)
log_output 出力先。FILEまたはTABLE(mysql.slow_log) FILE(デフォルト)

long_query_timeのデフォルトは10秒と長めです。実務では1〜2秒に下げておくと、遅いクエリをより広く拾えます。

my.cnfによる永続的な設定

再起動をまたいでも設定を維持したい場合は、/etc/mysql/my.cnf(または/etc/my.cnf)に追記します。

[mysqld]
slow_query_log        = 1
slow_query_log_file   = /var/log/mysql/slow.log
long_query_time       = 1
log_queries_not_using_indexes = 1

追記後はMySQLを再起動して設定を反映させます。

sudo systemctl restart mysql

再起動なしで動的に変更する

本番環境で再起動が難しい場合は、SET GLOBALで即時反映できます。

SET GLOBAL slow_query_log     = 'ON';
SET GLOBAL long_query_time    = 1;
SET GLOBAL log_queries_not_using_indexes = 1;

SET GLOBAL long_query_time は、このあとにつないだ接続にだけ効きます。アプリのコネクションプールのように、つながったままの接続には古い値(10秒)が残ります。プールを作り直すか、試すときは自分の接続で SET SESSION long_query_time = 1; も実行してください。

動的に変えた値は MySQL を再起動すると元に戻るので、my.cnf にも書いておきます。今の設定値は SHOW VARIABLES で確かめられます。

SHOW VARIABLES LIKE 'slow_query%';
SHOW GLOBAL VARIABLES LIKE 'long_query_time';

ログの出力フォーマットを読む

スロークエリログには、閾値を超えたクエリが次のような形式で書き出されます。

# Time: 2026-06-16T03:45:12.123456Z
# User@Host: app_user[app_user] @ [192.168.1.10]  Id: 1042
# Query_time: 2.345678  Lock_time: 0.000234  Rows_sent: 1  Rows_examined: 480000
SET timestamp=1750042312;
SELECT * FROM orders WHERE status = 'pending' AND total > 1000;

各フィールドの意味は次のとおりです。

フィールド 意味
Time ログに書かれた時刻(初期設定では UTC)
User@Host 実行ユーザーとホスト名・IPアドレス
Query_time クエリの実行時間(秒)
Lock_time ロック取得にかかった時間(秒)
Rows_sent クライアントに返した行数
Rows_examined MySQL内部で走査した行数

まず見るのは Rows_examined です。上の例では48万行を読んで、1行しか返していません。インデックスが効いていれば読む行はずっと少なくなります。Rows_sent との差が大きいほど、直す余地があります。

Lock_time が Query_time の大半を占める場合は、クエリそのものより、ほかの処理のロック待ちが原因かもしれません。その場合はインデックスより先に、トランザクションの長さや順番を見直します。

mysqldumpslowで集計・分析する

ログが大きくなると、目で追うのは大変です。mysqldumpslow を使うと、同じ形の SQL をまとめて表示できます。数値は N、文字列は 'S' に置きかえられるので、値だけが違う SQL は1つにまとまります。

基本の使い方

mysqldumpslow /var/log/mysql/slow.log

オプションなしでは、平均の実行時間(at)が長い順に並びます。出力例は次のとおりです。

Count: 42  Time=2.35s (98s)  Lock=0.00s (0s)  Rows=1.0 (42), app_user@192.168.1.10
  SELECT * FROM orders WHERE status = 'S' AND total > N

この例では、同じ構造のクエリが42回実行され、合計98秒かかっていることが読み取れます。

よく使うオプション

オプション 意味
-s t クエリ時間の合計が大きい順(total time)
-s at クエリ時間の平均が大きい順(average time)※デフォルト
-s c 実行回数が多い順(count)
-s r 返した行数(Rows_sent)の合計が多い順。平均なら -s ar
-t N 上位N件のみ表示
-g "pattern" クエリ内容でgrepフィルタ

実務でよく使う組み合わせを示します。

# 実行時間の合計が長い上位5クエリ(サーバ負荷の元凶を探す)
mysqldumpslow -s t -t 5 /var/log/mysql/slow.log

# 実行回数が多い上位5クエリ(頻発する問題クエリを探す)
mysqldumpslow -s c -t 5 /var/log/mysql/slow.log

# ordersテーブルに関するクエリのみ絞り込む
mysqldumpslow -g "orders" /var/log/mysql/slow.log

「1回で5秒かかる」SQL は -s at で上に来ます。「1回0.2秒でも1万回実行されて、合計で一番時間を使っている」SQL は -s t で見つかります。両方の並べ方で見てください。

よくある落とし穴と注意点

  • long_query_time=10のまま運用しない:10秒では、かなり重い SQL しか記録されません。まず1〜2秒に下げます。調査のあいだだけ0にして、すべての SQL を記録する方法もあります(ログが急に増えるので、終わったら戻します)。
  • ログファイルの肥大化に注意:log_queries_not_using_indexes=1 にすると、速くてもインデックスを使わない SQL がすべて記録され、ディスクを圧迫することがあります。本番でずっと有効にするのは避け、logrotate でのローテーションも設定しておきます。
  • Rows_examined が大きい = インデックス不足のサイン:Rows_sent が小さいのに Rows_examined が大きいときは、全件を読んでいる可能性があります。EXPLAIN で実行計画を確かめます。よくある原因は「インデックスが効かない7つのパターンと直し方」にまとめています。
  • ログファイルのパーミッションを確認する:slow_query_log_file のパスに MySQL のプロセスが書き込めないと、ログは残りません。ファイルがなければ touch で作り、chown mysql:mysql で持ち主を変えます。

まとめ

遅い SQL を探すときは、まずスロークエリログを有効にします。long_query_time を1〜2秒にし、mysqldumpslow で合計時間と回数の両方から、直す SQL を選びます。見つけた SQL は、EXPLAIN や EXPLAIN ANALYZE で実行計画を確かめてから直します。

参考リンク

アイキャッチ画像: Photo by WebFaster on Unsplash

タイトルとURLをコピーしました