pg_store_plansを使ってみた(1)

はじめに

先日、pg_plan_advsrを使ってみた(1)という記事を書いたんだけど、そのpg_plan_advsrでは、pg_hint_planとpg_store_plansという拡張機能を利用している。
pg_hint_planは（実案件ではないが）何回か使ったことはあるけど、もう一つのpg_store_plansはそういえば使ったことがなかった。依存している拡張機能を良くわからないままpg_plan_advsrを調べ続けるのも、ちょっと不安だったので、pg_plan_advsrの調査を続ける前に、pg_store_plansを使ってみようと思った。

pg_stat_statements自体は、以前、ちょっと使ってみたことはあるけど、pg_store_plansとの共通点も多く、またpg_store_plansとの併用もできるということで、改めて使ってみることにした。

インストール手順等はpg_plan_advsrを使ってみた(1)の記事と若干重複しているけどご容赦を。

pg_store_plans is 何？

• すごく簡単に言うと、contrib/pg_stat_statementsによく似たモジュールである。contrib/pg_stat_statementsではSQL文とその統計情報を記録するが、pg_store_plansは、実行された「ステートメントSQL文の実行計画」とその統計情報を記録する。
• PostgreSQL 9.4以降に対応。
• 単体で使うだけでなく、他の拡張モジュールを補助するもの？
  • pg_statsinfoとか
  • pg_plan_advsrとか
• contrib/auto_explainを包含しているともいえる。
• 今のところ、AWS RDS PostgreSQLや、AWS Aurora PostgreSQL互換には対応していなかった（はず）。

pg_store_plansのインストール

パッケージの入手

pg_store_plansのページを見ると、ビルド用のソースとRPM作成用のSPECファイルが置いてある。RPMファイル自体は置いていない。

ビルドインストール

今回はソースをビルドしてインストールする。
まず、pg_store_plansのインストール前にPostgreSQL本体をインストールする。詳細な手順は省略。今回はPostgreSQL 11.2をソースビルドしてインストールしている。
次に、pg_store_plansのソースコードを入手する。
リリース用のページから、ソースのソースコードのアーカイブ(tar.gz)をDLするなり、リポジトリ自体をgit cloneするなりで入手する。今回は、pg_store_plans 1.3のソースアーカイブをwgetコマンドでDLして解凍する。

$ wget https://github.com/ossc-db/pg_store_plans/archive/1.3.tar.gz
$ xfz 1.3.tar.gz

解凍したら、解凍先のフォルダに移動して、make & make installするだけ。

$ cd pg_store_plans-1.3/
$ make USE_PGXS=1
$ make USE_PGXS=1 install

ドキュメント

pg_store_plansのドキュメントは、リポジトリ内のdocフォルダ内にある。
ドキュメントの形式はMarkdownではなく、HTML形式。ブラウザで開いてみると、PostgreSQL公式文書の形式になっていることがわかる。残念ながら日本語ドキュメントはない。

ドキュメントの内容については後で説明する。

PostgreSQLサーバの環境設定

pg_store_plansを使う場合、postgresql.confのshared_preload_librariesにpg_stre_planasのモジュールを設定して、PostgreSQLサーバを起動する必要がある。

shared_preload_libraries = 'pg_store_plans'

データベースへの登録

このモジュールもshared_preload_librariesに登録するだけでなく、CREATE EXTENSIONコマンドで拡張機能をデータベースに登録する必要がある。
なお、pg_store_plans拡張機能は、データベースオーナーの権限では登録できず、特権ロールが必要になる（これは、pg_stat_statmentsも同様）。

$ psql -U user1 testdb -c "CREATE EXTENSION pg_store_plans"
ERROR:  permission denied to create extension "pg_store_plans"
HINT:  Must be superuser to create this extension.
$ psql -U postgres testdb -c "CREATE EXTENSION pg_store_plans"
CREATE EXTENSION
$

何ができるのか

ビューの提供

pg_stat_statementsと同様に、実行計画に関連する統計情報を表示するビュー(pg_store_plansビュー)を提供する。以下に、pg_store_plansビューの内容を示す。

