Subject: Re: Removing more vacuumlazy.c special cases, relfrozenxid optimizations

From: Peter Geoghegan <[email-masked]>
Date: Wed, 23 Mar 2022 12:59:01 -0700

On Sun, Mar 13, 2022 at 9:05 PM Peter Geoghegan <[email-masked]> wrote:
> Attached is v10. While this does still include the freezing patch,
> it's not in scope for Postgres 15. As I've said, I still think that it
> makes sense to maintain the patch series with the freezing stuff,
> since it's structurally related.

Attached is v11. Changes:

* No longer includes the patch that adds page-level freezing. It was
making it harder to assess code coverage for the patches that I'm
targeting Postgres 15 with. And so including it with each new revision
no longer seems useful. I'll pick it up for Postgres 16.

* Extensive isolation tests added to v11-0001-*, exercising a lot of
hard-to-hit code paths that are reached when VACUUM is unable to
immediately acquire a cleanup lock on some heap page. In particular,
we now have test coverage for the code in heapam.c that handles
tracking the oldest extant XID and MXID in the presence of MultiXacts
(on a no-cleanup-lock heap page).

* v11-0002-* (which is the patch that avoids missing out on advancing
relfrozenxid in non-aggressive VACUUMs due to a race condition on
HEAD) now moves even more of the logic for deciding how VACUUM will
skip using the visibility map into its own helper routine. Now
lazy_scan_heap just does what the state returned by the helper routine
tells it about the current skippable range -- it doesn't make any
decisions itself anymore. This is far simpler than what we do
currently, on HEAD.

There are no behavioral changes here, but this approach could be
pushed further to improve performance. We could easily determine
*every* page that we're going to scan (not skip) up-front in even the
largest tables, very early, before we've even scanned one page. This
could enable things like I/O prefetching, or capping the size of the
dead_items array based on our final scanned_pages (not on rel_pages).

* A new patch (v11-0003-*) alters the behavior of VACUUM's
DISABLE_PAGE_SKIPPING option. DISABLE_PAGE_SKIPPING no longer forces
aggressive VACUUM -- now it only forces the use of the visibility map,
since that behavior is totally independent of aggressiveness.

I don't feel too strongly about the DISABLE_PAGE_SKIPPING change. It
just seems logical to decouple no-vm-skipping from aggressiveness --
it might actually be helpful in testing the work from the patch series
in the future. Any page counted in scanned_pages has essentially been
processed by VACUUM with this work in place -- that was the idea
behind the lazy_scan_noprune stuff from commit 44fa8488. Bear in mind
that the relfrozenxid tracking stuff from v11-0001-* makes it almost
certain that a DISABLE_PAGE_SKIPPING-without-aggressiveness VACUUM
will still manage to advance relfrozenxid -- usually by the same
amount as an equivalent aggressive VACUUM would anyway. (Failing to
acquire a cleanup lock on some heap page might result in the final
older relfrozenxid being appreciably older, but probably not, and we'd
still almost certainly manage to advance relfrozenxid by *some* small
amount.)

Of course, anybody that wants both an aggressive VACUUM and a VACUUM
that never skips even all-frozen pages in the visibility map will
still be able to get that behavior quite easily. For example,
VACUUM(DISABLE_PAGE_SKIPPING, FREEZE) will do that. Several of our
existing tests must already use both of these options together,
because the tests require an effective vacuum_freeze_min_age of 0 (and
vacuum_multixact_freeze_min_age of 0) -- DISABLE_PAGE_SKIPPING alone
won't do that on HEAD, which seems to confuse the issue (see commit
b700f96c for an example of that).

In other words, since DISABLE_PAGE_SKIPPING doesn't *consistently*
force lazy_scan_noprune to refuse to process a page on HEAD (it all
depends on FreezeLimit/vacuum_freeze_min_age), it is logical for
DISABLE_PAGE_SKIPPING to totally get out of the business of caring
about that -- better to limit it to caring only about the visibility
map (by no longer making it force aggressiveness).

-- 
Peter Geoghegan

---

From: Robert Haas <[email-masked]>
Date: Wed, 23 Mar 2022 16:41:33 -0400

> map (by no longer making it force aggressiveness).

It seems to me that if DISABLE_PAGE_SKIPPING doesn't completely
disable skipping pages, we have a problem.

The option isn't named CARE_ABOUT_VISIBILITY_MAP. It's named
DISABLE_PAGE_SKIPPING.

-- 
Robert Haas
EDB: http://www.enterprisedb.com

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 23 Mar 2022 13:49:09 -0700

> disable skipping pages, we have a problem.

It depends on how you define skipping. DISABLE_PAGE_SKIPPING was
created at a time when a broader definition of skipping made a lot
more sense.

> The option isn't named CARE_ABOUT_VISIBILITY_MAP. It's named

VACUUM(DISABLE_PAGE_SKIPPING, VERBOSE) will still consistently show
that 100% of all of the pages from rel_pages are scanned. A page that
is "skipped" by lazy_scan_noprune isn't pruned, and won't have any of
its tuples frozen. But every other aspect of processing the page
happens in just the same way as it would in the cleanup
lock/lazy_scan_prune path.

We'll even still VACUUM the page if it happens to have some existing
LP_DEAD items left behind by opportunistic pruning. We don't need a
cleanup in either lazy_scan_noprune (a share lock is all we need), nor
do we even need one in lazy_vacuum_heap_page (a regular exclusive lock
is all we need).

-- 
Peter Geoghegan

---

From: Robert Haas <[email-masked]>
Date: Wed, 23 Mar 2022 16:53:13 -0400

> lock/lazy_scan_prune path.

I see what you mean about it depending on how you define "skipping".
But I think that DISABLE_PAGE_SKIPPING is intended as a sort of
emergency safeguard when you really, really don't want to leave
anything out. And therefore I favor defining it to mean that we don't
skip any work at all.

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 23 Mar 2022 13:58:31 -0700

On Wed, Mar 23, 2022 at 1:53 PM Robert Haas <[email-masked]> wrote:
> anything out.

I agree.

> And therefore I favor defining it to mean that we don't
> skip any work at all.

But even today DISABLE_PAGE_SKIPPING won't do pruning when we cannot
acquire a cleanup lock on a page, unless it happens to have XIDs from
before FreezeLimit (which is probably 50 million XIDs behind
OldestXmin, the vacuum_freeze_min_age default). I don't see much
difference.

Anyway, this isn't important. I'll just drop the third patch.

-- 
Peter Geoghegan

---

From: Thomas Munro <[email-masked]>
Date: Thu, 24 Mar 2022 10:02:48 +1300

> OldestXmin, the vacuum_freeze_min_age default). I don't see much

Yeah, I found it confusing that DISABLE_PAGE_SKIPPING doesn't disable
all page skipping, so 3414099c turned out to be not enough.

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 23 Mar 2022 15:28:05 -0700

> all page skipping, so 3414099c turned out to be not enough.

The proposed change to DISABLE_PAGE_SKIPPING is partly driven by that,
and partly driven by a similar concern about aggressive VACUUM.

It seems worth emphasizing the idea that an aggressive VACUUM is now
just the same as any other VACUUM except for one detail: we're
guaranteed to advance relfrozenxid to a value >= FreezeLimit at the
end. The non-aggressive case has the choice to do things that make
that impossible. But there are only two places where this can happen now:

1. Non-aggressive VACUUMs might decide to skip some all-visible pages in
the new lazy_scan_skip() helper routine for skipping with the VM (see
v11-0002-*).

2. A non-aggressive VACUUM can *always* decide to ratchet back its
target relfrozenxid in lazy_scan_noprune, to avoid waiting for a
cleanup lock -- a final value from before FreezeLimit is usually still
pretty good.

The first scenario is the only one where it becomes impossible for
non-aggressive VACUUM to be able to advance relfrozenxid (with
v11-0001-* in place) by any amount. Even that's a choice, made by
weighing costs against benefits.

There is no behavioral change in v11-0002-* (we're still using the
old SKIP_PAGES_THRESHOLD strategy), but the lazy_scan_skip()
helper routine could fairly easily be taught a lot more about the
downside of skipping all-visible pages (namely how that makes it
impossible to advance relfrozenxid).

Maybe it's worth skipping all-visible pages (there are lots of them
and age(relfrozenxid) is still low), and maybe it isn't worth it. We
should get to decide, without implementation details making
relfrozenxid advancement unsafe.

