「postgresql」カテゴリーアーカイブ

PostgreSQL WALの中身を表示する

この記事は【2019年10月6日】と作成から2年以上経っているため、記事の内容が古い可能性があります。最新の情報を合わせてご確認されることを推奨いたします。

PostgreSQLのWAL周りについて調べる機会がありメモ。

pg_waldump

PostgreSQLでは、WALレコードをダンプするpg_waldumpというツールが用意されています。pg_waldumpはコマンドラインツールで、引数にWALセグメントファイルを指定することで、対象のセグメントのレコードを画面にダーっと出力してくれます。WALの内部を知りたい場合、pg_waldumpは大変便利です。

例えば、こんな感じで使えます。

$ psql -d postgres
psql (12beta3)
Type "help" for help.
postgres=# select * from pg_ls_waldir() limit 1;
name           |   size   |      modification      
--------------------------+----------+------------------------
000000010000000000000004 | 16777216 | 2019-09-15 11:59:30+09
(1 row)
postgres=# \! pg_waldump pg_wal/000000010000000000000004;
rmgr: Standby     len (rec/tot):     50/    50, tx:          0, lsn: 0/04000028, prev 0/03000110, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488
rmgr: Standby     len (rec/tot):     50/    50, tx:          0, lsn: 0/04000060, prev 0/04000028, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488
rmgr: XLOG        len (rec/tot):    114/   114, tx:          0, lsn: 0/04000098, prev 0/04000060, desc: CHECKPOINT_ONLINE redo 0/4000028; tli 1; prev tli 1; fpw true; xid 0:488; oid 24576; multi 1; offset 0; oldest xid 479 in DB 1; oldest multi 1 in DB 1; oldest/newest commit timestamp xid: 0/0; oldest running xid 488; online
rmgr: Standby     len (rec/tot):     50/    50, tx:          0, lsn: 0/04000110, prev 0/04000098, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488
rmgr: Heap        len (rec/tot):     54/   150, tx:        488, lsn: 0/04000148, prev 0/04000110, desc: INSERT off 2 flags 0x00, blkref #0: rel 1663/12937/16384 blk 0 FPW
rmgr: Transaction len (rec/tot):     34/    34, tx:        488, lsn: 0/040001E0, prev 0/04000148, desc: COMMIT 2019-09-15 11:56:40.963685 JST
rmgr: Standby     len (rec/tot):     50/    50, tx:          0, lsn: 0/04000208, prev 0/040001E0, desc: RUNNING_XACTS nextXid 489 latestCompletedXid 488 oldestRunningXid 489
rmgr: XLOG        len (rec/tot):    114/   114, tx:          0, lsn: 0/04000240, prev 0/04000208, desc: CHECKPOINT_SHUTDOWN redo 0/4000240; tli 1; prev tli 1; fpw true; xid 0:489; oid 24576; multi 1; offset 0; oldest xid 479 in DB 1; oldest multi 1 in DB 1; oldest/newest commit timestamp xid: 0/0; oldest running xid 0; shutdown
rmgr: Standby     len (rec/tot):     50/    50, tx:          0, lsn: 0/040002B8, prev 0/04000240, desc: RUNNING_XACTS nextXid 489 latestCompletedXid 488 oldestRunningXid 489
rmgr: XLOG        len (rec/tot):     24/    24, tx:          0, lsn: 0/040002F0, prev 0/040002B8, desc: SWITCH

$ psql -d postgres

psql (12beta3)

Type "help" for help.

postgres=# select * from pg_ls_waldir() limit 1;

name | size | modification

--------------------------+----------+------------------------

000000010000000000000004 | 16777216 | 2019-09-15 11:59:30+09

(1 row)

postgres=# \! pg_waldump pg_wal/000000010000000000000004;

rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn: 0/04000028, prev 0/03000110, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488

rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn: 0/04000060, prev 0/04000028, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488

rmgr: XLOG len (rec/tot): 114/ 114, tx: 0, lsn: 0/04000098, prev 0/04000060, desc: CHECKPOINT_ONLINE redo 0/4000028; tli 1; prev tli 1; fpw true; xid 0:488; oid 24576; multi 1; offset 0; oldest xid 479 in DB 1; oldest multi 1 in DB 1; oldest/newest commit timestamp xid: 0/0; oldest running xid 488; online

rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn: 0/04000110, prev 0/04000098, desc: RUNNING_XACTS nextXid 488 latestCompletedXid 487 oldestRunningXid 488

rmgr: Heap len (rec/tot): 54/ 150, tx: 488, lsn: 0/04000148, prev 0/04000110, desc: INSERT off 2 flags 0x00, blkref #0: rel 1663/12937/16384 blk 0 FPW

rmgr: Transaction len (rec/tot): 34/ 34, tx: 488, lsn: 0/040001E0, prev 0/04000148, desc: COMMIT 2019-09-15 11:56:40.963685 JST

rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn: 0/04000208, prev 0/040001E0, desc: RUNNING_XACTS nextXid 489 latestCompletedXid 488 oldestRunningXid 489

rmgr: XLOG len (rec/tot): 114/ 114, tx: 0, lsn: 0/04000240, prev 0/04000208, desc: CHECKPOINT_SHUTDOWN redo 0/4000240; tli 1; prev tli 1; fpw true; xid 0:489; oid 24576; multi 1; offset 0; oldest xid 479 in DB 1; oldest multi 1 in DB 1; oldest/newest commit timestamp xid: 0/0; oldest running xid 0; shutdown

rmgr: Standby len (rec/tot): 50/ 50, tx: 0, lsn: 0/040002B8, prev 0/04000240, desc: RUNNING_XACTS nextXid 489 latestCompletedXid 488 oldestRunningXid 489

rmgr: XLOG len (rec/tot): 24/ 24, tx: 0, lsn: 0/040002F0, prev 0/040002B8, desc: SWITCH

pg_waldumpが出力する内容は以下の通りです。

rmgr	リソースマネージャの種別です。PostgreSQLでは、レコード種別ごとにレコードを処理する関数が用意されており、レコード種別で呼び分けられるようになっています。https://doxygen.postgresql.org/rmgrlist_8h_source.html
len (rec/tot)	Full-page image (FPI)を除いた長さとレコード全体長さ
tx	トランザクションID
lsn	現在読み取ったレコードのLSN
prev	１つ前のレコードのLSN
desc	リソースマネージャが出力するWALレコードに関する情報

他にもトランザクションIDを指定したり、WALの開始や終了位置を指定してダンプすることも可能です。

出力はテキスト形式ですので、コマンドラインで加工したりすることもできます。pg_waldumpを触っている中、ふとSQLでも操作できたら良いなと思い、walの読み取り方法や拡張機能の作り方の学習もかねて、walをSQLで出力できるツールwalreaderを作ってみました。この拡張機能は、あくまで学習用です。あまり慣れていないのでバグがあるかもしれません（きっと）。。

walreader

使い方は簡単です。以下で拡張機能をインストールします。

$ git clone https://github.com/moritetu/walreader.git
$ cd walreader
$ make USE_PGXS=1 install

$ git clone https://github.com/moritetu/walreader.git

$ cd walreader

$ make USE_PGXS=1 install

続いて、拡張機能を有効化して、SELECT文を実行します。

postgres=# CREATE EXTENSION walreader;
CREATE EXTENSION
postgres=# \x
Expanded display is on.
postgres=# select * from read_wal_segment('000000010000000000000016') limit 3;
WARNING:  invalid record length at 0/161D5D18: wanted 24, got 0
-[ RECORD 1 ]------------------------------------------------------
timeline  | 1
walseg    | 000000010000000000000016
seg_off   | 40
page      | 1
page_off  | 40
rmgr      | Standby
rec_len   | 50
tot_len   | 50
tot_rlen  | 56
tx        | 0
lsn       | 0/16000028
end_lsn   | 0/1600005F
prev_lsn  | 0/1501A5B0
identify  | RUNNING_XACTS
rmgr_desc | nextXid 649 latestCompletedXid 648 oldestRunningXid 649
-[ RECORD 2 ]------------------------------------------------------
timeline  | 1
walseg    | 000000010000000000000016
seg_off   | 96
page      | 1
page_off  | 96
rmgr      | Heap
rec_len   | 163
tot_len   | 163
tot_rlen  | 168
tx        | 649
lsn       | 0/16000060
end_lsn   | 0/16000107
prev_lsn  | 0/16000028
identify  | INSERT+INIT
rmgr_desc | off 1 flags 0x00
-[ RECORD 3 ]------------------------------------------------------
timeline  | 1
walseg    | 000000010000000000000016
seg_off   | 264
page      | 1
page_off  | 264
rmgr      | Transaction
rec_len   | 34
tot_len   | 34
tot_rlen  | 40
tx        | 649
lsn       | 0/16000108
end_lsn   | 0/1600012F
prev_lsn  | 0/16000060
identify  | COMMIT
rmgr_desc | 2019-09-29 01:42:47.230124+09
postgres=# select rec.* from (select name from pg_ls_waldir()) w, lateral read_wal_segment(w.name) rec; -- walディレクトリ下のwalファイルを読む