列名	型	参照	説明
userid	oid	pg_authid.oid	文を実行したユーザのOID。
dbid	oid	pg_database.oid	文が実行されたデータベースのOID
queryid	bigint		文のクエリ文字列から計算された内部ハッシュコード。 このqueryidと、pg_stat_statementsが提供するpg_stat_statementsビューのqueryidを使って結合可能。
planid	bigint		文の解析木から計算された内部ハッシュコード
queryid_stat_statements	bigint		pg_stat_statementsのクエリハッシュコードのコピー。 これはpg_stat_statementsがインストールされている場合にのみ利用可能です。
plan	text		代表的な実行計画のテキスト。 フォーマットは設定パラメータpg_store_plans.plan_formatで指定されます。
calls	bigint		実行回数。
total_time	double precision		SQL文の処理に費やした総時間（ミリ秒単位）
rows	bigint		プランを使用している文によって取得または影響を受けた行の総数。
shared_blks_hit	bigint		プランを使用している文による共有ブロックキャッシュヒットの総数。
shared_blks_read	bigint		プランを使用している文によって読み取られた共有ブロックの合計数。
shared_blks_dirtied	bigint		プランを使用している文によってダーティにされた共有ブロックの合計数。
shared_blks_written	bigint		プランを使用している文によって書き込まれた共有ブロックの合計数。
local_blks_hit	bigint		プランを使用している文によるローカルブロックキャッシュヒットの総数。
local_blks_read	bigint		プランを使用している文によって読み取られたローカルブロックの総数。
local_blks_dirtied	bigint		プランを使用している文によってダーティにされたローカルブロックの総数。
local_blks_written	bigint		プランを使用している文によって書き込まれたローカルブロックの総数。
temp_blks_read	bigint		プランを使用している文によって読み取られた一時ブロックの合計数。
temp_blks_written	bigint		プランを使用している文によって書き込まれた一時ブロックの合計数。
blk_read_time	double precision		計画を使用している文がブロックの読取りに費やした合計時間（ミリ秒単位）（track_io_timingが有効な場合。それ以外の場合はゼロ）。
blk_write_time	double precision		その計画を使用しているステートメントがブロックの書き込みに費やした合計時間（ミリ秒単位）（track_io_timingが有効な場合、それ以外の場合はゼロ）。
first_call	timestamp with time zone		このプランを使用した、最初のクエリの呼び出しのタイムスタンプ。
last_call	timestamp with time zone		このプランを使用しているクエリの最後の呼び出しのタイムスタンプ。

なお、このビューをpsqlの\d+メタコマンドで表示してみると、pg_store_plans()関数を検索した結果をビューにしていることがわかる(なので、当然ながらpg_store_plansビューに対して更新操作はできない)。

関数

関数名	引数	返却型	説明
pg_store_plans_reset	なし	void	pg_store_plans_resetは、これまでにpg_store_plansによって収集されたすべての統計を破棄する。 デフォルトでは、スーパーユーザーだけがこの機能を実行できる。
pg_store_plans	showtext boolean	setof record	pg_store_plansビューはpg_store_plansという名前の関数で定義されています。
pg_store_hash_query	query text	oid	この関数はクエリテキストのハッシュ値を計算する。 pg_store_plansのqueryidの計算にも同じアルゴリズムが使用されているため、この関数はpg_store_plansと結合するのに使用できる。
pg_store_plans_textplan	query text	text	この関数はpg_store_plansのplanの生の表現から通常のテキスト表現を生成する。これはpg_store_plans.plan_formats = 'raw'のときにそこに表示される。 結果計画テキストはjson表現から生成されるため、 EXPLAINコマンドから直接取得するものとは多少異なる場合がある。
pg_store_plans_jsonplan	query text	text	この関数は、 "short format json plan"または "raw format"を通常のjson形式に変換します。 short format jsonはpg_store_plansのplanの内部形式である。pg_store_plans.plan_formats= 'json'のときに表示される。
pg_store_plans_xmlplan	query text	text	この関数は、pg_store_plansのplanのraw表現からXML表現を生成する。これはpg_store_plans.plan_formats = 'xml'のときに表示さされる。
pg_store_plans_yamlplan	query text	text	この関数はpg_store_plansのplanのraw表現からYAML表現を生成する。これはpg_store_plans.plan_formats = 'yaml'のときに表示される。