It would be great if you could take a look v11-0002-*, Robert. Does it
make sense to you?

Thanks
--
Peter Geoghegan

---

From: Robert Haas <[email-masked]>
Date: Thu, 24 Mar 2022 13:20:50 -0400

> It would be great if you could take a look v11-0002-*, Robert. Does it

You're probably not going to love hearing this, but I think you're
still explaining things here in ways that are too baroque and hard to
follow. I do think it's probably better. But, for example, in the
commit message for 0001, I think you could change the subject line to
"Allow non-aggressive vacuums to advance relfrozenxid" and it would be
clearer. And then I think you could eliminate about half of the first
paragraph, starting with "There is no fixed relationship", and all of
the third paragraph (which starts with "Later work..."), and I think
removing all that material would make it strictly more clear than it
is currently. I don't think it's the place of a commit message to
speculate too much on future directions or to wax eloquent on
theoretical points. If that belongs anywhere, it's in a mailing list
discussion.

It seems to me that 0002 mixes code movement with functional changes.
I'm completely on board with moving the code that decides how much to
skip into a function. That seems like a great idea, and probably
overdue. But it is not easy for me to see what has changed
functionally between the old and new code organization, and I bet it
would be possible to split this into two patches, one of which creates
a function, and the other of which fixes the problem, and I think that
would be a useful service to future readers of the code. I have a hard
time believing that if someone in the future bisects a problem back to
this commit, they're going to have an easy time finding the behavior
change in here. In fact I can't see it myself. I think the actual
functional change is to fix what is described in the second paragraph
of the commit message, but I haven't been able to figure out where the
logic is actually changing to address that. Note that I would be happy
with the behavior change happening either before or after the code
reorganization.

I also think that the commit message for 0002 is probably longer and
more complex than is really helpful, and that the subject line is too
vague, but since I don't yet understand exactly what's happening here,
I cannot comment on how I think it should be revised at this point,
except to say that the second paragraph of that commit message looks
like the most useful part.

I would also like to mention a few things that I do like about 0002.
One is that it seems to collapse two different pieces of logic for
page skipping into one. That seems good. As mentioned, it's especially
good because that logic is abstracted into a function. Also, it looks
like it is making a pretty localized change to one (1) aspect of what
VACUUM does -- and I definitely prefer patches that change only one
thing at a time.

Hope that's helpful.

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 24 Mar 2022 12:28:08 -0700

On Thu, Mar 24, 2022 at 10:21 AM Robert Haas <[email-masked]> wrote:
> follow. I do think it's probably better.

There are a lot of dimensions to this work. It's hard to know which to
emphasize here.

> But, for example, in the
> clearer.

But non-aggressive VACUUMs have always been able to do that.

How about: "Set relfrozenxid to oldest extant XID seen by VACUUM"

> And then I think you could eliminate about half of the first

Okay, I'll do that.

> It seems to me that 0002 mixes code movement with functional changes.

Believe it or not, I avoided functional changes in 0002 -- at least in
one important sense. That's why you had difficulty spotting any. This
must sound peculiar, since the commit message very clearly says that
the commit avoids a problem seen only in the non-aggressive case. It's
really quite subtle.

You wrote this comment and code block (which I propose to remove in
0002), so clearly you already understand the race condition that I'm
concerned with here:

-           if (skipping_blocks && blkno < rel_pages - 1)
-           {
-               /*
-                * Tricky, tricky.  If this is in aggressive vacuum, the page
-                * must have been all-frozen at the time we checked whether it
-                * was skippable, but it might not be any more.  We must be
-                * careful to count it as a skipped all-frozen page in that
-                * case, or else we'll think we can't update relfrozenxid and
-                * relminmxid.  If it's not an aggressive vacuum, we don't
-                * know whether it was initially all-frozen, so we have to
-                * recheck.
-                */
-               if (vacrel->aggressive ||
-                   VM_ALL_FROZEN(vacrel->rel, blkno, &vmbuffer))
-                   vacrel->frozenskipped_pages++;
-               continue;
-           }

What you're saying here boils down to this: it doesn't matter what the
visibility map would say right this microsecond (in the aggressive
case) were we to call VM_ALL_FROZEN(): we know for sure that the VM
said that this page was all-frozen *in the recent past*. That's good
enough; we will never fail to scan a page that might have an XID <
OldestXmin (ditto for XMIDs) this way, which is all that really
matters.

This is absolutely mandatory in the aggressive case, because otherwise
relfrozenxid advancement might be seen as unsafe. My observation is:
Why should we accept the same race in the non-aggressive case? Why not
do essentially the same thing in every VACUUM?

In 0002 we now track if each range that we actually chose to skip had
any all-visible (not all-frozen) pages -- if that happens then
relfrozenxid advancement becomes unsafe. The existing code uses
"vacrel->aggressive" as a proxy for the same condition -- the existing
code reasons based on what the visibility map must have said about the
page in the recent past. Which makes sense, but only works in the
aggressive case. The approach taken in 0002 also makes the code
simpler, which is what enabled putting the VM skipping code into its
own helper function, but that was just a bonus.

And so you could almost say that there is now behavioral change at
all. We're skipping pages in the same way, based on the same
information (from the visibility map) as before. We're just being a
bit more careful than before about how that information is tracked, to
avoid this race. A race that we always avoided in the aggressive case
is now consistently avoided.

> would be a useful service to future readers of the code.

It seems kinda tricky to split up 0002 like that. It's possible, but
I'm not sure if it's possible to split it in a way that highlights the
issue that I just described. Because we already avoided the race in
the aggressive case.

> like the most useful part.

I'll work on that.

> VACUUM does -- and I definitely prefer patches that change only one

Totally embracing the idea that we don't necessarily need very recent
information from the visibility map (it just has to be after
OldestXmin was established) has a lot of advantages, architecturally.
It could in principle be hours out of date in the longest VACUUM
operations -- that should be fine. This is exactly the same principle
that makes it okay to stick with our original rel_pages, even when the
table has grown during a VACUUM operation (I documented this in commit
73f6ec3d3c recently).

We could build on the approach taken by 0002 to create a totally
comprehensive picture of the ranges we're skipping up-front, before we
actually scan any pages, even with very large tables. We could in
principle cache a very large number of skippable ranges up-front,
without ever going back to the visibility map again later (unless we
need to set a bit). It really doesn't matter if somebody else unsets a
page's VM bit concurrently, at all.

I see a lot of advantage to knowing our final scanned_pages almost
immediately. Things like prefetching, capping the size of the
dead_items array more intelligently (use final scanned_pages instead
of rel_pages in dead_items_max_items()), improvements to progress
reporting...not to mention more intelligent choices about whether we
should try to advance relfrozenxid a bit earlier during non-aggressive
VACUUMs.

> Hope that's helpful.

Very helpful -- thanks!

-- 
Peter Geoghegan

---

From: Robert Haas <[email-masked]>
Date: Thu, 24 Mar 2022 16:21:19 -0400

> How about: "Set relfrozenxid to oldest extant XID seen by VACUUM"

Sure, that sounds nice.

> the commit avoids a problem seen only in the non-aggressive case. It's

Well, I think the goal in revising the code is to be as un-subtle as
possible. Commits that people can't easily understand breed future
bugs.

> OldestXmin (ditto for XMIDs) this way, which is all that really

Makes sense. So maybe the commit message should try to emphasize this
point e.g. "If a page is all-frozen at the time we check whether it
can be skipped, don't allow it to affect the relfrozenxmin and
relminmxid which we set for the relation. This was previously true for
aggressive vacuums, but not for non-aggressive vacuums, which was
inconsistent. (The reason this is a safe thing to do is that any new
XIDs or MXIDs that appear on the page after we initially observe it to
be frozen must be newer than any relfrozenxid or relminmxid the
current vacuum could possibly consider storing into pg_class.)"

> do essentially the same thing in every VACUUM?

Sure, that seems like a good idea. I think I basically agree with the
goals of the patch. My concern is just about making the changes
understandable to future readers. This area is notoriously subtle, and
people are going to introduce more bugs even if the comments and code
organization are fantastic.

> all.

I vigorously object to this part, though. We should always err on the
side of saying that commits *do* have behavioral changes. We should go
out of our way to call out in the commit message any possible way that
someone might notice the difference between the post-commit situation
and the pre-commit situation. It is fine, even good, to also be clear
about how we're maintaining continuity and why we don't think it's a
problem, but the only commits that should be described as not having
any behavioral change are ones that do mechanical code movement, or
are just changing comments, or something like that.

