こんにちは。この記事では、MySQLのパフォーマンスチューニングの前に実施するパフォーマンス測定のうち、スロークエリの特定について紹介します。
MySQLのスロークエリの特定は、データベースのパフォーマンスを向上させるための重要なプロセスです。
パフォーマンスチューニングの概要は以下の記事で紹介しておりますので、ご参考ください。
スロークエリ（遅いクエリ）の特定方法
実行に時間がかかるクエリ（スロークエリ）を特定します。
スロークエリを特定する主な方法は以下の通りです。
スロークエリログの活用
my.cnfまたはMySQLコンソールでスロークエリログを有効にします。
ログに出力する実行時間とスロークエリログのパスは状況に応じて、適切に設定します。
[root@localhost ~]# cat /etc/my.cnf
・・・
slow_query_log = ON
long_query_time = 5 # 5秒以上のクエリをログに記録
slow_query_log_file = /var/log/mysql/mysql-slow.log
[root@localhost ~]#設定反映のため、mysqldサービスを再起動します。
[root@localhost ~]# systemctl restart mysqld
[root@localhost ~]#上記設定で、設定ファイルのslow_query_log_fileで指定した「/var/log/mysql/mysql-slow.log」に5秒以上のクエリログが出力されるようになります。
SHOW FULL PROCESSLISTコマンドの使用
SHOW FULL PROCESSLISTコマンドを利用すると、現在実行中のクエリとその実行時間を確認できます。
基本的なコマンド文法
実行コマンドは以下の通りです。
SHOW FULL PROCESSLIST;出力結果例と見方
実際にコマンド実行した結果は以下の通りです。
この結果から実行時間が遅いクエリや、デッドロックが発生していて問題があるクエリを見つけることができます。
mysql> SHOW FULL PROCESSLIST;
+----+-----------------+-----------+-------------+---------+------+------------------------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-----------------+-----------+-------------+---------+------+------------------------+-----------------------+
| 5 | event_scheduler | localhost | NULL | Daemon | 1685 | Waiting on empty queue | NULL |
| 10 | root | localhost | my_database | Query | 0 | init | SHOW FULL PROCESSLIST |
+----+-----------------+-----------+-------------+---------+------+------------------------+-----------------------+
2 rows in set, 1 warning (0.01 sec)
mysql>各カラムの見方は以下の通りです。
| 列名 | 説明 |
|---|---|
| Id | スレッドの一意の識別子です。各接続に対してユニークなIDが割り当てられます。 |
| User | クエリを実行しているユーザー名です。 |
| Host | 接続元のホスト情報です。通常はIPアドレスやホスト名、ポート番号が含まれます。 |
| db | 現在のクエリが実行されているデータベース名です。 NULLの場合、データベースが選択されていないことを示します。 |
| Command | スレッドが現在実行しているコマンドの種類を示します。 例として、以下のような値が表示されます。 ・Query: SQLクエリが実行中であることを示します。 ・Sleep: スレッドがアイドル状態にあり、新しいリクエストを待機していることを示します。通常、接続が維持されているが、何も実行していない状態です。 ・Connect: 新しい接続が確立されていることを示します。 ・Binlog Dump: バイナリログのダンプ処理中であることを示します。レプリケーションやバックアップに関連する場合があります。 ・Daemon: バックグラウンドプロセス（例：イベントスケジューラ）が実行中であることを示します。 ・Prepare: プリペアードステートメントが準備中であることを示します。 ・Execute: プリペアードステートメントが実行中であることを示します。 ・Close: 接続が閉じられているか、終了処理中であることを示します。 ・Waiting for …: 特定のリソース（例：ロックやI/O）を待機している状態です。この場合、具体的な待機内容がState列に表示されます。 |
| Time | 現在の状態にスレッドが費やした時間（秒単位）です。 |
| State | スレッドの現在の状態を示します。 例として、以下のような値が表示されます。多くのスレッドが「Locked」や「Waiting for lock」状態にある場合は、ロックの競合が発生している可能性があり、対策が必要かもしれません。 ・Waiting for next activation: スケジュールされたイベントの次の実行を待機中。 ・Waiting for table flush: テーブルのフラッシュ操作の完了を待機中。 ・Waiting for global read lock: グローバル読み取りロックの取得を待機中。 ・Sending data: クライアントにデータを送信中。 ・Sorting result: 結果セットのソート中。 ・Copying to tmp table: 一時テーブルにデータをコピー中。 ・Locked: テーブルロックを待機中。 ・Table lock: テーブルロックの取得を待機中。 ・Waiting for lock: ロックの取得を待機中。 ・Connecting: クライアントとの接続を確立中。 ・Executing: クエリを実行中。 ・Updating: データの更新中。 ・Deleting: データの削除中。 ・Inserting: データの挿入中。 ・Sleeping: アイドル状態。新しいリクエストを待機中。 ・Waiting on empty queue: 新しいタスクやリクエストの待機中。 ・init: 初期化中または初期化直後の状態 |
| Info | 実行中または最後に実行されたSQLクエリのテキストです。SHOW PROCESSLISTでは最初の100文字のみが表示されますが、SHOW FULL PROCESSLISTを使用すると全文が表示されます。 |
パフォーマンススキーマの利用
パフォーマンススキーマ(Performance Schema)は、サーバーの内部実行を実行時に監視するためのツールです。
デフォルトで有効になっています。
スロークエリはパフォーマンススキーマ内のテーブル「events_statements_summary_by_digest」を確認します。
mysql> SHOW VARIABLES LIKE 'performance_schema';
+--------------------+-------+
| Variable_name | Value |
+--------------------+-------+
| performance_schema | ON |
+--------------------+-------+
1 row in set (0.04 sec)
mysql>パフォーマンススキーマ内のevents_statements_summary_by_digestテーブルの見方
パフォーマンススキーマ内のevents_statements_summary_by_digestテーブルの各カラムの情報は以下の通りです。
| 列名 | 説明 |
|---|---|
| SCHEMA_NAME | クエリが実行されたデータベース（スキーマ）の名前 |
| DIGEST | クエリのハッシュ値。同じ構造のクエリは同じダイジェスト値を持ちます。 |
| DIGEST_TEXT | 正規化されたクエリテキスト。具体的な値は?や数字に置き換えられています。 |
| COUNT_STAR | このダイジェストに一致するクエリの実行回数 |
| SUM_TIMER_WAIT | このダイジェストに一致するクエリの合計実行時間（ピコ秒単位） |
| MIN_TIMER_WAIT | 最小実行時間（ピコ秒単位） |
| AVG_TIMER_WAIT | 平均実行時間（ピコ秒単位） |
| MAX_TIMER_WAIT | 最大実行時間（ピコ秒単位） |
| SUM_LOCK_TIME | このダイジェストに一致するクエリの合計ロック時間 |
| SUM_ERRORS | エラーの合計数 |
| SUM_WARNINGS | 警告の合計数 |
| SUM_ROWS_AFFECTED | 影響を受けた行の合計数 |
| SUM_ROWS_SENT | クライアントに送信された行の合計数 |
| SUM_ROWS_EXAMINED | 検査された行の合計数 |
| SUM_CREATED_TMP_DISK_TABLES | 成された一時ディスクテーブルの数 |
| SUM_CREATED_TMP_TABLES | 作成された一時テーブルの数 |
| SUM_SELECT_FULL_JOIN | フルジョインの数 |
| SUM_SELECT_FULL_RANGE_JOIN | フルレンジジョインの数 |
| SUM_SELECT_RANGE | 範囲選択の数 |
| SUM_SELECT_RANGE_CHECK | 範囲チェックの数 |
| SUM_SELECT_SCAN | フルテーブルスキャンの数 |
| SUM_SORT_MERGE_PASSES | ソートマージパスの数 |
| SUM_SORT_RANGE | 範囲によるソートの数 |
| SUM_SORT_ROWS | ソートされた行の数 |
| SUM_SORT_SCAN | スキャンによるソートの数 |
| SUM_NO_INDEX_USED | インデックスが使用されなかった回数 |
| SUM_NO_GOOD_INDEX_USED | 適切なインデックスが使用されなかった回数 |
| SUM_CPU_TIME | 特定のダイジェスト（クエリパターン）に一致するすべてのステートメントで消費されたCPU時間の合計 |
| MAX_CONTROLLED_MEMORY | ステートメント（データベースに対して実行される命令や操作のこと。SQLコマンドやクエリ等）実行中に使用された制御されたメモリの最大量 |
| MAX_TOTAL_MEMORY | クエリやイベントの実行中に使用された総メモリの最大値 |
| COUNT_SECONDARY | セカンダリインデックスを使用してクエリが実行された回数 |
| FIRST_SEEN | このダイジェストが最初に見られた時刻 |
| LAST_SEEN | このダイジェストが最後に見られた時刻 |
| QUANTILE_95 | 95パーセンタイルの実行時間 |
| QUANTILE_99 | 99パーセンタイルの実行時間 |
| QUANTILE_999 | 99.9パーセンタイルの実行時間 |
| QUERY_SAMPLE_TEXT | このダイジェストを生成したサンプルSQLステートメント |
| QUERY_SAMPLE_SEEN | サンプルクエリが最後に観測された時刻 |
| QUERY_SAMPLE_TIMER_WAIT | サンプルクエリの実行時間 |
基本的な確認コマンド文法
実行コマンドは以下の通りです。
属性SUM_TIMER_WAIT（クエリの合計実行時間）が遅い順に上位１０クエリ表示するSQL文になります。
SELECT * FROM performance_schema.events_statements_summary_by_digest
ORDER BY SUM_TIMER_WAIT DESC LIMIT 10;出力結果例と見方
実行結果は以下の通りです。
この結果から、実行時間が遅いクエリを特定することができます。
mysql> SELECT * FROM performance_schema.events_statements_summary_by_digest ORDER BY SUM_TIMER_WAIT DESC LIMIT 10;
+-------------+------------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+--------------+-----------------------+------------------+-----------------+----------------------------+----------------------------+-------------+-------------+--------------+------------------------------------------------------------------------------------------------------------+----------------------------+-------------------------+
| SCHEMA_NAME | DIGEST | DIGEST_TEXT | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | SUM_LOCK_TIME | SUM_ERRORS | SUM_WARNINGS | SUM_ROWS_AFFECTED | SUM_ROWS_SENT | SUM_ROWS_EXAMINED | SUM_CREATED_TMP_DISK_TABLES | SUM_CREATED_TMP_TABLES | SUM_SELECT_FULL_JOIN | SUM_SELECT_FULL_RANGE_JOIN | SUM_SELECT_RANGE | SUM_SELECT_RANGE_CHECK | SUM_SELECT_SCAN | SUM_SORT_MERGE_PASSES | SUM_SORT_RANGE | SUM_SORT_ROWS | SUM_SORT_SCAN | SUM_NO_INDEX_USED | SUM_NO_GOOD_INDEX_USED | SUM_CPU_TIME | MAX_CONTROLLED_MEMORY | MAX_TOTAL_MEMORY | COUNT_SECONDARY | FIRST_SEEN | LAST_SEEN | QUANTILE_95 | QUANTILE_99 | QUANTILE_999 | QUERY_SAMPLE_TEXT | QUERY_SAMPLE_SEEN | QUERY_SAMPLE_TIMER_WAIT |
+-------------+------------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+--------------+-----------------------+------------------+-----------------+----------------------------+----------------------------+-------------+-------------+--------------+------------------------------------------------------------------------------------------------------------+----------------------------+-------------------------+
| my_database | 707c2caa9af15b532ad83a4c479124ff89c4327892d176757c5be7493c0c02fe | SELECT * FROM `performance_schema` . `events_statements_summary_by_digest` ORDER BY `SUM_TIMER_WAIT` DESC LIMIT ? | 3 | 142600673000 | 31075119000 | 47533557000 | 70884105000 | 259000000 | 0 | 0 | 0 | 29 | 62 | 0 | 0 | 0 | 0 | 0 | 0 | 3 | 0 | 0 | 29 | 3 | 3 | 0 | 0 | 1088364 | 1444063 | 0 | 2024-09-21 17:28:52.461423 | 2024-09-23 15:35:34.977914 | 72443596007 | 72443596007 | 72443596007 | SELECT * FROM performance_schema.events_statements_summary_by_digest
ORDER BY SUM_TIMER_WAIT DESC LIMIT 10 | 2024-09-23 15:35:34.977914 | 31075119000 |
| my_database | 230e50b71157a47e34c64f86d958d304e42cc8bad0d5a345f7f60672da38222c | SHOW VARIABLES LIKE ? | 1 | 34127183000 | 34127183000 | 34127183000 | 34127183000 | 245000000 | 0 | 0 | 0 | 1 | 1 | 0 | 1 | 0 | 0 | 0 | 0 | 2 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 1115360 | 1403884 | 0 | 2024-09-21 17:29:51.058671 | 2024-09-21 17:29:51.058671 | 34673685045 | 34673685045 | 34673685045 | SHOW VARIABLES LIKE 'performance_schema' | 2024-09-21 17:29:51.058671 | 34127183000 |
| my_database | edd434aaef4e700d07f0b7980a61b104e100c1d93e850fc260af98cc34a9b7a8 | DESC `performance_schema` . `events_statements_summary_by_digest` | 2 | 30943265000 | 12034782000 | 15471632000 | 18908483000 | 358000000 | 0 | 0 | 0 | 78 | 318 | 0 | 2 | 0 | 0 | 0 | 0 | 2 | 0 | 0 | 78 | 2 | 0 | 0 | 0 | 1465424 | 1854259 | 0 | 2024-09-21 17:45:16.697705 | 2024-09-23 15:36:02.906296 | 19054607179 | 19054607179 | 19054607179 | DESC performance_schema.events_statements_summary_by_digest | 2024-09-23 15:36:02.906296 | 12034782000 |
| my_database | dbea8921b559b8cdd4976d57d70304daa8a242fbbfe6df94427006b54ead6b0f | SHOW SCHEMAS | 2 | 16011466000 | 7272477000 | 8005733000 | 8738989000 | 79000000 | 0 | 0 | 0 | 10 | 42 | 0 | 0 | 2 | 0 | 0 | 0 | 2 | 0 | 0 | 10 | 2 | 2 | 0 | 0 | 466104 | 726908 | 0 | 2024-09-21 17:26:39.189486 | 2024-09-21 17:27:56.203239 | 9120108393 | 9120108393 | 9120108393 | show databases | 2024-09-21 17:27:56.203239 | 8738989000 |
| my_database | e62d62e35ba1f4d81917462b3b410343261389b64a6f745a024427b4a19da4f5 | SELECT * FROM `performance_schema` | 1 | 5837465000 | 5837465000 | 5837465000 | 5837465000 | 9000000 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 18480 | 245575 | 0 | 2024-09-21 17:28:00.275326 | 2024-09-21 17:28:00.275326 | 6025595860 | 6025595860 | 6025595860 | SELECT * FROM performance_schema | 2024-09-21 17:28:00.275326 | 5837465000 |
| my_database | 4e6d867fdbd51a357d4d16a9acef1f23299ffa6f12156a3bc6a56c1d1be71e0a | SELECT * FROM `students` LIMIT ? | 2 | 5492138000 | 837483000 | 2746069000 | 4654655000 | 17000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 39296 | 521928 | 0 | 2024-09-21 17:26:39.197198 | 2024-09-21 17:27:56.207887 | 4786300923 | 4786300923 | 4786300923 | SELECT * FROM `students` LIMIT 0 | 2024-09-21 17:27:56.207887 | 837483000 |
| my_database | f5f9379fdd2f199049426ccb51bcabedfca9117cc96c58f51b155f7f2390450f | SHOW TABLES | 2 | 5345183000 | 2290412000 | 2672591000 | 3054771000 | 16000000 | 0 | 0 | 0 | 6 | 22 | 0 | 0 | 0 | 0 | 0 | 0 | 2 | 0 | 0 | 6 | 2 | 0 | 0 | 0 | 647288 | 1001883 | 0 | 2024-09-21 17:26:39.192204 | 2024-09-21 17:27:56.206640 | 3162277660 | 3162277660 | 3162277660 | show tables | 2024-09-21 17:27:56.206640 | 3054771000 |
| my_database | 2399742b2122a34c17d357bfadba69225a770eaa4d8a521eb2b3c2133d0ae43d | SELECT * FROM `users` WHERE `birthplace` = ? | 1 | 4868651000 | 4868651000 | 4868651000 | 4868651000 | 11000000 | 0 | 0 | 0 | 7 | 20 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 0 | 0 | 1 | 0 | 0 | 50560 | 574273 | 0 | 2024-09-21 17:26:41.207659 | 2024-09-21 17:26:41.207659 | 5011872336 | 5011872336 | 5011872336 | select * from users where birthplace='tokyo' | 2024-09-21 17:26:41.207659 | 4868651000 |
| my_database | 60bb67f93ca4794b132572dbce9a9e5aeabb44811d90d3ba7a9eb88f63267a56 | SHOW FULL PROCESSLIST | 1 | 3872003000 | 3872003000 | 3872003000 | 3872003000 | 0 | 0 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1056848 | 1412403 | 0 | 2024-09-21 17:54:33.898189 | 2024-09-21 17:54:33.898189 | 3981071705 | 3981071705 | 3981071705 | SHOW FULL PROCESSLIST | 2024-09-21 17:54:33.898189 | 3872003000 |
| NULL | 44e35cee979ba420eb49a8471f852bbe15b403c89742704817dfbaace0d99dbb | SELECT @@`version_comment` LIMIT ? | 2 | 3089604000 | 595363000 | 1544802000 | 2494241000 | 0 | 0 | 0 | 0 | 2 | 2 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 16720 | 65849 | 0 | 2024-09-21 17:26:37.093563 | 2024-09-21 17:27:54.523851 | 2511886431 | 2511886431 | 2511886431 | select @@version_comment limit 1 | 2024-09-21 17:27:54.523851 | 2494241000 |
+-------------+------------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+--------------+-----------------------+------------------+-----------------+----------------------------+----------------------------+-------------+-------------+--------------+------------------------------------------------------------------------------------------------------------+----------------------------+-------------------------+
10 rows in set (0.03 sec)
mysql>まとめ
今回はMySQLのパフォーマンスチューニングの前に実施するパフォーマンス測定のうち、スロークエリの特定方法を紹介しました。
パフォーマンス測定時の参考になれば、幸いです。
以上になります。ありがとうございました。
参考
https://qiita.com/bohebohechan/items/30103a0b79a520e991fa
https://zenn.dev/ohkisuguru/articles/48dff6cf195244
http://mysql.javarou.com/dat/000582.html
https://dev.mysql.com/doc/refman/8.0/ja/show-processlist.html
https://qiita.com/akokubu/items/8395cde296c76f263973
https://gihyo.jp/dev/serial/01/MySQL-tuning-scale/0004
https://dev.mysql.com/doc/refman/8.0/ja/performance-schema.html
https://gontora.hatenadiary.com/entry/2019/03/07/150656
https://updraft.hatenadiary.com/entry/2023/12/18/000000
コメント