proposal: refactoring vacuum verbose output

  • Jump to comment-1
    Pavel Stehule<pavel.stehule@gmail.com>
    Apr 27, 2026, 7:04 AM UTC
    Hi
    I am working on a patch that tries to colourize some lines from VACUUM
    VERBOSE output.
    The main problem is inconsistent output from VACUUM, ANALYZE, REINDEX and
    REPACK.
    Can we introduce some new error levels, and new error fields that allows to
    write these reports more readable:
    Current output from REINDEX VERBOSE
    (2026-04-24 21:30:41) postgres=# reindex (verbose) table pg_class;
    INFO: index "pgclassoid_index" was reindexed
    DETAIL: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO: index "pgclassrelnamenspindex" was reindexed
    DETAIL: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO: index "pgclasstblspcrelfilenodeindex" was reindexed
    DETAIL: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    REINDEX
    Current output from VACUUM VERBOSE
    (2026-04-24 21:30:49) postgres=# vacuum verbose pg_proc;
    INFO: vacuuming "postgres.pgcatalog.pgproc"
    INFO: finished vacuuming "postgres.pgcatalog.pgproc": index scans: 0
    pages: 0 removed, 101 remain, 1 scanned (0.99% of total), 0 eagerly scanned
    tuples: 0 removed, 3437 remain, 0 are dead but not yet removable
    removable cutoff: 702, which was 0 XIDs old when operation ended
    new relfrozenxid: 702, which is 1 XIDs ahead of previous value
    frozen: 0 pages from table (0.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 (0.00% of total) had 0 dead item
    identifiers removed
    avg read rate: 0.000 MB/s, avg write rate: 12.440 MB/s
    buffer usage: 22 hits, 0 reads, 1 dirtied
    WAL usage: 1 records, 1 full page images, 5871 bytes, 5752 full page image
    bytes, 0 buffers full
    memory usage: dead item storage 0.02 MB accumulated across 0 resets (limit
    64.00 MB each)
    system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO: vacuuming "postgres.pgtoast.pgtoast_1255"
    INFO: finished vacuuming "postgres.pgtoast.pgtoast_1255": index scans: 0
    pages: 0 removed, 2 remain, 2 scanned (100.00% of total), 0 eagerly scanned
    tuples: 0 removed, 7 remain, 0 are dead but not yet removable
    removable cutoff: 702, which was 0 XIDs old when operation ended
    new relfrozenxid: 702, which is 1 XIDs ahead of previous value
    frozen: 0 pages from table (0.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 (0.00% of total) had 0 dead item
    identifiers removed
    avg read rate: 0.000 MB/s, avg write rate: 16.482 MB/s
    buffer usage: 43 hits, 0 reads, 1 dirtied
    WAL usage: 1 records, 1 full page images, 4255 bytes, 4136 full page image
    bytes, 0 buffers full
    memory usage: dead item storage 0.02 MB accumulated across 0 resets (limit
    64.00 MB each)
    system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    VACUUM
    My proposal is introduction new three levels of INFO - INFO1, INFO2, and
    INFO3
    INFO1 can be used for starting, finishing processing of primary object like
    tables
    INFO2 can be used for starting, finishing processing of depending objects
    like toast tables or partitions
    INFO3 can be used for starting, finishing processing of nested objects like
    indexes
    We can introduce new error field RESOURCES
    After change new verbose output can looks like:
    (2026-04-24 21:30:41) postgres=# reindex (verbose) table pg_class;
    INFO3: index "pgclassoid_index" was reindexed
    RESOURCES: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO3: index "pgclassrelnamenspindex" was reindexed
    RESOURCES: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO3: index "pgclasstblspcrelfilenodeindex" was reindexed
    RESOURCES: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    REINDEX
    (2026-04-24 21:30:49) postgres=# vacuum verbose pg_proc;
    *INFO1: vacuuming "postgres.pgcatalog.pgproc"INFO1: finished vacuuming
    "postgres.pgcatalog.pgproc"*
    DETAIL: index scans: 0,
    pages: 0 removed, 101 remain, 1 scanned (0.99% of total), 0 eagerly scanned
    tuples: 0 removed, 3437 remain, 0 are dead but not yet removable
    removable cutoff: 702, which was 0 XIDs old when operation ended
    new relfrozenxid: 702, which is 1 XIDs ahead of previous value
    frozen: 0 pages from table (0.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 (0.00% of total) had 0 dead item
    identifiers removed
    RESOURCES: avg read rate: 0.000 MB/s, avg write rate: 12.440 MB/s,
    buffer usage: 22 hits, 0 reads, 1 dirtied
    WAL usage: 1 records, 1 full page images, 5871 bytes, 5752 full page image
    bytes, 0 buffers full
    memory usage: dead item storage 0.02 MB accumulated across 0 resets (limit
    64.00 MB each)
    system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    INFO2: vacuuming "postgres.pg_toast.pg_toast_
    *1255"INFO2: finished vacuuming "postgres.pgtoast.pgtoast_**1255"*
    DETAIL: index scans: 0
    pages: 0 removed, 2 remain, 2 scanned (100.00% of total), 0 eagerly scanned
    tuples: 0 removed, 7 remain, 0 are dead but not yet removable
    removable cutoff: 702, which was 0 XIDs old when operation ended
    new relfrozenxid: 702, which is 1 XIDs ahead of previous value
    frozen: 0 pages from table (0.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 (0.00% of total) had 0 dead item
    identifiers removed
    RESOURCES: avg read rate: 0.000 MB/s, avg write rate: 16.482 MB/s
    buffer usage: 43 hits, 0 reads, 1 dirtied
    WAL usage: 1 records, 1 full page images, 4255 bytes, 4136 full page image
    bytes, 0 buffers full
    memory usage: dead item storage 0.02 MB accumulated across 0 resets (limit
    64.00 MB each)
    system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
    VACUUM
    There is a problem about the leveling of INFO, because the perspective of
    VACUUM and REINDEX is shifted.
    With proposed design we can highlight lines INFO1..INFO3 or we can hide
    DETAIL or RESOURCES fields.
    Maybe we can introduce a new error field DETAIL_CRITICAL. When I use VACUUM
    VERBOSE - I watch primary field `0 are dead but not yet removable`. Can be
    nice if this information is separated.
    Another possible error field can be "hint" with query to progress stat view
    INFO1: vacuuming "postgres.pgcatalog.pgproc"
    PROGRESSQUERY: SELECT * FROM pgstatprogressvacuum WHERE pid = xxx ...
    or maybe in more parseable form
    STATEMENTINFO: cmdtag "VACUUM": progresstab=pgstatprogressvacuum":
    pid=111
    Another idea - introduce a new error field dedicated for holding
    information for client in parseable format. This field should be processed
    by a client and should not be displayed to the user. And should not be
    stored in a log.
    INFO1: vacuuming "postgres.....
    CLIENTINFO: {"cmdtag":"VACUUM", "pid": 112,
    "progresview":"pgstatprogressvacuum", ...
    All new fields and error levels require protocol enhancement.
    What do you think about this proposal?
    Regards
    Pavel