> issue that I just described. Because we already avoided the race in

I do see that there are some difficulties there. I'm not sure what to
do about that. I think a sufficiently clear commit message could
possibly be enough, rather than trying to split the patch. But I also
think splitting the patch should be considered, if that can reasonably
be done.

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 24 Mar 2022 14:40:28 -0700

> > How about: "Set relfrozenxid to oldest extant XID seen by VACUUM"

Cool.

> current vacuum could possibly consider storing into pg_class.)"

Okay, I'll add something more like that.

Almost every aspect of relfrozenxid advancement by VACUUM seems
simpler when thought about in these terms IMV. Every VACUUM now scans
all pages that might have XIDs < OldestXmin, and so every VACUUM can
advance relfrozenxid to the oldest extant XID (barring non-aggressive
VACUUMs that *choose* to skip some all-visible pages).

There are a lot more important details, of course. My "Every
VACUUM..." statement works well as an axiom because all of those other
details don't create any awkward exceptions.

> goals of the patch.

Great.

> My concern is just about making the changes

Makes sense.

> side of saying that commits *do* have behavioral changes.

I think that you've taken my words too literally here. I would never
conceal the intent of a piece of work like that. I thought that it
would clarify matters to point out that I could in theory "get away
with it if I wanted to" in this instance. This was only a means of
conveying a subtle point about the behavioral changes from 0002 --
since you couldn't initially see them yourself (even with my commit
message).

Kind of like Tom Lane's 2011 talk on the query planner. The one where
he lied to the audience several times.

> think splitting the patch should be considered, if that can reasonably

I'll see if I can come up with something. It's hard to be sure about
that kind of thing when you're this close to the code.

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Sun, 27 Mar 2022 20:24:32 -0700

> > Sure, that seems like a good idea. I think I basically agree with the

Attached is v12. My current goal is to commit all 3 patches before
feature freeze. Note that this does not include the more complicated
patch including with previous revisions of the patch series (the
page-level freezing work that appeared in versions before v11).

Changes that appear in this new revision, v12:

* Reworking of the commit messages based on feedback from Robert.

* General cleanup of the changes to heapam.c from 0001 (the changes to
heap_prepare_freeze_tuple and related functions).  New and existing
code now fits together a bit better. I also added a couple of new
documenting assertions, to make the flow a bit easier to understand.

* Added new assertions that document
OldestXmin/FreezeLimit/relfrozenxid invariants, right at the point we
update pg_class within vacuumlazy.c.

These assertions would have a decent chance of failing if there were
any bugs in the code.

* Removed patch that made DISABLE_PAGE_SKIPPING not force aggressive
VACUUM, limiting the underlying mechanism to forcing scanning of all
pages in lazy_scan_heap (v11 was the first and last revision that
included this patch).

* Adds a new small patch 0003. This just moves the last piece of
resource allocation that still took place at the top of
lazy_scan_heap() back into its caller, heap_vacuum_rel().

The work in 0003 probably should have happened as part of the patch
that became commit 73f6ec3d -- same idea. It's totally mechanical
stuff. With 0002 and 0003, there is hardly any lazy_scan_heap code
before the main loop that iterates through blocks in rel_pages (and
the code that's still there is obviously related to the loop in a
direct and obvious way). This seems like a big overall improvement in
maintainability.

Didn't see a way to split up 0002, per Robert's suggestion 3 days ago.
As I said at the time, it's possible to split it up, but not in a way
that highlights the underlying issue (since the issue 0002 fixes was
always limited to non-aggressive VACUUMs). The commit message may have
to suffice.

--
Peter Geoghegan

---

From: Robert Haas <[email-masked]>
Date: Tue, 29 Mar 2022 13:03:32 -0400

> page-level freezing work that appeared in versions before v11).

Reviewing 0001, focusing on the words in the patch file much more than the code:

I can understand this version of the commit message. Woohoo! I like
understanding things.

I think the header comments for FreezeMultiXactId() focus way too much
on what the caller is supposed to do and not nearly enough on what
FreezeMultiXactId() itself does. I think to some extent this also
applies to the comments within the function body.

On the other hand, the header comments for heap_prepare_freeze_tuple()
seem good to me. If I were thinking of calling this function, I would
know how to use the new arguments. If I were looking for bugs in it, I
could compare the logic in the function to what these comments say it
should be doing. Yay.

I think I understand what the first paragraph of the header comment
for heap_tuple_needs_freeze() is trying to say, but the second one is
quite confusing. I think this is again because it veers into talking
about what the caller should do rather than explaining what the
function itself does.

I don't like the statement-free else block in lazy_scan_noprune(). I
think you could delete the else{} and just put that same comment there
with one less level of indentation. There's a clear "return false"
just above so it shouldn't be confusing what's happening.

The comment hunk at the end of lazy_scan_noprune() would probably be
better if it said something more specific than "caller can tolerate
reduced processing." My guess is that it would be something like
"caller does not need to do something or other."

I have my doubts about whether the overwrite-a-future-relfrozenxid
behavior is any good, but that's a topic for another day. I suggest
keeping the words "it seems best to", though, because they convey a
level of tentativeness, which seems appropriate.

I am surprised to see you write in maintenance.sgml that the VACUUM
which most recently advanced relfrozenxid will typically be the most
recent aggressive VACUUM. I would have expected something like "(often
the most recent VACUUM)".

---

From: Peter Geoghegan <[email-masked]>
Date: Tue, 29 Mar 2022 11:58:13 -0700

> I can understand this version of the commit message. Woohoo! I like

That's good news.

> applies to the comments within the function body.

To some extent this is a legitimate difference in style. I myself
don't think that it's intrinsically good to have these sorts of
comments. I just think that it can be the least worst thing when a
function is intrinsically written with one caller and one very
specific set of requirements in mind. That is pretty much a matter of
taste, though.

> about what the caller should do rather than explaining what the

I wouldn't have done it that way if the function wasn't called
heap_tuple_needs_freeze().

I would be okay with removing this paragraph if the function was
renamed to reflect the fact it now tells the caller something about
the tuple having an old XID/MXID relative to the caller's own XID/MXID
cutoffs. Maybe the function name should be heap_tuple_would_freeze(),
making it clear that the function merely tells caller what
heap_prepare_freeze_tuple() *would* do, without presuming to tell the
vacuumlazy.c caller what it *should* do about any of the information
it is provided.

Then it becomes natural to see the boolean return value and the
changes the function makes to caller's relfrozenxid/relminmxid tracker
variables as independent.

> just above so it shouldn't be confusing what's happening.

Okay, will fix.

> "caller does not need to do something or other."

I meant "caller can tolerate not pruning or freezing this particular
page". Will fix.

> level of tentativeness, which seems appropriate.

I agree that it's best to keep a tentative tone here. That code was
written following a very specific bug in pg_upgrade several years
back. There was a very recent bug fixed only last year, by commit
74cf7d46.

FWIW I tend to think that we'd have a much better chance of catching
that sort of thing if we'd had better relfrozenxid instrumentation
before now. Now you'd see a negative value in the "new relfrozenxid:
%u, which is %d xids ahead of previous value" part of the autovacuum
log message in the event of such a bug. That's weird enough that I bet
somebody would notice and report it.

> the most recent VACUUM)".

That's always been true, and will only be slightly less true in
Postgres 15 -- the fact is that we only need to skip one all-visible
page to lose out, and that's not unlikely with tables that aren't
quite small with all the patches from v12 applied (we're still much
too naive). The work that I'll get into Postgres 15 on VACUUM is very
valuable as a basis for future improvements, but not all that valuable
to users (improved instrumentation might be the biggest benefit in 15,
or maybe relminmxid advancement for certain types of applications).

I still think that we need to do more proactive page-level freezing to
make relfrozenxid advancement happen in almost every VACUUM, but even
that won't quite be enough. There are still cases where we need to
make a choice about giving up on relfrozenxid advancement in a
non-aggressive VACUUM -- all-visible pages won't completely go away
with page-level freezing. At a minimum we'll still have edge cases
like the case where heap_lock_tuple() unsets the all-frozen bit. And
pg_upgrade'd databases, too.