postgres=# CREATE EXTENSION walreader;

CREATE EXTENSION

postgres=# \x

Expanded display is on.

postgres=# select * from read_wal_segment('000000010000000000000016') limit 3;

WARNING: invalid record length at 0/161D5D18: wanted 24, got 0

-[ RECORD 1 ]------------------------------------------------------

timeline | 1

walseg | 000000010000000000000016

seg_off | 40

page | 1

page_off | 40

rmgr | Standby

rec_len | 50

tot_len | 50

tot_rlen | 56

tx | 0

lsn | 0/16000028

end_lsn | 0/1600005F

prev_lsn | 0/1501A5B0

identify | RUNNING_XACTS

rmgr_desc | nextXid 649 latestCompletedXid 648 oldestRunningXid 649

-[ RECORD 2 ]------------------------------------------------------

timeline | 1

walseg | 000000010000000000000016

seg_off | 96

page | 1

page_off | 96

rmgr | Heap

rec_len | 163

tot_len | 163

tot_rlen | 168

tx | 649

lsn | 0/16000060

end_lsn | 0/16000107

prev_lsn | 0/16000028

identify | INSERT+INIT

rmgr_desc | off 1 flags 0x00

-[ RECORD 3 ]------------------------------------------------------

timeline | 1

walseg | 000000010000000000000016

seg_off | 264

page | 1

page_off | 264

rmgr | Transaction

rec_len | 34

tot_len | 34

tot_rlen | 40

tx | 649

lsn | 0/16000108

end_lsn | 0/1600012F

prev_lsn | 0/16000060

identify | COMMIT

rmgr_desc | 2019-09-29 01:42:47.230124+09

postgres=# select rec.* from (select name from pg_ls_waldir()) w, lateral read_wal_segment(w.name) rec; -- walディレクトリ下のwalファイルを読む

pg_waldumpと少し出力が異なります。出力内容は以下です。

timeline	タイムラインID
walseg	walファイル名
seg_off	walファイル内での先頭からのオフセット
page	ページNo
page_off	ページ内の先頭からのオフセット
rmgr	リソースマネージャ種別
rec_len	Full-page image (FPI)を除いたレコード長
tot_len	トータルレコード長
tot_rlen	アライメントされたトータルレコード長
tx	トランザクションID
lsn	レコードの開始LSN
end_lsn	レコードの終了LSN
prev_lsn	１つ前のレコードの開始LSN
identify	リソースマネージャでの操作識別子
rmgr_desc	リソースマネージャが出力するWALレコードに関する情報

https://github.com/moritetu/walreader

出力したいwalの範囲指定も想定していますが、タイムラインなどの切り替えは考慮されていないです。

WALの構造

walの中身は以下のような感じになっているようです。

参考リンク

PostgreSQL 11に搭載されるJITコンパイラ機能を動かしてみる

コメントを残す

この記事は【2018年7月19日】と作成から2年以上経っているため、記事の内容が古い可能性があります。最新の情報を合わせてご確認されることを推奨いたします。

PostgreSQL 11から、JIT機能が追加されました。

https://www.postgresql.org/about/news/1855/

https://news.mynavi.jp/article/20180324-605157/

あまり理解できていないのですが、どんな感じで動くのか、まずは触ってみたいと思います。

導入と動作確認にあたり、以下の資料を参考にさせていただきました。

https://www.sraoss.co.jp/tech-blog/wp-content/uploads/2018/07/pg11_report-6.pdf

また、llvmについては参考リンクのページに事前に目を通しておくと、どんな事をしているのかイメージしやすいと思います。llvmのtutorialは、ざっと目を通しておくと良いかもしれません。

インストール

試してみた環境は以下です。

Mac OS X mac High Sierra 10.13.5
iMac (27-inch Late 2012) Intel Core i5 3.2GHz

llvmのインストール

PostgreSQLは、JITの実装としてデフォルトでLLVMを使用するようになっているようです。私の環境は、Homebrewを使用していますので、LLVMを以下のようにしてインストールします。

$ brew install --with-toolchain llvm

1	$ brew install --with-toolchain llvm

参考 src/backend/jit/jit.c

PostgreSQL11beta2のインストール

自作のpgenv2^[1]https://github.com/moritoru81/pgenv2でサクッとインストールします。

まず、configureオプションで--with-llvmを追加します。

$ echo "--with-llvm" | pgenv configure -e

1	$ echo "--with-llvm" \| pgenv configure -e

続いて11beta2をインストールします。

$ CC="$(brew --prefix llvm)/bin/clang" \
CXX="$(brew --prefix llvm)/bin/clang++" \
CLANG="$(brew --prefix llvm)/bin/clang" \
LLVM_CONFIG="$(brew --prefix llvm)/bin/llvm-config" \
pgenv install -f -v -d 11beta2

$ CC="$(brew --prefix llvm)/bin/clang" \

CXX="$(brew --prefix llvm)/bin/clang++" \

CLANG="$(brew --prefix llvm)/bin/clang" \

LLVM_CONFIG="$(brew --prefix llvm)/bin/llvm-config" \

pgenv install -f -v -d 11beta2

11beta2をデフォルト使用にします。

$ pgenv global 11beta2
$ psql -V
psql (PostgreSQL) 11beta2

$ pgenv global 11beta2

$ psql -V

psql (PostgreSQL) 11beta2

JITに関連するGUCs

PostgreSQL 11のソースツリーにあるsrc/backend/jit/READMEを参照すると、以下のGUCがjitの動作に関係してくるようです。テストで動作確認したい場合、以下のパラメータに小さなコスト値を設定することで、JITを発動しやすくできます。

jit	jitの有効または無効化。デフォルト`ON`（利用可能な場合）
jit_above_cost	jitコンパイル適用のコスト閾値。デフォルト`100000`
jit_optimize_above_cost	jitコンパイルされたプログラムを最適化するコスト閾値。デフォルト`500000`。
jit_inline_above_cost	jitコンパイルされたプログラムの関数や演算をインライン化するコスト閾値。デフォルト`500000`。

参考 https://www.postgresql.org/docs/11/static/runtime-config-query.html

SET jit TO on;
SET jit_above_cost TO 10;
SET jit_optimize_above_cost TO 10;
SET jit_inline_above_cost TO 10;

SET jit TO on;

SET jit_above_cost TO 10;

SET jit_optimize_above_cost TO 10;

SET jit_inline_above_cost TO 10;

参考

JITを動かしてみる

JITが活きてくるのは、CPUバウンドかつ長時間実行されるような処理、とドキュメントでも説明されています。そうでない場合は、JITコンパイルのオーバヘッドの方が大きくなってしまいます。

まずはJITが動くかクエリを実行してみます。GUCでJITが有効になるよう設定して、適当なクエリを実行してみます。演算式や関数が含まれるクエリが良いでしょう。

SET jit TO on;
SET jit_above_cost TO 10;
SET jit_optimize_above_cost TO 10;
SET jit_inline_above_cost TO 10;
DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (id int PRIMARY KEY, message text);
INSERT INTO t1 SELECT i, md5(i::text) FROM generate_series(1,10000) AS i;
explain analyze SELECT id, substring(message from 2 for 5) as msg FROM t1 WHERE id % 3 = 0;

SET jit TO on;

SET jit_above_cost TO 10;

SET jit_optimize_above_cost TO 10;

SET jit_inline_above_cost TO 10;

DROP TABLE IF EXISTS t1;

CREATE TABLE t1 (id int PRIMARY KEY, message text);

INSERT INTO t1 SELECT i, md5(i::text) FROM generate_series(1,10000) AS i;

explain analyze SELECT id, substring(message from 2 for 5) as msg FROM t1 WHERE id % 3 = 0;

上記のクエリを実行してみます。explainすると、JIT…という記述があるのが分かります。

$ psql -a -d postgres -f jit-test.sql 
SET jit TO on;
SET
SET jit_above_cost TO 10;
SET
SET jit_optimize_above_cost TO 10;
SET
SET jit_inline_above_cost TO 10;
SET
DROP TABLE IF EXISTS t1;
DROP TABLE
CREATE TABLE t1 (id int PRIMARY KEY, message text);
CREATE TABLE
INSERT INTO t1 SELECT i, md5(i::text) FROM generate_series(1,10000) AS i;
INSERT 0 10000
explain analyze SELECT id, substring(message from 2 for 5) as msg FROM t1 WHERE id % 3 = 0;
QUERY PLAN                                              
-----------------------------------------------------------------------------------------------------
Seq Scan on t1  (cost=0.00..244.15 rows=53 width=36) (actual time=41.886..43.290 rows=3333 loops=1)
Filter: ((id % 3) = 0)
Rows Removed by Filter: 6667
Planning Time: 0.156 ms
JIT:
Functions: 4
Generation Time: 0.747 ms
Inlining: true
Inlining Time: 8.330 ms
Optimization: true
Optimization Time: 22.257 ms
Emission Time: 11.185 ms
Execution Time: 44.248 ms
(13 rows)

