pt-query-digestを使用したクエリログの変換について
Percona Toolkitに含まれるpt-query-digestをスロークエリのレポーティングに使用している方は多いと思いますが、pt-query-digestは様々なクエリソースを受け取り、様々なフォーマットに変換できることをご存知でしょうか。
今回は、pt-query-digestを使用して、様々なクエリソースをスロークエリログ形式に変換する方法をご紹介します。
pt-query-digestが対応するクエリソースの形式
pt-query-digestは以下のクエリログ形式に対応しています。
- slowlog | スロークエリログ
- genlog | 一般ログ
- binlog | バイナリログ
- tcpdump | tcpdump
- rawlog | テキストログ
- –processlist | SHOW PROCESSLIST
入力するクエリログの形式は、 --processlistを除き–type オプションで指定します。
|
1 |
$ pt-query-digest --type slowlog mysql-slow.log |
--processlist はログからの読み取りを行うものではなく、–processlist オプションにMySQLへの接続のためのDSNを指定することで、一定間隔でポーリングした結果を入力とすることができるというものです。
rawlogは、1行、1SQL形式の以下のようなテキストログを意味します。
|
1 2 3 |
SELECT ... INSERT ... SELECT ... |
pt-query-digestが対応する出力形式
出力形式は以下のとおりです。
- report | テキストレポート形式
- slowlog | スロークエリログ形式
- secure-slowlog | セキュアスロークエリログ形式
- json | JSONレポート形式
- json-anon | セキュアJSONレポート形式
pt-query-digestの機能としては、スロークエリログをサマリしたレポートを作成するということが主ですが、レポート出力を行わず(--no-report)、あるクエリログをスロークエリログ等の形式に変換するということが可能です。
|
1 2 |
$ mysqlbinlog /var/lib/mysql/mysql-general.log | \ pt-query-digest --no-report --type genlog --output slowlog |
それぞれのクエリログ形式の、スロークエリログへの変換はベストエフォートで行われます。
例えば、バイナリログをスロークエリログに変換する場合、 binlog_format=ROW で記録されたDMLイベントはSQL形式ではなくBASE64エンコードされた文字列になりますので、スロークエリ形式で正常に出力されません。
一方で、DDLや、binlog_format=STATEMENTで記録されたDMLイベントはスロークエリ形式で出力されます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
$ mysqlbinlog /var/lib/mysql/binlog.000001 | \ pt-query-digest --no-report --type binlog --output slowlog # Time: 220120 0:46:10 # Thread_id: 12 # Query_time: 0.000000 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0 use sbtest; CREATE TABLE sbtest1( id INTEGER NOT NULL AUTO_INCREMENT, k INTEGER DEFAULT '0' NOT NULL, c CHAR(120) DEFAULT '' NOT NULL, pad CHAR(60) DEFAULT '' NOT NULL, PRIMARY KEY (id) ) /*! ENGINE = innodb */; |
一方でtcpdumpのログはLock_time, Rows_sent, Rows_examined等の統計は無いものの、クエリのフルテキスト、及び実行時間という基本的な内容が確認できます。
|
1 2 3 4 5 |
# Time: 220120 05:11:49.494710 # Client: 172.19.56.97:40334 # Thread_id: 4294967298 # Query_time: 0.000095 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0 EXECUTE SELECT c FROM sbtest1 WHERE id=4414; |
--processlist を指定した場合のログも同様に、詳細なメトリックは無いものの基本的な情報が確認できます。
|
1 2 3 4 5 6 |
$ pt-query-digest --no-report --processlist u=root,p=P@ssw0rd --output slowlog # Time: 2022-01-20T05:38:40 # User@Host: sbtest[sbtest] @ mysql2.example.com:40336 [] # Query_time: 0.100892 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0 use sbtest; COMMIT; |
tcpdumpやprocesslistのメリットは、long_query_time=0のようにインスタンスレベルでの全クエリの取得を有効化せずに実行されているクエリをロギングできるという点です。
tcpdumpについては、long_query_time = 0にするよりもMySQLのパフォーマンスに影響を与えないという計測結果があります。
https://www.percona.com/blog/2015/04/10/measuring-impact-tcpdump-busy-hosts/
processlistは定点観測になりますので高速なクエリは記録されない可能性がありますが、より影響を与えないロギングが可能でしょう。
secure-slowlogやjson-anon では、出力されるSQLの 条件値、数値 等が?に変換されます。
ベンダへの調査依頼の際に、センシティブなデータをマスクすることに役立つでしょう。
|
1 2 3 4 5 6 7 8 9 10 11 12 |
# Time: 2022-01-20T00:46:10 # User@Host: sbtest[sbtest] @ localhost [] # Thread_id: 12 # Query_time: 0.024568 Lock_time: 0.000029 Rows_sent: 0 Rows_examined: 0 use sbtest; create table sbtest?( id integer not ? auto_increment, k integer default ? not ?, c char(?) default ? not ?, pad char(?) default ? not ?, primary key (id) ) /*! engine = innodb */; # Time: 2022-01-20T00:46:10 # User@Host: sbtest[sbtest] @ localhost [] # Thread_id: 12 # Query_time: 0.140687 Lock_time: 0.000019 Rows_sent: 0 Rows_examined: 0 use sbtest; insert into sbtest?(k, c, pad) values(?+); |
|
1 2 3 4 5 6 7 8 9 10 11 12 |
{ "classes": [ : { "attribute": "fingerprint", "checksum": "F0C5AE75A52E847D737F39F04B198EF6", "distillate": "SELECT sbtest?", "fingerprint": "select distinct c from sbtest? where id between ? and ? order by c", : } ] } |
スロークエリログからJSONへ
--output json を使用することで、スロークエリログのレポートをJSON形式で出力することが可能です。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 |
$ pt-query-digest --output json slow.log | jq . { "classes": [ { "attribute": "fingerprint", "checksum": "8ED4A1775B8BF7E2A1EFA356C8F3EDBF", "distillate": "INSERT sbtest?", "example": { "Query_time": "0.177119", "query": "INSERT INTO sbtest1(k, c, pad) VALUES(4993, ...) "ts": "2022-01-20 05:11:45" }, "fingerprint": "insert into sbtest?(k, c, pad) values(?+)", "histograms": { "Query_time": [ 0, 0, 0, 0, 2, 1, 0, 0 ] }, "metrics": { "Client": { "value": "172.19.56.97:40332" }, "Lock_time": { "avg": "0.000000", "max": "0.000000", "median": "0.000000", "min": "0.000000", "pct": "0.008264", "pct_95": "0.000000", "stddev": "0.000000", "sum": "0.000000" }, "Query_length": { "avg": "468640", "max": "524224", "median": "522014", "min": "357472", "pct": "0", "pct_95": "522014", "stddev": "79523", "sum": "1405920" }, "Query_time": { "avg": "0.112432", "max": "0.177119", "median": "0.090844", "min": "0.068999", "pct": "0.008264", "pct_95": "0.171300", "stddev": "0.044371", "sum": "0.337297" }, "Rows_examined": { "avg": "0", "max": "0", "median": "0", "min": "0", "pct": "0", "pct_95": "0", "stddev": "0", "sum": "0" }, "Rows_sent": { "avg": "0", "max": "0", "median": "0", "min": "0", "pct": "0", "pct_95": "0", "stddev": "0", "sum": "0" } }, "query_count": 3, "tables": [ { "create": "SHOW CREATE TABLE <code>sbtest1</code>\\G", "status": "SHOW TABLE STATUS LIKE 'sbtest1'\\G" } ], "ts_max": "2022-01-20 05:11:45", "ts_min": "2022-01-20 05:11:45" }, |
他のプログラムにスロークエリログを連携する場合には、JSON形式が適しています。
例えば、日々のスロークエリレポートをJSON形式で他のデータストアにインポートし、RedashやGrafana、Kibana等で可視化するということも考えられます。
|
1 2 3 4 5 |
# MySQLへのインポート例 $ mysql -e 'CREATE TABLE test.slow_query_report (id bigint PRIMARY KEY AUTO_INCREMENT, data json)' $ pt-query-digest --output json tcpdump.slow.log | \ jq -c -r '.classes[]' | \ mysql --local-infile=1 -e 'LOAD DATA LOCAL INFILE "/dev/stdin" INTO TABLE test.slow_query_report FIELDS ESCAPED BY "\0" (data)' |
以下のように実行時間を抽出できます。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
mysql> SELECT -> data->'$.example.query' as query, -> data->'$.example.Query_time' as query_time_second -> from -> test.slow_query_report\G *************************** 1. row *************************** query: "CREATE INDEX k_1 ON sbtest1(k)" query_time_second: "0.123912" *************************** 2. row *************************** query: "COMMIT" query_time_second: "0.002941" *************************** 3. row *************************** query: "SELECT c FROM sbtest1 WHERE id=5033" query_time_second: "0.003965" : |
また、--group-by arg の指定により同じテキストであるクエリをまとめることも可能です。
|
1 2 3 |
$ pt-query-digest --output json tcpdump.slow.log --group-by arg | \ jq -c -r '.classes[]' | \ mysql --local-infile=1 -e 'LOAD DATA LOCAL INFILE "/dev/stdin" INTO TABLE test.slow_query_report FIELDS ESCAPED BY "\0" (data)' |
例えばある環境に実行されているクエリを、別のバージョンの環境に実行してテストしたい、というようなニーズに活用できます。
ここで注意したいのは、JSONレポート形式の場合、classes[].example.query に格納される文字数は10000文字に制限されていることです。
クエリが部分的にならないよう、pt-query-digestのmax_query_lengthの値を増やすことを推奨します。
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
7855 # ########################################################################### 7856 # JSONReportFormatter package 7857 # This package is a copy without comments from the original. The original 7858 # with comments and its test file can be found in the Bazaar repository at, 7859 # lib/JSONReportFormatter.pm 7860 # t/lib/JSONReportFormatter.t 7861 # See https://launchpad.net/percona-toolkit for more information. 7862 # ########################################################################### 7863 { 7864 package JSONReportFormatter; ： 7903 7904 has 'max_query_length' => ( 7905 is => 'rw', 7906 isa => 'Int', 7907 required => 0, 7908 default => sub { return 10_000; }, # characters, not bytes 7909 ); |
JSON形式のレポートから、以下のようにクエリを抽出し、別環境で実行することも可能です。
|
1 2 3 4 5 |
$ jq -r '.classes[].example.query|select(. | test("^SELECT")) + ";"' report-per-query.json SELECT SUM(k) FROM sbtest1 WHERE id BETWEEN 5030 AND 5129; SELECT DISTINCT c FROM sbtest1 WHERE id BETWEEN 5001 AND 5100 ORDER BY c; SELECT c FROM sbtest1 WHERE id BETWEEN 5035 AND 5134 ORDER BY c; : |
なお、取得元の環境と同じ状態でクエリが実行可能かという点は、条件値のレコードの有無によります。
実行環境のある時点のバックアップから検証環境を作成し、いつでも実行前の状態に戻せるようにファイルシステムのスナップショットを取得しておくことが望ましいでしょう。
また、この場合DMLを実行する際の時系列は考慮されませんのでご注意ください。
まとめ
今回紹介したJSON形式、スロークエリログ形式など、出力フォーマットが決まっていれば、自作のパース用スクリプトも作成しやすくなるのではと思います。
pt-query-digestはその歴史も長く、ユーザ数も多いこともあってアイデア次第で色々な使い方も考えられます。
たまにドキュメントを眺めてみてお気に入りの使用方法を見つけてみてはいかがでしょうか。
