Re: vacuum verbose detail logs are unclear (show debug lines at *start* of each stage?)

On Fri, Dec 20, 2019 at 12:11 PM Justin Pryzby <pryzby(at)telsasoft(dot)com> wrote:

> This is a usability complaint. If one knows enough about vacuum and/or
> logging, I'm sure there's no issue.
>

> | 11 DEBUG: "t": found 999 removable, 999 nonremovable row versions in 9
> out of 9 pages
>

I agree the mixture of pre-action and after-action reporting is rather
confusing sometimes. I'm more concerned about what the user sees in their
terminal, though, rather than the server's log file.

Also, the above quoted line is confusing. It makes it sound like it found
removable items, but didn't actually remove them. I think that that is
taking grammatical parallelism too far. How about something like:

DEBUG: "t": removed 999 row versions, found 999 nonremovable row versions
in 9 out of 9 pages

Also, I'd appreciate a report on how many hint-bits were set, and how many
pages were marked all-visible and/or frozen. When I do a manual vacuum, it
is more often for those purposes than it is for removing removable rows
(which autovac generally does a good enough job of).

Also, is not so clear that "nonremovable rows" includes both live and
recently dead. Although hopefully reading the next line will clarify that,
to the person who has enough background knowledge.

> | 12 DETAIL: 0 dead row versions cannot be removed yet, oldest xmin:
> 130886944
> | 13 There were 0 unused item identifiers.
> | 14 Skipped 0 pages due to buffer pins, 0 frozen pages.
>

It is a bit weird that we don't report skipped all-visible pages here. It
was implicitly reported in the "in 9 out of 9 pages" message, but I think
it should be reported explicitly as well.

Cheers,

Jeff