mita2 database life

主にMySQLに関するメモです

MySQL スロークエリログからやたら遅いクエリだけ取り出す

日常的に、long_query_time をちょっと超えているクエリが流れていて、スロークエリログが多く出力されているDBってあったりしますよね?

そんなログからノイズとなってしまっている、ちょっと遅いクエリは除いて、非常に重症のクエリのログだけに絞って見たいときどうするか。

今まで、grepawk でゴニョゴニョしてがんばってたんですが、pt-query-digest を使えば簡単にできました・・・

pt-query-digest でフィルタだけする

pt-query-digest はスロークエリログを集計し、「遅いクエリランキング」等のレポートを生成できるツールです。SQLチューニングする時によく使っています。

www.percona.com

pt-query-digest のレポート機能を無効にすることで、単なるログのフィルタツールとしても使えました(知らなかった!)

やたら遅いクエリだけ取り出す

--no-report でレポートを無効化し、出力形式を --output slowlog でスローログ形式にします。--filer に条件を指定します。

# 5秒以上のクエリだけを取り出す
$ pt-query-digest --type slowlog --output slowlog --no-report --filter '$event->{Query_time} > 5 '  localhost-slow.log

出力例)

$ pt-query-digest --type slowlog --output slowlog --no-report --filter '$event->{Query_time} > 5 '  localhost-slow.log
# Time: 2020-08-23T07:26:29
# User@Host: root[root] @ localhost []
# Thread_id: 13
# Query_time: 10.002385  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
SELECT SLEEP(10);
# Time: 2020-08-23T07:30:25
# User@Host: root[root] @ localhost []
# Thread_id: 14
# Query_time: 5.004318  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
SELECT SLEEP(5);
# Time: 2020-08-23T07:44:26
# User@Host: root[root] @ localhost []
# Thread_id: 15
# Query_time: 5.000435  Lock_time: 0.000163  Rows_sent: 1  Rows_examined: 4
SELECT *, SLEEP(5) FROM mysql.user WHERE User = 'root';

--output slowlog-secure とすると、バンド変数を ? に置き換えてマスキングしてくれます。

$ pt-query-digest --type slowlog --output secure-slowlog --no-report --filter ' $event->{Query_time} > 5 ' localhost-slow.log
<snip>
# Time: 2020-08-23T07:44:26
# User@Host: root[root] @ localhost []
# Thread_id: 15
# Query_time: 5.000435  Lock_time: 0.000163  Rows_sent: 1  Rows_examined: 4
select *, sleep(?) from mysql.user where user = ?;

特定のユーザのクエリだけ見る

pt-query-digestperl で書かれてます。--filer には任意の perl のプログラムを書くことができます。

Userを正規表現でフィルタして、appuser で実行されたクエリだけ取り出す。

# pt-query-digest --type slowlog --output secure-slowlog --no-report --filter ' $event->{user} =~ /appuser/ ' /var/lib/mysql/localhost-slow.log
# Time: 2020-08-23T07:02:53
# User@Host: appuser[appuser] @ localhost []
# Thread_id: 8
# Query_time: 0.000066  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
select @@version_comment limit ?;