Date: Wed, 19 May 2021 12:03:50 +0900
From: Michael Paquier <michael@paquier.xyz>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: pgsql-hackers@lists.postgresql.org
Subject: Re: Subscription tests fail under CLOBBER_CACHE_ALWAYS
Message-ID: <YKSAFhtltIr9GUEi@paquier.xyz>
References: <3382681.1621381328@sss.pgh.pa.us>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha512;
	protocol="application/pgp-signature"; boundary="oEifJEnlnesr1E3x"
Content-Disposition: inline
In-Reply-To: <3382681.1621381328@sss.pgh.pa.us>
Archived-At: 
 <https://www.postgresql.org/message-id/YKSAFhtltIr9GUEi%40paquier.xyz>
Precedence: bulk


--oEifJEnlnesr1E3x
Content-Type: multipart/mixed; boundary="AHp3mqEMd/GWSp/T"
Content-Disposition: inline


--AHp3mqEMd/GWSp/T
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

On Tue, May 18, 2021 at 07:42:08PM -0400, Tom Lane wrote:
> I count three distinct bugs that were exposed by this attempt:
>=20
> 1. In the part of 013_partition.pl that tests firing AFTER
> triggers on partitioned tables, we have a case of continuing
> to access a relcache entry that's already been closed.
> (I'm not quite sure why prion's -DRELCACHE_FORCE_RELEASE
> hasn't exposed this.)  It looks to me like instead we had
> a relcache reference leak before f3b141c48, but now, the
> only relcache reference count on a partition child table
> is dropped by ExecCleanupTupleRouting, which logical/worker.c
> invokes before it fires triggers on that table.  Kaboom.
> This might go away if worker.c weren't so creatively different
> from the other code paths concerned with executor shutdown.

The tuple routing has made the whole worker logic messier by a larger
degree compared to when this stuff was only able to apply DMLs changes
on the partition leaves.  I know that it is not that great to be more
creative here, but we need to make sure that AfterTriggerEndQuery() is
moved before ExecCleanupTupleRouting().  We could either keep the
ExecCleanupTupleRouting() calls as they are now, and call
AfterTriggerEndQuery() in more code paths.  Or we could have one
PartitionTupleRouting and one ModifyTableState created beforehand
in create_estate_for_relation() if applying the change on a
partitioned table but that means manipulating more structures across=20
more layers of this code.  Something like the attached fixes the
problem for me, but honestly it does not help in clarifying this code
more.  I was not patient enough to wait for CLOBBER_CACHE_ALWAYS to
initialize the nodes in the TAP tests, so I have tested that with a
setup initialized with a non-clobber build, and reproduced the problem
with CLOBBER_CACHE_ALWAYS builds on those same nodes.

You are right that this is not a problem of 14~.  I can reproduce the
problem on 13 as well, and we have no coverage for tuple routing with
triggers on this branch, so this would never have been stressed in the
buildfarm.  There is a good argument to be made here in cherry-picking
2ecfeda3 to REL_13_STABLE.

> 2. Said bug causes a segfault in the apply worker process.
> This causes the parent postmaster to give up and die.
> I don't understand why we don't treat that like a crash
> in a regular backend, considering that an apply worker
> is running largely user-defined code.

CleanupBackgroundWorker() and CleanupBackend() have a lot of common
points.  Are you referring to an inconsistent behavior with
restart_after_crash that gets ignored for bgworkers?  We disable it by
default in the TAP tests.

> 3. Once the subscriber1 postmaster has exited, the TAP
> test will eventually time out, and then this happens:
>
> [.. logs ..]
>
> That is, because we failed to shut down subscriber1, the
> test script neglects to shut down subscriber2, and now
> things just sit indefinitely.  So that's a robustness
> problem in the TAP infrastructure, rather than a bug in
> PG proper; but I still say it's a bug that needs fixing.

This one comes down to teardown_node() that uses system_or_bail(),
leaving things unfinished.  I guess that we could be more aggressive
and ignore failures if we have a non-zero error code and that not all
the tests have passed within the END block of PostgresNode.pm.
--
Michael

--AHp3mqEMd/GWSp/T
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment; filename="logirep-partition-clobber.patch"
Content-Transfer-Encoding: quoted-printable

diff --git a/src/backend/replication/logical/worker.c b/src/backend/replica=
tion/logical/worker.c
index 1432554d5a..01c1bd14f6 100644
--- a/src/backend/replication/logical/worker.c
+++ b/src/backend/replication/logical/worker.c
@@ -394,9 +394,6 @@ create_estate_for_relation(LogicalRepRelMapEntry *rel,
 static void
 finish_estate(EState *estate)
 {
-	/* Handle any queued AFTER triggers. */
-	AfterTriggerEndQuery(estate);
-
 	/* Cleanup. */
 	ExecResetTupleTable(estate->es_tupleTable, false);
 	FreeExecutorState(estate);
@@ -1226,9 +1223,14 @@ apply_handle_insert(StringInfo s)
 		apply_handle_tuple_routing(resultRelInfo, estate,
 								   remoteslot, NULL, rel, CMD_INSERT);
 	else
+	{
 		apply_handle_insert_internal(resultRelInfo, estate,
 									 remoteslot);
=20
+		/* Handle any queued AFTER triggers */
+		AfterTriggerEndQuery(estate);
+	}
+
 	PopActiveSnapshot();
=20
 	finish_estate(estate);
@@ -1371,9 +1373,14 @@ apply_handle_update(StringInfo s)
 		apply_handle_tuple_routing(resultRelInfo, estate,
 								   remoteslot, &newtup, rel, CMD_UPDATE);
 	else
+	{
 		apply_handle_update_internal(resultRelInfo, estate,
 									 remoteslot, &newtup, rel);
=20
+		/* Handle any queued AFTER triggers */
+		AfterTriggerEndQuery(estate);
+	}
+
 	PopActiveSnapshot();
=20
 	finish_estate(estate);
@@ -1494,9 +1501,14 @@ apply_handle_delete(StringInfo s)
 		apply_handle_tuple_routing(resultRelInfo, estate,
 								   remoteslot, NULL, rel, CMD_DELETE);
 	else
+	{
 		apply_handle_delete_internal(resultRelInfo, estate,
 									 remoteslot, &rel->remoterel);
=20
+		/* Handle any queued AFTER triggers */
+		AfterTriggerEndQuery(estate);
+	}
+
 	PopActiveSnapshot();
=20
 	finish_estate(estate);
@@ -1798,6 +1810,12 @@ apply_handle_tuple_routing(ResultRelInfo *relinfo,
 			break;
 	}
=20
+	/*
+	 * Handle any queued AFTER triggers.  Note that this needs to be done
+	 * before closing any references to the relation used for tuple routing.
+	 */
+	AfterTriggerEndQuery(estate);
+
 	ExecCleanupTupleRouting(mtstate, proute);
 }
=20

--AHp3mqEMd/GWSp/T--

--oEifJEnlnesr1E3x
Content-Type: application/pgp-signature; name="signature.asc"

-----BEGIN PGP SIGNATURE-----

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmCkgBYACgkQnvQgOdby
QH3wGw//UoJ2DlZosKcYCaRZXGXwgWt0j/HmlK+FvCXuG+QsB7g6x152SbHFcQNW
A7KC3AcRtmzAvwYZv9d6CMnItOqYLtNJV8JCXvhgsHx8kIOADm755D/L8OD674NM
KH8XudjBpPpMt6QHvJRJkkl1qJK577s/5gTLjgDGCsO7dEa+wXt9wyCQJwfNbIE1
1Tzr1LTurV1vtW7ioKIQgmoFDSDDOZwB/UrvIdu+ZRSC3KtGj0hfOeewQA/1ojrp
bIksBQl9ep7l1R+KnSTdNQUyEugSURYCFgtPdCWJ++R+VZQ5suSNc+9sNMmcWZV2
Tyu+ivQ7mWyxBfswVOmAfTmK5+MPxB0BFrdQbyJ3zpco35OggINRWkknmaWAS/3b
NWL/anOJdlucTC7W5jnmIwolI+HgT6Gr5BGniCI8KE5/7AhKr+4Hn6MKRwoPCdVv
sXmY2obaxcIFyj6lx9g9Nw5BW0V3QkGtvpYfabXi3N3SsQetiepJ3IaGEMrHQLt9
bD9VvnEei6Dsv5Dxm6j2TBlGHR1NY2JNXCRxNd2hcLhBf4aR13wd7P4CZEiCUSoR
mKHkr03eMXb++4bYKp5b5xEv6dmYmYhHa1sTKaWTjfWLNzuhysQ5GRrh6fw5QE8w
WFri8jNG9zNxbuv0lOc0EBIMz9P1onBl22amOpAmfL81oBc8kNM=
=hYL9
-----END PGP SIGNATURE-----

--oEifJEnlnesr1E3x--