PostgreSQL特性矩阵解析系列9之EXPLAIN (WAL) support

开源软件联盟PostgreSQL分会 2021-07-16

1029

文章转载自公众号：CP的PostgreSQL厨房

作者：CP

简介

EXPLAIN can now track WAL usage information along with auto_explain, autovacuum, and pg_stat_statements.

EXPLAIN现在可以跟踪 WAL 使用信息以及auto_explain、autovacuum和pg_stat_statements。

注:EXPLAIN的wal选型是PostgreSQL13版本中新增加选项。

Synopsis

EXPLAIN [ ( option [, ...] ) ] statementEXPLAIN [ ANALYZE ] [ VERBOSE ] statementwhere option can be one of:    ANALYZE [ boolean ]    VERBOSE [ boolean ]    COSTS [ boolean ]    SETTINGS [ boolean ]    BUFFERS [ boolean ]    WAL [ boolean ]#PG13中新增选项    TIMING [ boolean ]    SUMMARY [ boolean ]    FORMAT { TEXT | XML | JSON | YAML }
复制

概念

EXPLAIN的WAL选项

Include information on WAL record generation. Specifically, include the number of records, number of full page images (fpi) and amount of WAL bytes generated. In text format, only non-zero values are printed. This parameter may only be used when ANALYZE is also enabled. It defaults to FALSE.

包括有关WAL记录生成的信息。具体来说，包括记录数、整页图像数（fpi）和生成的WAL字节数。在文本格式中，仅打印非零值。此参数只能在同时启用ANALYZE时使用。它默认为FALSE。

WAL

事务日志,WAL可以显著降低磁盘的写次数，因为只有日志文件需要被刷出到磁盘以保证事务被提交，而被事务改变的每一个数据文件则不必被刷出。日志文件被按照顺序写入，因此同步日志的代价要远低于刷写数据页面的代价。在处理很多影响数据存储不同部分的小事务的服务器上这一点尤其明显。此外，当服务器在处理很多小的并行事务时，日志文件的一个fsync可以提交很多事务。

图像数（fpi）

FPI(Full Page Image)产生于checkpoint之后第一次变脏的page，在下次checkpoint到了之前，已经输出过PFI的page是不需要再次输出FPI。

因此checkpoint时间间隔越长，FPI产生的频度会越低。如果是checkpoint之后第一次修改页面，则输出整个page的内容(即full page image，简称FPI)。

FPI是full-page-write中xlog记录的状态

举例说明

在T1，数据库成功执行checkpoint；

在T2，执行DML语句，这时候相关的数据会写入到WAL中（此处忽略了WAL buffer）；

在T3，提交该事务；

在T4，bgwriter把dirty pages写入到Data file中，但在写入过程中机器出现故障导致Crash（如掉电等），出现了部分写的情况。

为了应对这种情况，PG在T2写入WAL的时候，会把出现变化的page整页写入到WAL中，而不仅仅是tuple data。在数据库重启执行恢复的时候，在Redo point开始回放WAL时，如发现XLOG Record是FPI（full-page-image），则整页替换，通过这种机制解决了部分写的问题。

操作

postgres=# create table test1postgres-# (userid int,name text,birthday date,crt_time timestamp without time zone);新增postgres=# explain(analyze,wal,verbose,costs) insert into test1 (userid,name,birthday,crt_time)select generate_series(1,100000),'abcdef','2015-08-10',clock_timestamp();                                                          QUERY PLAN                                                          ------------------------------------------------------------------------------------------------------------------------------ Insert on public.test1  (cost=0.00..1750.02 rows=100000 width=48) (actual time=309.442..309.444 rows=0 loops=1)   WAL: records=100000 bytes=7900000 (产生wal大小和记录数)   ->  Subquery Scan on "*SELECT*"  (cost=0.00..1750.02 rows=100000 width=48) (actual time=0.027..83.242 rows=100000 loops=1)         Output: "*SELECT*".generate_series, 'abcdef'::text, '2015-08-10'::date, "*SELECT*".clock_timestamp         ->  ProjectSet  (cost=0.00..500.02 rows=100000 width=76) (actual time=0.008..29.592 rows=100000 loops=1)               Output: generate_series(1, 100000), NULL::unknown, NULL::unknown, clock_timestamp()               ->  Result  (cost=0.00..0.01 rows=1 width=0) (actual time=0.003..0.004 rows=1 loops=1) Planning Time: 0.186 ms Execution Time: 309.546 ms(9 rows)
复制

