Date: Wed, 7 Apr 2021 20:47:13 -0700
From: Andres Freund <andres@anarazel.de>
To: "Drouvot, Bertrand" <bdrouvot@amazon.com>
Cc: fabriziomello@gmail.com, Alvaro Herrera <alvherre@2ndquadrant.com>,
	tushar <tushar.ahuja@enterprisedb.com>,
	"[pgdg] Robert Haas" <robertmhaas@gmail.com>,
	Amit Khandekar <amitdkhan.pg@gmail.com>,
	Rahila Syed <rahila.syed@2ndquadrant.com>,
	pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: Minimal logical decoding on standbys
Message-ID: <20210408034713.auf7oaxyymu2kc7n@alap3.anarazel.de>
References: 
 <CAFcNs+q9FvSW7gMqM__aeWOoDNqfcQCoB8LiO-X33fvqGO8mkQ@mail.gmail.com>
 <96644a03-0b4d-e0a6-2124-0bc37e5b54fb@amazon.com>
 <CAFcNs+pyDR+iwYpTAp=cnkX7BgEbOnF6rrr8w=2inPAn4rQB-A@mail.gmail.com>
 <842d60ce-99e6-f35e-8c92-0cd49381326e@amazon.com>
 <CAFcNs+pQ0jBvUUH8XzE9ct64Doy-pJsfiT13StsaLpmviPAa8Q@mail.gmail.com>
 <e6cfd6c9-29de-b7dc-d008-446fdafe1f08@amazon.com>
 <6b9168e5-6a29-7fda-8903-cd50563fa84c@amazon.com>
 <20210406180231.qsnkyrgrm7gtxb73@alap3.anarazel.de>
 <20210407170954.xbovgh3xdrnogg7w@alap3.anarazel.de>
 <20210407203218.pestfxu7watrnog4@alap3.anarazel.de>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20210407203218.pestfxu7watrnog4@alap3.anarazel.de>
Archived-At: 
 <https://www.postgresql.org/message-id/20210408034713.auf7oaxyymu2kc7n%40alap3.anarazel.de>
Precedence: bulk

Hi,

On 2021-04-07 13:32:18 -0700, Andres Freund wrote:
> While working on this I found a, somewhat substantial, issue:
>
> When the primary is idle, on the standby logical decoding via walsender
> will typically not process the records until further WAL writes come in
> from the primary, or until a 10s lapsed.
>
> The problem is that WalSndWaitForWal() waits for the *replay* LSN to
> increase, but gets woken up by walreceiver when new WAL has been
> flushed. Which means that typically walsenders will get woken up at the
> same time that the startup process will be - which means that by the
> time the logical walsender checks GetXLogReplayRecPtr() it's unlikely
> that the startup process already replayed the record and updated
> XLogCtl->lastReplayedEndRecPtr.
>
> I think fixing this would require too invasive changes at this point. I
> think we might be able to live with 10s delay issue for one release, but
> it sure is ugly :(.

This is indeed pretty painful. It's a lot more regularly occuring if you
either have a slot disk, or you switch around the order of
WakeupRecovery() and WalSndWakeup() XLogWalRcvFlush().


- There's about which timeline to use. If you use pg_recvlogical and you
  restart the server, you'll see errors like:

  pg_recvlogical: error: unexpected termination of replication stream: ERROR:  requested WAL segment 000000000000000000000003 has already been removed

  the real filename is 000000010000000000000003 - i.e. the timeline is
  0.

  This isn't too hard to fix, but definitely needs fixing.

- ResolveRecoveryConflictWithLogicalSlots() is racy - potentially
  leading us to drop a slot that has been created since we signalled a
  recovery conflict.  See
  https://www.postgresql.org/message-id/20210408020913.zzprrlvqyvlt5cyy%40alap3.anarazel.de
  for some very similar issues.

- Given the precedent of max_slot_wal_keep_size, I think it's wrong to
  just drop the logical slots. Instead we should just mark them as
  invalid, like InvalidateObsoleteReplicationSlots().

- There's no tests covering timeline switches, what happens if there's a
  promotion if logical decoding is currently ongoing.

- The way ResolveRecoveryConflictWithLogicalSlots() builds the error
  message is not good (and I've complained about it before...).

Unfortunately I think the things I have found are too many for me to
address within the given time. I'll send a version with a somewhat
polished set of the changes I made in the next few days...

Greetings,

Andres Freund