MySQLスロークエリログの設定と分析｜8.0/8.4対応の手順と見方

MySQLのスロークエリログとは、実行に long_query_time 秒以上かかったSQLを記録するログで、slow_query_log = ON にするだけで有効になります。 記録されたログを mysqldumpslow や pt-query-digest で集計すると、「どのSQLが、何回、合計何秒かかっているか」がひと目でわかり、インデックス追加などの改善につなげられます。

この記事では、MySQL 8.0.46 に50万件の注文テーブルを作り、実際に遅いクエリを発生させて、ログの中身・集計結果・改善前と後をそのまま掲載しています。設定項目の早見表、SET PERSIST と my.cnf の両方の書き方、ログを出さずに performance_schema / sys で調べる方法、ローテーションと本番での注意点までまとめました。

MySQL 8.0 は2026年4月にサポートが終了しています。この記事の手順は MySQL 8.4 LTS / 9.7 LTS でも同じように使えます（違いがある箇所は本文で明記）。検証は手元の MySQL 8.0.46（Ubuntu 24.04 パッケージ）で行いました。

スロークエリログ設定の早見表

設定の変え方は3通りです。

スロークエリログを有効にする手順

SET PERSIST で再起動なしに有効にする

MySQL 8.0 以降は SET PERSIST を使うと、その場で反映され、再起動後も設定が残ります。

-- MySQL 8.0.46 / 8.4 / 9.7 共通
SET PERSIST slow_query_log  = ON;
SET PERSIST long_query_time = 0.1;   -- 検証用に0.1秒。本番は1秒前後から
SET PERSIST log_slow_extra  = ON;
SET PERSIST log_output      = 'FILE';

SELECT @@slow_query_log, @@long_query_time, @@log_slow_extra;
SELECT * FROM performance_schema.persisted_variables;

実行結果（MySQL 8.0.46）:

+------------------+-------------------+------------------+
| @@slow_query_log | @@long_query_time | @@log_slow_extra |
+------------------+-------------------+------------------+
|                1 |          0.100000 |                1 |
+------------------+-------------------+------------------+
+-----------------+----------------+
| VARIABLE_NAME   | VARIABLE_VALUE |
+-----------------+----------------+
| log_output      | FILE           |
| long_query_time | 0.100000       |
| log_slow_extra  | ON             |
| slow_query_log  | ON             |
+-----------------+----------------+

保存先はデータディレクトリの mysqld-auto.cnf（JSON形式）です。取り消すときは RESET PERSIST long_query_time; のように変数名を指定します。

my.cnf に書く場合

構成管理ツールで設定を管理したい場合は my.cnf（Ubuntu なら /etc/mysql/mysql.conf.d/mysqld.cnf など）の [mysqld] セクションに書きます。

[mysqld]
slow_query_log = ON
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 1
log_output = FILE
log_slow_extra = ON
log_queries_not_using_indexes = OFF
min_examined_row_limit = 0
log_slow_admin_statements = OFF

再起動前に --validate-config で書き間違いを確認できます（8.0.16以降）。

mysqld --defaults-file=slow.cnf --validate-config --user=root; echo rc=$?

rc=0

変数名を long_query_tim と1文字間違えた場合の結果です。

2026-10-01T14:34:54.815187Z 0 [ERROR] [MY-000067] [Server] unknown variable 'long_query_tim=1'.
2026-10-01T14:34:54.815208Z 0 [ERROR] [MY-010119] [Server] Aborting
rc=1

SET PERSIST と my.cnf の両方に書いた場合は、mysqld-auto.cnf（SET PERSIST）の値が後から読まれて優先されます。 どちらで管理するかを決めておくと、「my.cnf を直したのに反映されない」という状況を避けられます。

SET GLOBAL は「新しい接続」から効く

long_query_time にはグローバル値とセッション値があり、SET GLOBAL は今つながっている接続のセッション値を変えません。

-- 接続A（直前のグローバル値は0.05）
SET GLOBAL long_query_time = 1;
SELECT @@GLOBAL.long_query_time, @@SESSION.long_query_time;

