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
