Subject: Re: avoid multiple hard links to same WAL file after a crash

From: Michael Paquier <[email-masked]>
Date: Sun, 1 May 2022 22:08:53 +0900

On Tue, Apr 12, 2022 at 09:27:42AM -0700, Nathan Bossart wrote:
> On Tue, Apr 12, 2022 at 03:46:31PM +0900, Kyotaro Horiguchi wrote:
>> At Mon, 11 Apr 2022 09:52:57 -0700, Nathan Bossart <[email-masked]> wrote in 
>>> I traced this back a while ago.  I believe the link() was first added in
>>> November 2000 as part of f0e37a8.  This even predates WAL recycling, which
>>> was added in July 2001 as part of 7d4d5c0.
>> 
>> f0e37a8 lacks discussion.. It introduced the CHECKPOINT command from
>> somwhere out of the ML.. This patch changed XLogFileInit to
>> supportusing existent files so that XLogWrite can use the new segment
>> provided by checkpoint and still allow XLogWrite to create a new
>> segment by itself.

Yes, I think that you are right here.  I also suspect that the
checkpoint command was facing a concurrency issue while working on
the feature and that Vadim saw that this part of the implementation
would be safer in the long run if we use link() followed by unlink().

> Yeah, I've been unable to find any discussion besides a brief reference to
> adding checkpointing [0].
> 
> [0] https://postgr.es/m/8F4C99C66D04D4118F580090272A7A23018D85%40sectorbase1.sectorbase.com

While looking at the history of this area, I have also noticed this
argument, telling also that this is a safety measure if this code were
to run in parallel, but that's without counting on the control file
lock hold while doing this operation anyway:
https://www.postgresql.org/message-id/[email-masked]

As mentioned already upthread, f0e37a8 is the origin of the
link()/unlink() business in the WAL segment initialization logic, and
also note 1f159e5 that has added a rename() as extra code path for
systems where link() was not working.

At the end, switching directly from durable_rename_excl() to
durable_rename() should be fine for the WAL segment initialization,
but we could do things a bit more carefully by adding a check on the
file existence before calling durable_rename() and issue a elog(LOG)
if a file is found, giving a mean for the WAL recycling to give up
peacefully as it does now.  Per my analysis, the TLI history file
created at the end of recovery ought to issue an elog(ERROR).

Now, I am surprised by the third code path of durable_rename_excl(),
as of the WAL receiver doing writeTimeLineHistoryFile(), to not cause
any issues, as link() should exit with EEXIST when the startup process
grabs the same history file concurrently.  It seems to me that in this
last case using durable_rename() could be an improvement and prevent
extra WAL receiver restarts as a TLI history fetched from the primary
via streaming or from some archives should be the same, but we could
be more careful, like the WAL init logic, by skipping the
durable_rename() and issuing an elog(LOG).  That would not be perfect,
still a bit better than the current state of HEAD.

As we are getting closer to the beta release, it looks safer to let
this change aside a bit longer and wait for v16 to be opened for
business on HEAD.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Mon, 2 May 2022 19:48:18 +0900

> still a bit better than the current state of HEAD.

Skimming through at the buildfarm logs, it happens that the tests are
able to see this race from time to time.  Here is one such example on
rorqual:
https://buildfarm.postgresql.org/cgi-bin/show_stage_log.pl?nm=rorqual&dt=2022-04-20%2004%3A47%3A58&stg=recovery-check

And here are the relevant logs:
2022-04-20 05:04:19.028 UTC [3109048][startup][:0] LOG:  restored log
file "00000002.history" from archive
2022-04-20 05:04:19.029 UTC [3109111][walreceiver][:0] LOG:  fetching
timeline history file for timeline 2 from primary server
2022-04-20 05:04:19.048 UTC [3109111][walreceiver][:0] FATAL:  could
not link file "pg_wal/xlogtemp.3109111" to "pg_wal/00000002.history":
File exists
[...]
2022-04-20 05:04:19.234 UTC [3109250][walreceiver][:0] LOG:  started
streaming WAL from primary at 0/3000000 on timeline 2

