pg_store_plans とは
pg_store_plans は PostgreSQL の実行計画を取得するためのオープンソースソフトウェアで、PostgreSQL の拡張機能として実装されています。
開発元はNTT OSSセンターのDBチームで、pg_hint_plan、pg_bulkload、pg_rman、pg_statsinfo などの著名なソフトウェアを開発しています。
pg_store_plans の機能
pg_store_plans は一言で言うと pg_stat_statements と一緒に使用して pg_stat_statements で取得できる情報に実行計画の情報を付加するものです。
pg_store_plans では、実行計画(プラン)は plan 列でわかりますがSQL文本体の情報は無いため、SQL文の情報は pg_store_plans の queryid 列を使って pg_stat_statements の query 列を参照する必要がありますので、本記事では pg_store_plans とあわせて pg_stat_statements も一緒にインストールして検証します。
pg_store_plansビュー
下記に pg_store_plansビューの列を示します。
pg_stat_statements と異なる pg_stat_plans ビュー独自の列は、planid(プランのハッシュコード)、plan(プランそのもの)、first_call(最も過去に呼ばれた時刻)、last_call(最も最近呼ばれた時刻)の4列のみで、その他の列は pg_stat_statements とほぼ同一の名称ですが実際に取得できる情報は、pg_store_plans では該当のプラン(実行計画)が使用された時、pg_stat_statements では該当のクエリが使用された時と違いがあり、後の実行例で違いを説明します。
pg_store_plansビュー定義
| pg_store_plans 独自 | 列 | 型 | 参照先 | 説明 |
|---|---|---|---|---|
| userid | oid | pg_authid.oid | SQL文を実行したユーザのOID | |
| dbid | oid | pg_database.oid | SQL文が実行されたデータベースのOID | |
| queryid | bigint | コアによって生成されたクエリID。 compute_query_id が「no」に設定されている場合、pg_store_plan は暗黙的に無効になります。 これは、pg_stat_statements との結合キーとして使用できます。 |
||
| * | planid | bigint | 正規化されたプラン表現から計算されるプランのハッシュコード | |
| * | plan | text | 代表的なプランのテキストです。書式は設定パラメータ pg_store_plans.plan_format で指定します。 | |
| calls | bigint | プランを使用したSQL文が実行された回数 | ||
| total_time | double precision | プランを使用したSQL文の処理に費やした時間（ミリ秒単位） | ||
| rows | bigint | プランを使用したSQL文によって取得された、あるいは影響を受けた行の総数 | ||
| shared_blks_hit | bigint | プランを使用したSQL文によってヒットした共有ブロックキャッシュの総数 | ||
| shared_blks_read | bigint | プランを使用したSQL文によって読み込まれた共有ブロックの総数 | ||
| shared_blks_dirtied | bigint | プランを使用したSQL文によってダーティ状態となった共有ブロックの総数 | ||
| shared_blks_written | bigint | プランを使用したSQL文によって書き込まれた共有ブロックの総数 | ||
| local_blks_hit | bigint | プランを使用したSQL文によってヒットしたローカルブロックキャッシュの総数 | ||
| local_blks_read | bigint | プランを使用したSQL文によって読み込まれたローカルブロックの総数 | ||
| local_blks_dirtied | bigint | プランを使用したSQL文によってダーティ状態となったローカルブロックの総数 | ||
| local_blks_written | bigint | プランを使用したSQL文によって書き込まれたローカルブロックの総数 | ||
| temp_blks_read | bigint | プランを使用したSQL文によって読み込まれた一時ブロックの総数 | ||
| temp_blks_written | bigint | プランを使用したSQL文によって書き込まれた一時ブロックの総数 | ||
| blk_read_time | double precision | プランを使用したSQL文がデータファイルブロックの読み取りに費やした総時間（ミリ秒単位）（track_io_timing が有効な場合。無効であればゼロ） | ||
| blk_write_time | double precision | プランを使用したSQL文がデータファイルブロックの書き出しに費やした総時間（ミリ秒単位）（track_io_timing が有効な場合。無効であればゼロ） | ||
| temp_blk_read_time | double precision | プランを使用したSQL文が一時ファイルブロックの読み取りに費やした総時間（ミリ秒単位）（track_io_timing が有効な場合。無効であればゼロ） | ||
| temp_blk_write_time | double precision | プランを使用したSQL文が一時ファイルブロックの書き出しに費やした総時間（ミリ秒単位） （track_io_timing が有効な場合。無効であればゼロ） | ||
| * | first_call | timestamp with time zone | このプランを使用したクエリの最も最近の呼び出しのタイムスタンプ | |
| * | last_call | timestamp with time zone | このプランを使用したクエリの直近の呼び出しのタイムスタンプ |
pg_store_plans_infoビュー
pg_store_plans モジュール自体の統計は追跡され、pg_store_plans_info というビューを通して利用することができます。 このビューは、1行のみが含まれます。
pg_store_plans_infoビュー定義
| 列名 | 型 | 参照先 | 説明 |
|---|---|---|---|
| dealloc | bigint | pg_store_plans.max よりも多くの個別のステートメントが観察されたために、最も実行頻度の低いステートメントに関する pg_store_plans エントリの割り当てが解除された合計回数 | |
| stats_reset | timestamp with time zone | pg_store_plans ビュー内のすべての統計が最後にリセットされた時刻 |
主なpg_store_plans関数
pg_store_plans_reset() returns void
pg_store_plans_resetは、pg_store_plansによってこれまでに収集された全ての統計情報を破棄します。デフォルトでは、スーパーユーザのみがこの関数を実行できます。
pg_store_plans サポート対象バージョン
pg_store_plans のバージョン体系は、 PostgreSQL 9.4 から PostgreSQL 11 までの複数のメジャーバージョンをサポート対象とする pg_store_plans 1.3.1 と、メジャーバージョンで導入された新機能に対応するため、単独の独立した PostgreSQL をサポートする pg_store_plans 1.4 以降とに分かれています。一旦リリースされた後はバグ修正のみが実施される PostgreSQL と同様のリリースモデルを採用しています。
pg_store_plans のバージョンとサポート対象の PostgreSQL のバージョンの対応は以下の通りです。
| pg_store_plans バージョン | サポート対象 PostgreSQL バージョン | rpm対象OS |
|---|---|---|
| pg_store_plans 1.7 | PostgreSQL 15 | RHEL 8.x |
| pg_store_plans 1.6.1 | PostgreSQL 14 | RHEL/CentOS 7.x, RHEL 8.x, RHEL 9.x |
| pg_store_plans 1.5 | PostgreSQL 13 | |
| pg_store_plans 1.4 | PostgreSQL 12 | |
| pg_store_plans 1.3.1 | PostgreSQL 9.4, 9.5, 9.6, 10, 11 |
pg_store_plans インストール方法(rpmパッケージ)
pg_store_plans のインストール方法は、大きく分けてソースコードからのインストールと、pg_store_plansのサイトに掲載されている rpm からのインストールがあります。
今回は rpm からのインストールをご紹介します。
下記のインストールの実行例では Rocky Linux release 8.9, PostgreSQL 15.5, pg_store_plans 1.7, pg_stats_statements 1.10 を使用して説明します。
Rocky Linux から直接インターネット接続が可能な環境を使用しています。
PostgreSQL 公式 Yum リポジトリから PostgreSQL 15.5 は contrib も含めて既にインストールとDB初期化が済んでいるものとします。
pg_store_plans のインストール
PostgreSQL 15用の pg_store_plans はこちらからダウンロード可能で、pg_store_plans15-1.7-1.el8.x86_64.rpm
をローカルディスクにダウンロードした後、dnf localinstall で rpm ファイルをインストールします。
# wget https://github.com/ossc-db/pg_store_plans/releases/download/1.7/pg_store_plans15-1.7-1.el8.x86_64.rpm :(略) 2023-12-25 15:19:00 (70.7 MB/s) - `pg_store_plans15-1.7-1.el8.x86_64.rpm' へ保存完了 [41492/41492] # dnf localinstall pg_store_plans15-1.7-1.el8.x86_64.rpm メタデータの期限切れの最終確認: 0:04:20 時間前の 2023年12月25日 15時15分07秒 に実施しました。 依存関係が解決しました。 ========================================================================================================================================= パッケージ アーキテクチャー バージョン リポジトリー サイズ ========================================================================================================================================= インストール: pg_store_plans15 x86_64 1.7-1.el8 @commandline 41 k トランザクションの概要 ========================================================================================================================================= インストール 1 パッケージ 合計サイズ: 41 k インストール後のサイズ: 104 k これでよろしいですか? [y/N]: y パッケージのダウンロード: トランザクションの確認を実行中 トランザクションの確認に成功しました。 トランザクションのテストを実行中 トランザクションのテストに成功しました。 トランザクションを実行中 準備 : 1/1 インストール中 : pg_store_plans15-1.7-1.el8.x86_64 1/1 scriptletの実行中: pg_store_plans15-1.7-1.el8.x86_64 1/1 検証 : pg_store_plans15-1.7-1.el8.x86_64 1/1 インストール済み: pg_store_plans15-1.7-1.el8.x86_64 完了しました! #
これで pg_store_plans がインストールできました。
postgresql.conf の shared_preload_libraries に pg_store_plans と pg_stat_statements を追加して PostgreSQL を再起動、有効になっていることを確認
shared_preload_libraries に共有ライブラリの pg_store_plans と pg_stat_statements を設定して PostgreSQL を再起動し、pg_store_plans と pg_stat_statements が有効になっていることを確認します。
$ cd $PGDATA
$ vi postgresql.conf
shared_preload_libraries = 'pg_store_plans, pg_stat_statements'
# systemctl restart postgresql-15
$ psql
psql (15.5)
"help"でヘルプを表示します。
postgres=# show shared_preload_libraries;
shared_preload_libraries
-----------------------------------
pg_store_plans, pg_stat_statements
(1 行)
CREATE EXTENSION を実行して拡張に登録
検証に使う db1 データベースを作成後 psql で接続して、CREATE EXTENSION を実行します。拡張が登録されていることを確認します。
$ createdb db1
$ psql db1
psql (15.5)
"help"でヘルプを表示します。
db1=# \dx
インストール済みの拡張一覧
名前 | バージョン | スキーマ | 説明
---------+------------+------------+------------------------------
plpgsql | 1.0 | pg_catalog | PL/pgSQL procedural language
(1 行)
db1=# CREATE EXTENSION pg_store_plans;
CREATE EXTENSION
db1=# CREATE EXTENSION pg_stat_statements;
db1=# \dx
インストール済みの拡張一覧
名前 | バージョン | スキーマ | 説明
--------------------+------------+------------+------------------------------------------------------------------------
pg_stat_statements | 1.10 | public | track planning and execution statistics of all SQL statements executed
pg_store_plans | 1.7 | public | track plan statistics of all SQL statements executed
plpgsql | 1.0 | pg_catalog | PL/pgSQL procedural language
(3 行)
db1=#
これで pg_store_plans と pg_stat_statements のインストールは完了しました。
pg_store_plans と pg_stat_statements で取得可能な情報
pgbench でDB初期化後、60秒間実行した後で、pg_store_plans と pg_stat_statements からのクエリと実行計画に関する情報を全実行時間の降順で並べて検索した例を以下に示します。
全実行時間(total_exec_time)を呼び出し回数(calls)で割れば1実行当たりの実行時間の平均が算出可能です。
このプランを使用した最初の実行時刻(first_call)と直近の実行時刻(last_call)でどの時間帯にどの実行計画が使われていたのかが判別できるので、この情報を定期的に保存しておけば自動ANALYZEにより途中で実行計画が変化してしまった場合に、通常時と悪化時の実行計画の両方が分かると思います。
db1=# \x
拡張表示は on です。
db1=# SELECT ps.query, ps.calls, ps.total_plan_time, ps.total_exec_time, pp.first_call, pp.last_call, pp.plan FROM pg_store_plans pp, pg_stat_statements ps WHERE pp.queryid = ps.queryid ORDER BY ps.total_exec_time DESC;
-[ RECORD 1 ]---+------------------------------------------------------------------------------------------------------------------------
query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2
calls | 26618
total_plan_time | 0
total_exec_time | 1740.1858220000065
first_call | 2024-01-11 14:29:53.134722+09
last_call | 2024-01-11 14:30:53.116803+09
planid | 2057223742
plan | Update on pgbench_accounts (cost=0.29..8.31 rows=0 width=0)
| -> Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.29..8.31 rows=1 width=10)
| Index Cond: (aid = 75060)
-[ RECORD 2 ]---+------------------------------------------------------------------------------------------------------------------------
query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2
calls | 26618
total_plan_time | 0
total_exec_time | 335.3067220000009
first_call | 2024-01-11 14:29:53.135509+09
last_call | 2024-01-11 14:30:53.116962+09
planid | 3391261630
plan | Update on pgbench_tellers (cost=0.00..1.13 rows=0 width=0)
| -> Seq Scan on pgbench_tellers (cost=0.00..1.13 rows=1 width=10)
| Filter: (tid = 2)
-[ RECORD 3 ]---+------------------------------------------------------------------------------------------------------------------------
query | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2
calls | 26618
total_plan_time | 0
total_exec_time | 299.5543750000008
first_call | 2024-01-11 14:29:53.138592+09
last_call | 2024-01-11 14:30:53.117044+09
planid | 1429560889
plan | Update on pgbench_branches (cost=0.00..1.01 rows=0 width=0)
| -> Seq Scan on pgbench_branches (cost=0.00..1.01 rows=1 width=10)
| Filter: (bid = 1)
同一のクエリで実行計画が変化した時の実行例
同一のクエリで、複数の実行計画が使用された場合に pg_store_plans で取得できる情報と、pg_stat_statementsで取得できる情報の違いについて説明します。
10000件のtable1テーブルでインデックスが無い状態での検索とtable1_i1_idx インデックスを付加した状態での検索を実施してみます。
テーブルを作成してデータを挿入した段階で、pg_store_plans_reset() 関数とpg_stat_statements_reset() 関数で pg_store_plans と pg_stat_statements の統計情報をリセットしています。
db1=# CREATE TABLE table1 (i1 integer, t1 text);
CREATE TABLE
db1=# INSERT INTO table1 SELECT i, LEFT(MD5(i::text), 8) FROM generate_series(1,10000) as i;
INSERT 0 10000
db1=# SELECT pg_store_plans_reset();
pg_store_plans_reset
----------------------
(1 行)
db1=# SELECT pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
(1 行)
db1=# SELECT * FROM pg_store_plans_info;
dealloc | stats_reset
---------+-------------------------------
0 | 2024-01-14 17:58:06.074107+09
(1 行)
db1=# SELECT * FROM pg_stat_statements_info;
dealloc | stats_reset
---------+------------------------------
0 | 2024-01-14 17:58:10.57708+09
(1 行)
まず、インデックスが無い状態で検索しますので、Seq Scanの検索になります。その後、インデックスを付加した状態で検索しますので、Index Scanの検索になります。
db1=# SELECT * FROM table1 WHERE i1 = 1; i1 | t1 ----+---------- 1 | c4ca4238 (1 行) db1=# CREATE INDEX table1_i1_idx ON table1 (i1); CREATE INDEX db1=# SELECT * FROM table1 WHERE i1 = 1; i1 | t1 ----+---------- 1 | c4ca4238 (1 行)
行数が多いので見やすくするために拡張表示をonにして、該当の検索のみを抽出します。また、pg_store_plans の列には先頭に p_ 、pg_stat_statements の列には先頭に s_ を付けて区別しやすくします。
db1=# \x
拡張表示は on です。
db1=# SELECT ps.query as s_query, pp.calls as p_calls, pp.total_time as p_total_time, ps.calls as s_calls, ps.total_plan_time s_total_plan_time, ps.total_exec_time as s_total_exec_time, pp.first_call as p_first_call, pp.last_call as p_last_call, pp.planid as p_planid, pp.plan as p_plan FROM pg_store_plans pp, pg_stat_statements ps WHERE pp.queryid = ps.queryid AND query LIKE 'SELECT * FROM table1%' ORDER BY ps.total_exec_time DESC;
-[ RECORD 1 ]-----+----------------------------------------------------------------------------
s_query | SELECT * FROM table1 WHERE i1 = $1
p_calls | 1
p_total_time | 0.06921400000000001
s_calls | 2
s_total_plan_time | 0
s_total_exec_time | 0.602927
p_first_call | 2024-01-14 17:59:18.511485+09
p_last_call | 2024-01-14 17:59:18.511485+09
p_planid | 1345757884
p_plan | Index Scan using table1_i1_idx on table1 (cost=0.29..8.30 rows=1 width=13)+
| Index Cond: (i1 = 1)
-[ RECORD 2 ]-----+----------------------------------------------------------------------------
s_query | SELECT * FROM table1 WHERE i1 = $1
p_calls | 1
p_total_time | 0.533713
s_calls | 2
s_total_plan_time | 0
s_total_exec_time | 0.602927
p_first_call | 2024-01-14 17:59:03.762229+09
p_last_call | 2024-01-14 17:59:03.762229+09
p_planid | 828508567
p_plan | Seq Scan on table1 (cost=0.00..180.00 rows=1 width=13) +
| Filter: (i1 = 1)
db1=#
pg_store_plans での calls(p_calls) と total_time(p_total_time )は該当の実行計画 (planid, plan) が使われた回数(1回ずつ)とその実行時間、pg_stat_statmentsでの calls(s_calls) と total_exec_time(s_total_exec_time )は(実行計画に関係無く)該当のクエリのすべての実行回数とすべての実行時間になるので、同じ calls でも取得される情報が異なることが分かります。
また、first_call と last_call を見比べると、Seq Scan は 17:59:03、Index Scan は 17:59:18 になっていますので、Seq Scan の後に Index Scan が実行されたことが分かります。この first_call と last_call で該当の実行計画がいつ実行されたのかが分かります。
まとめ
pg_store_plans を pg_stat_statements と一緒に使った時に取得できる情報について説明しました。pg_stat_statements 単独だとクエリの実行回数と実行時間は取得できますが、pg_store_plans を一緒に使うことで、クエリの実行計画とその実行計画で実行された実行時間も分かりますので、遅延が発生した時の実行計画を調査するために有用な機能だと思います。