0002 structures the logic for skipping using the VM in a way that will
make the choice to skip or not skip all-visible pages in
non-aggressive VACUUMs quite natural. I suspect that
SKIP_PAGES_THRESHOLD was always mostly just about relfrozenxid
advancement in non-aggressive VACUUM, all along. We can do much better
than SKIP_PAGES_THRESHOLD, especially if we preprocess the entire
visibility map up-front -- we'll know the costs and benefits up-front,
before committing to early relfrozenxid advancement.

Overall, aggressive vs non-aggressive VACUUM seems like a false
dichotomy to me. ISTM that it should be a totally dynamic set of
behaviors. There should probably be several different "aggressive
gradations''. Most VACUUMs start out completely non-aggressive
(including even anti-wraparound autovacuums), but can escalate from
there. The non-cancellable autovacuum behavior (technically an
anti-wraparound thing, but really an aggressiveness thing) should be
something we escalate to, as with the failsafe.

Dynamic behavior works a lot better. And it makes scheduling of
autovacuum workers a lot more straightforward -- the discontinuities
seem to make that much harder, which is one more reason to avoid them
altogether.

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Tue, 29 Mar 2022 20:08:32 -0700

> vacuumlazy.c caller what it *should* do about any of the information

Attached is v13, which does it that way. This does seem like a real
increase in clarity, albeit one that comes at the cost of renaming
heap_tuple_needs_freeze().

v13 also addresses all of the other items from Robert's most recent
round of feedback.

I would like to commit something close to v13 on Friday or Saturday.

Thanks
-- 
Peter Geoghegan

---

From: Justin Pryzby <[email-masked]>
Date: Wed, 30 Mar 2022 01:10:41 -0500

+                               diff = (int32) (vacrel->NewRelfrozenXid - vacrel->relfrozenxid);
+                               Assert(diff > 0);

Did you see that this crashed on windows cfbot?

https://api.cirrus-ci.com/v1/artifact/task/4592929254670336/log/tmp_check/postmaster.log
TRAP: FailedAssertion("diff > 0", File: "c:\cirrus\src\backend\access\heap\vacuumlazy.c", Line: 724, PID: 5984)
abort() has been called2022-03-30 03:48:30.267 GMT [5316][client backend] [pg_regress/tablefunc][3/15389:0] ERROR:  infinite recursion detected
2022-03-30 03:48:38.031 GMT [5592][postmaster] LOG:  server process (PID 5984) was terminated by exception 0xC0000354
2022-03-30 03:48:38.031 GMT [5592][postmaster] DETAIL:  Failed process was running: autovacuum: VACUUM ANALYZE pg_catalog.pg_database
2022-03-30 03:48:38.031 GMT [5592][postmaster] HINT:  See C include file "ntstatus.h" for a description of the hexadecimal value.

https://cirrus-ci.com/task/4592929254670336

00000000`007ff130 00000001`400b4ef8     postgres!ExceptionalCondition(
			char * conditionName = 0x00000001`40a915d8 "diff > 0", 
			char * errorType = 0x00000001`40a915c8 "FailedAssertion", 
			char * fileName = 0x00000001`40a91598 "c:\cirrus\src\backend\access\heap\vacuumlazy.c", 
			int lineNumber = 0n724)+0x8d [c:\cirrus\src\backend\utils\error\assert.c @ 70]
00000000`007ff170 00000001`402a0914     postgres!heap_vacuum_rel(
			struct RelationData * rel = 0x00000000`00a51088, 
			struct VacuumParams * params = 0x00000000`00a8420c, 
			struct BufferAccessStrategyData * bstrategy = 0x00000000`00a842a0)+0x1038 [c:\cirrus\src\backend\access\heap\vacuumlazy.c @ 724]
00000000`007ff350 00000001`402a4686     postgres!table_relation_vacuum(
			struct RelationData * rel = 0x00000000`00a51088, 
			struct VacuumParams * params = 0x00000000`00a8420c, 
			struct BufferAccessStrategyData * bstrategy = 0x00000000`00a842a0)+0x34 [c:\cirrus\src\include\access\tableam.h @ 1681]
00000000`007ff380 00000001`402a1a2d     postgres!vacuum_rel(
			unsigned int relid = 0x4ee, 
			struct RangeVar * relation = 0x00000000`01799ae0, 
			struct VacuumParams * params = 0x00000000`00a8420c)+0x5a6 [c:\cirrus\src\backend\commands\vacuum.c @ 2068]
00000000`007ff400 00000001`4050f1ef     postgres!vacuum(
			struct List * relations = 0x00000000`0179df58, 
			struct VacuumParams * params = 0x00000000`00a8420c, 
			struct BufferAccessStrategyData * bstrategy = 0x00000000`00a842a0, 
			bool isTopLevel = true)+0x69d [c:\cirrus\src\backend\commands\vacuum.c @ 482]
00000000`007ff5f0 00000001`4050dc95     postgres!autovacuum_do_vac_analyze(
			struct autovac_table * tab = 0x00000000`00a84208, 
			struct BufferAccessStrategyData * bstrategy = 0x00000000`00a842a0)+0x8f [c:\cirrus\src\backend\postmaster\autovacuum.c @ 3248]
00000000`007ff640 00000001`4050b4e3     postgres!do_autovacuum(void)+0xef5 [c:\cirrus\src\backend\postmaster\autovacuum.c @ 2503]

It seems like there should be even more logs, especially since it says:
[03:48:43.119] Uploading 3 artifacts for c:\cirrus\**\*.diffs
[03:48:43.122] Uploaded c:\cirrus\contrib\tsm_system_rows\regression.diffs
[03:48:43.125] Uploaded c:\cirrus\contrib\tsm_system_time\regression.diffs

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 00:01:06 -0700

> TRAP: FailedAssertion("diff > 0", File: "c:\cirrus\src\backend\access\heap\vacuumlazy.c", Line: 724, PID: 5984)

That's weird. There are very similar assertions a little earlier, that
must have *not* failed here, before the call to vac_update_relstats().
I was actually thinking of removing this assertion for that reason --
I thought that it was redundant.

Perhaps something is amiss inside vac_update_relstats(), where the
boolean flag that indicates that pg_class.relfrozenxid was advanced is
set:

    if (frozenxid_updated)
        *frozenxid_updated = false;
    if (TransactionIdIsNormal(frozenxid) &&
        pgcform->relfrozenxid != frozenxid &&
        (TransactionIdPrecedes(pgcform->relfrozenxid, frozenxid) ||
         TransactionIdPrecedes(ReadNextTransactionId(),
                               pgcform->relfrozenxid)))
    {
        if (frozenxid_updated)
            *frozenxid_updated = true;
        pgcform->relfrozenxid = frozenxid;
        dirty = true;
    }

Maybe the "existing relfrozenxid is in the future, silently update
relfrozenxid" part of the condition (which involves
ReadNextTransactionId()) somehow does the wrong thing here. But how?

The other assertions take into account the fact that OldestXmin can
itself "go backwards" across VACUUM operations against the same table:

    Assert(!aggressive || vacrel->NewRelfrozenXid == OldestXmin ||
           TransactionIdPrecedesOrEquals(FreezeLimit,
                                         vacrel->NewRelfrozenXid));

Note the "vacrel->NewRelfrozenXid == OldestXmin", without which the
assertion will fail pretty easily when the regression tests are run.
Perhaps I need to do something like that with the other assertion as
well (or more likely just get rid of it). Will figure it out tomorrow.

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 17:50:42 -0700

> ReadNextTransactionId()) somehow does the wrong thing here. But how?

I tried several times to recreate this issue on CI. No luck with that,
though -- can't get it to fail again after 4 attempts.

This was a VACUUM of pg_database, run from an autovacuum worker. I am
vaguely reminded of the two bugs fixed by Andres in commit a54e1f15.
Both were issues with the shared relcache init file affecting shared
and nailed catalog relations. Those bugs had symptoms like " ERROR:
found xmin ... from before relfrozenxid ..." for various system
catalogs.

We know that this particular assertion did not fail during the same VACUUM:

    Assert(vacrel->NewRelfrozenXid == OldestXmin ||
           TransactionIdPrecedesOrEquals(vacrel->relfrozenxid,
                                         vacrel->NewRelfrozenXid));