+--------------------------+---------------------------+
| @@GLOBAL.long_query_time | @@SESSION.long_query_time |
+--------------------------+---------------------------+
|                 1.000000 |                  0.050000 |
+--------------------------+---------------------------+

新しく接続し直すと 1.000000 になりました。コネクションプールを使うアプリでは、プールの接続が作り直されるまで変更前の閾値のままになる点を覚えておくと安心です。

設定時によく出るエラー

スロークエリログに記録される条件

MySQL は次の順番で判定し、すべて満たしたSQLだけを記録します（公式マニュアル「The Slow Query Log」より）。

検証では、ALTER TABLE ... ADD INDEX を実行してもログに残りませんでした。管理系文は既定で対象外だからです。また、構文エラーで実行できなかったSQLも記録されません。

遅いクエリを発生させてログの中身を見る

検証用データ（コピペで再現できます）

-- MySQL 8.0.46 で確認。8.4 / 9.7 でも同じSQLで動きます
CREATE DATABASE IF NOT EXISTS shop;
USE shop;
CREATE TABLE orders (
  id INT PRIMARY KEY AUTO_INCREMENT,
  member_id INT NOT NULL,
  status VARCHAR(10) NOT NULL,
  amount INT NOT NULL,
  ordered_at DATETIME NOT NULL
);
SET SESSION cte_max_recursion_depth = 1000000;
INSERT INTO orders (member_id, status, amount, ordered_at)
WITH RECURSIVE seq(n) AS (SELECT 1 UNION ALL SELECT n+1 FROM seq WHERE n < 500000)
SELECT n % 20000 + 1,
       ELT(n % 4 + 1, 'new','paid','shipped','done'),
       (n * 37) % 10000 + 100,
       '2026-01-01' + INTERVAL (n % 260) DAY + INTERVAL (n % 86400) SECOND
FROM seq;
ANALYZE TABLE orders;

50万件、主キー以外のインデックスはありません。ここに次のようなSQLを何度か流しました。

SELECT member_id, SUM(amount) total FROM orders
 WHERE status = 'paid' GROUP BY member_id ORDER BY total DESC LIMIT 10;
SELECT id, amount, ordered_at FROM orders
 WHERE member_id = 101 ORDER BY ordered_at DESC LIMIT 5;
SELECT SLEEP(0.3);

実際に出力されたログ（log_slow_extra=ON）

# Time: 2026-10-01T14:33:55.806469Z
# User@Host: root[root] @ localhost []  Id:    17
# Query_time: 0.202611  Lock_time: 0.000003 Rows_sent: 10  Rows_examined: 500010 Thread_id: 17 Errno: 0 Killed: 0 Bytes_received: 124 Bytes_sent: 272 Read_first: 1 Read_last: 0 Read_key: 125001 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 505002 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 10 Sort_scan_count: 1 Created_tmp_disk_tables: 0 Created_tmp_tables: 1 Start: 2026-10-01T14:33:55.603858Z End: 2026-10-01T14:33:55.806469Z
use shop;
SET timestamp=1790865235;
SELECT member_id, SUM(amount) total FROM orders WHERE status = 'paid' GROUP BY member_id ORDER BY total DESC LIMIT 10;
# Time: 2026-10-01T14:33:56.472880Z
# User@Host: root[root] @ localhost []  Id:    20
# Query_time: 0.300955  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 1 Thread_id: 20 Errno: 0 Killed: 0 （以下の項目はすべて0のため省略）
SET timestamp=1790865236;
SELECT SLEEP(0.3);

各項目の読み方

いちばん見るべきは Rows_examined ÷ Rows_sent の比率です。10行返すのに50万行調べている（比率5万倍）なら、インデックスで絞り込める余地があります。

一方、SELECT SLEEP(0.3) は Rows_examined: 1 なのに0.30秒です。Query_time が長くても Rows_examined が小さいなら、SQLの書き方より待ち時間（SLEEP、ネットワーク、ストアドプロシージャ内の処理など）を疑う、と読み分けられます。

mysqldumpslow で集計する

mysqldumpslow は MySQL に同梱されている集計スクリプトです。数値を N、文字列を 'S' に置き換えて同じ形のSQLをまとめるので、どのSQLのパターンが重いかがわかります。

合計時間の長い順に上位5件（-s t）