删除postgres=# explain(analyze,wal,verbose,costs) delete from test1 where userid=1;                                                   QUERY PLAN                                                   ---------------------------------------------------------------------------------------------------------------- Delete on public.test1  (cost=0.00..1887.00 rows=1 width=6) (actual time=15.638..15.640 rows=0 loops=1)   WAL: records=1 fpi=1 bytes=8247 (有1个FPI类型的wal)   ->  Seq Scan on public.test1  (cost=0.00..1887.00 rows=1 width=6) (actual time=0.022..15.574 rows=1 loops=1)         Output: ctid         Filter: (test1.userid = 1)         Rows Removed by Filter: 99999 Planning Time: 0.178 ms Execution Time: 15.922 ms(8 rows)postgres=# explain(analyze,wal,verbose,costs) delete from test1 where userid>=1 and userid<=100;                                                    QUERY PLAN                                                    ------------------------------------------------------------------------------------------------------------------ Delete on public.test1  (cost=0.00..2137.00 rows=86 width=6) (actual time=16.287..16.289 rows=0 loops=1)   WAL: records=100 bytes=5402(没产生FPI类型的wal)   ->  Seq Scan on public.test1  (cost=0.00..2137.00 rows=86 width=6) (actual time=0.072..16.136 rows=99 loops=1)         Output: ctid         Filter: ((test1.userid >= 1) AND (test1.userid <= 100))         Rows Removed by Filter: 99900         WAL: records=1 bytes=56 Planning Time: 0.223 ms Execution Time: 16.333 ms(9 rows)
复制

修改postgres=# explain(analyze,wal,verbose,costs) update test1 set name='123' where userid=101;                                                   QUERY PLAN                                                    ----------------------------------------------------------------------------------------------------------------- Update on public.test1  (cost=0.00..1887.00 rows=1 width=54) (actual time=16.967..16.969 rows=0 loops=1)   WAL: records=1 fpi=1 bytes=3505(第一次更新page一定会产生1个fpi类型的wal)   ->  Seq Scan on public.test1  (cost=0.00..1887.00 rows=1 width=54) (actual time=0.032..16.925 rows=1 loops=1)         Output: userid, '123'::text, birthday, crt_time, ctid         Filter: (test1.userid = 101)         Rows Removed by Filter: 99899 Planning Time: 0.106 ms Execution Time: 17.018 ms(8 rows)postgres=# explain(analyze,wal,verbose,costs) update test1 set name='123' where userid=101;                                                   QUERY PLAN                                                    ----------------------------------------------------------------------------------------------------------------- Update on public.test1  (cost=0.00..1887.00 rows=1 width=54) (actual time=14.997..14.999 rows=0 loops=1)   WAL: records=1 bytes=68((非第一次更新page不会产生fpi类型的wal))   ->  Seq Scan on public.test1  (cost=0.00..1887.00 rows=1 width=54) (actual time=0.041..14.962 rows=1 loops=1)         Output: userid, '123'::text, birthday, crt_time, ctid         Filter: (test1.userid = 101)         Rows Removed by Filter: 99899 Planning Time: 0.100 ms Execution Time: 15.045 ms(8 rows)
复制

查询(不生成wal变更过)postgres=# explain(analyze,wal,verbose,costs) select * from test1;                                                     QUERY PLAN                                                     -------------------------------------------------------------------------------------------------------------------- Seq Scan on public.test1  (cost=0.00..1637.00 rows=100000 width=23) (actual time=0.012..9.671 rows=100000 loops=1)   Output: userid, name, birthday, crt_time Planning Time: 0.185 ms Execution Time: 14.538 ms(4 rows)
复制

参考

https://www.postgresql.org/about/featurematrix/detail/348/

https://www.postgresql.org/about/featurematrix/#backend

http://postgres.cn/docs/13/sql-explain.html

https://www.jianshu.com/p/a7ef10eb1201