So it's hard to see how this could be a bug in the patch -- the final
new relfrozenxid is presumably equal to VACUUM's OldestXmin in the
problem scenario seen on the CI Windows instance yesterday (that's why
this earlier assertion didn't fail).  The assertion I'm showing here
needs the "vacrel->NewRelfrozenXid == OldestXmin" part of the
condition to account for the fact that
OldestXmin/GetOldestNonRemovableTransactionId() is known to "go
backwards". Without that the regression tests will fail quite easily.

The surprising part of the CI failure must have taken place just after
this assertion, when VACUUM's call to vacuum_set_xid_limits() actually
updates pg_class.relfrozenxid with vacrel->NewRelfrozenXid --
presumably because the existing relfrozenxid appeared to be "in the
future" when we examine it in pg_class again. We see evidence that
this must have happened afterwards, when the closely related assertion
(used only in instrumentation code) fails:

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 19:00:18 -0700

Hi,

> though -- can't get it to fail again after 4 attempts.

It's really annoying that we don't have Assert variants that show the compared
values, that might make it easier to intepret what's going on.

Something vaguely like EXPECT_EQ_U32 in regress.c. Maybe
AssertCmp(type, a, op, b),

Then the assertion could have been something like
   AssertCmp(int32, diff, >, 0)

Does the line number in the failed run actually correspond to the xid, rather
than the mxid case? I didn't check.

You could try to increase the likelihood of reproducing the failure by
duplicating the invocation that lead to the crash a few times in the
.cirrus.yml file in your dev branch. That might allow hitting the problem more
quickly.

Maybe reduce autovacuum_naptime in src/tools/ci/pg_ci_base.conf?

Or locally - one thing that windows CI does different from the other platforms
is that it runs isolation, contrib and a bunch of other tests using the same
cluster. Which of course increases the likelihood of autovacuum having stuff
to do, *particularly* on shared relations - normally there's probably not
enough changes for that.

You can do something similar locally on linux with
    make -Otarget -C contrib/ -j48 -s USE_MODULE_DB=1 installcheck prove_installcheck=true
(the prove_installcheck=true to prevent tap tests from running, we don't seem
to have another way for that)

I don't think windows uses USE_MODULE_DB=1, but it allows to cause a lot more
load concurrently than running tests serially...

>                                          vacrel->NewRelfrozenXid));

The comment in your patch says "is either older or newer than FreezeLimit" - I
assume that's some rephrasing damage?

> this earlier assertion didn't fail).

Perhaps it's worth commiting improved assertions on master? If this is indeed
a pre-existing bug, and we're just missing due to slightly less stringent
asserts, we could rectify that separately.

> (used only in instrumentation code) fails:

Hm. This triggers some vague memories. There's some oddities around shared
relations being vacuumed separately in all the databases and thus having
separate horizons.

After "remembering" that, I looked in the cirrus log for the failed run, and
the worker was processing shared a shared relation last:

2022-03-30 03:48:30.238 GMT [5984][autovacuum worker] LOG:  automatic analyze of table "contrib_regression.pg_catalog.pg_authid"

Obviously that's not a guarantee that the next table processed also is a
shared catalog, but ...

Oh, the relid is actually in the stack trace. 0x4ee = 1262 =
pg_database. Which makes sense, the test ends up with a high percentage of
dead rows in pg_database, due to all the different contrib tests
creating/dropping a database.

> From my patch:
> 
> >             if (frozenxid_updated)
> >             {
> > -               diff = (int32) (FreezeLimit - vacrel->relfrozenxid);
> >                 appendStringInfo(&buf,
> >                                  _("new relfrozenxid: %u, which is %d xids ahead of previous value\n"),
> > -                                FreezeLimit, diff);
> > +                                vacrel->NewRelfrozenXid, diff);
> >             }

Perhaps this ought to be an elog() instead of an Assert()? Something has gone
pear shaped if we get here... It's a bit annoying though, because it'd have to
be a PANIC to be visible on the bf / CI :(.

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 19:37:58 -0700

>    AssertCmp(int32, diff, >, 0)

I'd definitely use them if they were there.

> than the mxid case? I didn't check.

Yes, I verified -- definitely relfrozenxid.

> load concurrently than running tests serially...

Can't get it to fail locally with that recipe.

> assume that's some rephrasing damage?

Both the comment and the assertion are correct. I see what you mean, though.

> asserts, we could rectify that separately.

I don't think there's much chance of the assertion actually hitting
without the rest of the patch series. The new relfrozenxid value is
always going to be OldestXmin - vacuum_min_freeze_age on HEAD, while
with the patch it's sometimes close to OldestXmin. Especially when you
have lots of dead tuples that you churn through constantly (like
pgbench_tellers, or like these system catalogs on the CI test
machine).

> relations being vacuumed separately in all the databases and thus having

That's what I was thinking of, obviously.

> 2022-03-30 03:48:30.238 GMT [5984][autovacuum worker] LOG:  automatic analyze of table "contrib_regression.pg_catalog.pg_authid"

I noticed the same thing myself. Should have said sooner.

> be a PANIC to be visible on the bf / CI :(.

Yeah, a WARNING would be good here. I can write a new version of my
patch series with a separation patch for that this evening. Actually,
better make it a PANIC for now...

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 19:51:21 -0700

> better make it a PANIC for now...

Attached is v14, which includes a new patch that PANICs like that in
vac_update_relstats() --- 0003.

This approach also covers manual VACUUMs, which isn't the case with
the failing assertion, which is in instrumentation code (actually
VACUUM VERBOSE might hit it).

I definitely think that something like this should be committed.
Silently ignoring system catalog corruption isn't okay.

-- 
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 20:28:44 -0700

Hi,

I was able to trigger the crash.

cat ~/tmp/pgbench-createdb.sql
CREATE DATABASE pgb_:client_id;
DROP DATABASE pgb_:client_id;

pgbench -n -P1 -c 10 -j10 -T100 -f ~/tmp/pgbench-createdb.sql

while I was also running

for i in $(seq 1 100); do echo iteration $i; make -Otarget -C contrib/ -s installcheck -j48 -s prove_installcheck=true USE_MODULE_DB=1 > /tmp/ci-$i.log 2>&1; done

I triggered twice now, but it took a while longer the second time.

(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49
        set = {__val = {4194304, 0, 0, 0, 0, 0, 216172782113783808, 2, 2377909399344644096, 18446497967838863616, 0, 0, 0, 0, 0, 0}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007fe49a2db546 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x0, sa_sigaction = 0x0}, sa_mask = {__val = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}},
          sa_flags = 0, sa_restorer = 0x107e0}
        sigs = {__val = {32, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}}
#2  0x00007fe49b9706f1 in ExceptionalCondition (conditionName=0x7fe49ba0618d "diff > 0", errorType=0x7fe49ba05bd1 "FailedAssertion",
    fileName=0x7fe49ba05b90 "/home/andres/src/postgresql/src/backend/access/heap/vacuumlazy.c", lineNumber=724)
    at /home/andres/src/postgresql/src/backend/utils/error/assert.c:69
