スロークエリログとは、実行に long_query_time(既定10秒)を超えて時間がかかったSQLを記録するMySQLのログです。どのSQLが何秒かかり、何行を読んだのかが残るため、データベースが遅い原因を探すときに最初に開くログになります。「スロークエリ」は遅いSQLそのもの、「スロークエリログ」はそれを書き留める仕組みです。
この記事では、MySQL 8.4.8を手元で起動し、200万行のテーブルに遅いSQLを流して採取した実際のログとツールの出力を載せています。全SQLを記録する一般クエリログとの違いと有効化の手順、ログファイルの場所、出力項目の読み方、mysqldumpslow・pt-query-digestでの集計、EXPLAINでの改善、本番で常時有効にしたときの負荷まで、順に確認できます。
まとめ:スロークエリログの要点
- 既定は無効:
slow_query_log=OFF・long_query_time=10。SET GLOBAL slow_query_log=ONで再起動なしに有効化でき、恒久化はmy.cnfに書きます。 - long_query_timeのGLOBAL変更は既存セッション値に反映されない:
SET GLOBAL long_query_time=1の直後でも、その接続のしきい値は10秒のままでした。確認は新しい接続で行います。 - 見るべき数字はRows_examined:40行を返すために200万行を読んでいたSQLは、インデックス追加で1.43秒から0.0005秒になりました。
- 集計はツールで:同梱のmysqldumpslowは数値を
Nに置き換えて同じ形のSQLをまとめます。読んだ行数まで集計するならpt-query-digest(3.7.1)を使います。 - 本番は1秒前後を起点に負荷を確認:実測で、しきい値1秒のスロークエリログ(記録されるSQLが無い状態)は、無効時に比べ約3%の増加にとどまりました。全SQLを記録する設定(
long_query_time=0や一般クエリログ)は約2.4倍遅くなったので、調査の間だけにとどめます。 - 全SQLを見たいなら一般クエリログ:「mysql クエリログ」で探している設定はこちらで、
general_log=ONで有効になります。
スロークエリログとは|記録される条件とスロークエリとの違い
スロークエリログは、MySQLが「遅い」と判定したSQLを1件ずつ追記していくファイルです。SQL文だけでなく、実行時刻・実行時間・ロック待ち時間・返した行数・読んだ行数が一緒に残るので、アプリ側のログでは分からない「データベースの中で何が重かったか」を後から確認できます。
検索で並ぶ「スロークエリ」と「スロークエリログ」は別の言葉です。スロークエリは時間のかかるSQLそのもの、スロークエリログはそのSQLを記録したログです。「スロークエリを見つけるためにスロークエリログを使う」という関係になります。
スロークエリログの4つの記録条件
MySQL 8.4リファレンスマニュアルのスロークエリログの章は、次の順に判定して記録するかどうかを決めると説明しています。「設定したのに出ない」ときは、この順に当てはめると原因が絞れます。
- 管理文(ALTER TABLE・CREATE INDEX・OPTIMIZE TABLE など)でないこと。管理文は
log_slow_admin_statementsをONにしたときだけ対象になります。 - 実行時間が
long_query_time以上であること。またはlog_queries_not_using_indexesがONで、インデックスを使わずに行を探したこと。 - 読んだ行数が
min_examined_row_limit以上であること。 log_throttle_queries_not_using_indexesによる件数の間引き対象でないこと。
1つ目は見落としやすい条件です。手元で200万行のテーブルにインデックスを追加した ALTER TABLE は7.4秒かかりましたが、log_slow_admin_statements=OFF(既定)のままでは記録されず、ONにすると Query_time: 7.398115 で記録されました。夜間のバッチでDDLが遅い、という調査ではこの変数を先にONにします。
ログは文の実行が終わり、ロックを解放した後に書き込まれます。そのため、ログの並び順と実行順は一致しないことがあります。
MySQLのクエリログの種類|一般クエリログ・バイナリログ・エラーログとの違い
ここではMySQLのログのうち、調査や運用で確認する4種類を比較します。「mysql クエリログ」で探しているのが「実行されたSQLを全部見たい」なのか「遅いSQLだけ見たい」なのかで、開くべきログが変わります。次の既定値は、MySQL 8.4.8を設定ファイルなしで起動して SHOW VARIABLES で読んだ値です。
| ログ | 記録するもの | 主な用途 | 8.4の既定 | 有効化する変数 |
|---|---|---|---|---|
| スロークエリログ | しきい値を超えたSQL | 性能改善 | 無効 | slow_query_log |
| 一般クエリログ | 接続・切断と全SQL | デバッグ・調査 | 無効 | general_log |
| バイナリログ | データを変えた操作 | レプリケーション・復旧 | 有効 | log_bin |
| エラーログ | 起動・停止・エラー | 障害調査 | 有効 | log_error |
性能の調査で見るのはスロークエリログです。一般クエリログは「アプリが実際にどんなSQLを投げているか」を確かめるためのもので、ORMが発行するSQLの確認や、不具合の再現に向いています。
一般クエリログの有効化と記録対象
一般クエリログは general_log をONにすると、その時点から、クライアントの接続・受け取ったSQL・切断を log_output で指定した出力先へ書き出します。ただし、sql_log_off=ON にしたセッションの文と、構文エラーで解析できない文は記録されません。後者は、パスワードを含むかどうかを判定できないためとマニュアルは説明しています。出力先の既定は データディレクトリ/ホスト名.log です(log_output=FILE の場合)。
-- 出力先を決めてから有効化(再起動不要)
SET GLOBAL general_log_file = '/var/log/mysql/general.log';
SET GLOBAL general_log = ON;
-- 調べ終わったら必ず止める
SET GLOBAL general_log = OFF;
有効にした状態で SELECT と UPDATE を1本ずつ流すと、ファイルには次のように残りました。クライアントが接続直後に自動で送る select @@version_comment limit 1 まで記録されている点が、遅いSQLだけを残すスロークエリログとの違いです。
2026-10-20T22:08:32.006552Z 48 Connect root@localhost on shop using Socket
2026-10-20T22:08:32.006853Z 48 Query select @@version_comment limit 1
2026-10-20T22:08:32.007157Z 48 Query SELECT id FROM orders WHERE id=5
2026-10-20T22:08:32.007546Z 48 Query UPDATE orders SET amount=10 WHERE id=5
2026-10-20T22:08:32.009599Z 48 Quit
全SQLを書き出すぶん負荷とファイル容量が大きく、後述の実測では処理時間が約2.4倍になりました。本番で使うなら数分から数十分に区切り、終わったらOFFに戻します。
ログファイルの保存場所と確認用変数
どのログがどこに出ているかは、変数を見れば分かります。パスを指定していなければ、スロークエリログは ホスト名-slow.log、一般クエリログは ホスト名.log としてデータディレクトリに作られます。
SHOW VARIABLES WHERE Variable_name IN
('datadir', 'log_output', 'slow_query_log_file', 'general_log_file', 'log_error');
log_output が TABLE になっている環境(Amazon RDS for MySQLの既定)では、ファイルではなく mysql.slow_log・mysql.general_log テーブルに書かれます。ファイルを探しても見つからないときは、まずこの値を確認してください。
スロークエリログを有効にする設定
ここでは、再起動なしで効く SET GLOBAL と、再起動後も残る my.cnf の2通りを紹介します。MySQL 8.4では、SQLで設定を永続化する SET PERSIST も利用できます。試すときは前者、本番運用では両方を合わせて設定します。
SET GLOBALによる一時的な有効化
SET GLOBAL slow_query_log_file = '/var/log/mysql/slow.log';
SET GLOBAL long_query_time = 1;
SET GLOBAL slow_query_log = ON;
-- 確認は「新しい接続」で行う
SHOW VARIABLES LIKE 'slow_query%';
SELECT @@GLOBAL.long_query_time, @@SESSION.long_query_time;
ここでつまずきやすいのが、long_query_time はセッションごとに値を持つ点です。同じ接続で SET GLOBAL long_query_time=1 を実行した直後に値を読むと、@@GLOBAL は1.000000、@@SESSION は10.000000のままでした。続けて1.4秒かかるSELECTを流しても記録されず、新しい接続で同じSELECTを流すと記録されました。アプリのコネクションプールは張りっぱなしなので、プール内の既存接続には反映されないと考えて、確認は新しい接続で行います。
my.cnfによる有効化設定の永続化
再起動後も残すには、/etc/my.cnf や /etc/mysql/my.cnf(ディストリビューションで異なります)の [mysqld] セクションに書き、MySQLを再起動します。
[mysqld]
slow_query_log = ON
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
# 追加項目(読み取り回数・ソート・一時テーブル)も出す
log_slow_extra = ON
出力先のディレクトリにMySQLの実行ユーザーが書き込めないと、有効化してもファイルが作られません。エラーログに出力先を開けなかった旨が出ていないかも合わせて確認します。
スロークエリログの主要パラメータと既定値
既定値は8.4.8で読んだ値で、MySQL 8.4のシステム変数一覧の記載と一致します。
| 変数 | 意味 | 既定値 |
|---|---|---|
| slow_query_log | スロークエリログの有効化 | OFF |
| long_query_time | 遅いと判定する秒数(マイクロ秒精度) | 10 |
| slow_query_log_file | 出力ファイル | ホスト名-slow.log |
| log_output | 出力先(FILE・TABLE・NONE) | FILE |
| log_slow_extra | 追加項目をファイルに出す | OFF |
| min_examined_row_limit | 読んだ行数の下限 | 0 |
| log_queries_not_using_indexes | 無索引のSQLも記録 | OFF |
| log_throttle_queries_not_using_indexes | 無索引SQLの1分あたり記録上限 | 0(無制限) |
| log_slow_admin_statements | ALTER TABLE等の管理文も記録 | OFF |
| log_slow_replica_statements | レプリカで適用した文も記録 | OFF |
log_queries_not_using_indexes は単独でONにしないでください。3行しかないテーブルの無索引SELECT(0.000273秒)まで記録され、直すべきSQLが埋もれました。使うなら min_examined_row_limit を合わせて設定します。100にすると、この3行のテーブルへのSELECTは記録されなくなりました。log_throttle_queries_not_using_indexes で1分あたりの件数に上限を付ける方法もあります。
mysql.slow_logへのテーブル出力
log_output='TABLE' にすると、ログは mysql.slow_log(CSVエンジン)に入り、SQLで絞り込めます(ログ出力先の選択)。
SET GLOBAL log_output = 'TABLE';
SELECT start_time, query_time, rows_sent, rows_examined, LEFT(sql_text, 60)
FROM mysql.slow_log
ORDER BY query_time DESC
LIMIT 10;
実測では、start_time がサーバーのタイムゾーン(この環境はJST)の時刻で入り、ファイル出力の # Time(既定 log_timestamps=UTC)とは9時間ずれました。セッションの time_zone を +00:00 に変えて読み直しても、表示される値は変わりませんでした。また log_slow_extra の追加項目はテーブル出力には入りません。pt-query-digestで集計するならファイル出力のほうが向いています。
スロークエリログの見方|出力項目とRows_examined
次は、customer_id にインデックスの無い200万行の orders テーブルを検索したときに、8.4.8が実際に書き出した1件です。
# Time: 2026-10-20T22:07:04.050202Z
# User@Host: root[root] @ localhost [] Id: 12
# Query_time: 1.431912 Lock_time: 0.000003 Rows_sent: 40 Rows_examined: 2000000
use shop;
SET timestamp=1792534022;
SELECT * FROM orders WHERE customer_id=42;
スロークエリログの基本4項目と時刻の意味
| 項目 | 意味 | 上の例 |
|---|---|---|
| Query_time | 実行時間(秒) | 1.431912 |
| Lock_time | ロック取得にかかった時間(秒) | 0.000003 |
| Rows_sent | クライアントに返した行数 | 40 |
| Rows_examined | サーバー内で読んだ行数 | 2,000,000 |
最初に見るのは Rows_sent と Rows_examined の比です。この例は40行を返すために200万行を読んでいて、5万倍の差があります。インデックスが使えずに全行を読んでいる典型で、改善の効果が最も出やすいSQLです。逆に、Rows_examined が小さいのに Query_time が大きい場合は、ロック待ちか、ソートや一時テーブルの重さを疑います。
時刻は2か所にあります。SET timestamp=1792534022 は文の実行開始時刻(UTCで22:07:02)、# Time はログに書いた時刻(22:07:04.05)です。マニュアルによると、SET timestamp が開始時刻を表すのは8.0.14からで、それより前は記録した時刻でした。古いサーバーのログと並べて時系列を追うときは、実行時間のぶん(この例なら約1.4秒)ずれます。
log_slow_extraで増える20項目
8.0.14で追加された log_slow_extra をONにすると、Query_timeなどを記録する行に20項目が増えます(8.0.14のリリースノート)。status ごとに集計してソートするSQLで採取した例です。
# Query_time: 2.089549 Lock_time: 0.000002 Rows_sent: 5 Rows_examined: 2000005 Thread_id: 14 Errno: 0 Killed: 0 Bytes_received: 115 Bytes_sent: 201 Read_first: 1 Read_last: 0 Read_key: 500001 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 2012502 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 5 Sort_scan_count: 1 Created_tmp_disk_tables: 0 Created_tmp_tables: 1 Start: 2026-10-20T22:07:11.065480Z End: 2026-10-20T22:07:13.155029Z
原因の切り分けに使うのは次の項目です。Read_rnd_next が大きい(ここでは約201万)なら全行走査、Created_tmp_disk_tables が1以上なら、内部一時テーブルがディスク上に作成されています。最初からディスク上に作る場合もあるため、メモリからあふれたとは限りません。Sort_merge_passes が増えていればソート用のメモリが足りません。Errno と Killed は、タイムアウトや KILL で中断されたSQLを見分けるのに使えます。
Lock_timeに出るロック待ちと出ないロック待ち
Lock_time が小さいからロック待ちではない、とは言えません。手元で2種類の待ちを3秒ずつ発生させ、long_query_time=1 で記録された値を比べました。
| 待たせ方 | 待った文 | Query_time | Lock_time |
|---|---|---|---|
| 別の接続が SELECT … FOR UPDATE で行を保持 | UPDATE(同じ行) | 2.499019 | 2.495584 |
| 別の接続が LOCK TABLES … WRITE で保持 | SELECT | 2.643357 | 0.000002 |
行ロックの待ちは Lock_time に入りました。8.0.28のリリースノートには、Performance Schemaの LOCK_TIME が行ロックの待ちを数えず小さく出ていた不具合を直し、テーブルと行のロックで待った時間をすべて数えて、スロークエリログと同じ値を出すようにしたとあります。8.0.27以前でPerformance SchemaのLOCK_TIMEとスロークエリログのLock_timeを照合する場合は、両者の値が一致しない可能性に注意します。
一方、LOCK TABLES による待ちは Query_time にだけ現れ、Lock_time はほぼ0でした。Lock_time が小さく、Rows_examined も小さいのに Query_time だけ大きいSQLは、DDLやバックアップのテーブルロックで待たされた可能性があります。同じ時刻の他の文(とくに管理文)を並べて確認します。
なお、マニュアルには「初期ロックの取得時間は実行時間に数えない」とありますが、上のとおり8.4.8では行ロックで2.5秒待ったUPDATE(実際の更新は数ミリ秒)が、しきい値1秒で記録されました。ロック待ちが長いSQLは、実処理が速くてもスロークエリログに出ると考えておくほうが実態に合います。
スロークエリログの解析|mysqldumpslowとpt-query-digest
ログが数百件を超えたら、1件ずつ読まずに集計します。同じ形のSQL(値だけ違うもの)をまとめ、合計時間の長い順に並べるのが基本です。
mysqldumpslowによるSQLの合計時間順集計
mysqldumpslowはMySQLに同梱されています。顧客IDだけ違うSELECTを3本、ステータスだけ違う集計を2本、GROUP BYを1本流したログを集計した結果です。
$ mysqldumpslow -s t -t 3 /var/log/mysql/slow.log
Count: 2 Time=2.29s (4s) Lock=0.00s (0s) Rows=1.0 (2), root[root]@localhost
SELECT COUNT(*) FROM orders WHERE status='S' AND amount > N
Count: 3 Time=1.43s (4s) Lock=0.00s (0s) Rows=40.0 (120), root[root]@localhost
SELECT * FROM orders WHERE customer_id=N
Count: 1 Time=3.31s (3s) Lock=0.00s (0s) Rows=3.0 (3), root[root]@localhost
SELECT customer_id, SUM(amount) FROM orders GROUP BY customer_id ORDER BY N DESC LIMIT N
数値は N、文字列は 'S' に置き換えられ、値違いのSQLが1行にまとまります。Time= は平均、括弧内は合計ですが、既定ではQuery_timeからLock_timeを差し引いて集計します。ロック待ちを含むQuery_timeで比較する場合は -l を追加します。主なオプションは次のとおりで、-s を省くと平均時間順(at)になります(mysqldumpslowのマニュアル)。
| オプション | 意味 |
|---|---|
| -s t | 合計時間順(改善の優先度を決めるときの基本) |
| -s c | 実行回数順 |
| -s at | 平均時間順(既定) |
| -s l / -s r | ロック時間順 / 返した行数順 |
| -t N | 上位N件だけ表示 |
| -g パターン | パターンに一致するSQLだけ集計 |
| -a | 数値・文字列を置き換えない |
弱点は、Rows_examined を集計しないことです。上の出力でも、200万行を読んだことは分かりません。行数の比で優先度を決めたいときは、次のpt-query-digestを使います。
pt-query-digestによる実行時間と読み取り行数の集計
pt-query-digestはPercona Toolkitに含まれるPerlのツールで、本記事の実測に使用した版は3.7.1です(pt-query-digestのドキュメント)。同じ形のログ(7件)を集計すると、先頭に次の順位表が出ます。
$ pt-query-digest --limit 3 /var/log/mysql/slow.log
# Overall: 7 total, 3 unique, 0.58 QPS, 1.13x concurrency
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== =================================== ============= ===== ====== ====
# 1 0x34F6C229F95D6D36BB5A03CD51261D1C 5.8103 42.9% 4 1.4526 0.00 SELECT orders
# 2 0x49877BD033D07F21C61288FE0CCC4619 4.5121 33.3% 2 2.2560 0.00 SELECT orders
# 3 0x2298036ACA13A296218738C1FD1EB287 3.2322 23.8% 1 3.2322 0.00 SELECT orders
続く各SQLの詳細に、Rows examine の合計・最小・最大・95パーセンタイルと実行時間の分布が出ます。log_slow_extra の項目(Read rnd next など)も集計されます。1つ注意があり、200万行は 1.91M と表示されました。1,048,576を1Mとする単位なので、件数を報告書に転記するときは換算します。
mysqldumpslowとpt-query-digestの選択基準
Perlが利用でき、Percona Toolkitを追加せずにまず当たりを付けたい場合は、mysqldumpslowで集計できます。Perlを利用できないサーバーでは、ログを解析用の別環境へ移して処理します。改善の前後で比べる、Rows_examined の比で優先度を付ける、週次で同じ集計を回す、のどれかに当てはまるならpt-query-digestを使います。ログをためて集計するのではなく常時グラフで見たい場合は、Datadog Database Monitoringの実装手順のように、監視サービスの収集機能に任せる方法もあります。
遅いSQLの改善|EXPLAINによる診断とインデックス追加
集計で上位に来たSQLは、EXPLAIN で実行計画を見ます。先ほどの customer_id=42 の検索では、次のように全行走査になっていました。
EXPLAIN SELECT * FROM orders WHERE customer_id = 42\G
-- type: ALL
-- key: NULL
-- rows: 1994949
-- Extra: Using where
ALTER TABLE orders ADD INDEX idx_customer (customer_id);
EXPLAIN SELECT * FROM orders WHERE customer_id = 42\G
-- type: ref
-- key: idx_customer
-- rows: 40
type: ALL と key: NULL の組み合わせが全行走査のしるしです。インデックスを追加した後に同じSQLを流すと、スロークエリログ上で次のように変わりました。
| Query_time | Rows_examined | |
|---|---|---|
| インデックスなし | 1.431912秒 | 2,000,000 |
| インデックスあり | 0.000521秒 | 40 |
改善後の確認には、その接続だけ SET SESSION long_query_time=0 にして同じSQLを流すと、速くなった後の数字もログに残せます。インデックスを足しても効かない場合は、列に関数をかけている(WHERE DATE(created_at)=...)、先頭が % のLIKE、選択性の低い列(値の種類が少ない列)といった原因を疑います。どの列にインデックスを張るかの判断はカーディナリティとインデックス設計の記事で詳しく扱っています。
SQLを直してもディスク読み取りが多いままなら、メモリ上で処理できている割合をバッファヒット率で確認します。テーブル設計やインデックスの見直しが広範囲に及ぶ場合は、データベース設計・移行支援で既存DBの診断から相談できます。
本番で常時有効にしてよいか|オーバーヘッドの実測
主キーで1行を引くSELECTを、8並列で8万回流すのにかかった時間を、ログ設定ごとに比べました。この試験には1秒を超えるSQLが無く、しきい値1秒の行は「有効にしているが書き込みは発生しない」状態の負荷です(MySQL 8.4.8 Community・macOS Intel・ローカルのSSD・mysqlslapで3回の平均を2回測定)。
| 設定 | 1回目 | 2回目 | 全OFF比 |
|---|---|---|---|
| ログすべてOFF | 2.742秒 | 2.635秒 | 1.00 |
| スロークエリログON(1秒) | 2.786秒 | 2.752秒 | 約1.03 |
| スロークエリログON(0秒) | 6.014秒 | 6.803秒 | 約2.4 |
| 一般クエリログON | 6.688秒 | 6.516秒 | 約2.5 |
しきい値1秒ではどのSQLも記録されず、2回の平均で全OFF比約3%の増加でした。記録対象のSQLが多ければ、しきい値1秒でもその件数ぶんの書き込み負荷がかかります。全SQLを書く設定では、long_query_time=0 は48万件で110MB(1件あたり約230バイト)、一般クエリログは39MB(約80バイト)のファイルになりました。
有効にしておくこと自体の負荷は小さく、負荷を決めるのは記録される件数です。常時有効にしたら、1日の記録件数・ディスクの書き込み量・応答時間を確認して、しきい値を決めます。運用の目安は次のとおりです。
- 本番の常時設定は
long_query_time=1から始め、1日の件数が多すぎれば2〜3秒、ほとんど出なければ0.5秒に動かします。 long_query_time=0は「全SQLを棚卸ししたい」ときに、時間を区切って使います。採取後はすぐ元に戻し、pt-query-digestで集計します。- 数十ミリ秒のSQLが大量に積み重なって遅い問題は、1秒だけでなく0.1秒のしきい値でも取りこぼします。この場合は対象SQLより低いしきい値で短時間採取するか、Performance Schemaの文ダイジェスト統計で実行回数と合計時間を調べます。
版・環境による違い|MySQL 8.4以降・RDS・MariaDB
MySQLの版による違い
MySQL 8.0は2026年4月の8.0.46で終了(EOL)しました(8.0のリリースノート)。現在の長期サポート版は8.4と9.7で、2026年10月20日に8.4.13と9.7.4が出ています。9.7の次からは版番号が「年.月.パッチ」になり、26.10.0が公開されています。8.0から上げるときの非互換はMySQL 5.7と8.0の違いの記事で、8.4・9.7への移行と合わせて実測しています。
スロークエリログに関する版の境目は次の3つです。8.4以降は、ここまでの設定と出力がそのまま使えます。
| 版 | 変更 |
|---|---|
| 8.0.14 | log_slow_extra追加・SET timestampが開始時刻に |
| 8.0.19 | SIGUSR1でスロークエリログを開き直せる |
| 8.0.28 | Lock_timeの数え方をPerformance Schemaと統一 |
Amazon RDS・Auroraのパラメータグループ設定
マネージドサービスでは SET GLOBAL ではなく、パラメータグループで設定します。AWSのドキュメントによると、RDS for MySQLは slow_query_log の既定が0、log_output の既定が TABLE です。そのままではファイルではなく mysql.slow_log テーブルに入ります。
CloudWatch Logsで見たい場合は、カスタムパラメータグループで slow_query_log=1 と log_output=FILE を設定し、インスタンスの「ログのエクスポート」でスロークエリログを選びます(CloudWatch Logsへの発行)。Aurora MySQLのバージョン2と3は log_output の既定が FILE で、設定はDBクラスターのパラメータグループに書きます。Aurora固有の版の確認方法はAurora MySQLの実装ガイドにまとめています。
MariaDBの変数名と間引き設定
MariaDBでも同じ考え方で使えますが、10.11.0から有効化の変数名が log_slow_query になり、slow_query_log は別名として残っています(MariaDBのシステム変数)。MySQLにない設定として、log_slow_rate_limit(20にすると20件に1件だけ記録)と、実行計画などを一緒に出す log_slow_verbosity があります。しきい値を下げたいが件数が多すぎる、という場面では log_slow_rate_limit が使えます。両者の差分全体はMariaDBとMySQLの違いの記事で扱っています。
ログローテーションと保存期間
スロークエリログは追記され続けるので、放置すると大きくなり続けます。切り替えの手順で注意するのは順序です。手元でファイルを slow.log.1 にリネームしただけでは、MySQLは開いたままのリネーム後のファイルに書き続けました。FLUSH SLOW LOGS を実行した時点で、元の名前の slow.log が新しく作られました(サーバーログのメンテナンス)。
# 1. リネーム 2. 開き直し(slowだけを対象にできる)
mv /var/log/mysql/slow.log /var/log/mysql/slow.log.1
mysqladmin flush-logs slow
logrotateで回すなら、postrotateで同じ開き直しを実行します。実行ユーザーが接続できるクライアント設定と、ログをフラッシュするためのRELOAD権限を用意し、MySQLの実行ユーザーが出力先に新しいファイルを作成できることも確認します。FLUSH LOGS はバイナリログやエラーログも一緒に切り替えるので、スロークエリログだけを回すなら FLUSH SLOW LOGS か mysqladmin flush-logs slow を使います。
/var/log/mysql/slow.log {
daily
rotate 14
missingok
notifempty
compress
delaycompress
postrotate
mysqladmin flush-logs slow
endscript
}
保存期間は、性能が落ち始めた時期を後からさかのぼれる長さで決めます。日次で2週間分を圧縮して残す設定が出発点です。8.0.19以降は、mysqldプロセスに SIGUSR1 を送っても開き直せます。
よくある質問
スロークエリとは何ですか?
実行に時間のかかる遅いSQLのことです。MySQLでは long_query_time(既定10秒)を超えたSQLが遅いと判定され、スロークエリログに記録されます。スロークエリは「遅いSQL」、スロークエリログは「その記録」です。
long_query_timeは何秒にすべきですか?
本番は1秒から始め、1日の件数を見て0.5〜3秒で調整します。既定の10秒では、ユーザーが遅いと感じるSQLの多くを取りこぼします。全SQLを棚卸ししたいときだけ短時間0秒にし、終わったら戻します。
スロークエリログのファイルはどこにありますか?
SHOW VARIABLES LIKE 'slow_query_log_file'; で確認できます。指定していなければ、データディレクトリの ホスト名-slow.log です。log_output が TABLE の場合(RDS for MySQLの既定)は、ファイルではなく mysql.slow_log テーブルに入ります。
設定したのにスロークエリログが出力されないのはなぜですか?
多い原因は3つです。SET GLOBAL の変更が既存の接続に効いていない、出力先のディレクトリにMySQLが書き込めない、対象が ALTER TABLE などの管理文で log_slow_admin_statements がOFF、のいずれかです。新しい接続で SET SESSION long_query_time=1; と SET SESSION min_examined_row_limit=0; を実行してから SELECT SLEEP(2); を流すと、しきい値と行数条件をそろえて記録の有無を確認できます。
MySQLで実行された全SQLを記録するにはどうしますか?
一般クエリログを使います。SET GLOBAL general_log = ON; で有効になり、接続・切断と受け取ったSQLが、log_output=FILE なら general_log_file に、TABLE なら mysql.general_log に書かれます。負荷とファイル容量が大きいので、調査の間だけ有効にしてください。