制御パラメータ

パラメータ名の名前空間(pg_store_plans)は省略しているので注意。

パラメータ名	型	デフォルト値	context	説明
max	integer	1000	postmaster	pg_store_plansモジュールによってトレースされる計画の最大数(すなわち、pg_store_plansビュー内の最大行数)。 それを超えた場合、最も頻度の低い実行計画に関する情報は破棄される。 デフォルト値は1000です。このパラメータはサーバ起動時にのみ設定可能。 pg_stat_statementsの同種のパラメータのデフォルトは5000なので、少し異なることに注意。
track	enum	top	superuser	pg_stat_statementsと同様に、pg_store_plans.trackはどの文がモジュールによってカウントされるかを制御する。トップレベルの文(クライアントによって直接発行されたもの)を追跡するにはtopを、関数内で呼び出された文などのネストされた文も追跡するにはallを指定し、ステートメント統計収集を無効にするにはnoneを指定する。 デフォルト値はtopである。 この設定を変更できるのはスーパーユーザーだけである。
plan_format	enum	text	user	pg_store_plansが保存している実行計画のフォーマットを制御する。 textがデフォルト値で、通常のテキスト表現で表示される。json, xml, yamlは対応するフォーマットで表示される。 rawはpg_store_plans_*関数に渡す内部表現(シンプルなJSON形式)を示す。
min_duration	integer	0	superuser	文のプランがログに記録される最小の実行時間（ミリ秒）。 これを0 (デフォルト)に設定すると、すべての実行計画がログに記録される。 この設定を変更できるのは、スーパーユーザーのみ。
log_analyze	bool	off	superuser	単なるEXPLAIN出力ではなく、EXPLAIN ANALYZE出力を(保存される)実行計画に含めるようにする。 このパラメータはデフォルトではoff。
log_buffers	bool	off	superuser	単なるEXPLAIN出力ではなく、EXPLAIN (ANALYZE、BUFFERS) 出力を実行計画に含めるようにする。 このパラメータはデフォルトではoff。
log_timing	bool	on	superuser	offに設定すると、実際のタイミングを記録できなくなる。 システムクロックを繰り返し読み取ることによるオーバーヘッドは、システムによってはクエリを大幅に遅くする可能性があるため、各実行ノードの正確な実行時間ではなく実際の行数のみが必要な場合は、このパラメータをoffに設定すると便利である。 pg_store_plans.log_analyzeがonの場合、ステートメント全体の実行時間は常に測定される。 デフォルトはon。
log_triggers	bool	off	superuser	トリガー実行の統計を記録済み実行計画に含めるようする。 pg_store_plans.log_analyzeがオンになっていない限り、このパラメータは効果はない。デフォルトはoff
verbose	bool	off	superuser	単なるEXPLAIN出力ではなく、EXPLAIN VERBOSE出力が実行計画に含まれる。 このパラメータはデフォルトではoff。
save	bool	on	sighup	サーバーのシャットダウン後に計画統計を保存するかどうかを指定する。offの場合、統計はシャットダウン時に保存されず、サーバー起動時に再ロードされません。 デフォルト値はon。 このパラメータはpostgresql.confファイルまたはサーバーのコマンドラインでのみ設定できる。

使ってみた

とりあえず、最初はデフォルト設定のままで動かしてみる。

testdb=# SELECT name, setting FROM pg_settings WHERE name LIKE 'pg_store_plans.%';
            name             | setting
-----------------------------+---------
 pg_store_plans.log_analyze  | off
 pg_store_plans.log_buffers  | off
 pg_store_plans.log_timing   | on
 pg_store_plans.log_triggers | off
 pg_store_plans.log_verbose  | off
 pg_store_plans.max          | 1000
 pg_store_plans.min_duration | 0
 pg_store_plans.plan_format  | text
 pg_store_plans.save         | on
 pg_store_plans.track        | top
(10 rows)

