log_autovacuum output looks like this (as of Postgres 14):
LOG: automatic vacuum of table "regression.public.bmsql_order_line":
index scans: 1
pages: 0 removed, 8810377 remain, 0 skipped due to pins, 3044924 frozen
tuples: 16819838 removed, 576364686 remain, 2207444 are dead but not
yet removable, oldest xmin: 88197949
buffer usage: 174505 hits, 7630386 misses, 5628271 dirtied
index scan needed: 1959301 pages from table (22.24% of total) had
11745226 dead item identifiers removed
index "bmsql_order_line_pkey": pages: 2380261 in total, 0 newly
deleted, 0 currently deleted, 0 reusable
avg read rate: 65.621 MB/s, avg write rate: 48.403 MB/s
I/O timings: read: 65813.666 ms, write: 11310.689 ms
system usage: CPU: user: 72.55 s, system: 52.07 s, elapsed: 908.42 s
WAL usage: 7387358 records, 4051205 full page images, 28472185998 bytes
I think that this output is slightly misleading. I'm concerned about
the specific order of the lines here: the "buffer usage" line comes
after the information that applies specifically to the heap structure,
but before the information about indexes. This is the case despite the
fact that its output applies to all buffers (not just those for the
heap structure).
It would be a lot clearer if the "buffer usage" line was simply moved
down. I think that it should appear after the lines that are specific
to the table's indexes -- just before the "avg read rate" line. That
way we'd group the buffer usage output with all of the other I/O
related output that summarizes the VACUUM operation as a whole.
I propose changing the ordering along those lines, and backpatching
the change to Postgres 14.
--
Peter Geoghegan