mysqldumpslow -s t -t 5 /tmp/t97my/vm-slow.log

Reading mysql slow query log from /tmp/t97my/vm-slow.log
Count: 5  Time=0.24s (1s)  Lock=0.00s (0s)  Rows=10.0 (50), root[root]@localhost
  SELECT member_id, SUM(amount) total FROM orders WHERE status = 'S' GROUP BY member_id ORDER BY total DESC LIMIT N

Count: 6  Time=0.19s (1s)  Lock=0.00s (0s)  Rows=5.0 (30), root[root]@localhost
  SELECT id, amount, ordered_at FROM orders WHERE member_id = N ORDER BY ordered_at DESC LIMIT N

Count: 1  Time=0.30s (0s)  Lock=0.00s (0s)  Rows=1.0 (1), root[root]@localhost
  SELECT SLEEP(N.N)

Count: 1  Time=0.21s (0s)  Lock=0.00s (0s)  Rows=1.0 (1), root[root]@localhost
  SELECT COUNT(*) FROM orders o JOIN orders p ON p.member_id = o.member_id AND p.id = o.id + N WHERE o.ordered_at >= 'S'

Count: 2  Time=0.08s (0s)  Lock=0.00s (0s)  Rows=1.0 (2), root[root]@localhost
  SELECT COUNT(*) FROM orders WHERE DATE(ordered_at) = 'S'

読み方は「Count＝回数、Time＝平均（かっこ内は合計）、Rows＝平均返却行数（かっこ内は合計）」です。合計は秒単位に丸められるため、短い時間の比較には平均と回数を見ます。

よく使うオプション

-a を付けると、status = 'done' と 'paid' が別々に集計されました。値によって速さが変わるSQL（特定の値だけ件数が多い等）を探すときは -a が便利です。

Count: 2  Time=0.26s (0s)  Lock=0.00s (0s)  Rows=10.0 (20), root[root]@localhost
  SELECT member_id, SUM(amount) total FROM orders WHERE status = 'done' GROUP BY member_id ORDER BY total DESC LIMIT 10

Count: 2  Time=0.22s (0s)  Lock=0.00s (0s)  Rows=10.0 (20), root[root]@localhost
  SELECT member_id, SUM(amount) total FROM orders WHERE status = 'paid' GROUP BY member_id ORDER BY total DESC LIMIT 10

pt-query-digest でさらに詳しく集計する

Percona Toolkit の pt-query-digest は、95パーセンタイルや実行時間の分布、Rows_examined の合計まで出せる集計ツールです。Ubuntu 24.04 では apt で入ります（入ったのは 3.2.1）。

sudo apt-get install -y percona-toolkit
pt-query-digest --limit 2 /tmp/t97my/vm-slow.log

実行結果（抜粋）:

# Overall: 15 total, 5 unique, 1.36 QPS, 0.27x concurrency _______________
# Time range: 2026-10-01T14:33:55 to 2026-10-01T14:34:06
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time             3s    74ms   394ms   200ms   293ms    78ms   194ms
# Lock time           41us       0     4us     2us     3us       0     2us
# Rows sent             84       1      10    5.60    9.83    3.43    4.96
# Rows examine       6.71M       1 518.93k 457.78k 485.50k 121.69k 485.50k

# Profile
# Rank Query ID                          Response time Calls R/Call V/M
# ==== ================================= ============= ===== ====== =====
#    1 0x63101FE76D3FEC912107E5B9A66A...  1.2108 40.4%     5 0.2422  0.03 SELECT orders
#    2 0x9B578E5FED184BDA926A72B780E5...  1.1130 37.2%     6 0.1855  0.00 SELECT orders
# MISC 0xMISC                             0.6712 22.4%     4 0.1678   0.0 <3 ITEMS>

# Query 1: 0.45 QPS, 0.11x concurrency, ID 0x63101FE76D3FEC912107E5B9A66AC865 at byte 7342
# Exec time     40      1s   134ms   394ms   242ms   393ms    87ms   230ms
# Rows examine  35   2.38M 488.29k 488.29k 488.29k 488.29k       0 488.29k
# （中略：Query_time distribution、Tables、EXPLAIN 用のSQLが続く）

