PostgreSQL 13: EXPLAIN、Auto_explain、autovacuum、pg_stat_statements跟踪WAL使用信息

发表于 | 分类于 | | 阅读次数:

PostgreSQL 13版本的EXPLAIN、auto_explain、autovacuum、pg_stat_statements可以跟踪WAL使用信息，本文分别做个简单说明和演示。

手册说明

Allow EXPLAIN, auto_explain, autovacuum, and pg_stat_statements to track WAL usage statistics (Kirill Bychik, Julien Rouhaud)

EXPLAIN跟踪WAL使用信息

13版本的EXPLAIN命令新增WAL选项，启用后可以跟踪WAL使用信息，此选项的说明如下:

1
2
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信息的前提条件是启用ANALYZE选项，WAL信息包括以下三部分:

  • WAL record: WAL记录条目数。
  • (Fpi): Full page images。
  • WAL bytes: WAL日志大小，单位为字节。

接下来演示下，创建测试表，并插入测试数据，如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
mydb=> CREATE TABLE t_wal(id int4,info text,create_time timestamp(0) without time zone);
CREATE TABLE

mydb=> EXPLAIN (ANALYZE ON,WAL ON)INSERT INTO t_wal(id,info,create_time)SELECT n,'hello_'|| n,clock_timestamp() FROM generate_series(1,2000000) n;
                                                                    QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------------
 Insert on t_wal  (cost=0.00..70000.00 rows=2000000 width=44) (actual time=7171.484..7171.484 rows=0 loops=1)
   WAL: records=2000000 bytes=173200008
   ->  Subquery Scan on "*SELECT*"  (cost=0.00..70000.00 rows=2000000 width=44) (actual time=299.631..2892.382 rows=2000000 loops=1)
         ->  Function Scan on generate_series n  (cost=0.00..40000.00 rows=2000000 width=44) (actual time=299.619..2031.302 rows=2000000 loops=1)
 Planning Time: 0.145 ms
 Execution Time: 7182.449 ms
(6 rows)

WAL这行信息显示 WAL records=2000000, 正好和插入的记录条数对应； WAL bytes=173200008，165MB左右的WAL日志。

查看pg_wal目录确认下，如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
[pg13@ydtf01 pg_wal]$ ll $PGDATA/pg_wal

省略...
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000CE
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000CF
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D0
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D1
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D2
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D3
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D4
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D5
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D6
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D7
-rw-------. 1 pg13 pg13  16M Jul  4 20:30 0000000100000003000000D8
省略...

产生了12个16MB的WAL日志，和EXPLAIN命令输出的WAL字节数相当。

update表数据，如下:

1
2
3
4
5
6
7
8
9
mydb=> EXPLAIN (ANALYZE ON,WAL ON) UPDATE t_wal SET info=info||'_a';
                                                       QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------
 Update on t_wal  (cost=0.00..39608.00 rows=2000000 width=50) (actual time=14629.798..14629.798 rows=0 loops=1)
   WAL: records=4000000 fpi=7014 bytes=377429558
   ->  Seq Scan on t_wal  (cost=0.00..39608.00 rows=2000000 width=50) (actual time=0.844..2658.072 rows=2000000 loops=1)
 Planning Time: 8.558 ms
 Execution Time: 14633.562 ms
(5 rows)

DELETE表数据，如下:

1
2
3
4
5
6
7
8
9
mydb=> EXPLAIN (ANALYZE ON,WAL ON) DELETE FROM t_wal;
                                                       QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
 Delete on t_wal  (cost=0.00..49313.00 rows=2000000 width=6) (actual time=4592.145..4592.145 rows=0 loops=1)
   WAL: records=2000000 fpi=7691 bytes=170981623
   ->  Seq Scan on t_wal  (cost=0.00..49313.00 rows=2000000 width=6) (actual time=44.685..995.695 rows=2000000 loops=1)
 Planning Time: 0.185 ms
 Execution Time: 4630.729 ms
(5 rows)