$ psql -a -d postgres -f jit-test.sql

SET jit TO on;

SET

SET jit_above_cost TO 10;

SET

SET jit_optimize_above_cost TO 10;

SET

SET jit_inline_above_cost TO 10;

SET

DROP TABLE IF EXISTS t1;

DROP TABLE

CREATE TABLE t1 (id int PRIMARY KEY, message text);

CREATE TABLE

INSERT INTO t1 SELECT i, md5(i::text) FROM generate_series(1,10000) AS i;

INSERT 0 10000

explain analyze SELECT id, substring(message from 2 for 5) as msg FROM t1 WHERE id % 3 = 0;

QUERY PLAN

-----------------------------------------------------------------------------------------------------

Seq Scan on t1 (cost=0.00..244.15 rows=53 width=36) (actual time=41.886..43.290 rows=3333 loops=1)

Filter: ((id % 3) = 0)

Rows Removed by Filter: 6667

Planning Time: 0.156 ms

JIT:

Functions: 4

Generation Time: 0.747 ms

Inlining: true

Inlining Time: 8.330 ms

Optimization: true

Optimization Time: 22.257 ms

Emission Time: 11.185 ms

Execution Time: 44.248 ms

(13 rows)

次は、JITコンパイルの効果が出ているのがわかるように、もう少し複雑なクエリを実行してみます。（実行するクエリは、参考資料と同様、実際には大容量のデータの入ったテーブルを準備するのでなく、実行時にタプルを生成するようにしています）

$ psql -a -d postgres -f jit-test2.sql 
SET jit_above_cost TO 0;
SET
SET jit_optimize_above_cost TO 0;
SET
SET jit_inline_above_cost TO 0;
SET
CREATE OR REPLACE FUNCTION bigtable() RETURNS SETOF bigint ROWS 100000000
LANGUAGE sql AS $$
SELECT i from generate_series(1, 100000000::bigint) AS i;
$$;
CREATE FUNCTION
------------- Test1 -------------
-- JIT off
SET jit TO off;
SET
explain analyze
SELECT i + 1
FROM bigtable() AS i;
QUERY PLAN                                                               
---------------------------------------------------------------------------------------------------------------------------------------
Function Scan on bigtable i  (cost=0.25..1250000.25 rows=100000000 width=8) (actual time=30235.864..44473.956 rows=100000000 loops=1)
Planning Time: 0.112 ms
Execution Time: 49630.957 ms
(3 rows)
-- JIT on
SET jit TO on;
SET
explain analyze
SELECT i + 1
FROM bigtable() AS i;
QUERY PLAN                                                               
---------------------------------------------------------------------------------------------------------------------------------------
Function Scan on bigtable i  (cost=0.25..1250000.25 rows=100000000 width=8) (actual time=29792.983..42322.049 rows=100000000 loops=1)
Planning Time: 0.040 ms
JIT:
Functions: 2
Generation Time: 0.414 ms
Inlining: true
Inlining Time: 7.773 ms
Optimization: true
Optimization Time: 10.477 ms
Emission Time: 5.095 ms
Execution Time: 47463.748 ms
(11 rows)
------------- Test2 -------------
-- JIT off
SET jit TO off;
SET
explain analyze
SELECT i, random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50)))
FROM bigtable() AS i;
QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
Function Scan on bigtable i  (cost=0.25..6000000.25 rows=100000000 width=16) (actual time=29855.820..63744.774 rows=100000000 loops=1)
Planning Time: 0.055 ms
Execution Time: 68899.182 ms
(3 rows)
-- JIT on
SET jit TO on;
SET
explain analyze
SELECT i, random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50)))
FROM bigtable() AS i;
QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
Function Scan on bigtable i  (cost=0.25..6000000.25 rows=100000000 width=16) (actual time=29844.647..55540.690 rows=100000000 loops=1)
Planning Time: 0.049 ms
JIT:
Functions: 2
Generation Time: 0.685 ms
Inlining: true
Inlining Time: 5.877 ms
Optimization: true
Optimization Time: 25.856 ms
Emission Time: 24.207 ms
Execution Time: 60690.048 ms
(11 rows)
------------- Test3 -------------
-- JIT off
SET jit TO off;
SET
explain analyze
SELECT (i % 3) AS G, sum(random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50))))
FROM bigtable() AS i
WHERE i % 3 = 0
GROUP BY G;
QUERY PLAN                                                                
------------------------------------------------------------------------------------------------------------------------------------------
GroupAggregate  (cost=0.25..1528752.75 rows=200 width=16) (actual time=54172.701..54172.701 rows=1 loops=1)
Group Key: (i % '3'::bigint)
->  Function Scan on bigtable i  (cost=0.25..1501250.25 rows=500000 width=16) (actual time=29738.813..43309.330 rows=33333333 loops=1)
Filter: ((i % '3'::bigint) = 0)
Rows Removed by Filter: 66666667
Planning Time: 1.470 ms
Execution Time: 54232.246 ms
(7 rows)
-- JIT on
SET jit TO on;
SET
explain analyze
SELECT (i % 3) AS G, sum(random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50))))
FROM bigtable() AS i
WHERE i % 3 = 0
GROUP BY G;
QUERY PLAN                                                                
------------------------------------------------------------------------------------------------------------------------------------------
GroupAggregate  (cost=0.25..1528752.75 rows=200 width=16) (actual time=48123.079..48123.079 rows=1 loops=1)
Group Key: (i % '3'::bigint)
->  Function Scan on bigtable i  (cost=0.25..1501250.25 rows=500000 width=16) (actual time=30027.104..41229.939 rows=33333333 loops=1)
Filter: ((i % '3'::bigint) = 0)
Rows Removed by Filter: 66666667
Planning Time: 0.089 ms
JIT:
Functions: 11
Generation Time: 1.914 ms
Inlining: true
Inlining Time: 12.941 ms
Optimization: true
Optimization Time: 67.625 ms
Emission Time: 44.255 ms
Execution Time: 48204.660 ms
(15 rows)

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

128

$ psql -a -d postgres -f jit-test2.sql

SET jit_above_cost TO 0;

SET

SET jit_optimize_above_cost TO 0;

SET

SET jit_inline_above_cost TO 0;

SET

CREATE OR REPLACE FUNCTION bigtable() RETURNS SETOF bigint ROWS 100000000

LANGUAGE sql AS $$

SELECT i from generate_series(1, 100000000::bigint) AS i;

$$;

CREATE FUNCTION

------------- Test1 -------------

-- JIT off

SET jit TO off;

SET

explain analyze

SELECT i + 1

FROM bigtable() AS i;

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------

Function Scan on bigtable i (cost=0.25..1250000.25 rows=100000000 width=8) (actual time=30235.864..44473.956 rows=100000000 loops=1)

Planning Time: 0.112 ms

Execution Time: 49630.957 ms

(3 rows)

-- JIT on

SET jit TO on;

SET

explain analyze

SELECT i + 1

FROM bigtable() AS i;

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------

Function Scan on bigtable i (cost=0.25..1250000.25 rows=100000000 width=8) (actual time=29792.983..42322.049 rows=100000000 loops=1)

Planning Time: 0.040 ms

JIT:

Functions: 2

Generation Time: 0.414 ms

Inlining: true

Inlining Time: 7.773 ms

Optimization: true

Optimization Time: 10.477 ms

Emission Time: 5.095 ms

Execution Time: 47463.748 ms

(11 rows)

------------- Test2 -------------

-- JIT off

SET jit TO off;

SET

explain analyze

SELECT i, random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50)))

FROM bigtable() AS i;

QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------

Function Scan on bigtable i (cost=0.25..6000000.25 rows=100000000 width=16) (actual time=29855.820..63744.774 rows=100000000 loops=1)

Planning Time: 0.055 ms

Execution Time: 68899.182 ms

(3 rows)

-- JIT on

SET jit TO on;

SET

explain analyze

SELECT i, random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50)))

FROM bigtable() AS i;

QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------

Function Scan on bigtable i (cost=0.25..6000000.25 rows=100000000 width=16) (actual time=29844.647..55540.690 rows=100000000 loops=1)

Planning Time: 0.049 ms

JIT:

Functions: 2

Generation Time: 0.685 ms

Inlining: true

Inlining Time: 5.877 ms

Optimization: true

Optimization Time: 25.856 ms

Emission Time: 24.207 ms

Execution Time: 60690.048 ms

(11 rows)

------------- Test3 -------------

-- JIT off

SET jit TO off;

SET

explain analyze

SELECT (i % 3) AS G, sum(random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50))))

FROM bigtable() AS i

WHERE i % 3 = 0

GROUP BY G;

QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------

GroupAggregate (cost=0.25..1528752.75 rows=200 width=16) (actual time=54172.701..54172.701 rows=1 loops=1)

Group Key: (i % '3'::bigint)

