pgBadgerを使ってPostgreSQLの遅いクエリーを可視化する

本稿では、PostgreSQLのログファイルを解析して、HTML形式のレポートを出力するCLIツールpgBadgerを用い、PostgreSQLのスロークエリの分析方法を紹介する。pgBadgerのインストールからレポートの閲覧方法まで手順に説明していくので、上から順に読んでもらえれば思う。

pgBadgerがどんなレポートを出すのかをまず知りたい人はレポートのデモを御覧ください。

pgBadgerのインストール方法

Homebrewで入れる:

brew install pgbadger

PostgreSQLの設定

ログを収集するようためにpostgresql.confに次の設定を書く:

postgresql.conf

log_destination = 'stderr'
logging_collector = on
log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d '
log_statement = 'none'
log_duration = off
log_min_duration_statement = 0
log_checkpoints = on
log_connections = on
log_disconnections = on
log_lock_waits = on
log_temp_files = 0
lc_messages = 'C'

Docker Composeの設定

上の設定ファイルを作ったら、postgres自体は、postgres -c 'config_file=/etc/postgresql/postgresql.conf'で起動すればいい。これでログが収集されるようになる。

Docker Composeでpostgresを起動している場合は、次のような設定にしておく:

docker-compose.yml

  db:
    image: postgres:9.6.4
    command: postgres -c 'config_file=/etc/postgresql/postgresql.conf' # postgresql.confを読み込ませる
    volumes:
      - ./postgresql.conf:/etc/postgresql/postgresql.conf
      - ./postgresql-logs:/var/lib/postgresql/data/pg_log # ログファイルの書き出し先ディレクトリをマウント

アプリを動かしてログをためる

クエリログを集めるために、実際にアプリを動かし、ログを集めていく。しばらくすると、ログファイルがいくつかできる:

$ ls -1 ./postgresql-logs/pg_log
postgresql-2019-04-05_082713.log
postgresql-2019-04-05_082801.log
postgresql-2019-04-05_082819.log
postgresql-2019-04-05_082840.log
postgresql-2019-04-05_082900.log
postgresql-2019-04-05_082914.log

pgBadgerにログを食わせる

集められたログファイルをpgbadgerコマンドの引数に指定して実行する。

pgbadger postgresql-logs/pg_log/postgresql-2019-04-05_08*

そうすると、out.htmlが生成される。これをブラウザで開く。

スロークエリーのレポートを開く

out.htmlを開いたら、メニューの「Top」→「Slowest Indivisual queries」を開く。

ここには、遅い順に個々のクエリが表示される。

値を一般化したクエリで遅いものを知りたいときは「Normalized slowest queries」を見てみると良い。「Normalized slowest queries」は同じ形のクエリが何回発行されたかの回数も分かるようになっている。

参考

• pgBadger Documentation