pg_store_plansを使ってみた(1)

# はじめに
先日、[pg_plan_advsrを使ってみた(1)](https://qiita.com/nuko_yokohama/items/6e54b1fe412fe96c9873)という記事を書いたんだけど、その[pg_plan_advsr](https://github.com/ossc-db/pg_plan_advsr)では、[pg_hint_plan](https://github.com/ossc-db/pg_hint_plan)と[pg_store_plans](https://github.com/ossc-db/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)](https://qiita.com/nuko_yokohama/items/6e54b1fe412fe96c9873)の記事と若干重複しているけどご容赦を。

# 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](https://github.com/ossc-db/pg_store_plans)のページを見ると、ビルド用のソースとRPM作成用のSPECファイルが置いてある。RPMファイル自体は置いていない。

## ビルドインストール
今回はソースをビルドしてインストールする。
まず、pg_store_plansのインストール前にPostgreSQL本体をインストールする。詳細な手順は省略。今回はPostgreSQL 11.2をソースビルドしてインストールしている。
次に、pg_store_plansのソースコードを入手する。
[リリース用のページ](https://github.com/ossc-db/pg_store_plans/releases/tag/1.3)から、ソースのソースコードのアーカイブ(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公式文書の形式になっていることがわかる。残念ながら日本語ドキュメントはない。

<img width="494" alt="pg_store_plans_doc_image.png" src="https://qiita-image-store.s3.amazonaws.com/0/32626/9f692f75-c885-35f0-4ba4-81d6f4932479.png">

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

## 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](http://www.postgresql.org/docs/current/static/catalog-pg-authid.html)`.oid` | 文を実行したユーザのOID。                                    |
| dbid                    | oid                      | [pg_database](http://www.postgresql.org/docs/current/static/catalog-pg-database.html)`.oid` | 文が実行されたデータベースのOID                              |
| queryid                 | bigint                   |                                                              | 文のクエリ文字列から計算された内部ハッシュコード。<br />この``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です。このパラメータはサーバ起動時にのみ設定可能。<br />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``ファイルまたはサーバーのコマンドラインでのみ設定できる。 |


# 使ってみた

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

```sql
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``のみを表示してみる。

```sql

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``に条件をつけて検索してみる。

```sql

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ビューに記録されるはずである。

```sql
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を参照する。

```sql
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モジュールが提供する関数、表示フォーマットの違いなど、もう少し細かい部分を調べてまとめる予定。