-> Function Scan on bigtable i (cost=0.25..1501250.25 rows=500000 width=16) (actual time=29738.813..43309.330 rows=33333333 loops=1)

Filter: ((i % '3'::bigint) = 0)

Rows Removed by Filter: 66666667

Planning Time: 1.470 ms

Execution Time: 54232.246 ms

(7 rows)

-- JIT on

SET jit TO on;

SET

explain analyze

SELECT (i % 3) AS G, sum(random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50))))

FROM bigtable() AS i

WHERE i % 3 = 0

GROUP BY G;

QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------

GroupAggregate (cost=0.25..1528752.75 rows=200 width=16) (actual time=48123.079..48123.079 rows=1 loops=1)

Group Key: (i % '3'::bigint)

-> Function Scan on bigtable i (cost=0.25..1501250.25 rows=500000 width=16) (actual time=30027.104..41229.939 rows=33333333 loops=1)

Filter: ((i % '3'::bigint) = 0)

Rows Removed by Filter: 66666667

Planning Time: 0.089 ms

JIT:

Functions: 11

Generation Time: 1.914 ms

Inlining: true

Inlining Time: 12.941 ms

Optimization: true

Optimization Time: 67.625 ms

Emission Time: 44.255 ms

Execution Time: 48204.660 ms

(15 rows)

私の環境では、結果は以下のようでした（本来は、複数回の計測を行ないばらつきを考慮すべきですが、以下では簡単のため省略しています）

Test	クエリ	Execution Time (msec)
Test	クエリ	JIT OFF	JIT ON
1	SELECT i + 1 FROM bigtable() AS i;	49630.957	47463.748
2	SELECT i, random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50))) FROM bigtable() AS i;	68899.182	60690.048
3	SELECT (i % 3) AS G, sum(random() * pi() * exp(i % 2) + log(i % 100 + random() + 1) + sqrt(round(log(i % 100 + 50)))) FROM bigtable() AS i WHERE i % 3 = 0 GROUP BY G;	54232.246	48204.660

Test1は、単純な加算処理ですが、演算対象の行数が多いためか、JITがONの場合には多少の改善が見られました。

Test2・3では、関数と演算を組み合わせてみましたが、数秒程度の改善が見られました。

厳密なベンチではないので適正な評価はできませんが、どのようなケースでJITが有効か、ざっと雰囲気は掴めたような気がします。

JIT機能を少し追ってみる

『PostgreSQLのJITは、どのような仕組みなのだろうか？』、ざっと雰囲気が掴めたら、次は内部を知りたくなってきます。あまり深いところまで追いきれていませんが、入り口部分を覗いて見ました。

JITプロバイダ

PostgreSQLでは、JIT機能のデフォルト実装はLLVMとなっているが、他のJIT実装も可能なよう設計されている（といっても、私はLLVM以外であまり知りません。。）。

参考 src/backend/jit/jit.c

変数jit_providerで指定される動的ライブラリをロードし、実装ごとの_PG_jit_provider_init関数内でJitProviderCallbacks構造体オブジェクトの関数ポインタに実装ごとの関数のアドレスが登録される。デフォルト実装はLLVMであるが、LLVMの場合はllvmjit.cに_PG_jit_provider_init定義がある。

参考 src/backend/jit/llvm/llvmjit.c

JITプロバイダの初期化は、SQL関数を呼ぶことによって明示的に初期化することもできる。以下を実行すると、backendプロセスで、jit_providerで指定される動的モジュールをロードすることができる。

$ psql
psql (11beta2)
Type "help" for help.
postgres=# set client_min_messages to DEBUG1;
SET
postgres=# select pg_jit_available();
DEBUG:  probing availability of JIT provider at /Users/guests/workspace/github/pgenv2/versions/11beta2/lib/postgresql/llvmjit.so
DEBUG:  successfully loaded JIT provider in current session
pg_jit_available 
------------------
t
(1 row)

$ psql

psql (11beta2)

Type "help" for help.

postgres=# set client_min_messages to DEBUG1;

SET

postgres=# select pg_jit_available();

DEBUG: probing availability of JIT provider at /Users/guests/workspace/github/pgenv2/versions/11beta2/lib/postgresql/llvmjit.so

DEBUG: successfully loaded JIT provider in current session

pg_jit_available

------------------

(1 row)

pg_jit_available関数の呼び出し前後で、lldbで動的ライブラリの適当なシンボルが見えるか確認してみる。以下は、LLVMCreateBuilder関数が見えるかbackendプロセスにアタッチして調べた例である。pg_jit_available関数からprovider_init関数が呼ばれ、llvmjit.soがロードされたことがわかる。

(lldb) image lookup -r -n LLVMCreateBuilder
# provider_init()呼び出し前は、シンボル見つからず
(lldb) image lookup -r -n LLVMCreateBuilder
2 matches found in /Users/guests/workspace/github/pgenv2/versions/11beta2/lib/postgresql/llvmjit.so:
Address: llvmjit.so[0x0000000000ad3a78] (llvmjit.so.__TEXT.__text + 11347560)
Summary: llvmjit.so`LLVMCreateBuilder        Address: llvmjit.so[0x0000000000ad3a3c] (llvmjit.so.__TEXT.__text + 11347500)
Summary: llvmjit.so`LLVMCreateBuilderInContext

(lldb) image lookup -r -n LLVMCreateBuilder

# provider_init()呼び出し前は、シンボル見つからず

(lldb) image lookup -r -n LLVMCreateBuilder

2 matches found in /Users/guests/workspace/github/pgenv2/versions/11beta2/lib/postgresql/llvmjit.so:

Address: llvmjit.so[0x0000000000ad3a78] (llvmjit.so.__TEXT.__text + 11347560)

Summary: llvmjit.so`LLVMCreateBuilder Address: llvmjit.so[0x0000000000ad3a3c] (llvmjit.so.__TEXT.__text + 11347500)

Summary: llvmjit.so`LLVMCreateBuilderInContext

JITの対象

PostgreSQLでは、JIT機能はbackendプロセスで動作し、JITコンパイルの対象は以下となっている。

expression evaluation
1. WHERE句、ターゲットリスト、集約、射影などの式評価
tuple deforming
1. ディスク上のタプル表現のインメモリ表現への変換

参考 https://www.postgresql.org/docs/11/static/jit-reason.html#JIT-ACCELERATED-OPERATIONS

JIT Contextと生成されるコード

以降はLLVMを前提で記述する。

JITコンパイルのエントリーポイントは、jit_compile_expr関数である。

１.expression evaluationでは、LLVM IRでevalexpr_<module_generation>_<counter>という関数が生成される。module_generationは、LLVMモジュールの生成数（名前はpg）、counterはオブジェクトの出力回数であり、これらの変数はLLVMJitContext構造体で定義されている。

参考 src/backend/jit/llvm/llvmjit_expr.c

2. tuple deformingでは、LLVM IRでdeform_<module_generation>_<counter>という関数が生成される。

参考 src/backend/jit/llvm/llvmjit_deform.c

LLVMJitContextは、plan実行時に作成され、トランザクションの終わりで解放される。

参考 src/backend/executor/execMain.c

1、2で生成されるLLVM IRをみるには、jit_dump_bitcodeパラメータをonにすればよい。パラメータをonにして、JITが働くクエリを実行すると、pgdata下に.bcファイルが生成される。.llで人が読める形式に変換するにはllvm-disを実行する。

試しに以下のようなクエリを実行してみる。

postgres=# set jit_dump_bitcode to on;
SET
postgres=# select abs(-100);
abs 
-----
100
(1 row)

postgres=# set jit_dump_bitcode to on;

SET

postgres=# select abs(-100);

abs

-----

100

(1 row)

私の実行した環境では、以下のファイルが生成された。

90645.14.bc
90645.14.optimized.bc

optimizedは最適化されたビットコードである。90645.14.bcをllvm-disでテキストとして読めるLLVM IR形式に変換してみた結果が以下である。

最初の%で始まる定義は、型定義である。LLVM IRでは、%で始まる名前はローカル識別子、@で始まる名前はグローバル識別子を示している^[2]https://llvm.org/docs/LangRef.html#identifiers。