汇总如下:

  • INSERT: WAL: records=2000000 bytes=173200008
  • UPDATE: WAL: records=4000000 fpi=7014 bytes=377429558
  • DELETE: WAL: records=2000000 fpi=7691 bytes=170981623

在上数据只看懂了前两条:

  • INSERT这行，插入了200万条数据，产生了200万条WAL记录和165MB的WAL日志。
  • UPDATE这行，更新了200万条数据，产生了400万条WAL记录和359MB的WAL日志，由于PG的MVCC机制，WAL信息量差不多是INSERT这行的两倍。
  • DELETE这行，WAL信息使用量反而和INSERT这行一致，表示看不太明白。

Auto_explain跟踪WAL使用信息

同理，auto_explain外部模块新增了是否跟踪WAL使用信息的选项，通过参数auto_explain.log_wal控制，手册说明如下。

手册说明如下:

1
2
3
4
5
6
7
This also allows the WAL usage information to be displayed via
the auto_explain module.  A new parameter auto_explain.log_wal controls
whether WAL usage statistics are printed when an execution plan is logged.
This parameter has no effect unless auto_explain.log_analyze is enabled.

auto_explain.log_wal (boolean)
auto_explain.log_wal controls whether WAL usage statistics are printed when an execution plan is logged; it s equivalent to the WAL option of EXPLAIN. This parameter has no effect unless auto_explain.log_analyze is enabled. This parameter is off by default. Only superusers can change this setting.

Autovacuum跟踪WAL使用信息

autovacuum同样支持是否跟踪WAL信息，下面演示下:

设置log_autovacuum_min_duration参数为0，如下:

1
log_autovacuum_min_duration = 0

执行pg_ctl reload使参数生效。

查看日志文件，如下:

1
2
3
4
5
6
7
8
2020-07-04 21:02:50.004 CST,,,117418,,5f007df9.1caaa,1,,2020-07-04 21:02:49 CST,10/148932,0,LOG,00000,"automatic vacuum of table ""mydb.pguser.t_wal"": index scans: 0
pages: 0 removed, 14608 remain, 0 skipped due to pins, 0 skipped frozen
tuples: 0 removed, 2000000 remain, 0 are dead but not yet removable, oldest xmin: 1045383
buffer usage: 29247 hits, 1 misses, 2 dirtied
avg read rate: 0.008 MB/s, avg write rate: 0.016 MB/s
system usage: CPU: user: 0.32 s, system: 0.05 s, elapsed: 0.96 s
WAL usage: 14609 records, 1 full page images, 870302 bytes",,,,,,,,,"","autovacuum worker"
2020-07-04 21:02:51.359 CST,,,117418,,5f007df9.1caaa,2,,2020-07-04 21:02:49 CST,10/148933,1045383,LOG,00000,"automatic analyze of table ""mydb.pguser.t_wal"" system usage: CPU: user: 0.96 s, system: 0.09 s, elapsed: 1.35 s",,,,,,,,,"","autovacuum worker"

注意WAL usage这行，显示了WAL的使用信息。

pg_stat_statements跟踪WAL使用信息

pg_stat_statements视图同样新增wal_records、wal_fpi、wal_bytes三个字段，可以跟踪WAL的使用信息，如下:

  • wal_records: Total number of WAL records generated by the statement
  • wal_fpi: Total number of WAL full page images generated by the statement
  • wal_bytes: Total amount of WAL bytes generated by the statement

总结

本文简单介绍了EXPLAIN、auto_explain、autovacuum、pg_stat_statements如何跟踪WAL使用信息。

WAL日志膨胀是PostgreSQL数据库运维过程中的常见问题，13版本的这一新特性使得对WAL的膨胀分析带来帮助。

参考

最后推荐和张文升共同编写的《PostgreSQL实战》，本书基于PostgreSQL 10 编写，共18章，重点介绍SQL高级特性、并行查询、分区表、物理复制、逻辑复制、备份恢复、高可用、性能优化、PostGIS等，涵盖大量实战用例！

购买链接：https://item.jd.com/12405774.html

PostgreSQL实战
感谢支持！
0%