Content-Type: text/plain;
	charset=utf-8
Mime-Version: 1.0 (Mac OS X Mail 13.4 \(3608.120.23.2.7\))
Subject: Re: Unstable tests for recovery conflict handling
From: Mark Dilger <mark.dilger@enterprisedb.com>
In-Reply-To: <F9294C25-83A0-49F1-9F39-3179739AEF63@enterprisedb.com>
Date: Wed, 27 Apr 2022 10:50:06 -0700
Cc: Andres Freund <andres@anarazel.de>,
 Melanie Plageman <melanieplageman@gmail.com>,
 pgsql-hackers@lists.postgresql.org
Content-Transfer-Encoding: quoted-printable
Message-Id: <A188C72D-E63F-405A-8992-237E1995CB38@enterprisedb.com>
References: <E1nca5h-000nN0-6f@gemulon.postgresql.org>
 <394950.1651077914@sss.pgh.pa.us>
 <F9294C25-83A0-49F1-9F39-3179739AEF63@enterprisedb.com>
To: Tom Lane <tgl@sss.pgh.pa.us>
Archived-At: <https://www.postgresql.org/message-id/A188C72D-E63F-405A-8992-237E1995CB38%40enterprisedb.com>
Precedence: bulk


> On Apr 27, 2022, at 10:11 AM, Mark Dilger =
<mark.dilger@enterprisedb.com> wrote:
>=20
> I'll try again on master....

Still with coverage and dtrace enabled, I get the same thing, except =
that master formats the logs a bit differently:

# Postmaster PID for node "primary" is 19797
psql:<stdin>:1: ERROR:  prepared transaction with identifier =
"xact_012_1" does not exist
[10:26:16.314](1.215s) not ok 11 - Rollback of =
PGPROC_MAX_CACHED_SUBXIDS+ prepared transaction on promoted standby
[10:26:16.314](0.000s)
[10:26:16.314](0.000s) #   Failed test 'Rollback of =
PGPROC_MAX_CACHED_SUBXIDS+ prepared transaction on promoted standby'
[10:26:16.314](0.000s) #   at t/012_subtransactions.pl line 208.
[10:26:16.314](0.000s) #          got: '3'
#     expected: '0'


With coverage but not dtrace enabled, I still get the error, though the =
log leading up to the error now has a bunch of coverage noise lines =
like:

profiling: =
/Users/mark.dilger/recovery_test/postgresql/src/backend/utils/sort/tupleso=
rt.gcda: cannot merge previous GCDA file: corrupt arc tag

The error itself looks the same except the timing numbers differ a =
little.


With neither enabled, all tests pass.


I'm inclined to think that either the recovery code or the test have a =
race condition, and that enabling coverage causes the race to come out =
differently.  I'll keep poking....

=E2=80=94
Mark Dilger
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company