$ llvm-dis 90645.14.bc
$ cat 90645.14.ll
; ModuleID = '90645.14.bc'
source_filename = "pg"
target datalayout = "e-m:o-i64:64-f80:128-n8:16:32:64-S128"
target triple = "x86_64-apple-macosx10.13.0"
%struct.ExprState = type { %struct.Node, i8, i8, i64, %struct.TupleTableSlot*, %struct.ExprEvalStep*, i64 (%struct.ExprState*, %struct.ExprContext*, i8*)*, %struct.Expr*, i8*, i32, i32, %struct.PlanState*, %struct.ParamListInfoData*, i64*, i8*, i64*, i8* }
%struct.Node = type { i32 }
%struct.TupleTableSlot = type { i32, i8, i8, i8, i8, %struct.HeapTupleData*, %struct.tupleDesc*, %struct.MemoryContextData*, i32, i32, i64*, i8*, %struct.MinimalTupleData*, %struct.HeapTupleData, i32, i8 }
%struct.tupleDesc = type { i32, i32, i32, i8, i32, %struct.tupleConstr*, [0 x %struct.FormData_pg_attribute] }
%struct.tupleConstr = type { %struct.attrDefault*, %struct.constrCheck*, %struct.attrMissing*, i16, i16, i8 }
%struct.attrDefault = type { i16, i8* }
%struct.constrCheck = type { i8*, i8*, i8, i8 }
%struct.attrMissing = type opaque
%struct.FormData_pg_attribute = type { i32, %struct.nameData, i32, i32, i16, i16, i32, i32, i32, i8, i8, i8, i8, i8, i8, i8, i8, i8, i32, i32 }
%struct.nameData = type { [64 x i8] }
%struct.MemoryContextData = type { i32, i8, i8, %struct.MemoryContextMethods*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.MemoryContextData*, i8*, i8*, %struct.MemoryContextCallback* }
%struct.MemoryContextMethods = type { i8* (%struct.MemoryContextData*, i64)*, void (%struct.MemoryContextData*, i8*)*, i8* (%struct.MemoryContextData*, i8*, i64)*, void (%struct.MemoryContextData*)*, void (%struct.MemoryContextData*)*, i64 (%struct.MemoryContextData*, i8*)*, i1 (%struct.MemoryContextData*)*, void (%struct.MemoryContextData*, void (%struct.MemoryContextData*, i8*, i8*)*, i8*, %struct.MemoryContextCounters*)* }
%struct.MemoryContextCounters = type { i64, i64, i64, i64 }
%struct.MemoryContextCallback = type { void (i8*)*, i8*, %struct.MemoryContextCallback* }
%struct.MinimalTupleData = type { i32, [6 x i8], i16, i16, i8, [0 x i8] }
%struct.HeapTupleData = type { i32, %struct.ItemPointerData, i32, %struct.HeapTupleHeaderData* }
%struct.ItemPointerData = type { %struct.BlockIdData, i16 }
%struct.BlockIdData = type { i16, i16 }
%struct.HeapTupleHeaderData = type { %union.anon, %struct.ItemPointerData, i16, i16, i8, [0 x i8] }
%union.anon = type { %struct.HeapTupleFields }
%struct.HeapTupleFields = type { i32, i32, %union.anon.0 }
%union.anon.0 = type { i32 }
%struct.ExprEvalStep = type { i64, i64*, i8*, %union.anon.1 }
%union.anon.1 = type { %struct.anon.25 }
%struct.anon.25 = type { i64*, i8*, i32, i32, %struct.FmgrInfo*, %struct.FunctionCallInfoData* }
%struct.FmgrInfo = type { {}*, i32, i16, i8, i8, i8, i8*, %struct.MemoryContextData*, %struct.Node* }
%struct.FunctionCallInfoData = type { %struct.FmgrInfo*, %struct.Node*, %struct.Node*, i32, i8, i16, [100 x i64], [100 x i8] }
%struct.Expr = type { i32 }
%struct.PlanState = type { i32, %struct.Plan*, %struct.EState*, %struct.TupleTableSlot* (%struct.PlanState*)*, %struct.TupleTableSlot* (%struct.PlanState*)*, %struct.Instrumentation*, %struct.WorkerInstrumentation*, %struct.ExprState*, %struct.PlanState*, %struct.PlanState*, %struct.List*, %struct.List*, %struct.Bitmapset*, %struct.TupleTableSlot*, %struct.ExprContext*, %struct.ProjectionInfo*, %struct.tupleDesc* }
%struct.Plan = type { i32, double, double, double, i32, i8, i8, i32, %struct.List*, %struct.List*, %struct.Plan*, %struct.Plan*, %struct.List*, %struct.Bitmapset*, %struct.Bitmapset* }
%struct.EState = type { i32, i32, %struct.SnapshotData*, %struct.SnapshotData*, %struct.List*, %struct.PlannedStmt*, i8*, %struct.JunkFilter*, i32, %struct.ResultRelInfo*, i32, %struct.ResultRelInfo*, %struct.ResultRelInfo*, i32, %struct.List*, %struct.List*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.ParamListInfoData*, %struct.ParamExecData*, %struct.QueryEnvironment*, %struct.MemoryContextData*, %struct.List*, %struct.List*, i64, i32, i32, i32, i8, %struct.List*, %struct.List*, %struct.List*, %struct.ExprContext*, %struct.HeapTupleData**, i8*, i8*, i8, %struct.dsa_area*, i32, %struct.JitContext* }
%struct.SnapshotData = type { i1 (%struct.HeapTupleData*, %struct.SnapshotData*, i32)*, i32, i32, i32*, i32, i32*, i32, i8, i8, i8, i32, i32, i32, i32, %struct.pairingheap_node, i64, i64 }
%struct.pairingheap_node = type { %struct.pairingheap_node*, %struct.pairingheap_node*, %struct.pairingheap_node* }
%struct.PlannedStmt = type { i32, i32, i64, i8, i8, i8, i8, i8, i8, i32, %struct.Plan*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.Bitmapset*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.Node*, i32, i32 }
%struct.JunkFilter = type { i32, %struct.List*, %struct.tupleDesc*, i16*, %struct.TupleTableSlot*, i16 }
%struct.ResultRelInfo = type { i32, i32, %struct.RelationData*, i32, %struct.RelationData**, %struct.IndexInfo**, %struct.TriggerDesc*, %struct.FmgrInfo*, %struct.ExprState**, %struct.Instrumentation*, %struct.FdwRoutine*, i8*, i8, %struct.List*, %struct.List*, %struct.ExprState**, %struct.JunkFilter*, %struct.List*, %struct.ProjectionInfo*, %struct.List*, %struct.OnConflictSetState*, %struct.List*, %struct.ExprState*, %struct.RelationData*, i8 }
%struct.IndexInfo = type { i32, i32, i32, [32 x i16], %struct.List*, %struct.List*, %struct.List*, %struct.ExprState*, i32*, i32*, i16*, i32*, i32*, i16*, i8, i8, i8, i8, i32, i32, i8*, %struct.MemoryContextData* }
%struct.TriggerDesc = type { %struct.Trigger*, i32, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8 }
%struct.Trigger = type { i32, i8*, i32, i16, i8, i8, i32, i32, i32, i8, i8, i16, i16, i16*, i8**, i8*, i8*, i8* }
%struct.FdwRoutine = type opaque
%struct.OnConflictSetState = type { i32, %struct.ProjectionInfo*, %struct.tupleDesc*, %struct.ExprState* }
%struct.RelationData = type opaque
%struct.ParamExecData = type { i8*, i64, i8 }
%struct.QueryEnvironment = type opaque
%struct.dsa_area = type opaque
%struct.JitContext = type opaque
%struct.Instrumentation = type { i8, i8, i8, %struct.timespec, %struct.timespec, double, double, %struct.BufferUsage, double, double, double, double, double, double, double, %struct.BufferUsage }
%struct.timespec = type { i64, i64 }
%struct.BufferUsage = type { i64, i64, i64, i64, i64, i64, i64, i64, i64, i64, %struct.timespec, %struct.timespec }
%struct.WorkerInstrumentation = type { i32, [0 x %struct.Instrumentation] }
%struct.List = type { i32, i32, %struct.ListCell*, %struct.ListCell* }
%struct.ListCell = type { %union.anon.4, %struct.ListCell* }
%union.anon.4 = type { i8* }
%struct.Bitmapset = type { i32, [0 x i32] }
%struct.ProjectionInfo = type { i32, %struct.ExprState, %struct.ExprContext* }
%struct.ParamListInfoData = type { %struct.ParamExternData* (%struct.ParamListInfoData*, i32, i1, %struct.ParamExternData*)*, i8*, void (%struct.ParamListInfoData*, %struct.Param*, %struct.ExprState*, i64*, i8*)*, i8*, void (%struct.ParseState*, i8*)*, i8*, i32, [0 x %struct.ParamExternData] }
%struct.ParamExternData = type { i64, i8, i16, i32 }
%struct.Param = type { %struct.Expr, i32, i32, i32, i32, i32, i32 }
%struct.ParseState = type opaque
%struct.ExprContext = type { i32, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.ParamExecData*, %struct.ParamListInfoData*, i64*, i8*, i64, i8, i64, i8, %struct.EState*, %struct.ExprContext_CB* }
%struct.ExprContext_CB = type { %struct.ExprContext_CB*, void (i64)*, i64 }
; Function Attrs: norecurse nounwind ssp uwtable
define i64 @evalexpr_14_0(%struct.ExprState*, %struct.ExprContext*, i1*) #0 {
entry:
%v.state.resvalue = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 3
%v.state.resnull = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 2
%3 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 1
%v_scanslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %3
%4 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 2
%v_innerslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %4
%5 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 3
%v_outerslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %5
%6 = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 4
%v_resultslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %6
%7 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_scanslot, i32 0, i32 10
%v_scanvalues = load i64*, i64** %7
%8 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_scanslot, i32 0, i32 11
%v_scannulls = load i8*, i8** %8
%9 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_innerslot, i32 0, i32 10
%v_innervalues = load i64*, i64** %9
%10 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_innerslot, i32 0, i32 11
%v_innernulls = load i8*, i8** %10
%11 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_outerslot, i32 0, i32 10
%v_outervalues = load i64*, i64** %11
%12 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_outerslot, i32 0, i32 11
%v_outernulls = load i8*, i8** %12
%13 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_resultslot, i32 0, i32 10
%v_resultvalues = load i64*, i64** %13
%14 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_resultslot, i32 0, i32 11
%v_resultnulls = load i8*, i8** %14
%15 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 8
%v.econtext.aggvalues = load i64*, i64** %15
%16 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 9
%v.econtext.aggnulls = load i8*, i8** %16
br label %b.op.0.start
b.op.0.start:                                     ; preds = %entry
store i64 100, i64* inttoptr (i64 140524024251152 to i64*)
store i8 0, i8* inttoptr (i64 140524024251149 to i8*)
br label %b.op.1.start
b.op.1.start:                                     ; preds = %b.op.0.start
%17 = load i64, i64* %v.state.resvalue
%18 = load i8, i8* %v.state.resnull
%19 = getelementptr i64, i64* %v_resultvalues, i32 0
%20 = getelementptr i8, i8* %v_resultnulls, i32 0
store i64 %17, i64* %19
store i8 %18, i8* %20
br label %b.op.2.start
b.op.2.start:                                     ; preds = %b.op.1.start
%21 = load i64, i64* %v.state.resvalue
%22 = load i8, i8* %v.state.resnull
%23 = trunc i8 %22 to i1
store i1 %23, i1* %2
ret i64 %21
}
attributes #0 = { norecurse nounwind ssp uwtable "correctly-rounded-divide-sqrt-fp-math"="false" "disable-tail-calls"="false" "less-precise-fpmad"="false" "no-frame-pointer-elim"="true" "no-frame-pointer-elim-non-leaf" "no-infs-fp-math"="false" "no-jump-tables"="false" "no-nans-fp-math"="false" "no-signed-zeros-fp-math"="false" "no-trapping-math"="false" "stack-protector-buffer-size"="8" "target-cpu"="penryn" "target-features"="+cx16,+fxsr,+mmx,+sahf,+sse,+sse2,+sse3,+sse4.1,+ssse3,+x87" "unsafe-fp-math"="false" "use-soft-float"="false" }

