由 John Doe 四月 28, 2025
PostgreSQL 自动清理进程在工作时，会不时地进行休眠，很难判断它的工作饱和度。现在，PostgreSQL 在清理日志中添加了基于成本的 VACUUM 延迟时间。
特性提交日志
在 VACUUM/ANALYZE (VERBOSE) 和自动清理日志中添加延迟时间。
之前的提交 将该信息添加到了pg_stat_progress_vacuum和pg_stat_progress_analyze系统视图中。本次提交则将相同信息添加到了带有 VERBOSE 选项的 VACUUM 和 ANALYZE 命令的输出结果，以及自动清理的日志中。
讨论：https://postgr.es/m/ZmaXmWDL829fzAVX@ip-10-97-1-34.eu-west-3.compute.internal
示例
就在几天前提交的特性中，我们已经能在显示 VACUUM 进度的视图中获取延迟信息了，而现在，该延迟信息也能在 VACUUM 结束时记录到 PostgreSQL 日志中了。
我们来进行两次测试，首先创建一个表，以便有可以进行 VACUUM 操作的对象。
create table test_it as
select i, repeat( 'redrock' || i::text, 200) as payload
from generate_series(1,1000000) i;
alter table test_it add primary key (i);
现在，让我们给 VACUUM 产生一些清理任务，然后立即手动运行 VACUUM：
delete from test_it where random() < 0.75;
vacuum verbose test_it;
INFO: vacuuming "postgres.public.test_it"
INFO: finished vacuuming "postgres.public.test_it": index scans: 1
pages: 0 removed, 12736 remain, 12736 scanned (100.00% of total), 0 eagerly scanned
tuples: 750324 removed, 249676 remain, 0 are dead but not yet removable
removable cutoff: 2159, which was 0 XIDs old when operation ended
frozen: 0 pages from table (0.00% of total) had 0 tuples frozen
visibility map: 12706 pages set all-visible, 799 pages set all-frozen (0 were all-visible)
index scan needed: 12698 pages from table (99.70% of total) had 750324 dead item identifiers removed
index "test_it_pkey": pages: 2745 in total, 0 newly deleted, 0 currently deleted, 0 reusable
delay time: 2493.787 ms
I/O timings: read: 8.274 ms, write: 11.363 ms
avg read rate: 7.771 MB/s, avg write rate: 7.760 MB/s
buffer usage: 38215 hits, 2752 reads, 2748 dirtied
WAL usage: 40843 records, 7 full page images, 6766991 bytes, 0 buffers full
system usage: CPU: user: 0.17 s, system: 0.02 s, elapsed: 2.76 s
INFO: vacuuming "postgres.pg_toast.pg_toast_798487"
INFO: finished vacuuming "postgres.pg_toast.pg_toast_798487": index scans: 0
pages: 0 removed, 0 remain, 0 scanned (100.00% of total), 0 eagerly scanned
tuples: 0 removed, 0 remain, 0 are dead but not yet removable
removable cutoff: 2159, which was 0 XIDs old when operation ended
new relfrozenxid: 2159, which is 3 XIDs ahead of previous value
frozen: 0 pages from table (100.00% of total) had 0 tuples frozen
visibility map: 0 pages set all-visible, 0 pages set all-frozen (0 were all-visible)
index scan not needed: 0 pages from table (100.00% of total) had 0 dead item identifiers removed
delay time: 5.580 ms
I/O timings: read: 0.031 ms, write: 0.000 ms
avg read rate: 1.351 MB/s, avg write rate: 0.000 MB/s
buffer usage: 25 hits, 1 reads, 0 dirtied
WAL usage: 1 records, 0 full page images, 254 bytes, 0 buffers full
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
VACUUM
请查看上面的第 26 行，delay time: 5.580 ms。
然后，我们重新进行设置，让自动清理机制来处理。为确保日志记录，这里将log_autovacuum_min_duration设置为 0。过了一段时间，会在日志中看到以下的内容：
2025-04-19 12:32:04.690 CST @ 379450 LOG: automatic vacuum of table "postgres.public.test_it": index scans: 1
pages: 0 removed, 115008 remain, 115008 scanned (100.00% of total), 0 eagerly scanned
tuples: 7500218 removed, 2499782 remain, 0 are dead but not yet removable
removable cutoff: 2175, which was 0 XIDs old when operation ended
frozen: 114185 pages from table (99.28% of total) had 2499726 tuples frozen
visibility map: 114976 pages set all-visible, 114962 pages set all-frozen (0 were all-visible)
index scan needed: 114962 pages from table (99.96% of total) had 7500218 dead item identifiers removed
index "test_it_pkey": pages: 27422 in total, 0 newly deleted, 0 currently deleted, 0 reusable
delay time: 57002.466 ms
I/O timings: read: 384.980 ms, write: 1032.635 ms
avg read rate: 27.745 MB/s, avg write rate: 30.244 MB/s
buffer usage: 146632 hits, 225888 reads, 246238 dirtied
WAL usage: 487219 records, 223217 full page images, 1224286719 bytes, 11605 buffers full
system usage: CPU: user: 3.74 s, system: 2.41 s, elapsed: 63.60 s
这次，查看第 9 行，delay time: 57002.466 ms。
非常不错的改进。感谢社区的所有相关人员。
参考
提交日志：https://git.postgresql.org/pg/commitdiff/7720082ae53280857f1eacb86134a9a759290f40