No locals.
#3  0x00007fe49b2fc739 in heap_vacuum_rel (rel=0x7fe497a8d148, params=0x7fe49c130d7c, bstrategy=0x7fe49c130e10)
    at /home/andres/src/postgresql/src/backend/access/heap/vacuumlazy.c:724
        buf = {
          data = 0x7fe49c17e238 "automatic vacuum of table \"contrib_regression_dict_int.pg_catalog.pg_database\": index scans: 1\npages: 0 removed, 3 remain, 3 scanned (100.00% of total)\ntuples: 49 removed, 53 remain, 9 are dead but no"..., len = 279, maxlen = 1024, cursor = 0}
        msgfmt = 0x7fe49ba06038 "automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
        diff = 0
        endtime = 702011687982080
        vacrel = 0x7fe49c19b5b8
        verbose = false
        instrument = true
        ru0 = {tv = {tv_sec = 1648696487, tv_usec = 975963}, ru = {ru_utime = {tv_sec = 0, tv_usec = 0}, ru_stime = {tv_sec = 0, tv_usec = 3086}, {
--Type <RET> for more, q to quit, c to continue without paging--c
              ru_maxrss = 10824, __ru_maxrss_word = 10824}, {ru_ixrss = 0, __ru_ixrss_word = 0}, {ru_idrss = 0, __ru_idrss_word = 0}, {ru_isrss = 0, __ru_isrss_word = 0}, {ru_minflt = 449, __ru_minflt_word = 449}, {ru_majflt = 0, __ru_majflt_word = 0}, {ru_nswap = 0, __ru_nswap_word = 0}, {ru_inblock = 0, __ru_inblock_word = 0}, {ru_oublock = 0, __ru_oublock_word = 0}, {ru_msgsnd = 0, __ru_msgsnd_word = 0}, {ru_msgrcv = 0, __ru_msgrcv_word = 0}, {ru_nsignals = 0, __ru_nsignals_word = 0}, {ru_nvcsw = 2, __ru_nvcsw_word = 2}, {ru_nivcsw = 0, __ru_nivcsw_word = 0}}}
        starttime = 702011687975964
        walusage_start = {wal_records = 0, wal_fpi = 0, wal_bytes = 0}
        walusage = {wal_records = 11, wal_fpi = 7, wal_bytes = 30847}
        secs = 0
        usecs = 6116
        read_rate = 16.606033355134073
        write_rate = 7.6643230869849575
        aggressive = false
        skipwithvm = true
        frozenxid_updated = true
        minmulti_updated = true
        orig_rel_pages = 3
        new_rel_pages = 3
        new_rel_allvisible = 0
        indnames = 0x7fe49c19bb28
        errcallback = {previous = 0x0, callback = 0x7fe49b3012fd <vacuum_error_callback>, arg = 0x7fe49c19b5b8}
        startreadtime = 180
        startwritetime = 0
        OldestXmin = 67552
        FreezeLimit = 4245034848
        OldestMxact = 224
        MultiXactCutoff = 4289967520
        __func__ = "heap_vacuum_rel"
#4  0x00007fe49b523d92 in table_relation_vacuum (rel=0x7fe497a8d148, params=0x7fe49c130d7c, bstrategy=0x7fe49c130e10) at /home/andres/src/postgresql/src/include/access/tableam.h:1680
No locals.
#5  0x00007fe49b527032 in vacuum_rel (relid=1262, relation=0x7fe49c1ae360, params=0x7fe49c130d7c) at /home/andres/src/postgresql/src/backend/commands/vacuum.c:2065
        lmode = 4
        rel = 0x7fe497a8d148
        lockrelid = {relId = 1262, dbId = 0}
        toast_relid = 0
        save_userid = 10
        save_sec_context = 0
        save_nestlevel = 2
        __func__ = "vacuum_rel"
#6  0x00007fe49b524c3b in vacuum (relations=0x7fe49c1b03a8, params=0x7fe49c130d7c, bstrategy=0x7fe49c130e10, isTopLevel=true) at /home/andres/src/postgresql/src/backend/commands/vacuum.c:482
        vrel = 0x7fe49c1ae3b8
        cur__state = {l = 0x7fe49c1b03a8, i = 0}
        cur = 0x7fe49c1b03c0
        _save_exception_stack = 0x7fff97e35a10
        _save_context_stack = 0x0
        _local_sigjmp_buf = {{__jmpbuf = {140735741652128, 6126579318940970843, 9223372036854775747, 0, 0, 0, 6126579318957748059, 6139499258682879835}, __mask_was_saved = 0, __saved_mask = {__val = {32, 140619848279000, 8590910454, 140619848278592, 32, 140619848278944, 7784, 140619848278592, 140619848278816, 140735741647200, 140619839915137, 8458711686435861857, 32, 4869, 140619848278592, 140619848279024}}}}
        _do_rethrow = false
        in_vacuum = true
        stmttype = 0x7fe49baff1a7 "VACUUM"
        in_outer_xact = false
        use_own_xacts = true
        __func__ = "vacuum"
#7  0x00007fe49b6d483d in autovacuum_do_vac_analyze (tab=0x7fe49c130d78, bstrategy=0x7fe49c130e10) at /home/andres/src/postgresql/src/backend/postmaster/autovacuum.c:3247
        rangevar = 0x7fe49c1ae360
        rel = 0x7fe49c1ae3b8
        rel_list = 0x7fe49c1ae3f0
#8  0x00007fe49b6d34bc in do_autovacuum () at /home/andres/src/postgresql/src/backend/postmaster/autovacuum.c:2495
        _save_exception_stack = 0x7fff97e35d70
        _save_context_stack = 0x0
        _local_sigjmp_buf = {{__jmpbuf = {140735741652128, 6126579318779490139, 9223372036854775747, 0, 0, 0, 6126579319014371163, 6139499700101525339}, __mask_was_saved = 0, __saved_mask = {__val = {140619840139982, 140735741647712, 140619841923928, 957, 140619847223443, 140735741647656, 140619847312112, 140619847223451, 140619847223443, 140619847224399, 0, 139637976727552, 140619817480714, 140735741647616, 140619839856340, 1024}}}}
        _do_rethrow = false
        tab = 0x7fe49c130d78
        skipit = false
        stdVacuumCostDelay = 0
        stdVacuumCostLimit = 200
        iter = {cur = 0x7fe497668da0, end = 0x7fe497668da0}
        relid = 1262
        classTup = 0x7fe497a6c568
        isshared = true
        cell__state = {l = 0x7fe49c130d40, i = 0}
        classRel = 0x7fe497a5ae18
        tuple = 0x0
        relScan = 0x7fe49c130928
        dbForm = 0x7fe497a64fb8
        table_oids = 0x7fe49c130d40
        orphan_oids = 0x0
        ctl = {num_partitions = 0, ssize = 0, dsize = 1296236544, max_dsize = 140619847224424, keysize = 4, entrysize = 96, hash = 0x0, match = 0x0, keycopy = 0x0, alloc = 0x0, hcxt = 0x7fff97e35c50, hctl = 0x7fe49b9a787e <AllocSetFree+670>}
        table_toast_map = 0x7fe49c19d2f0
        cell = 0x7fe49c130d58
        shared = 0x7fe49c17c360
        dbentry = 0x7fe49c18d7a0
        bstrategy = 0x7fe49c130e10
        key = {sk_flags = 0, sk_attno = 17, sk_strategy = 3, sk_subtype = 0, sk_collation = 950, sk_func = {fn_addr = 0x7fe49b809a6a <chareq>, fn_oid = 61, fn_nargs = 2, fn_strict = true, fn_retset = false, fn_stats = 2 '\002', fn_extra = 0x0, fn_mcxt = 0x7fe49c12f7f0, fn_expr = 0x0}, sk_argument = 116}
        pg_class_desc = 0x7fe49c12f910
        effective_multixact_freeze_max_age = 400000000
        did_vacuum = false
        found_concurrent_worker = false
        i = 32740
        __func__ = "do_autovacuum"
#9  0x00007fe49b6d21c4 in AutoVacWorkerMain (argc=0, argv=0x0) at /home/andres/src/postgresql/src/backend/postmaster/autovacuum.c:1719
        dbname = "contrib_regression_dict_int\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
        local_sigjmp_buf = {{__jmpbuf = {140735741652128, 6126579318890639195, 9223372036854775747, 0, 0, 0, 6126579318785781595, 6139499699353759579}, __mask_was_saved = 1, __saved_mask = {__val = {18446744066192964099, 8, 140735741648416, 140735741648352, 3156423108750738944, 0, 30, 140735741647888, 140619835812981, 140735741648080, 32666874400, 140735741648448, 140619836964693, 140735741652128, 2586778441, 140735741648448}}}}
        dbid = 205328
        __func__ = "AutoVacWorkerMain"
#10 0x00007fe49b6d1d5b in StartAutoVacWorker () at /home/andres/src/postgresql/src/backend/postmaster/autovacuum.c:1504
        worker_pid = 0
        __func__ = "StartAutoVacWorker"
#11 0x00007fe49b6e79af in StartAutovacuumWorker () at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:5635
        bn = 0x7fe49c0da920
        __func__ = "StartAutovacuumWorker"
#12 0x00007fe49b6e745d in sigusr1_handler (postgres_signal_arg=10) at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:5340
        save_errno = 4
        __func__ = "sigusr1_handler"
#13 <signal handler called>
No locals.
#14 0x00007fe49a3a9fc4 in __GI___select (nfds=8, readfds=0x7fff97e36c20, writefds=0x0, exceptfds=0x0, timeout=0x7fff97e36ca0) at ../sysdeps/unix/sysv/linux/select.c:71
        sc_ret = -4
        sc_ret = <optimized out>
        s = <optimized out>
        us = <optimized out>
        ns = <optimized out>
        ts64 = {tv_sec = 59, tv_nsec = 765565741}
        pts64 = <optimized out>
        r = <optimized out>