100

101

102

103

104

105

106

107

108

109

110

111

112

113

114

115

116

117

118

119

120

121

122

123

124

125

126

127

$ llvm-dis 90645.14.bc

$ cat 90645.14.ll

; ModuleID = '90645.14.bc'

source_filename = "pg"

target datalayout = "e-m:o-i64:64-f80:128-n8:16:32:64-S128"

target triple = "x86_64-apple-macosx10.13.0"

%struct.ExprState = type { %struct.Node, i8, i8, i64, %struct.TupleTableSlot*, %struct.ExprEvalStep*, i64 (%struct.ExprState*, %struct.ExprContext*, i8*)*, %struct.Expr*, i8*, i32, i32, %struct.PlanState*, %struct.ParamListInfoData*, i64*, i8*, i64*, i8* }

%struct.Node = type { i32 }

%struct.TupleTableSlot = type { i32, i8, i8, i8, i8, %struct.HeapTupleData*, %struct.tupleDesc*, %struct.MemoryContextData*, i32, i32, i64*, i8*, %struct.MinimalTupleData*, %struct.HeapTupleData, i32, i8 }

%struct.tupleDesc = type { i32, i32, i32, i8, i32, %struct.tupleConstr*, [0 x %struct.FormData_pg_attribute] }

%struct.tupleConstr = type { %struct.attrDefault*, %struct.constrCheck*, %struct.attrMissing*, i16, i16, i8 }

%struct.attrDefault = type { i16, i8* }

%struct.constrCheck = type { i8*, i8*, i8, i8 }

%struct.attrMissing = type opaque

%struct.FormData_pg_attribute = type { i32, %struct.nameData, i32, i32, i16, i16, i32, i32, i32, i8, i8, i8, i8, i8, i8, i8, i8, i8, i32, i32 }

%struct.nameData = type { [64 x i8] }

%struct.MemoryContextData = type { i32, i8, i8, %struct.MemoryContextMethods*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.MemoryContextData*, i8*, i8*, %struct.MemoryContextCallback* }

%struct.MemoryContextMethods = type { i8* (%struct.MemoryContextData*, i64)*, void (%struct.MemoryContextData*, i8*)*, i8* (%struct.MemoryContextData*, i8*, i64)*, void (%struct.MemoryContextData*)*, void (%struct.MemoryContextData*)*, i64 (%struct.MemoryContextData*, i8*)*, i1 (%struct.MemoryContextData*)*, void (%struct.MemoryContextData*, void (%struct.MemoryContextData*, i8*, i8*)*, i8*, %struct.MemoryContextCounters*)* }

%struct.MemoryContextCounters = type { i64, i64, i64, i64 }

%struct.MemoryContextCallback = type { void (i8*)*, i8*, %struct.MemoryContextCallback* }

%struct.MinimalTupleData = type { i32, [6 x i8], i16, i16, i8, [0 x i8] }

%struct.HeapTupleData = type { i32, %struct.ItemPointerData, i32, %struct.HeapTupleHeaderData* }

%struct.ItemPointerData = type { %struct.BlockIdData, i16 }

%struct.BlockIdData = type { i16, i16 }

%struct.HeapTupleHeaderData = type { %union.anon, %struct.ItemPointerData, i16, i16, i8, [0 x i8] }

%union.anon = type { %struct.HeapTupleFields }

%struct.HeapTupleFields = type { i32, i32, %union.anon.0 }

%union.anon.0 = type { i32 }

%struct.ExprEvalStep = type { i64, i64*, i8*, %union.anon.1 }

%union.anon.1 = type { %struct.anon.25 }

%struct.anon.25 = type { i64*, i8*, i32, i32, %struct.FmgrInfo*, %struct.FunctionCallInfoData* }

%struct.FmgrInfo = type { {}*, i32, i16, i8, i8, i8, i8*, %struct.MemoryContextData*, %struct.Node* }

%struct.FunctionCallInfoData = type { %struct.FmgrInfo*, %struct.Node*, %struct.Node*, i32, i8, i16, [100 x i64], [100 x i8] }

%struct.Expr = type { i32 }

%struct.PlanState = type { i32, %struct.Plan*, %struct.EState*, %struct.TupleTableSlot* (%struct.PlanState*)*, %struct.TupleTableSlot* (%struct.PlanState*)*, %struct.Instrumentation*, %struct.WorkerInstrumentation*, %struct.ExprState*, %struct.PlanState*, %struct.PlanState*, %struct.List*, %struct.List*, %struct.Bitmapset*, %struct.TupleTableSlot*, %struct.ExprContext*, %struct.ProjectionInfo*, %struct.tupleDesc* }

%struct.Plan = type { i32, double, double, double, i32, i8, i8, i32, %struct.List*, %struct.List*, %struct.Plan*, %struct.Plan*, %struct.List*, %struct.Bitmapset*, %struct.Bitmapset* }

%struct.EState = type { i32, i32, %struct.SnapshotData*, %struct.SnapshotData*, %struct.List*, %struct.PlannedStmt*, i8*, %struct.JunkFilter*, i32, %struct.ResultRelInfo*, i32, %struct.ResultRelInfo*, %struct.ResultRelInfo*, i32, %struct.List*, %struct.List*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.ParamListInfoData*, %struct.ParamExecData*, %struct.QueryEnvironment*, %struct.MemoryContextData*, %struct.List*, %struct.List*, i64, i32, i32, i32, i8, %struct.List*, %struct.List*, %struct.List*, %struct.ExprContext*, %struct.HeapTupleData**, i8*, i8*, i8, %struct.dsa_area*, i32, %struct.JitContext* }

%struct.SnapshotData = type { i1 (%struct.HeapTupleData*, %struct.SnapshotData*, i32)*, i32, i32, i32*, i32, i32*, i32, i8, i8, i8, i32, i32, i32, i32, %struct.pairingheap_node, i64, i64 }

%struct.pairingheap_node = type { %struct.pairingheap_node*, %struct.pairingheap_node*, %struct.pairingheap_node* }

%struct.PlannedStmt = type { i32, i32, i64, i8, i8, i8, i8, i8, i8, i32, %struct.Plan*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.Bitmapset*, %struct.List*, %struct.List*, %struct.List*, %struct.List*, %struct.Node*, i32, i32 }

%struct.JunkFilter = type { i32, %struct.List*, %struct.tupleDesc*, i16*, %struct.TupleTableSlot*, i16 }

