RDS MySQLでSQL文を取得する
本記事では、AWS Relational Database Service (RDS)上でMySQLを利用する際に、SQL文を取得するためにMySQLが標準で備えている機能をひととおり紹介します。SQL文を把握することは、アプリケーションの利用状況や負荷、パフォーマンスへの影響、データベースの設定に起因するボトルネックを理解するうえで欠かせない、設計・運用上の重要なポイントです。
本記事の目的は、SQL文の情報を「取得」する方法を整理することです。SQL文と合わせて取得できるその他の補足情報、たとえばクエリ実行計画(QEP)、テーブル構造、インデックスのカーディナリティ、オプティマイザーの設定や統計情報などは扱いません。これらは別の記事で取り上げる予定です。
SQL文の収集方法
MySQLには、実行中または実行済みのSQL文を収集する手段が複数用意されています。どれか1つだけが万能というわけではなく、システムを詳細に観測し、SQL文をより深く分析するには、複数の手段を組み合わせて十分な情報を集める必要があります。利用できる主な方法は次のとおりです。同じ情報を取得するために複数のやり方が用意されているケースもあります。
- Processlist
- Performance Schema
- Sys Schema
- スロークエリログ
- 一般クエリログ
- バイナリログ
特に断りがない限り、以下の出力例ではコマンドラインクライアントのmysqlを使用しています。
注: 本記事のSQL例はMySQL 5.7とMySQL 8.0の両方で動作します。MySQL 5.7コミュニティ版のEOL(サポート終了)、およびAWS RDS MySQL 5.7のEOLが近づいていることから、すべての出力例とドキュメント参照は現行のMySQL 8.0をベースにしています。掲載している出力の一部は、MySQL 5.7で得られる結果と異なる場合があります。
1\. MySQL processlistでSQLを確認する
MySQLのprocesslistは、現在実行中のSQL文を表示します。表示されるのは、processlist文を実行した時点で動いているSQL文です。長時間動作するクエリであれば、SQL文を見つけるのに有効な方法です。一方、高頻度かつ低レイテンシのSQL文をprocesslistで捉えるのはかなり困難です。実行中のSQL文に加えて、接続元のユーザーとホスト、使用中のデータベーススキーマ、実行時間(秒)、クエリ内部の現在のステートなども確認できます。
MySQLのprocesslist出力は、次の方法で取得できます。
- performance schema
- sys schema
- information schema
- SHOWステートメント
- mysqladminコマンド
得られる列が同じであれば、上記のどれを選んでも特に優劣はありません。一部は古いバージョンのMySQLでは利用できず、ISO SQL文として有効な業界標準に沿うかたちで後から追加されています(SHOWはこの標準には含まれません)。mysqladminコマンドはさまざまな管理オプションを備えており、例で示すように複数の出力を組み合わせて取得できます。
Performance Schema経由のProcesslist
有効化されている場合、performance_schemaのthreadsテーブルおよびprocesslistテーブルからこの情報を取得できます。
mysql> SELECT * FROM performance_schema.processlist;
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 5 | event_scheduler | localhost | NULL | Daemon | 456 | Waiting on empty queue | NULL |
| 9 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 11 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 19 | rdsadmin | localhost | NULL | Sleep | 3 | | NULL |
| 23 | rdsadmin | localhost | NULL | Sleep | 65 | | NULL |
| 263 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 404 | dba | 172.31.16.14:43464 | airport | Query | 0 | executing | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 406 | dba | 172.31.16.14:43484 | airport | Query | 0 | executing | SELECT * FROM performance_schema.processlist |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
- 詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
Sys Schema経由のProcesslist
sys schemaのprocesslistビューとsessionビューからは、SQL文に加えて関連する補助情報も参照できます。これらのビューはperformance schemaの上に構築されているため、sys schema経由でSQLを取得するにはperformance schemaを有効にしておく必要があります。これらのビューでは、SQL文に紐づく追加のメタデータ属性も得られます。以下はsys.x$processlistビューを使った例です。
mysql> SELECT * FROM sys.x$processlist WHERE command = 'Query'\G
*************************** 1. row ***************************
thd_id: 675
conn_id: 650
user: [email protected]
db: airport
command: Query
state: executing
time: 0
current_statement: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
statement_latency: 116727428000
progress: NULL
lock_latency: 506000000
rows_examined: 0
rows_sent: 0
rows_affected: 0
tmp_tables: 1
tmp_disk_tables: 0
full_scan: YES
last_statement: NULL
last_statement_latency: NULL
current_memory: 165019
last_wait: NULL
last_wait_latency: NULL
source: NULL
trx_latency: 116250140000
trx_state: ACTIVE
trx_autocommit: YES
pid: 15730
program_name: mysql
上記の終端記号を使うと、通常のように列と行で並ぶ横方向のテーブル形式ではなく、1行ごとに「列名: 値」を並べる縦方向の形式で出力されます。ここでは通常のセミコロン「;」の代わりに、SQL文の終端記号「\G」を使用しています。これはmysqlクライアント固有の構文で、サードパーティ製のGUIクライアントでは利用できません。
注: 次のエラーメッセージが表示された場合は、上記のSQL文を実行する前にSET SQL_BIG_SELECTS=1;を実行してかまいません。
ERROR 1104 (42000) at line 1: The SELECT would examine more than
MAX_JOIN_SIZE rows; check your WHERE and use SET SQL_BIG_SELECTS=1
or SET MAX_JOIN_SIZE=# if the SELECT is okay
- 詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
Information Schema経由のProcesslist
Information Schemaは多くのRDBMS製品で事実上の標準として使われていますが、processlistテーブル自体は標準化されたものではありません。MySQLでは次の文で内容を確認できます。
mysql > SELECT * FROM information_schema.processlist;
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | USER | HOST | DB | COMMAND | TIME | STATE | INFO |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 88 | dba | 172.31.16.14:59474 | airport | Query | 0 | executing | SELECT SQL_NO_CACHE a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 9 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 26 | rdsadmin | localhost | NULL | Sleep | 1 | | NULL |
| 11 | rdsadmin | localhost | NULL | Sleep | 0 | | NULL |
| 19 | rdsadmin | localhost | NULL | Sleep | 9 | | NULL |
| 5 | event_scheduler | localhost | NULL | Daemon | 352 | Waiting on empty queue | NULL |
| 94 | dba | 172.31.16.14:59522 | airport | Query | 0 | executing | SELECT * FROM information_schema.processlist |
| 23 | rdsadmin | localhost | NULL | Sleep | 261 | | NULL |
+----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
- 詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
SHOWステートメント経由のProcesslist
バージョン5.1でInformation Schemaが、5.5でPerformance Schemaが導入されるまでは、MySQLでprocesslistを取得する主な手段はSHOWコマンドでした。
mysql> SHOW FULL PROCESSLIST;
この出力は、先ほど示したSELECT * FROM performance_schema.processlist;の結果と同一です。SQL文を切り詰めずに表示するにはFULLキーワードが必要です。
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
_mysqladmin_クライアント経由のProcesslist
各種管理操作に使うMySQLクライアントツールmysqladminからも、実行中のprocesslistを表形式で取得できます。
$ mysqladmin --verbose processlist status
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 5 | event_scheduler | localhost | | Daemon | 1419 | Waiting on empty queue | |
| 9 | rdsadmin | localhost | | Sleep | 1 | | |
| 11 | rdsadmin | localhost | | Sleep | 1 | | |
| 19 | rdsadmin | localhost | | Sleep | 6 | | |
| 23 | rdsadmin | localhost | | Sleep | 128 | | |
| 771 | rdsadmin | localhost | | Sleep | 3 | | |
| 830 | dba | 172.31.16.14:54000 | airport | Query | 0 | executing | SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
| 832 | dba | 172.31.16.14:54026 | | Query | 0 | init | show full processlist |
+-----+-----------------+--------------------+---------+---------+------+------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------+
Uptime: 1421 Threads: 8 Questions: 14058 Slow queries: 1290 Opens: 261 Flush tables: 3 Open tables: 181 Queries per second avg: 9.893
--verboseを指定しないと、短いSQL文でも次のように途中で切り詰められます。
| 786 | dba | 172.31.16.14:59446 | airport | Query | 0 | executing | SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_c |
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
2\. Performance SchemaでSQLを確認する
Performance Schemaが有効で、対応するコンシューマーもオンになっていれば、複数のテーブルから実行中・実行済みのSQL文に関する詳細情報を取得できます。
設定オプション
素のMySQLでは、次のようにperformance schemaを有効化します。
mysql> SET GLOBAL performance_schema=1;
AWS RDSのマネージドサービスでは、パラメータの変更にパラメータグループを使う必要があります。例:
$ modify-parameter ${PG_NAME} performance_schema 1 pending-reboot
注: RDSインスタンスの場合、ここで言うパラメータグループはインスタンスのパラメータグループを指します。インスタンスがAWS RDS Auroraクラスタの一部として動作しているときは、クラスタのパラメータグループがデフォルトで適用され、インスタンスのパラメータグループで上書きされない限りそちらが優先されます。
performance schemaを初めて有効化する際は、MySQLインスタンス、つまりAWS RDSインスタンスの再起動が必要です。
$ aws rds reboot-db-instance --db-instance-identifier ${INSTANCE_ID}
SQL文を取得するためのperformance schemaのコンシューマーやインストルメントはデフォルトで有効になっていますが、稼働中のMySQLインスタンスでも変更できます。現在の設定は次の方法で確認できます。
mysql> SELECT * FROM performance_schema.setup_instruments WHERE NAME LIKE 'statement/%';
mysql> SELECT * FROM performance_schema.setup_consumers WHERE NAME LIKE '%statements%';
設定の確認
次の文で、performance schemaが有効かどうかを確認できます。
mysql> SELECT @@performance_schema;
+----------------------+
| @@performance_schema |
+----------------------+
| 1 |
+----------------------+
Performance Schemaのprocesslistテーブル
すでに紹介したとおり、processlistテーブルからは現在実行中のステートメントの基本情報が得られます。
Performance Schemaのthreadsテーブル
threadsテーブルでは、現在実行中のSQL文について、より多くの属性を確認できます。
mysql> SELECT * FROM performance_schema.threads WHERE PROCESSLIST_STATE="executing"\G
*************************** 1. row ***************************
THREAD_ID: 960
NAME: thread/sql/one_connection
TYPE: FOREGROUND
PROCESSLIST_ID: 935
PROCESSLIST_USER: dba
PROCESSLIST_HOST: 172.31.16.14
PROCESSLIST_DB: airport
PROCESSLIST_COMMAND: Query
PROCESSLIST_TIME: 0
PROCESSLIST_STATE: executing
PROCESSLIST_INFO: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
PARENT_THREAD_ID: NULL
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: SSL/TLS
THREAD_OS_ID: 353
RESOURCE_GROUP: NULL
Performance Schemaのevents_statements_*テーブル
performance schemaの真価は、直前に実行されたSQL文を取得できる点にあり、ごく短時間で完了するSQL文の調査には欠かせない手段です。
mysql> SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'\G
*************************** 1. row ***************************
THREAD_ID: 981
EVENT_ID: 4
END_EVENT_ID: NULL
EVENT_NAME: statement/sql/select
SOURCE: init_net_server_extension.cc:110
TIMER_START: 2471111163284000
TIMER_END: 2471111453481000
TIMER_WAIT: 290197000
LOCK_TIME: 175000000
SQL_TEXT: SELECT * FROM performance_schema.events_statements_current WHERE SQL_TEXT like '%airport%'
DIGEST: 2fdfe28204e80c382a14597873be575ea8c7ede6e4757e77700a333bbe50b025
DIGEST_TEXT: SELECT * FROM `performance_schema` . `events_statements_current` WHERE `SQL_TEXT` LIKE ?
CURRENT_SCHEMA: NULL
OBJECT_TYPE: NULL
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: NULL
MYSQL_ERRNO: 0
RETURNED_SQLSTATE: NULL
MESSAGE_TEXT: NULL
ERRORS: 0
WARNINGS: 0
ROWS_AFFECTED: 0
ROWS_SENT: 0
ROWS_EXAMINED: 0
CREATED_TMP_DISK_TABLES: 0
CREATED_TMP_TABLES: 0
SELECT_FULL_JOIN: 0
SELECT_FULL_RANGE_JOIN: 0
SELECT_RANGE: 0
SELECT_RANGE_CHECK: 0
SELECT_SCAN: 1
SORT_MERGE_PASSES: 0
SORT_RANGE: 0
SORT_ROWS: 0
SORT_SCAN: 0
NO_INDEX_USED: 1
NO_GOOD_INDEX_USED: 0
NESTING_EVENT_ID: NULL
NESTING_EVENT_TYPE: NULL
NESTING_EVENT_LEVEL: 0
STATEMENT_ID: 22413
1 row in set (0.01 sec)
このほか、実行済みSQL文を扱うperformance系テーブルとしてevents_statements_current、events_statements_history、events_statements_longなどがあります。詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
3\. Sys SchemaでSQLを確認する
MySQLのsys schemaは、Performance Schemaのデータをわかりやすく解釈し、利用者にとって扱いやすいビューとして提供する一連のオブジェクトとビューの集合体です。実行済みのSQL文や、その実行回数の集計統計も確認できます。最初に注目したいのは、statement_analysisビュー、もしくはx$statement_analysisビューです。
mysql> select * from sys.x$statement_analysis where query like '%airport%'\G
*************************** 1. row ***************************
query: SELECT `a` . `country_code` , `c` . `name` , COUNT ( * ) AS `cnt` FROM `airport` `a` INNER JOIN `country` `c` USING ( `country_code` ) GROUP BY `country_code` , NAME ORDER BY ? DESC LIMIT ?
db: airport
full_scan: *
exec_count: 8
err_count: 0
warn_count: 0
total_latency: 1330746923000
max_latency: 304276507000
avg_latency: 166343365000
lock_latency: 1937000000
rows_sent: 80
rows_sent_avg: 10
rows_examined: 1223680
rows_examined_avg: 152960
rows_affected: 0
rows_affected_avg: 0
tmp_tables: 8
tmp_disk_tables: 0
rows_sorted: 80
sort_merge_passes: 0
digest: 616aa31e4f99b22a194c91ae9f1cfbfb95d6957621b55393b4a01603d8e1fd47
first_seen: 2023-10-12 14:55:56.021003
last_seen: 2023-10-12 15:23:14.225503
このほかにも、実行済みSQL文や、その一部を集計したsys schemaのテーブルが多数あります。たとえばstatements_with_full_table_scansやstatements_with_temp_tablesなどです。詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
4\. スロークエリログでSQLを確認する
スロークエリログを有効にすると、その名のとおりの動作をします。あらかじめ設定した実行時間を超えたすべてのスロークエリが記録されます。古いバージョンでは秒単位でしたが、MySQL 5.7以降はマイクロ秒単位になりました。値0も指定でき、その場合は実行されたすべてのSQL文が記録されます。ただし、これはパフォーマンスのオーバーヘッドとなり、同時実行数の多いデータベースではコスト増につながる点に注意してください。
設定オプション
素のMySQLでは、次のようにスロークエリログを有効化できます。
mysql> SET GLOBAL slow_query_log=1;
mysql> SET GLOBAL long_query_time=0.001;
mysql> SET GLOBAL log_output=FILE; /* This is the default */
AWS RDSのマネージドサービスでは、パラメータの変更にパラメータグループを使います。これらの変更は即時反映されます。例:
$ modify-parameter ${PG_NAME} slow_query_log 1
$ modify-parameter ${PG_NAME} long_query_time 0.001
$ modify-parameter ${PG_NAME} log_output FILE
本記事では取り上げない追加の設定パラメータとして、slow_query_log_file、log_queries_not_using_indexes、log_slow_admin_statementsなどがあります。
注: これらの追加オプションを有効化する際の影響は、十分に検討してください。いずれもログファイルのサイズを大きく押し上げる可能性があります。行数が少ないために意図的にフルテーブルスキャンを行うクエリや、監視ツールでの計測・観測に欠かせない、頻繁に実行される管理ステートメントが記録されてしまう場合もあります。
設定の確認
スロークエリログが有効化・設定されていることを確認するには、次のようにします。
mysql> SELECT @@slow_query_log, @@long_query_time, @@log_output;
+------------------+-------------------+--------------+
| @@slow_query_log | @@long_query_time | @@log_output |
+------------------+-------------------+--------------+
| 1 | 0.001000 | FILE |
+------------------+-------------------+--------------+
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
AWS RDSからスロークエリログをダウンロードする
有効化されている場合、スロークエリログはRDSインスタンス上のログファイルに書き出されます。AWS CLIで取得できます。
$ INSTANCE_ID=
$ aws rds download-db-log-file-portion \
--db-instance-identifier ${INSTANCE_ID} \
--starting-token 0 \
--output text \
--log-file-name slowquery/mysql-slowquery.log > slowquery.log
RDSのスロークエリログファイルは1時間ごとにローテーションされます。ダウンロード可能なログファイルの一覧は、次のコマンドで確認できます。
$ aws rds describe-db-log-files --db-instance-identifier ${INSTANCE_ID}
{
"DescribeDBLogFiles": [\
...\
{\
"LogFileName": "slowquery/mysql-slowquery.log",\
"LastWritten": 1697125638054,\
"Size": 761426\
},\
{\
"LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.14",\
"LastWritten": 1697121600696,\
"Size": 60517\
},\
{\
"LogFileName": "slowquery/mysql-slowquery.log.2023-10-12.15",\
"LastWritten": 1697122801087,\
"Size": 343085\
}\
]
}
スロークエリログから得られる情報
スロークエリログに記録される個々のSQL文には、次の情報が含まれます。
- 実行時刻
- ユーザーとホスト
- スレッドID
- クエリ実行時間
- ロック時間
- 送信行数
- 検査行数
- SQL文の全文
スロークエリログの出力例
# Time: 2023-10-05T15:56:58.831165Z
# User@Host: dba[dba] @ [172.31.16.14] Id: 295
# Query_time: 0.259097 Lock_time: 0.000178 Rows_sent: 10 Rows_examined: 76733
SET timestamp=1696521418;
SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC
LIMIT 10;
注: スロークエリログはきれいに構造化されており、コメント行以外はすべて実際のSQL文で、それぞれ正しく終端されています。そのため、SQL文を収集・記録・再実行するのは比較的容易です。唯一の制約は、テーブル名がスキーマ修飾されていない場合に、対象テーブルのデータベーススキーマを把握しておく必要がある点です。
SQLテーブル経由のスロークエリログ
あまり推奨はできませんが、スロークエリログを有効にし、設定値log_output=TABLEを使えば、SQL文経由でスロークエリを取得することも可能です。
SQLによるスロークエリログ情報の取得
次のSQL文で、mysql.slow_logテーブルに記録されたクエリを取得できます。
# Table does not have a PK, so this is a crud hack
SELECT sl.*,
CONVERT(q.sql_text USING utf8mb4)AS query
FROM mysql.slow_log sl
INNER JOIN mysql.slow_log q USING (start_time)
WHERE CONVERT(q.sql_text USING utf8mb4) like '%airport%'\G
テーブル経由のスロークエリログ出力例
start_time: 2023-10-05 15:59:30.878226
user_host: dba[dba] @ [172.31.16.14]
query_time: 00:00:00.295653
lock_time: 00:00:00.000164
rows_sent: 10
rows_examined: 76733
db: airport
last_insert_id: 0
insert_id: 0
server_id: 1843089174
sql_text: 0x53454C45435420612E636F756E7472795F636F64652C20632E6E616D652C20434F554E54282A2920415320636E742046524F4D20616972706F72742061202020494E4E4552204A4F494E20636F756E7472792063205553494E472028636F756E7472795F636F6465292047524F555020425920636F756E7472795F636F64652C206E616D65204F5244455220425920332044455343204C494D4954203130
thread_id: 295
query: SELECT a.country_code, c.name, COUNT(*) AS cnt FROM airport a INNER JOIN country c USING (country_code) GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
5\. 一般クエリログでSQLを確認する
適切に設定すれば、MySQLはすべてのSQL文を一般クエリログに記録します。
注: 一般クエリログを有効にする環境と期間は、十分に検討してください。次の例は、ほぼアイドル状態のシステムにおいて、対象のSQL文と同じ秒内に追加で実行された12件のSQL文を示したものです。
警告: スロークエリログと同様、一般クエリログの出力もMySQLテーブルに記録できます。ただし、稼働中のシステムのパフォーマンスへの影響が大きいため、推奨されません。
設定オプション
素のMySQLでは、次のように一般クエリログを有効化できます。
mysql> SET GLOBAL general_log=1;
mysql> SET GLOBAL log_output=FILE; /* This is the default */
AWS RDSのマネージドサービスでは、パラメータの変更にパラメータグループを使用します。変更は即時に反映されます。例:
$ modify-parameter ${PG_NAME} general_log 1
$ modify-parameter ${PG_NAME} log_output FILE
ここでは扱わない追加の設定パラメータとして、general_log_file変数があります。
設定の確認
一般クエリログが有効化・設定されていることを確認するには、次のようにします。
mysql> SELECT @@general_log, @@log_output, @@general_log_file;
+---------------+--------------+------------------------------------------+
| @@general_log | @@log_output | @@general_log_file |
+---------------+--------------+------------------------------------------+
| 1 | FILE | /rdsdbdata/log/general/mysql-general.log |
+---------------+--------------+------------------------------------------+
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
AWS RDSから一般クエリログをダウンロードする
有効化されている場合、一般クエリログはRDSインスタンス上のログファイルに書き出されます。AWS CLIで取得できます。
$ INSTANCE_ID=
$ aws rds download-db-log-file-portion \
--db-instance-identifier ${INSTANCE_ID} \
--starting-token 0 \
--output text \
--log-file-name general/mysql-general.log > general.log
前のセクションで述べたとおり、describe-db-log-files引数を使えば、ローテーション済みの一般クエリログファイルを一覧で確認できます。
一般クエリログの出力例
2023-10-05T17:31:06.006853Z 9 Query set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.006963Z 9 Query SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.007500Z 9 Query set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.836552Z 540 Query SELECT
a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10
2023-10-05T17:31:06.932194Z 9 Query set local oscar_local_only_replica_host_status=1;
2023-10-05T17:31:06.932368Z 9 Query SELECT durable_lsn, current_read_point, server_id, last_update_timestamp FROM information_schema.replica_host_status;
2023-10-05T17:31:06.933104Z 9 Query set local oscar_local_only_replica_host_status=0
2023-10-05T17:31:06.935817Z 11 Query SET @@sql_log_bin=off
2023-10-05T17:31:06.936615Z 11 Query select @@session.transaction_read_only
2023-10-05T17:31:06.937118Z 11 Query INSERT INTO mysql.rds_heartbeat2(id, value) values (1,1696527066936) ON DUPLICATE KEY UPDATE value = 1696527066936
2023-10-05T17:31:06.947853Z 11 Query select @@session.transaction_read_only
2023-10-05T17:31:06.948293Z 11 Query COMMIT
2023-10-05T17:31:06.948725Z 11 Query SET @@sql_log_bin=on
注: 一般クエリログは半構造化された形式です。SQL文は複数行にわたることがあり、クライアントプログラムからMySQLへ渡された形がそのまま保持されます。各行から先頭41文字を削るだけでSQL文を取り出せるとは限りません。
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
6\. バイナリログでSQLを確認する
見落とされがちですが、有効化したMySQLのバイナリログは、データベースに対する書き込みSQLの宝庫です。トランザクションの境界や、トランザクション内のSQL文の順序を特定する手がかりとなり、ロックを調査する際にも役立ちます。さらに、INSERT、UPDATE、DELETE文については、すべての列の詳細も得られます。
リードレプリカを使用するRDSインスタンス構成では、バイナリログがデフォルトで有効になっています。
設定の確認
バイナリログが有効化・設定されていることを確認するには、次のようにします。
mysql> SELECT @@log_bin, @@binlog_format, @@log_statements_unsafe_for_binlog, @@log_bin_trust_function_creators;
+-----------+-----------------+------------------------------------+-----------------------------------+
| @@log_bin | @@binlog_format | @@log_statements_unsafe_for_binlog | @@log_bin_trust_function_creators |
+-----------+-----------------+------------------------------------+-----------------------------------+
| 0 | ROW | 1 | 0 |
+-----------+-----------------+------------------------------------+-----------------------------------+
MySQLインスタンスで利用可能なバイナリログは、次の方法で確認できます。
mysql> SHOW BINARY LOGS;
バイナリログはmysqlbinlogコマンドでダウンロードできます。例:
$ TMP_DIR=${TMP_DIR:-/tmp}
$ AUTHENTICATION="-h<host> -u<user> -p<password"
$ BINLOG_FILE="binlog.00042"
mysqlbinlog --read-from-remote-server --raw --result-file=${TMP_DIR}/ ${AUTHENTICATION} ${BINLOG_FILE} 2>/dev/null # Kill warning message and not mess with $?
バイナリログの内容はmysqlbinlogコマンドで参照できます。設定によって有効な引数は異なりますが、概ねどの形式でも以下が無難な選択です。
$ mysqlbinlog -vvv --base64-output=DECODE-ROWS ${TMP_DIR}/${BINLOG_FILE}
バイナリログの分析はより踏み込んだ作業になるため、本記事では扱いません。分析内容は、バイナリログの行フォーマット設定変数の値にも左右されます。引数を追加すれば、特定のファイル単位、あるいは複数ファイルにまたがる期間でテーブル別の集計情報を取得できます。次のスニペットはbinlog_format=ROWを使っているときに、テーブル別のサマリーを得るためのものです。
mysqlbinlog ${BINLOG_ADDITIONAL_ARGS} ${TMP_DIR}/${BINLOG_FILE} | \
sed -e "s/^### //;" | \
sed -e "/^#/d;s/\/\*.*\*\/[;]//;/^$/d" | \
cut -c1-100 | \
tr '[A-Z]' '[a-z]' | \
egrep "^(insert|update|delete|replace|commit|alter|drop|create)" | \
sed -e "s/\t/ /g;s/\`//g;s/(.*$//;s/ set .*$//;s/ as .*$//;s/ join .*$//;s/ values .*$//;" | sed -e "s/ where .*$//;s/ignore //g;s/ inner//g;s/ left//g;s/ right//g;s/ from//g;s/ into//g" | \
sed -e "s/or replace//;s/sql security definer//;s/algorithm=.* //;s/definer=.* //g" | \
sed -e "s/ \w.*\.\*//" | \
awk '{ print $1,$2 }' | \
sort | uniq -c | sort -nr
バイナリログファイルのダウンロードと処理を行う完全なスクリプトは、こちらのGithub gistから入手できます。
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
SQL収集方法のまとめ
各方法の主な利点と制約を以下にまとめます。自分のニーズに合った方法を見極めるには、本記事で示した手順に沿って、それぞれを実際に試してみるのが一番です。
Processlistの利点
- デフォルトで有効
Processlistの制約
- その時点で実行中のSQL文しか取得できない
- すべてのユーザーのクエリを参照するには、上位の権限が必要
Performance Schemaの利点
- 実行中のステートメントに加え、過去に実行されたステートメントも取得できる
- 集計結果が得られるため、高頻度クエリの分析に適している
Performance Schemaの制約
- 有効化が必要。初回有効化時にはインスタンスの再起動が必要
- 高負荷システムでは、リソースのオーバーヘッドを抑えるためのチューニングが必要
Sys Schemaの利点
- 用途別に整理された分かりやすい命名のビューやオブジェクトでperformance schemaを拡張し、扱いやすくする
Sys Schemaの制約
- performance schemaが有効化されていることが前提
スロークエリログの利点
- あらかじめ設定した実行時間を超えるすべてのスロークエリを取得できる
スロークエリログの制約
- 実質的な制約はほぼなし。すべてのMySQLインスタンスで適切なしきい値を設定し、常時有効化しておくのが望ましい
一般クエリログの利点
- すべてのSQL文を時系列で完全に並べて確認できる。トランザクションの分析や、データアクセスのアンチパターン評価に最適
一般クエリログの制約
- 稼働率の高い本番システムではオーバーヘッドが大きい。テストスイートで、できればシングルスレッドで使うことを推奨
バイナリログの利点
- HAおよびPITRを担保するため、基本的には常時有効になっている
バイナリログの制約
- 有効化されていても、取得できるのは書き込み系のみ
- SQL文全体を取り出すための処理形式がやや複雑
付録
使用したサンプルデータ
本記事では、https://github.com/ronaldbradford/data/tree/main/mysql-data/airportで公開されている空港データセットを使用しました。
使用したサンプルSQL
各収集方法の例では、次のサンプルSQL文を使用しています。
SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10;
このSQL文を実行すると、次のような結果が得られます。
+--------------+----------------+-------+
| country_code | name | cnt |
+--------------+----------------+-------+
| US | United States | 30581 |
| BR | Brazil | 6849 |
| JP | Japan | 3430 |
| CA | Canada | 3075 |
| AU | Australia | 2576 |
| MX | Mexico | 2288 |
| RU | Russia | 1556 |
| KR | South Korea | 1400 |
| GB | United Kingdom | 1398 |
| DE | Germany | 1042 |
+--------------+----------------+-------+
10 rows in set (0.47 sec)
注: 実際の空港数や国の並び順は、データセットを取得した時点によって異なる場合があります。
SQLの収集について
これは利用がほとんどないテストシステムであるため、ステートメントによっては該当する全行を取得し、別のステートメントでは対象のサンプルSQL文だけを拾えるようにWHERE句で絞り込んでいます。実環境でSQLを取得する際は、出力量を抑えるために適切なフィルタ条件を加える必要があるかもしれません。
Bashのmodify-parameterヘルパー関数
本記事では、AWS RDSのパラメータグループ変数を変更する構文を簡略化するために、次の関数を使っています。
modify-parameter() {
[[ $# -lt 3 ]] || [[ $# -gt 4 ]] && echo "ERROR: <parameter-group> <parameter> <value> [pending-reboot]" && return 1
local PARAMETER_GROUP="$1"
local PARAMETER_NAME="$2"
local PARAMETER_VALUE="$3"
local APPLY_METHOD="immediate"
[[ $# -eq 4 ]] && APPLY_METHOD="$4"
aws rds modify-db-parameter-group --db-parameter-group-name ${PARAMETER_GROUP} --parameters "ParameterName=${PARAMETER_NAME},ParameterValue='${PARAMETER_VALUE}',ApplyMethod=${APPLY_METHOD}"
aws rds describe-db-parameters --db-parameter-group-name ${PARAMETER_GROUP} --query 'Parameters[] | [?ParameterName == `'${PARAMETER_NAME}'`]'
}
詳しくはAWS CLIコマンドリファレンスのmodify-db-parameter-groupとdescribe-db-parametersの構文をご覧ください。
SQLを識別するためのヒント
MySQLではSQL文にコメントを埋め込めますが、すべてのツールがその情報まで取得・記録してくれるわけではありません。エンジニアリングの良い習慣として、SQL文ごとに何らかのユニークなラベルを付けておくことをおすすめします。コメントの値そのものは重要ではなく、ユニークであることが肝心です。コメント付きのクエリを目にしたときに、ソースコード上ですぐ該当箇所を特定できれば、原因特定までの時間や平均修復時間(MTTR)の短縮につながります。
SELECT /* Countries with the most airports */
a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name
ORDER BY 3 DESC LIMIT 10;
詳しくはMySQL 8.0リファレンスマニュアルをご覧ください。
AWS RDS上で動作するMySQLからSQL文を収集する手段は、MySQL標準のクライアントツールだけでも複数あります。本記事では取り上げないものの、MySQLでSQL文を収集できるツールや手法はほかにもいろいろあります。
SQL文を集めることは、アプリケーションのデータアクセスパターンを把握するための、最初の重要な一歩です。アーキテクチャ設計、テスト、パフォーマンスチューニングのいずれにおいても、欠かせない情報になります。
続編では、パフォーマンス分析の際にSQL文と合わせて必要となる補足メタデータの収集について取り上げる予定です。具体的には、クエリ実行計画(QEP)、テーブルやインデックスのメタデータ、列の分布統計、SQL文の実行に影響し得る個別の設定オプションなどを扱います。