#15 0x00007fe49b6e26c7 in ServerLoop () at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1765
        timeout = {tv_sec = 60, tv_usec = 0}
        rmask = {fds_bits = {224, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}}
        selres = -1
        now = 1648696487
        readmask = {fds_bits = {224, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0}}
        nSockets = 8
        last_lockfile_recheck_time = 1648696432
        last_touch_time = 1648696072
        __func__ = "ServerLoop"
#16 0x00007fe49b6e2031 in PostmasterMain (argc=55, argv=0x7fe49c0aa2d0) at /home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1473
        opt = -1
        status = 0
        userDoption = 0x7fe49c0951d0 "/srv/dev/pgdev-dev/"
        listen_addr_saved = true
        i = 64
        output_config_variable = 0x0
        __func__ = "PostmasterMain"
#17 0x00007fe49b5d2808 in main (argc=55, argv=0x7fe49c0aa2d0) at /home/andres/src/postgresql/src/backend/main/main.c:202
        do_check_root = true

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 20:35:25 -0700

Great.

I wonder if you can get an RR recording...
-- 
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 20:35:51 -0700

Hi,

> I triggered twice now, but it took a while longer the second time.

Forgot to say how postgres was started. Via my usual devenv script, which
results in:

+ /home/andres/build/postgres/dev-assert/vpath/src/backend/postgres -c hba_file=/home/andres/tmp/pgdev/pg_hba.conf -D /srv/dev/pgdev-dev/ -p 5440 -c shared_buffers=2GB -c wal_level=hot_standby -c max_wal_senders=10 -c track_io_timing=on -c restart_after_crash=false -c max_prepared_transactions=20 -c log_checkpoints=on -c min_wal_size=48MB -c max_wal_size=150GB -c 'cluster_name=dev assert' -c ssl_cert_file=/home/andres/tmp/pgdev/ssl-cert-snakeoil.pem -c ssl_key_file=/home/andres/tmp/pgdev/ssl-cert-snakeoil.key -c 'log_line_prefix=%m [%p][%b][%v:%x][%a] ' -c shared_buffers=16MB -c log_min_messages=debug1 -c log_connections=on -c allow_in_place_tablespaces=1 -c log_autovacuum_min_duration=0 -c log_lock_waits=true -c autovacuum_naptime=10s -c fsync=off

Greetings,

Andres Freund

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 21:04:07 -0700

Hi,

> I wonder if you can get an RR recording...

Started it, but looks like it's too slow.

(gdb) p MyProcPid
$1 = 2172500

(gdb) p vacrel->NewRelfrozenXid
$3 = 717
(gdb) p vacrel->relfrozenxid
$4 = 717
(gdb) p OldestXmin
$5 = 5112
(gdb) p aggressive
$6 = false

There was another autovacuum of pg_database 10s before:

2022-03-30 20:35:17.622 PDT [2165344][autovacuum worker][5/3:0][] LOG:  automatic vacuum of table "postgres.pg_catalog.pg_database": index scans: 1
        pages: 0 removed, 3 remain, 3 scanned (100.00% of total)
        tuples: 61 removed, 4 remain, 1 are dead but not yet removable
        removable cutoff: 1921, older by 3 xids when operation ended
        new relfrozenxid: 717, which is 3 xids ahead of previous value
        index scan needed: 3 pages from table (100.00% of total) had 599 dead item identifiers removed
        index "pg_database_datname_index": pages: 2 in total, 0 newly deleted, 0 currently deleted, 0 reusable
        index "pg_database_oid_index": pages: 4 in total, 0 newly deleted, 0 currently deleted, 0 reusable
        I/O timings: read: 0.029 ms, write: 0.034 ms
        avg read rate: 134.120 MB/s, avg write rate: 89.413 MB/s
        buffer usage: 35 hits, 12 misses, 8 dirtied
        WAL usage: 12 records, 5 full page images, 27218 bytes
        system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s

The dying backend:
2022-03-30 20:35:27.668 PDT [2172500][autovacuum worker][7/0:0][] DEBUG:  autovacuum: processing database "contrib_regression_hstore"
...
2022-03-30 20:35:27.690 PDT [2172500][autovacuum worker][7/674:0][] CONTEXT:  while cleaning up index "pg_database_oid_index" of relation "pg_catalog.pg_database"

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 21:11:48 -0700

> (gdb) p vacrel->relfrozenxid

Does this OldestXmin seem reasonable at this point in execution, based
on context? Does it look too high? Something else?

-- 
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 21:20:38 -0700

Hi,

> Started it, but looks like it's too slow.

I added a bunch of debug elogs to see what sets *frozenxid_updated to true.

(gdb) p *vacrel
$1 = {rel = 0x7fe24f3e0148, indrels = 0x7fe255c17ef8, nindexes = 2, aggressive = false, skipwithvm = true, failsafe_active = false,
  consider_bypass_optimization = true, do_index_vacuuming = true, do_index_cleanup = true, do_rel_truncate = true, bstrategy = 0x7fe255bb0e28, pvs = 0x0,
  relfrozenxid = 717, relminmxid = 6, old_live_tuples = 42, OldestXmin = 20751, vistest = 0x7fe255058970 <GlobalVisSharedRels>, FreezeLimit = 4244988047,
  MultiXactCutoff = 4289967302, NewRelfrozenXid = 717, NewRelminMxid = 6, skippedallvis = false, relnamespace = 0x7fe255c17bf8 "pg_catalog",
  relname = 0x7fe255c17cb8 "pg_database", indname = 0x0, blkno = 4294967295, offnum = 0, phase = VACUUM_ERRCB_PHASE_SCAN_HEAP, verbose = false,
  dead_items = 0x7fe255c131d0, rel_pages = 8, scanned_pages = 8, removed_pages = 0, lpdead_item_pages = 0, missed_dead_pages = 0, nonempty_pages = 8,
  new_rel_tuples = 124, new_live_tuples = 42, indstats = 0x7fe255c18320, num_index_scans = 0, tuples_deleted = 0, lpdead_items = 0, live_tuples = 42,
  recently_dead_tuples = 82, missed_dead_tuples = 0}

But the debug elog reports that

relfrozenxid updated 714 -> 717
relminmxid updated 1 -> 6

Tthe problem is that the crashing backend reads the relfrozenxid/relminmxid
from the shared relcache init file written by another backend:

2022-03-30 21:10:47.626 PDT [2625038][autovacuum worker][6/433:0][] LOG:  automatic vacuum of table "contrib_regression_postgres_fdw.pg_catalog.pg_database": index scans: 1
        pages: 0 removed, 8 remain, 8 scanned (100.00% of total)
        tuples: 4 removed, 114 remain, 72 are dead but not yet removable
        removable cutoff: 20751, older by 596 xids when operation ended
        new relfrozenxid: 717, which is 3 xids ahead of previous value
        new relminmxid: 6, which is 5 mxids ahead of previous value
        index scan needed: 3 pages from table (37.50% of total) had 8 dead item identifiers removed
        index "pg_database_datname_index": pages: 2 in total, 0 newly deleted, 0 currently deleted, 0 reusable
        index "pg_database_oid_index": pages: 6 in total, 0 newly deleted, 2 currently deleted, 2 reusable
        I/O timings: read: 0.050 ms, write: 0.102 ms
        avg read rate: 209.860 MB/s, avg write rate: 76.313 MB/s
        buffer usage: 42 hits, 22 misses, 8 dirtied
        WAL usage: 13 records, 5 full page images, 33950 bytes
        system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
...
2022-03-30 21:10:47.772 PDT [2625043][autovacuum worker][:0][] DEBUG:  InitPostgres
2022-03-30 21:10:47.772 PDT [2625043][autovacuum worker][6/0:0][] DEBUG:  my backend ID is 6
2022-03-30 21:10:47.772 PDT [2625043][autovacuum worker][6/0:0][] LOG:  reading shared init file
2022-03-30 21:10:47.772 PDT [2625043][autovacuum worker][6/443:0][] DEBUG:  StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/sub>
2022-03-30 21:10:47.772 PDT [2625043][autovacuum worker][6/443:0][] LOG:  reading non-shared init file

This is basically the inverse of a54e1f15 - we read a *newer* horizon. That's
normally fairly harmless - I think.