%struct.ResultRelInfo = type { i32, i32, %struct.RelationData*, i32, %struct.RelationData**, %struct.IndexInfo**, %struct.TriggerDesc*, %struct.FmgrInfo*, %struct.ExprState**, %struct.Instrumentation*, %struct.FdwRoutine*, i8*, i8, %struct.List*, %struct.List*, %struct.ExprState**, %struct.JunkFilter*, %struct.List*, %struct.ProjectionInfo*, %struct.List*, %struct.OnConflictSetState*, %struct.List*, %struct.ExprState*, %struct.RelationData*, i8 }

%struct.IndexInfo = type { i32, i32, i32, [32 x i16], %struct.List*, %struct.List*, %struct.List*, %struct.ExprState*, i32*, i32*, i16*, i32*, i32*, i16*, i8, i8, i8, i8, i32, i32, i8*, %struct.MemoryContextData* }

%struct.TriggerDesc = type { %struct.Trigger*, i32, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8, i8 }

%struct.Trigger = type { i32, i8*, i32, i16, i8, i8, i32, i32, i32, i8, i8, i16, i16, i16*, i8**, i8*, i8*, i8* }

%struct.FdwRoutine = type opaque

%struct.OnConflictSetState = type { i32, %struct.ProjectionInfo*, %struct.tupleDesc*, %struct.ExprState* }

%struct.RelationData = type opaque

%struct.ParamExecData = type { i8*, i64, i8 }

%struct.QueryEnvironment = type opaque

%struct.dsa_area = type opaque

%struct.JitContext = type opaque

%struct.Instrumentation = type { i8, i8, i8, %struct.timespec, %struct.timespec, double, double, %struct.BufferUsage, double, double, double, double, double, double, double, %struct.BufferUsage }

%struct.timespec = type { i64, i64 }

%struct.BufferUsage = type { i64, i64, i64, i64, i64, i64, i64, i64, i64, i64, %struct.timespec, %struct.timespec }

%struct.WorkerInstrumentation = type { i32, [0 x %struct.Instrumentation] }

%struct.List = type { i32, i32, %struct.ListCell*, %struct.ListCell* }

%struct.ListCell = type { %union.anon.4, %struct.ListCell* }

%union.anon.4 = type { i8* }

%struct.Bitmapset = type { i32, [0 x i32] }

%struct.ProjectionInfo = type { i32, %struct.ExprState, %struct.ExprContext* }

%struct.ParamListInfoData = type { %struct.ParamExternData* (%struct.ParamListInfoData*, i32, i1, %struct.ParamExternData*)*, i8*, void (%struct.ParamListInfoData*, %struct.Param*, %struct.ExprState*, i64*, i8*)*, i8*, void (%struct.ParseState*, i8*)*, i8*, i32, [0 x %struct.ParamExternData] }

%struct.ParamExternData = type { i64, i8, i16, i32 }

%struct.Param = type { %struct.Expr, i32, i32, i32, i32, i32, i32 }

%struct.ParseState = type opaque

%struct.ExprContext = type { i32, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.TupleTableSlot*, %struct.MemoryContextData*, %struct.MemoryContextData*, %struct.ParamExecData*, %struct.ParamListInfoData*, i64*, i8*, i64, i8, i64, i8, %struct.EState*, %struct.ExprContext_CB* }

%struct.ExprContext_CB = type { %struct.ExprContext_CB*, void (i64)*, i64 }

; Function Attrs: norecurse nounwind ssp uwtable

define i64 @evalexpr_14_0(%struct.ExprState*, %struct.ExprContext*, i1*) #0 {

entry:

%v.state.resvalue = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 3

%v.state.resnull = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 2

%3 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 1

%v_scanslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %3

%4 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 2

%v_innerslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %4

%5 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 3

%v_outerslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %5

%6 = getelementptr inbounds %struct.ExprState, %struct.ExprState* %0, i32 0, i32 4

%v_resultslot = load %struct.TupleTableSlot*, %struct.TupleTableSlot** %6

%7 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_scanslot, i32 0, i32 10

%v_scanvalues = load i64*, i64** %7

%8 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_scanslot, i32 0, i32 11

%v_scannulls = load i8*, i8** %8

%9 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_innerslot, i32 0, i32 10

%v_innervalues = load i64*, i64** %9

%10 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_innerslot, i32 0, i32 11

%v_innernulls = load i8*, i8** %10

%11 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_outerslot, i32 0, i32 10

%v_outervalues = load i64*, i64** %11

%12 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_outerslot, i32 0, i32 11

%v_outernulls = load i8*, i8** %12

%13 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_resultslot, i32 0, i32 10

%v_resultvalues = load i64*, i64** %13

%14 = getelementptr inbounds %struct.TupleTableSlot, %struct.TupleTableSlot* %v_resultslot, i32 0, i32 11

%v_resultnulls = load i8*, i8** %14

%15 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 8

%v.econtext.aggvalues = load i64*, i64** %15

%16 = getelementptr inbounds %struct.ExprContext, %struct.ExprContext* %1, i32 0, i32 9

%v.econtext.aggnulls = load i8*, i8** %16

br label %b.op.0.start

b.op.0.start: ; preds = %entry

store i64 100, i64* inttoptr (i64 140524024251152 to i64*)

store i8 0, i8* inttoptr (i64 140524024251149 to i8*)

br label %b.op.1.start

b.op.1.start: ; preds = %b.op.0.start

%17 = load i64, i64* %v.state.resvalue

%18 = load i8, i8* %v.state.resnull

%19 = getelementptr i64, i64* %v_resultvalues, i32 0

%20 = getelementptr i8, i8* %v_resultnulls, i32 0

store i64 %17, i64* %19

store i8 %18, i8* %20

br label %b.op.2.start

b.op.2.start: ; preds = %b.op.1.start

%21 = load i64, i64* %v.state.resvalue

%22 = load i8, i8* %v.state.resnull

%23 = trunc i8 %22 to i1

store i1 %23, i1* %2

ret i64 %21

}

attributes #0 = { norecurse nounwind ssp uwtable "correctly-rounded-divide-sqrt-fp-math"="false" "disable-tail-calls"="false" "less-precise-fpmad"="false" "no-frame-pointer-elim"="true" "no-frame-pointer-elim-non-leaf" "no-infs-fp-math"="false" "no-jump-tables"="false" "no-nans-fp-math"="false" "no-signed-zeros-fp-math"="false" "no-trapping-math"="false" "stack-protector-buffer-size"="8" "target-cpu"="penryn" "target-features"="+cx16,+fxsr,+mmx,+sahf,+sse,+sse2,+sse3,+sse4.1,+ssse3,+x87" "unsafe-fp-math"="false" "use-soft-float"="false" }

71行目付近に関数定義があり、evalexpr_xx_xという名前になっていることがわかる。

LLVM IRを生成しているllvm_compile_expr関数をみると、LLVMのIRの構造に沿って、コード作成されていくことがわかる。

LLVMModuleCreateWithNameでModuleを作成し、LLVMAddFunctionでModuleにFunctionを追加し、LLVMAppendBasicBlockでBasicBlockを追加、BuilderでInstructionの構築・・・といった感じである。

参考リンク

きつねさんでもわかるLLVM ~コンパイラを自作するためのガイドブック~

posted with amazlet at 18.07.07

柏木餅子風薬
インプレス
売り上げランキング: 87,944

Amazon.co.jpで詳細を見る

脚注[+]

脚注
↑1	https://github.com/moritoru81/pgenv2
↑2	https://llvm.org/docs/LangRef.html#identifiers

複数バージョンのPostgreSQLを入れる２

コメントを残す

この記事は【2018年6月23日】と作成から2年以上経っているため、記事の内容が古い可能性があります。最新の情報を合わせてご確認されることを推奨いたします。

拙作なツールですが、複数バージョンのPostgreSQLをローカルマシンに入れて、テストや動作確認でバージョンを切り替えたりするツールを以前に作成したことがありましたが、色々と使い勝手も含めて改良したいなあと思っていたこともあり、今回新たに作り直してみました。

動作確認は自分のMac環境でしかできていませんが、それなりに動いて重宝しているので、以下に概要をまとめてみました。

pgenv2

https://github.com/moritoru81/pgenv2

動作環境

Bash 4.2 or later（4.4以上を推奨）

インストール

リポジトリをクローンして、install.shでパスを通すだけです。設置場所は、任意です。

$ git clone https://github.com/moritoru81/pgenv2.git
$ cd pgenv2
$ source install.sh

$ git clone https://github.com/moritoru81/pgenv2.git

$ cd pgenv2

$ source install.sh

機能

今のところ以下ができます。ざっくりと言うと、xxenvと言われるソフトウェアと類似の機能があります。

PostgreSQLのインストール（ソースアーカイブをダウンロードしてビルド）
インストールした複数バージョンのPostgreSQLの切り替え
ローカルマシン上でのレプリケーション環境の構築

利用可能なバージョン一覧の表示

公式サイトのWebページからリリースされているバージョン一覧を取得して表示します。

$ pgenv versions
1.08
1.09
...

$ pgenv versions

1.08