こういうパラメータ確認のSQLや、psql内部で発行されるキーワード/データベースオブジェクト名の補完のためのSQLも当然ながら、pg_store_plansに記録されてしまうので、一旦、pg_store_plans_reset();関数を発行してリセットしておく。

testdb=# SELECT pg_store_plans_reset();
 pg_store_plans_reset
----------------------

(1 row)

この状態で、pgbenchを動かして、ますスキーマの生成とデータベースの初期化を行う。

$ pgbench -U user1 -i -s 10 --unlogged-tables testdb -q
dropping old tables...
NOTICE:  table "pgbench_accounts" does not exist, skipping
NOTICE:  table "pgbench_branches" does not exist, skipping
NOTICE:  table "pgbench_history" does not exist, skipping
NOTICE:  table "pgbench_tellers" does not exist, skipping
creating tables...
generating data...
1000000 of 1000000 tuples (100%) done (elapsed 0.70 s, remaining 0.00 s)
vacuuming...
creating primary keys...
done.

pgbenchの初期化が終わったあとでpg_store_plansビューのうち、userid, dbid, queryid, planidのみを表示してみる。

testdb=# SELECT userid, dbid, queryid, planid FROM ``pg_store_plans``;
 userid | dbid  |  queryid   |   planid
--------+-------+------------+------------
  30351 | 30352 | 3126036813 | 4099339529
  30351 | 30352 | 1446640908 | 1861260675
     10 | 30352 | 3137955951 | 2881624998
(3 rows)

この状態で、では次にqueryidに条件をつけて検索してみる。

testdb=# SELECT queryid, plan FROM pg_store_pans WHERE queryid IN (3126036813, 1446640908);
  queryid   |                             plan
------------+---------------------------------------------------------------
 3126036813 | Insert on pgbench_tellers  (cost=0.00..0.01 rows=1 width=44) +
            |   ->  Result  (cost=0.00..0.01 rows=1 width=44)
 1446640908 | Insert on pgbench_branches  (cost=0.00..0.01 rows=1 width=40)+
            |   ->  Result  (cost=0.00..0.01 rows=1 width=40)
(2 rows)

それぞれ、pgbench_tellersとpgbench_branchesへのINSERT文の実行計画が表示される。そう、一番巨大なpgbench_accountsのCOPYはDMLではないので、記録対象外となる。

今度はpgbenchによる更新/参照を行う。pgbenchのデフォルトトランザクションが、どういったSQLを発行するのかは、pgbenchの公式ドキュメントに記載されているが、ざっと抜き出すと、

• 3種類のUPDATE
• 1種類のSELECT
• 1種類のDELETE

がpg_store_plansビューに記録されるはずである。

BEGIN;
UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
END;

では、一旦、記録された実行計画を削除し、その後にpgbenchを使って、上記のトランザクションを1000回実行してみる。

$ pgbench -U user1 -c 1 -t 1000 testdb
starting vacuum...end.
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 10
query mode: simple
number of clients: 1
number of threads: 1
number of transactions per client: 1000
number of transactions actually processed: 1000/1000
latency average = 0.909 ms
tps = 1100.143956 (including connections establishing)
tps = 1101.778674 (excluding connections establishing)

この状態で、pg_store_plansのqueryidとcallsとplanを参照する。

testdb=# SELECT queryid, calls, plan FROM pg_store_plans;
  queryid   | calls |                                                 plan
