スロークエリの確認方法：PostgreSQL編

スロークエリは、アプリケーション側のボトルネックとしてよく現れる、処理速度が遅いSQLです。意図せずフルスキャンをしているケースが多く、データ件数が増えるにつれて急激に性能問題を引き起こします。負荷テスト実施時には1秒以上かかるものは把握しておくとよいでしょう。

スロークエリへの対処は次の3ステップで行います。

  1. スロークエリを特定する
  2. スロークエリを解析する
  3. スロークエリを改修する

MySQL、PostgreSQL、Oracleなど複数のRDBMSがありますが、基本的な流れは共通となります。

この記事では、PostgreSQL12を対象に3ステップについて解説します。

1．スロークエリを特定する

スロークエリの設定

「pg_stat_statements」を使うことで、SQLを使ってスロークエリを抽出することができます。

下記手順でインストールを行います。

# インストールを行う
# yum install -y postgresql12-contrib

# 有効化
# su - postgres
# psql
postgres=# select * from pg_available_extensions where name = 'pg_stat_statements';
        name        | default_version | installed_version |                          comment
--------------------+-----------------+-------------------+-----------------------------------------------------------
 pg_stat_statements | 1.7             |                   | track execution statistics of all SQL statements executed
(1 row)

postgres=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSION

postgres=# select * from pg_available_extensions where name = 'pg_stat_statements';
        name        | default_version | installed_version |                          comment
--------------------+-----------------+-------------------+-----------------------------------------------------------
 pg_stat_statements | 1.7             | 1.7               | track execution statistics of all SQL statements executed
(1 row)

postgresql.confへ下記を追加し、再起動を実施します。

shared_preload_libraries = 'pg_stat_statements'

2．スロークエリを解析する

スロークエリの見方

SQL文で取得することが可能です。callsやtotal_timeでソートをすることで必要なSQLの取得を行いましょう。

postgres=# \x
Expanded display is on.

postgres=#  SELECT * FROM pg_stat_statements order by total_time desc limit 1;
-[ RECORD 1 ]-------+--------------------
userid              | 10
dbid                | 14187
queryid             | 8068993708030807443
query               | select pg_sleep($1)
calls               | 1
total_time          | 2002.162921
min_time            | 2002.162921
max_time            | 2002.162921
mean_time           | 2002.162921
stddev_time         | 0
rows                | 1
shared_blks_hit     | 0
shared_blks_read    | 0
shared_blks_dirtied | 0
shared_blks_written | 0
local_blks_hit      | 0
local_blks_read     | 0
local_blks_dirtied  | 0
local_blks_written  | 0
temp_blks_read      | 0
temp_blks_written   | 0
blk_read_time       | 0
blk_write_time      | 0

スロークエリの解析

スロークエリの解析は「Explain」コマンドを利用します。explainの後にクエリを入れることでクエリの実行パスの情報を取得できます。

postgres=# explain select pg_sleep(3);
                QUERY PLAN
------------------------------------------
 Result  (cost=0.00..0.01 rows=1 width=4)
(1 row)

サンプルのSQLはスリープさせているだけなので、実行計画がほぼありません。読み解き方は本家のサイトにわかりやすくまとめてあるので確認してください。

参考－＞Explaining Explain ～ PostgreSQLの実行計画を読む

また、「explain」を「explain analyze」コマンドへ変更することで、取得する時間についても調べることが可能です。

参考－＞PostgreSQLのExplain analyzeを読みやすくする方法

3．スロークエリを改修する

スロークエリの改修は次のことに注意して実施しましょう。

  • まずは、インデックス追加で解消しないか検討する
  • SQLを改修する場合は、取得結果が変わらないように慎重に
  • 必要に応じてアプリケーションの改修も視野に入れる

参考　スロークエリをファイルへ出力する方法

解析するのが大変になりますが、スロークエリをファイルへ出力することも可能です。「pg_stat_statements」のインストールが難しい場合はこちらを利用しましょう。

設定

postgresql.confへ下記を追加し、PostgreSQLの再起動を行います。

log_directory = 'log'
log_filename = 'postgresql-%a.log'
log_min_duration_statement = 1s

標準では、「/var/lib/pgsql/12/data/log/postgresql-Tue.log」へ該当SQLが出力されます。

スロークエリの見方

ログファイルへスロークエリは次のように出力されます。下記は3秒スリープするSQLを流してみた場合のスロークエリログです。

2020-05-12 11:41:57.451 JST [5251] LOG:  duration: 3000.677 ms  statement: select pg_sleep(3);

まとめ

スロークエリはシステムの性能に大きな影響を与えます。そのため、スロークエリを取得し、影響度の大きいものを特定し改修することで大幅な性能改善が見込めるため覚えておきましょう。

コメントは受け付けていません。