1.09

...

インストール時に、ここで表示されるバージョンを指定します。

指定のバージョンのPostgreSQLをインストールする

pgenv versionsで利用可能なバージョン一覧を確認できたら、次はインストールします。以下では、10.1をインストールしています。

$ pgenv install 10.1

1	$ pgenv install 10.1

コマンドを実行すると、10.1のソースアーカイブをダウンロードして、展開、configure、makeと実行していきます。ビルドのログは、pgenv/logsにバージョンの名前で出力されます。

configureのオプションは、pgenv/configure_optionsにデフォルトの条件が書いてあります。pgenvのconfigureコマンドで編集ができます。$EDITORで指定されるエディタでファイルを編集します。

pgenv configure --edit --global 10.1

1	pgenv configure --edit --global 10.1

無事にインストールできたら、以下でバージョン確認ができます。

$ pgenv list
10.1       
* 10.3       
10.4       
9.6.9      
9.5

$ pgenv list

10.1

* 10.3

10.4

9.6.9

9.5

上記では、現在10.3が有効ですが、10.1に切り替えてみます。

$ pgenv global 10.1
Current version -> versions/10.1
[Next step]
Create an instance and start postmaster:
$ initdb pgdata
$ pg_ctl -D pgdata -l postgresql.log start
Connect to the postgres database:
$ psql postgres

$ pgenv global 10.1

Current version -> versions/10.1

[Next step]

Create an instance and start postmaster:

$ initdb pgdata

$ pg_ctl -D pgdata -l postgresql.log start

Connect to the postgres database:

$ psql postgres

切り替わったか確認します。

$ pgenv list
* 10.1       
10.3       
10.4       
9.6.9      
9.5
$ psql -V
psql (PostgreSQL) 10.1
$ pgenv prefix --bin ./psql -V
psql (PostgreSQL) 10.1

$ pgenv list

* 10.1

10.3

10.4

9.6.9

9.5

$ psql -V

psql (PostgreSQL) 10.1

$ pgenv prefix --bin ./psql -V

psql (PostgreSQL) 10.1

インストール場所を確認してみます。

$ pgenv prefix 
/Users/guest/workspace/pgenv2/versions/10.1

1 2	$ pgenv prefix /Users/guest/workspace/pgenv2/versions/10.1

レプリケーション環境の構築

PostgreSQLには、レプリケーション機能がありますが、サクッと手元で環境を構築し、動作確認したいことがあります。pgenv2には、そういった機能があります。

１対１の同期レプリケーションを組みたい場合、以下のようにできます。

$ pgenv cluster -D foo setup --sync-standby standby primary

1	$ pgenv cluster -D foo setup --sync-standby standby primary

上記例では、fooというディレクトリに、各種インスタンスディレクトリが作成されます。

$ ls foo
archivedir        cluster_config.sh primary           primary.conf      standby           standby.conf

1 2	$ ls foo archivedir cluster_config.sh primary primary.conf standby standby.conf

プライマリは「primary」、同期スタンバイは「standby」としています。各ノードの設定は、基本的に外出しで、includeパラメータで読み込ませています。port番号は、デフォルトでは24312から順にインクリメントして使用しています。

以下で構築した環境の状態を確認してみます。primary -> standbyはレプリケーション関係を示しています。pg_stat_replicationビューの情報をもとにしています。

$ pgenv cluster -D foo status
[Cluster Servers]
# Primary server
primary:24312       pg_ctl: server is running (PID: 17941)
# Synchronous standby servers
standby:24313       pg_ctl: server is running (PID: 18042)
# Asynchronous standby servers
[Replication Graph]
primary -> standby 
standby ->

$ pgenv cluster -D foo status

[Cluster Servers]

# Primary server

primary:24312 pg_ctl: server is running (PID: 17941)

# Synchronous standby servers

standby:24313 pg_ctl: server is running (PID: 18042)

# Asynchronous standby servers

[Replication Graph]

primary -> standby

standby ->

別ターミナルで、各種インスタンスのログを表示しておきます。

$ pgenv cluster -D foo tail -f -a
==> primary/log/postgresql-2018-06-23.log <==
2018-06-23 09:01:16.905 JST [17944] LOG:  database system was shut down at 2018-06-23 09:01:16 JST
2018-06-23 09:01:16.914 JST [17941] LOG:  database system is ready to accept connections
2018-06-23 09:01:17.372 JST [17978] LOG:  standby "standby" is now a synchronous standby with priority 1
2018-06-23 09:01:18.170 JST [18049] LOG:  standby "standby" is now a synchronous standby with priority 1
==> standby/log/postgresql-2018-06-23.log <==
2018-06-23 09:01:16.905 JST [17944] LOG:  database system was shut down at 2018-06-23 09:01:16 JST
2018-06-23 09:01:16.914 JST [17941] LOG:  database system is ready to accept connections
2018-06-23 09:01:17.372 JST [17978] LOG:  standby "standby" is now a synchronous standby with priority 1
2018-06-23 09:01:18.012 JST [18044] LOG:  database system was interrupted; last known up at 2018-06-23 09:01:17 JST
2018-06-23 09:01:18.050 JST [18044] LOG:  entering standby mode
2018-06-23 09:01:18.052 JST [18044] LOG:  redo starts at 0/2000028
2018-06-23 09:01:18.052 JST [18044] LOG:  consistent recovery state reached at 0/20000F8
2018-06-23 09:01:18.054 JST [18042] LOG:  database system is ready to accept read only connections
2018-06-23 09:01:18.069 JST [18048] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1

$ pgenv cluster -D foo tail -f -a

==> primary/log/postgresql-2018-06-23.log <==

2018-06-23 09:01:16.905 JST [17944] LOG: database system was shut down at 2018-06-23 09:01:16 JST

2018-06-23 09:01:16.914 JST [17941] LOG: database system is ready to accept connections

2018-06-23 09:01:17.372 JST [17978] LOG: standby "standby" is now a synchronous standby with priority 1

2018-06-23 09:01:18.170 JST [18049] LOG: standby "standby" is now a synchronous standby with priority 1

==> standby/log/postgresql-2018-06-23.log <==

2018-06-23 09:01:16.905 JST [17944] LOG: database system was shut down at 2018-06-23 09:01:16 JST

2018-06-23 09:01:16.914 JST [17941] LOG: database system is ready to accept connections

2018-06-23 09:01:17.372 JST [17978] LOG: standby "standby" is now a synchronous standby with priority 1

2018-06-23 09:01:18.012 JST [18044] LOG: database system was interrupted; last known up at 2018-06-23 09:01:17 JST

2018-06-23 09:01:18.050 JST [18044] LOG: entering standby mode

2018-06-23 09:01:18.052 JST [18044] LOG: redo starts at 0/2000028

2018-06-23 09:01:18.052 JST [18044] LOG: consistent recovery state reached at 0/20000F8

2018-06-23 09:01:18.054 JST [18042] LOG: database system is ready to accept read only connections

2018-06-23 09:01:18.069 JST [18048] LOG: started streaming WAL from primary at 0/3000000 on timeline 1

続いて、スタンバイを昇格させてみます。

$ pg_ctl -D foo/standby promote
waiting for server to promote.... done
server promoted

$ pg_ctl -D foo/standby promote

waiting for server to promote.... done

server promoted

ログも出力されていることを確認します。

==> standby/log/postgresql-2018-06-23.log <==
2018-06-23 09:01:16.905 JST [17944] LOG:  database system was shut down at 2018-06-23 09:01:16 JST
2018-06-23 09:01:16.914 JST [17941] LOG:  database system is ready to accept connections
2018-06-23 09:01:17.372 JST [17978] LOG:  standby "standby" is now a synchronous standby with priority 1
2018-06-23 09:01:18.012 JST [18044] LOG:  database system was interrupted; last known up at 2018-06-23 09:01:17 JST
2018-06-23 09:01:18.050 JST [18044] LOG:  entering standby mode
2018-06-23 09:01:18.052 JST [18044] LOG:  redo starts at 0/2000028
2018-06-23 09:01:18.052 JST [18044] LOG:  consistent recovery state reached at 0/20000F8
2018-06-23 09:01:18.054 JST [18042] LOG:  database system is ready to accept read only connections
2018-06-23 09:01:18.069 JST [18048] LOG:  started streaming WAL from primary at 0/3000000 on timeline 1
2018-06-23 09:09:32.542 JST [18044] LOG:  received promote request
2018-06-23 09:09:32.542 JST [18048] FATAL:  terminating walreceiver process due to administrator command
2018-06-23 09:09:32.543 JST [18044] LOG:  invalid record length at 0/3000140: wanted 24, got 0
2018-06-23 09:09:32.543 JST [18044] LOG:  redo done at 0/3000108
2018-06-23 09:09:32.544 JST [18044] LOG:  selected new timeline ID: 2
2018-06-23 09:09:32.609 JST [18044] LOG:  archive recovery complete
2018-06-23 09:09:32.611 JST [18042] LOG:  database system is ready to accept connections