------------+-------+------------------------------------------------------------------------------------------------------
 1445217560 |  1000 | Update on pgbench_tellers  (cost=0.00..2.25 rows=1 width=106)                                       +
            |       |   ->  Seq Scan on pgbench_tellers  (cost=0.00..2.25 rows=1 width=106)                               +
            |       |         Filter: (tid = 38)
  796100257 |  1000 | Update on pgbench_accounts  (cost=0.42..8.45 rows=1 width=103)                                      +
            |       |   ->  Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.42..8.45 rows=1 width=103)+
            |       |         Index Cond: (aid = 983785)
 2767262120 |  1000 | Insert on pgbench_history  (cost=0.00..0.01 rows=1 width=56)                                        +
            |       |   ->  Result  (cost=0.00..0.01 rows=1 width=56)
  570324514 |     1 | Aggregate  (cost=1.12..1.14 rows=1 width=8)                                                         +
            |       |   ->  Seq Scan on pgbench_branches  (cost=0.00..1.10 rows=10 width=0)
 2032872830 |  1000 | Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.42..8.44 rows=1 width=4)        +
            |       |   Index Cond: (aid = 983785)
 1437714141 |  1000 | Update on pgbench_branches  (cost=0.00..1.13 rows=1 width=106)                                      +
            |       |   ->  Seq Scan on pgbench_branches  (cost=0.00..1.13 rows=1 width=106)                              +
            |       |         Filter: (bid = 6)
 3137955951 |     1 | Result  (cost=0.00..0.01 rows=1 width=4)
 4194727582 |     1 | Function Scan on pg_store_plans  (cost=0.00..10.00 rows=1000 width=40)
(8 rows)

上記の結果をざっと見てみると・・・

• queryidが、1445217560, 796100257, 2767262120, 2032872830, 1437714141のものについては想定どおり、pgbenchで発行されるDMLの実行計画が出力されている。また、実行回数もcallsに示された回数と一致している。
• queryidが570324514のものは、おそらくpgbenchの測定前にスケールファクタを算出するために、pgbench_branchesの行数を取得しているのだろう。
• queryidが3137955951のものは、これだけでは正直言ってわからん。クエリ内容を見たいなら、pg_store_plansではなく、pg_stat_statementsを組み込んで、そっちのビューを見る必要がありそうだ。

その他

pg_store_plansビューへのアクセス権限

pg_store_plansビューのうち、いくつかの列は特定の権限がないと参照することはできない。
たとえば、さっきのようにuser1というロールで実行されたDMLの実行権限は参照することができるが、それ以外のロールによって実行された場合は、一部の列が0(queryid)と表示されたり、<insufficient privilege>のようにマスクされた文字列になったりする。

$ psql -U user1 testdb
psql (11.2)
Type "help" for help.

testdb=> SELECT queryid, calls, plan FROM pg_store_plans;
  queryid   | calls |                                                 plan
------------+-------+------------------------------------------------------------------------------------------------------
 1445217560 |  1000 | Update on pgbench_tellers  (cost=0.00..2.25 rows=1 width=106)                                       +
            |       |   ->  Seq Scan on pgbench_tellers  (cost=0.00..2.25 rows=1 width=106)                               +
            |       |         Filter: (tid = 38)
  796100257 |  1000 | Update on pgbench_accounts  (cost=0.42..8.45 rows=1 width=103)                                      +
            |       |   ->  Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.42..8.45 rows=1 width=103)+
            |       |         Index Cond: (aid = 983785)
 2767262120 |  1000 | Insert on pgbench_history  (cost=0.00..0.01 rows=1 width=56)                                        +
            |       |   ->  Result  (cost=0.00..0.01 rows=1 width=56)
  570324514 |     1 | Aggregate  (cost=1.12..1.14 rows=1 width=8)                                                         +
            |       |   ->  Seq Scan on pgbench_branches  (cost=0.00..1.10 rows=10 width=0)
 2032872830 |  1000 | Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.42..8.44 rows=1 width=4)        +
            |       |   Index Cond: (aid = 983785)
 1437714141 |  1000 | Update on pgbench_branches  (cost=0.00..1.13 rows=1 width=106)                                      +
            |       |   ->  Seq Scan on pgbench_branches  (cost=0.00..1.13 rows=1 width=106)                              +
            |       |         Filter: (bid = 6)
          0 |     1 | <insufficient privilege>
          0 |     1 | <insufficient privilege>
          0 |     1 | <insufficient privilege>
(9 rows)

これらの列を表示するためには、特権ロールが必要になる(PostgreSQL 10以降に導入された、pg_read_all_statsあるいはpg_monitorロールを付与して参照できるか実験してみたがダメった・・・)。

おわりに

今回は、とりあえずインストールして動かしてみるところまでやってみた。
次回は、pg_store_plansビューの他の列の内容、pg_store_plansモジュールが提供する関数、表示フォーマットの違いなど、もう少し細かい部分を調べてまとめる予定。