The WAL receiver upgrades the ERROR to a FATAL, and restarts
streaming shortly after.  Using durable_rename() would not be an issue
here.
--
Michael

---

From: Nathan Bossart <[email-masked]>
Date: Mon, 2 May 2022 10:36:57 -0700

> created at the end of recovery ought to issue an elog(ERROR).

My only concern with this approach is that it inevitably introduces a race
condition.  In most cases, the file existence check will prevent
overwrites, but it might not always.  Furthermore, we believe that such
overwrites either 1) should not happen (e.g., WAL recycling) or 2) won't
cause problems if they happen (e.g., when the WAL receiver writes the TLI
history file).  Also, these races will be difficult to test, so we won't
know what breaks when they occur.

My instinct is to just let the overwrites happen.  That way, we are more
likely to catch breakage in tests, and we'll have one less race condition
to worry about.  I don't mind asserting that the file doesn't exist when we
don't expect it to, as that might help catch potential problems in
development without affecting behavior in production.  If we do want to
add file existence checks, I think we'd better add a comment about the
potential for race conditions.

-- 
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

---

From: Nathan Bossart <[email-masked]>
Date: Mon, 2 May 2022 10:39:07 -0700

> streaming shortly after.  Using durable_rename() would not be an issue

Thanks for investigating this one.  I think I agree that we should simply
switch to durable_rename() (without a file existence check beforehand).

---

From: Nathan Bossart <[email-masked]>
Date: Mon, 2 May 2022 16:06:13 -0700

> switch to durable_rename() (without a file existence check beforehand).

Here is a new patch set.  For now, I've only removed the file existence
check in writeTimeLineHistoryFile().  I don't know if I'm totally convinced
that there isn't a problem here (e.g., due to concurrent .ready file
creation), but since some platforms have been using rename() for some time,
I don't know how worried we should be.  I thought about adding some kind of
locking between the WAL receiver and startup processes, but that seems
excessive.  Alternatively, we could just fix xlog.c as proposed earlier
[0].  AFAICT that is the only caller that can experience problems due to
the multiple-hard-link issue.  All other callers are simply renaming a
temporary file into place, and the temporary file can be discarded if left
behind after a crash.

[0] https://postgr.es/m/20220407182954.GA1231544%40nathanxps13

---

From: Michael Paquier <[email-masked]>
Date: Thu, 5 May 2022 20:10:02 +0900

On Mon, May 02, 2022 at 04:06:13PM -0700, Nathan Bossart wrote:
> I don't know how worried we should be.

That's only about Windows these days, meaning that there is much less
coverage in this code path.

> I thought about adding some kind of
> excessive.

Agreed.

> Alternatively, we could just fix xlog.c as proposed earlier

I'd agree with removing all the callers at the end.  pgrename() is
quite robust on Windows, but I'd keep the two checks in
writeTimeLineHistory(), as the logic around findNewestTimeLine() would
consider a past TLI history file as in-use even if we have a crash
just after the file got created in the same path by the same standby,
and the WAL segment init part.  Your patch does that.
--
Michael

---

From: Michael Paquier <[email-masked]>
Date: Tue, 5 Jul 2022 10:19:49 +0900

> and the WAL segment init part.  Your patch does that.

As v16 is now open for business, I have revisited this change and
applied 0001 to change all the callers (aka removal of the assertion
for the WAL receiver when it overwrites a TLI history file).  The
commit log includes details about the reasoning of all the areas
changed, for clarity, as of the WAL recycling part, the TLI history
file part and basic_archive. 
--
Michael

---

From: Nathan Bossart <[email-masked]>
Date: Tue, 5 Jul 2022 09:58:38 -0700

> file part and basic_archive. 

Thanks!  I wonder if we should add a comment in writeTimeLineHistoryFile()
about possible concurrent use by a WAL receiver and the startup process and
why that is okay.

---

From: Michael Paquier <[email-masked]>
Date: Wed, 6 Jul 2022 08:57:24 +0900

> about possible concurrent use by a WAL receiver and the startup process and

Agreed.  Adding an extra note at the top of the routine would help in
the future.
--
Michael