稼働中のMySQLに対して、どのようなクエリが発行されているか確認したいことがあると思います。たとえば、対象のMySQLに対してSQLステートメントの傾向を確認したいときや、テスト環境で実行されたSQLステートメントの内容を保持しておきたい場合などです。実行されるすべてのSQLステートメントの取得方法としてはMySQLの機能を使用して取得する方法とパケットをキャプチャーして取得する方法などありますが、今回は以下のMySQLの機能を使用して取得してみます。
一般クエリーログから取得する方法
スロークエリーログから取得する方法
ただし、これらの取得方法を実施する際は負荷が掛かるため、本番環境で実行する場合には注意が必要です。
検証環境
今回のMySQLのバージョンは5.7.13
をyumを使用してインストールしたものを使用します。サーバのホスト名はtest-host
です。
一般クエリーログから取得する方法
一般クエリーログはクライアントから受け取ったSQLステートメントをすべてログに出力します。設定方法はパラメータgeneral_log
を1またはONで有効、0またはOFFで無効になります。パラメータgeneral_log
は、稼働中のMySQLに対してオンラインで変更可能です。デフォルトではOFFになっています。
mysql> show variables like 'general_log';
+------------------+---------------------------------+
| Variable_name | Value |
+------------------+---------------------------------+
| general_log | OFF |
+------------------+---------------------------------+
SET GLOBAL general_log=ON;
で一般クエリーログを有効化します。
mysql> SET GLOBAL general_log=ON;
Query OK, 0 rows affected (0.00 sec)
一般クエリーログはON
にしたタイミングで現在接続中のセッションを含めてすべてのセッションに対して有効となります。
一般クエリーログファイルに以下のような形でステートメントが記述されます。デフォルトのファイル名はHOSTNAME.log
となります。ファイル名を変更する場合はオンラインで変更可能なパラメータgeneral_log_file
を変更してください。
# vi /var/lib/mysql/test-host.log
Time Id Command Argument
2016-08-19T09:44:02.578750Z 12 Query select 1
2016-08-19T09:44:08.571657Z 12 Query SELECT count(*) FROM tbl_a
一般クエリーログから取得できる項目は以下となります。
Time … 対象のステートメントが実行された時間
Id … 接続識別子(SHOW PROCESSLIST
で表示されるid列)
Command … 対象のステートメントのコマンドタイプ
Argument … 実行されたステートメント
そして、一定期間SQLワークロードを取得してからパラメータgeneral_log
の値をOFF
へ戻します。
mysql> SET GLOBAL general_log=OFF;
Query OK, 0 rows affected (0.00 sec)
こうすることで、一時的にMySQLに実行されるすべてのステートメントを出力することができます。
スロークエリーログから取得する方法
スロークエリーログの内容や設定方法は第7回 スロークエリーログを使って遅いクエリを収集する を参照してください。
一般的にスロークエリーログはパラメータlong_query_time
に指定した秒数よりも処理に時間がかかるクエリを抽出して、チューニングをするために使用されます。
スロークエリーログから実行されるすべてSQLステートメントを取得するためには、以下の変更が必要です。
パラメータlong_query_time
の値を0
に変更します。値を0
にすることで0秒以上 経過したSQLステートメントが出力されるようになります。
パラメータlog_slow_admin_statements
を1
に変更します。デフォルト設定の0
では管理ステートメント(ALTER TABLE、ANALYZE TABLE、CHECK TABLE、CREATE INDEX、DROP INDEX、OPTIMIZE TABLE、および REPAIR TABLE)が含まれないためです。
また、いくつかのパラメータで出力するSQLステートメントの抑制も可能です。詳しくはMySQLドキュメントの5.2.5 スロークエリーログ をご参照ください。
パラメータlong_query_time
とパラメータlog_slow_admin_statements
は稼働中のMySQLに対してオンラインで変更可能です。
mysql> SET GLOBAL long_query_time=0;
Query OK, 0 rows affected (0.00 sec)
mysql> SET GLOBAL log_slow_admin_statements=1;
Query OK, 0 rows affected (0.00 sec)
ここで注意として、SET GLOBAL long_query_time=0;
を実行したタイミングで現在接続中のセッションについてはこの変更は適用されません。設定した以降に接続されたセッションから有効となります。よって、コネクションプーリング機構を使用しているアプリケーションでは一度セッションの再接続が必要となります。
セッションを再接続することで、値が変更されていることが確認できます。
mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 0.000000 |
+-----------------+----------+
1 row in set (0.01 sec)
スロークエリーログファイルに以下のような形でステートメントが記述されます。デフォルトのファイル名はHOSTNAME-slow.log
となっています。ファイル名を変更する場合は、オンラインで変更可能なパラメータslow_query_log_file
を変更してください。
# vi /var/lib/mysql/test-host-slow.log
# Time: 2016-08-19T09:48:29.216211Z
# User@Host: root[root] @ localhost [] Id: 15
# Query_time: 0.000112 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0
SET timestamp=1471600109;
SELECT 1;
# Time: 2016-08-19T09:48:37.049002Z
# User@Host: root[root] @ localhost [] Id: 15
# Query_time: 0.000073 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0
SET timestamp=1471600117;
SELECT count(*) FROM tbl_a;
そして、一定期間SQLワークロードを取得してからパラメータlong_query_time
の値を元の値へ戻します。
mysql> SET GLOBAL long_query_time=10;
Query OK, 0 rows affected (0.00 sec)
このようにすることで、一時的にMySQLに実行されるすべてのステートメントを出力することができます。
まとめ
今回はスロークエリーログと一般クエリーログを使用して稼動中のMySQLに対して実行されるすべてのSQLステートメントを出力する方法をご紹介しました。
実行されたホストや処理にかかった実行時間などの付加情報が必要な場合はスロークエリーログを使用したり、単純にSQLステートメントのみを取得したい場合は一般クエリーログを使用するなど使い分けることができます。また、筆者はこれらをMySQLのアップグレード前によく使用します。たとえば、本番環境から一定の期間のSQLワークロードを取得し、アップグレード前とアップグレード後のMySQLに対してクエリを実行してSQLの実行計画の変化を確認します。そして、SQLの性能劣化が見られた場合は本番環境をアップグレードする前に事前にSQLを書き換えるなどの対応ができます。