Profile の「Response time」の割合が大きい順に直すと、全体の負荷が効率よく下がります。 上の例では上位2つで全体の77.6%を占めています。

ログを出さずに performance_schema / sys で調べる

performance_schema は既定で ON（8.0.46で確認）で、スロークエリログを有効にしていなくても、SQLの種類ごとの実行回数や時間を集計し続けています。sys スキーマはそれを読みやすくしたビューです。

-- 実行時間が上位5%に入るSQL
SELECT query, exec_count, total_latency, avg_latency, rows_examined_avg
  FROM sys.statements_with_runtimes_in_95th_percentile
 WHERE db = 'shop' LIMIT 5;

-- フルテーブルスキャンしているSQL
SELECT query, exec_count, no_index_used_count, no_index_used_pct, rows_examined_avg
  FROM sys.statements_with_full_table_scans
 WHERE db = 'shop' LIMIT 5;

実行結果（MySQL 8.0.46、一部の列を省略）:

+-------------------------------------------------------------------+------------+---------------+-------------+-------------------+
| query                                                             | exec_count | total_latency | avg_latency | rows_examined_avg |
+-------------------------------------------------------------------+------------+---------------+-------------+-------------------+
| INSERT INTO `orders` ( `member ...  ? ) SQL_TSI_SECOND FROM `seq` |          1 | 2.84 s        | 2.84 s      |            500000 |
| SELECT `SLEEP` (?)                                                |          1 | 301.00 ms     | 301.00 ms   |                 1 |
+-------------------------------------------------------------------+------------+---------------+-------------+-------------------+
+-------------------------------------------------------------------+------------+---------------------+-------------------+-------------------+
| query                                                             | exec_count | no_index_used_count | no_index_used_pct | rows_examined_avg |
+-------------------------------------------------------------------+------------+---------------------+-------------------+-------------------+
| SELECT COUNT ( * ) FROM `order ...  WHERE `o` . `ordered_at` >= ? |          1 |                   1 |               100 |            531382 |
| INSERT INTO `orders` ( `member ...  ? ) SQL_TSI_SECOND FROM `seq` |          1 |                   1 |               100 |            500000 |
| SELECT COUNT ( * ) FROM `orders` WHERE DATE ( `ordered_at` ) = ?  |          2 |                   2 |               100 |            500000 |
| SELECT `id` , `amount` , `orde ... R BY `ordered_at` DESC LIMIT ? |          9 |                   9 |               100 |            500005 |
| SELECT `member_id` , SUM ( `am ...  ORDER BY `total` DESC LIMIT ? |          5 |                   5 |               100 |            500010 |
+-------------------------------------------------------------------+------------+---------------------+-------------------+-------------------+

注目したいのは member_id 検索の exec_count が 9回になっていることです。スロークエリログには閾値を超えた6回しか残っていませんが、performance_schema は閾値未満の実行も含めて全件を数えています。「1回は速いが回数が多いSQL」を見つけるのはこちらが得意です。

95パーセンタイルのビューは、このサーバーで実行されたSQL全体の中で上位5%を出すため、データ投入の INSERT や SLEEP が上位に来ています。対象を絞るなら元のテーブルを直接並べ替えます。

SELECT LEFT(DIGEST_TEXT, 70) AS digest_text, COUNT_STAR,
       ROUND(SUM_TIMER_WAIT/1e12, 3) AS total_s,
       ROUND(AVG_TIMER_WAIT/1e12, 3) AS avg_s,
       SUM_ROWS_EXAMINED, SUM_NO_INDEX_USED
  FROM performance_schema.events_statements_summary_by_digest
 WHERE SCHEMA_NAME = 'shop'
 ORDER BY SUM_TIMER_WAIT DESC LIMIT 5;

結果は member_id 検索が COUNT_STAR 9、合計1.387秒、SUM_ROWS_EXAMINED 4,500,045 となり、sys のビューと同じ傾向を秒単位で確認できました。

TIMER_WAIT はピコ秒単位なので 1e12 で割ると秒になります。集計をリセットしたいときは CALL sys.ps_truncate_all_tables(FALSE); を使います。

スロークエリログと performance_schema の使い分け

普段は performance_schema で傾向をつかみ、詳しく調べたい時期だけスロークエリログの閾値を下げる、という組み合わせが扱いやすい方法です。

EXPLAIN ANALYZE とインデックス追加で改善する

ログで見つけたSQLは EXPLAIN ANALYZE（8.0.18以降）で実際の処理を確認します。詳しい読み方は別記事「実行計画の見方」に譲り、ここでは改善前と後の要点だけ載せます。

改善前

EXPLAIN ANALYZE SELECT id, amount, ordered_at FROM orders
 WHERE member_id = 101 ORDER BY ordered_at DESC LIMIT 5\G

EXPLAIN: -> Limit: 5 row(s)  (cost=50258 rows=5) (actual time=189..189 rows=5 loops=1)
    -> Sort: orders.ordered_at DESC, limit input to 5 row(s) per chunk  (cost=50258 rows=499130) (actual time=189..189 rows=5 loops=1)
        -> Filter: (orders.member_id = 101)  (cost=50258 rows=499130) (actual time=0.651..189 rows=25 loops=1)
            -> Table scan on orders  (cost=50258 rows=499130) (actual time=0.631..140 rows=500000 loops=1)

Table scan で50万行を読み、25行に絞り込んでからソートしています。ログの Rows_examined: 500005 と一致します。

インデックスを追加した後

ALTER TABLE orders ADD INDEX idx_member_ordered (member_id, ordered_at);

EXPLAIN: -> Limit: 5 row(s)  (cost=8.75 rows=5) (actual time=0.137..0.139 rows=5 loops=1)
    -> Index lookup on orders using idx_member_ordered (member_id=101) (reverse)  (cost=8.75 rows=25) (actual time=0.137..0.138 rows=5 loops=1)

(member_id, ordered_at) の複合インデックスにすると、絞り込みと並べ替えの両方をインデックスで済ませられるため、ソートも消えました。インデックスが使われないパターン（関数をかける、型が違う等）は別記事「SQLのインデックスが効かない10のパターン」にまとめています。今回のログにあった WHERE DATE(ordered_at) = '...' も、ordered_at >= '2026-08-01' AND ordered_at < '2026-08-02' と書き換えるとインデックスを使える形になります。

log_queries_not_using_indexes と min_examined_row_limit の効き方

「遅くはないが、データが増えると遅くなりそうなSQL」を先に見つけたいときは log_queries_not_using_indexes を使います。そのまま ON にすると小さなテーブルの全件読みまで記録されるため、min_examined_row_limit と組み合わせるのがコツです。

SET GLOBAL long_query_time = 10;
SET GLOBAL log_queries_not_using_indexes = ON;
SET GLOBAL min_examined_row_limit = 1000;

SELECT COUNT(*) FROM orders WHERE amount > 9000;      -- インデックスなし・50万行
SELECT * FROM orders WHERE id = 5;                    -- 主キー
SELECT COUNT(*) FROM orders WHERE member_id = 7;      -- 追加したインデックス
SELECT * FROM tiny WHERE id = 2;                      -- 3行だけのテーブル

ログに残ったのは1件だけでした。

# Query_time: 0.076530  Lock_time: 0.000003 Rows_sent: 1  Rows_examined: 500000 ...
SELECT COUNT(*) FROM orders WHERE amount > 9000;

0.08秒と速いSQLでも、インデックスを使わず50万行を読んでいるものだけを拾えています。3行のテーブルは min_examined_row_limit で除外されました。記録が多すぎるときは log_throttle_queries_not_using_indexes = 30 のように1分あたりの上限も付けられます。

log_output=TABLE で SQL から読む

log_output = 'TABLE' にすると、ログは mysql.slow_log テーブルに入り、SQLで検索できます。

SET GLOBAL log_output = 'TABLE';
SELECT SLEEP(0.2);
SELECT start_time, query_time, rows_examined, db,
       LEFT(CONVERT(sql_text USING utf8mb4), 60) AS sql_text
  FROM mysql.slow_log ORDER BY start_time;

+----------------------------+-----------------+---------------+------+-------------------+
| start_time                 | query_time      | rows_examined | db   | sql_text          |
+----------------------------+-----------------+---------------+------+-------------------+
| 2026-10-01 23:34:46.425028 | 00:00:00.201378 |             1 | shop | SELECT SLEEP(0.2) |
+----------------------------+-----------------+---------------+------+-------------------+

集計ツールを使うなら FILE、SQLで手軽に見たいなら TABLE が目安です。sql_text はバイナリ型なので CONVERT(... USING utf8mb4) で読める形にしています。

ログのローテーションと容量の管理

スロークエリログは自動では分割・削除されません。閾値を下げるほど増えるため、ローテーションを用意しておきます。

手動でローテーションする

mv /tmp/t97my/vm-slow.log /tmp/t97my/vm-slow.log.1
mysql -e "FLUSH SLOW LOGS;"
ls -la /tmp/t97my/*slow*

-rw-r----- 1 mysql mysql   172 Oct  1 23:34 /tmp/t97my/vm-slow.log
-rw-r----- 1 mysql mysql 11183 Oct  1 23:34 /tmp/t97my/vm-slow.log.1

mv しただけでは MySQL は元のファイル（名前が変わったファイル）に書き続けます。FLUSH SLOW LOGS でファイルを開き直させると、新しいファイルが作られます。

logrotate の設定例

/var/log/mysql/mysql-slow.log {
    daily
    rotate 14
    missingok
    notifempty
    compress
    delaycompress
    create 640 mysql mysql
    postrotate
        mysql --defaults-extra-file=/etc/mysql/debian.cnf -e 'FLUSH SLOW LOGS;' > /dev/null 2>&1 || true
    endscript
}

※ logrotate の設定はディストリビューションにより認証ファイルの場所が異なります（上は未実行の設定例です）。

本番での注意点チェックリスト

MySQL 8.0・8.4・9.7 での違い

本記事のSQL・コマンドは 8.0.46 で実行し、8.4 / 9.7 については公式リファレンスマニュアルの同じ章で変数名と既定値を確認しました。

よくある質問

Q. long_query_time は何秒にすればよいですか？ A. 本番では1秒前後から始め、記録件数を見て0.5秒、0.2秒と下げていくのが扱いやすい方法です。短時間で多数実行されるSQLは閾値を下げても拾いにくいため、sys.statements_with_full_table_scans などの performance_schema 側と併用すると見落としが減ります。

Q. slow_query_log を ON にしたのにファイルが作られません。 A. SELECT @@log_output, @@slow_query_log_file, @@long_query_time; を確認します。log_output が TABLE や NONE だとファイルには出ません。ファイルの場所はデータディレクトリ（SELECT @@datadir;）が既定です。

Q. ログに記録された時刻が9時間ずれています。 A. log_timestamps の既定値が UTC のためです。SET PERSIST log_timestamps = 'SYSTEM'; にするとサーバーのタイムゾーンで記録されます。

Q. スロークエリログを有効にすると性能は落ちますか？ A. 記録されるのは閾値を超えたSQLだけなので、通常の閾値なら影響は小さく収まります。long_query_time = 0 で全件記録すると書き込みが増えるため、短時間の調査に限って使うと安心です。

まとめ

• SET PERSIST slow_query_log = ON と long_query_time で、再起動なしに有効化でき、設定は再起動後も残る
• log_slow_extra = ON で、フルスキャン（Read_rnd_next）や一時テーブルの有無までログで読める
• 最初に見るのは Rows_examined ÷ Rows_sent。大きければインデックスで絞り込める余地がある
• mysqldumpslow は -s t で合計時間順、pt-query-digest は割合と95%値まで出せる
• performance_schema / sys は閾値未満の実行も数えるため、回数の多いSQL探しに向いている
• 改善は EXPLAIN ANALYZE で確認し、今回の例では複合インデックスで189msから0.14msになった
• ローテーションは mv の後に FLUSH SLOW LOGS。ログにはSQLの値が残るので閲覧権限も整える

株式会社RJCでは、データベースの性能調査の進め方を仲間と学び合っています。こうした知識を共有しながら、日々技術を磨いています。

株式会社RJC ― SI事業・SES事業・AI駆動開発。RJCは一緒に成長を楽しめる会社です。