Feedback-ID: id4a34324:Fastmail
Date: Tue, 26 Jul 2022 11:16:11 -0700
From: Andres Freund <andres@anarazel.de>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: Thomas Munro <thomas.munro@gmail.com>,
	Melanie Plageman <melanieplageman@gmail.com>,
	pgsql-hackers@lists.postgresql.org
Subject: Re: Unstable tests for recovery conflict handling
Message-ID: <20220726181611.4xw3blxigqzsz4d4@alap3.anarazel.de>
References: <E1nca5h-000nN0-6f@gemulon.postgresql.org>
 <394950.1651077914@sss.pgh.pa.us>
 <447238.1651082925@sss.pgh.pa.us>
 <2454340.1658858273@sss.pgh.pa.us>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <2454340.1658858273@sss.pgh.pa.us>
Archived-At: 
 <https://www.postgresql.org/message-id/20220726181611.4xw3blxigqzsz4d4%40alap3.anarazel.de>
Precedence: bulk

Hi,

On 2022-07-26 13:57:53 -0400, Tom Lane wrote:
> I happened to notice that while skink continues to fail off-and-on
> in 031_recovery_conflict.pl, the symptoms have changed!  What
> we're getting now typically looks like [1]:
> 
> [10:45:11.475](0.023s) ok 14 - startup deadlock: lock acquisition is waiting
> Waiting for replication conn standby's replay_lsn to pass 0/33FB8B0 on primary
> done
> timed out waiting for match: (?^:User transaction caused buffer deadlock with recovery.) at t/031_recovery_conflict.pl line 367.
> 
> where absolutely nothing happens in the standby log, until we time out:
> 
> 2022-07-24 10:45:11.452 UTC [1468367][client backend][2/4:0] LOG:  statement: SELECT * FROM test_recovery_conflict_table2;
> 2022-07-24 10:45:11.472 UTC [1468547][client backend][3/2:0] LOG:  statement: SELECT 'waiting' FROM pg_locks WHERE locktype = 'relation' AND NOT granted;
> 2022-07-24 10:48:15.860 UTC [1468362][walreceiver][:0] FATAL:  could not receive data from WAL stream: server closed the connection unexpectedly
> 
> So this is not a case of RecoveryConflictInterrupt doing the wrong thing:
> the startup process hasn't detected the buffer conflict in the first
> place.

I wonder if this, at least partially, could be be due to the elog thing
I was complaining about nearby. I.e. we decide to FATAL as part of a
recovery conflict interrupt, and then during that ERROR out as part of
another recovery conflict interrupt (because nothing holds interrupts as
part of FATAL).

Greetings,

Andres Freund