Perhaps we should just fetch the horizons from the "local" catalog for shared
rels?

Greetings,

Andres Freund

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 21:24:43 -0700

Hi,

> on context? Does it look too high? Something else?

Reasonable:
(gdb) p *ShmemVariableCache
$1 = {nextOid = 78969, oidCount = 2951, nextXid = {value = 21411}, oldestXid = 714, xidVacLimit = 200000714, xidWarnLimit = 2107484361,
  xidStopLimit = 2144484361, xidWrapLimit = 2147484361, oldestXidDB = 1, oldestCommitTsXid = 0, newestCommitTsXid = 0, latestCompletedXid = {value = 21408},
  xactCompletionCount = 1635, oldestClogXid = 714}

I think the explanation I just sent explains the problem, without "in-memory"
confusion about what's running and what's not.

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 21:29:16 -0700

> from the shared relcache init file written by another backend:

We should have added logging of relfrozenxid and relminmxid a long time ago.

> normally fairly harmless - I think.

Is this one pretty old?

> Perhaps we should just fetch the horizons from the "local" catalog for shared

Not sure what you mean.

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Wed, 30 Mar 2022 21:44:32 -0700

> > Perhaps we should just fetch the horizons from the "local" catalog for shared

Wait, you mean use vacrel->relfrozenxid directly? Seems kind of ugly...

-- 
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Wed, 30 Mar 2022 21:59:15 -0700

Hi,

> We should have added logging of relfrozenxid and relminmxid a long time ago.

At least at DEBUG1 or such.

> > normally fairly harmless - I think.

What do you mean with "this one"? The cause for the assert failure?

I'm not sure there's a proper bug on HEAD here. I think at worst it can delay
the horizon increasing a bunch, by falsely not using an aggressive vacuum when
we should have - might even be limited to a single autovacuum cycle.

> > Perhaps we should just fetch the horizons from the "local" catalog for shared

Basically, instead of relying on the relcache, which for shared relation is
vulnerable to seeing "too new" horizons due to the shared relcache init file,
explicitly load relfrozenxid / relminmxid from the the catalog / syscache.

I.e. fetch the relevant pg_class row in heap_vacuum_rel() (using
SearchSysCache[Copy1](RELID)). And use that to set vacrel->relfrozenxid
etc. Whereas right now we only fetch the pg_class row in
vac_update_relstats(), but use the relcache before.

Greetings,

Andres Freund

---

From: Andres Freund <[email-masked]>
Date: Thu, 31 Mar 2022 09:37:15 -0700

Hi,

> vac_update_relstats(), but use the relcache before.

Perhaps we should explicitly mask out parts of relcache entries in the shared
init file that we know to be unreliable. I.e. set relfrozenxid, relminmxid to
Invalid* or such.

I even wonder if we should just generally move those out of the fields we have
in the relcache, not just for shared rels loaded from the init
fork. Presumably by just moving them into the CATALOG_VARLEN ifdef.

The only place that appears to access rd_rel->relfrozenxid outside of DDL is
heap_abort_speculative().

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 31 Mar 2022 09:58:18 -0700

> init file that we know to be unreliable. I.e. set relfrozenxid, relminmxid to

That has the advantage of being more honest. If you're going to break
the abstraction, then it seems best to break it in an obvious way,
that leaves no doubts about what you're supposed to be relying on.

This bug doesn't seem like the kind of thing that should be left
as-is. If only because it makes it hard to add something like a
WARNING when we make relfrozenxid go backwards (on the basis of the
existing value apparently being in the future), which we really should
have been doing all along.

The whole reason why we overwrite pg_class.relfrozenxid values from
the future is to ameliorate the effects of more serious bugs like the
pg_upgrade/pg_resetwal one fixed in commit 74cf7d46 not so long ago
(mid last year). We had essentially the same pg_upgrade "from the
future" bug twice (once for relminmxid in the MultiXact bug era,
another more recent version affecting relfrozenxid).

> heap_abort_speculative().

I wonder how necessary that really is. Even if the XID is before
relfrozenxid, does that in itself really make it "in the future"?
Obviously it's often necessary to make the assumption that allowing
wraparound amounts to allowing XIDs "from the future" to exist, which
is dangerous. But why here? Won't pruning by VACUUM eventually correct
the issue anyway?

--
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Thu, 31 Mar 2022 10:11:14 -0700

Hi,

> is dangerous. But why here? Won't pruning by VACUUM eventually correct

I don't think we should weaken defenses against xids from before relfrozenxid
in vacuum / amcheck / .... If anything we should strengthen them.

Isn't it also just plainly required for correctness? We'd not necessarily
trigger a vacuum in time to remove the xid before approaching wraparound if we
put in an xid before relfrozenxid? That happening in prune_xid is obviously
les bad than on actual data, but still.

ISTM we should just use our own xid. Yes, it might delay cleanup a bit
longer. But unless there's already crud on the page (with prune_xid already
set, the abort of the speculative insertion isn't likely to make the
difference?

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 31 Mar 2022 10:12:49 -0700

> we should have - might even be limited to a single autovacuum cycle.

So, to be clear: vac_update_relstats() never actually considered the
new relfrozenxid value from its vacuumlazy.c caller to be "in the
future"? It just looked that way to the failing assertion in
vacuumlazy.c, because its own version of the original relfrozenxid was
stale from the beginning? And so the worst problem is probably just
that we don't use aggressive VACUUM when we really should in rare
cases?

-- 
Peter Geoghegan

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 31 Mar 2022 10:16:59 -0700

> les bad than on actual data, but still.

Yeah, you're right. Ambiguity about stuff like this should be avoided
on general principle.

> set, the abort of the speculative insertion isn't likely to make the

Speculative insertion abort is pretty rare in the real world, I bet.
The speculative insertion precheck is very likely to work almost
always with real workloads.

-- 
Peter Geoghegan

---

From: Andres Freund <[email-masked]>
Date: Thu, 31 Mar 2022 10:50:07 -0700

Hi,

On 2022-03-31 10:12:49 -0700, Peter Geoghegan wrote:
> future"?

No, I added separate debug messages for those, and also applied your patch,
and it didn't trigger.

I don't immediately see how we could end up computing a frozenxid value that
would be problematic? The pgcform->relfrozenxid value will always be the
"local" value, which afaics can be behind the other database's value (and thus
behind the value from the relcache init file). But it can't be ahead, we have
the proper invalidations for that (I think).

I do think we should apply a version of the warnings you have (with a WARNING
instead of PANIC obviously). I think it's bordering on insanity that we have
so many paths to just silently fix stuff up around vacuum. It's like we want
things to be undebuggable, and to give users no warnings about something being
up.

> It just looked that way to the failing assertion in

Yes, I think that's right.

Can you repro the issue with my recipe? FWIW, adding log_min_messages=debug5
and fsync=off made the crash trigger more quickly.

Greetings,

Andres Freund

---

From: Peter Geoghegan <[email-masked]>
Date: Thu, 31 Mar 2022 11:19:53 -0700

> No, I added separate debug messages for those, and also applied your patch,

The assert is "Assert(diff > 0)", and not "Assert(diff >= 0)". Plus
the other related assert I mentioned did not trigger. So when this
"diff" assert did trigger, the value of "diff" must have been 0 (not a
negative value). While this state does technically indicate that the
"existing" relfrozenxid value (actually a stale version) appears to be
"in the future" (because the OldestXmin XID might still never have
been allocated), it won't ever be in the future according to
vac_update_relstats() (even if it used that version).

I suppose that I might be wrong about that, somehow -- anything is
possible. The important point is that there is currently no evidence
that this bug (or any very recent bug) could ever allow
vac_update_relstats() to actually believe that it needs to update
relfrozenxid/relminmxid, purely because the existing value is in the
future.

The fact that vac_update_relstats() doesn't log/warn when this happens
is very unfortunate, but there is nevertheless no evidence that that
would have informed us of any bug on HEAD, even including the actual
bug here, which is a bug in vacuumlazy.c (not in vac_update_relstats).

> things to be undebuggable, and to give users no warnings about something being

Yeah, it's just totally self defeating to not at least log it. I mean
this is a code path that is only hit once per VACUUM, so there is
practically no risk of that causing any new problems.

> and fsync=off made the crash trigger more quickly.

I'll try to do that today. I'm not feeling the most energetic right
now, to be honest.

--
Peter Geoghegan