Feedback-ID: i0fe9450f:Fastmail
Date: Mon, 19 Feb 2024 15:01:40 +0900
From: Michael Paquier <michael@paquier.xyz>
To: Postgres hackers <pgsql-hackers@lists.postgresql.org>
Cc: Ashutosh Bapat <ashutosh.bapat@gmail.com>
Subject: Injection points: some tools to wait and wake
Message-ID: <ZdLuxBk5hGpol91B@paquier.xyz>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha512;
	protocol="application/pgp-signature"; boundary="X0GL1CDiql1g1kUr"
Content-Disposition: inline
Archived-At: <https://www.postgresql.org/message-id/ZdLuxBk5hGpol91B%40paquier.xyz>
Precedence: bulk


--X0GL1CDiql1g1kUr
Content-Type: multipart/mixed; boundary="Sv2h70NRUTF47mb6"
Content-Disposition: inline


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

Hi all,
(Ashutosh in CC as he was involved in the discussion last time.)

I have proposed on the original thread related to injection points to
have more stuff to be able to wait at an arbtrary point and wake at
will the process waiting so as it is possible to control the order of
actions taken in a test:
https://www.postgresql.org/message-id/ZTiV8tn_MIb_H2rE%40paquier.xyz

I didn't do that in the other thread out of time, but here is a patch
set to complete what I wanted, using a condition variable to wait and
wake processes:
- State is in shared memory, using a DSM tracked by the registry and
an integer counter.
- Callback to wait on a condition variable.
- SQL function to update the shared state and broadcast the update to
the condition variable.
- Use a custom wait event to track the wait in pg_stat_activity.

0001 requires no backend changes, only more stuff into the test module
injection_points so that could be backpatched assuming that the
backend is able to support injection points.  This could be expanded
into using more variables and/or states, but I don't really see a
point in introducing more without a reason to do so, and I have no
need for more at the moment.

0002 is a polished version of the TAP test that makes use of this
facility, providing coverage for the bug fixed by 7863ee4def65
(reverting this commit causes the test to fail), where a restart point=20
runs across a promotion request.  The trick is to stop the
checkpointer in the middle of a restart point and issue a promotion
in-between.

Thoughts and comments are welcome.
--
Michael

--Sv2h70NRUTF47mb6
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="0001-injection_points-Add-routines-to-wait-and-wake-proce.patch"
Content-Transfer-Encoding: quoted-printable

=46rom ef27d6eba619f5106915de6b05cbeb5294263c30 Mon Sep 17 00:00:00 2001
=46rom: Michael Paquier <michael@paquier.xyz>
Date: Mon, 19 Feb 2024 14:35:55 +0900
Subject: [PATCH 1/2] injection_points: Add routines to wait and wake proces=
ses

This commit is made of two parts:
- A new callback that can be attached to a process to make it wait on a
condition variable.  The condition checked is registered in shared
memory by the module injection_points.
- A new SQL function to update the shared state and broadcast the update
using a condition variable.

The shared state used by the module is registered using the DSM
registry, and is optional.
---
 .../injection_points--1.0.sql                 |  10 ++
 .../injection_points/injection_points.c       | 104 ++++++++++++++++++
 src/tools/pgindent/typedefs.list              |   1 +
 3 files changed, 115 insertions(+)

diff --git a/src/test/modules/injection_points/injection_points--1.0.sql b/=
src/test/modules/injection_points/injection_points--1.0.sql
index 5944c41716..20479991f2 100644
--- a/src/test/modules/injection_points/injection_points--1.0.sql
+++ b/src/test/modules/injection_points/injection_points--1.0.sql
@@ -24,6 +24,16 @@ RETURNS void
 AS 'MODULE_PATHNAME', 'injection_points_run'
 LANGUAGE C STRICT PARALLEL UNSAFE;
=20
+--
+-- injection_points_wake()
+--
+-- Wakes a condition variable waited on in an injection point.
+--
+CREATE FUNCTION injection_points_wake()
+RETURNS void
+AS 'MODULE_PATHNAME', 'injection_points_wake'
+LANGUAGE C STRICT PARALLEL UNSAFE;
+
 --
 -- injection_points_detach()
 --
diff --git a/src/test/modules/injection_points/injection_points.c b/src/tes=
t/modules/injection_points/injection_points.c
index e843e6594f..3a319b1525 100644
--- a/src/test/modules/injection_points/injection_points.c
+++ b/src/test/modules/injection_points/injection_points.c
@@ -18,18 +18,67 @@
 #include "postgres.h"
=20
 #include "fmgr.h"
+#include "storage/condition_variable.h"
 #include "storage/lwlock.h"
 #include "storage/shmem.h"
+#include "storage/dsm_registry.h"
 #include "utils/builtins.h"
 #include "utils/injection_point.h"
 #include "utils/wait_event.h"
=20
 PG_MODULE_MAGIC;
=20
+/* Shared state information for injection points. */
+typedef struct InjectionPointSharedState
+{
+	/* protects accesses to wait_counts */
+	slock_t		lock;
+
+	/* Counter advancing when injection_points_wake() is called */
+	int			wait_counts;
+
+	/*
+	 * Condition variable that can be used in an injection point, checking
+	 * upon wait_counts when waiting.
+	 */
+	ConditionVariable wait_point;
+} InjectionPointSharedState;
+
+/* Pointer to shared-memory state. */
+static InjectionPointSharedState *inj_state =3D NULL;
+
+/* Wait event when waiting on condition variable */
+static uint32 injection_wait_event =3D 0;
+
 extern PGDLLEXPORT void injection_error(const char *name);
 extern PGDLLEXPORT void injection_notice(const char *name);
+extern PGDLLEXPORT void injection_wait(const char *name);
=20
=20
+static void
+injection_point_init_state(void *ptr)
+{
+	InjectionPointSharedState *state =3D (InjectionPointSharedState *) ptr;
+
+	state->wait_counts =3D 0;
+	SpinLockInit(&state->lock);
+	ConditionVariableInit(&state->wait_point);
+}
+
+static void
+injection_init_shmem(void)
+{
+	bool		found;
+
+	if (inj_state !=3D NULL)
+		return;
+
+	inj_state =3D GetNamedDSMSegment("injection_points",
+								   sizeof(InjectionPointSharedState),
+								   injection_point_init_state,
+								   &found);
+}
+
 /* Set of callbacks available to be attached to an injection point. */
 void
 injection_error(const char *name)
@@ -43,6 +92,38 @@ injection_notice(const char *name)
 	elog(NOTICE, "notice triggered for injection point %s", name);
 }
=20
+/* Wait on a condition variable, awaken by injection_points_wake() */
+void
+injection_wait(const char *name)
+{
+	int			old_wait_counts;
+
+	if (inj_state =3D=3D NULL)
+		injection_init_shmem();
+	if (injection_wait_event =3D=3D 0)
+		injection_wait_event =3D WaitEventExtensionNew("injection_wait");
+
+	SpinLockAcquire(&inj_state->lock);
+	old_wait_counts =3D inj_state->wait_counts;
+	SpinLockRelease(&inj_state->lock);
+
+	/* And sleep.. */
+	ConditionVariablePrepareToSleep(&inj_state->wait_point);
+	for (;;)
+	{
+		int			new_wait_counts;
+
+		SpinLockAcquire(&inj_state->lock);
+		new_wait_counts =3D inj_state->wait_counts;
+		SpinLockRelease(&inj_state->lock);
+
+		if (old_wait_counts !=3D new_wait_counts)
+			break;
+		ConditionVariableSleep(&inj_state->wait_point, injection_wait_event);
+	}
+	ConditionVariableCancelSleep();
+}
+
 /*
  * SQL function for creating an injection point.
  */
@@ -58,6 +139,8 @@ injection_points_attach(PG_FUNCTION_ARGS)
 		function =3D "injection_error";
 	else if (strcmp(action, "notice") =3D=3D 0)
 		function =3D "injection_notice";
+	else if (strcmp(action, "wait") =3D=3D 0)
+		function =3D "injection_wait";
 	else
 		elog(ERROR, "incorrect action \"%s\" for injection point creation", acti=
on);
=20
@@ -80,6 +163,27 @@ injection_points_run(PG_FUNCTION_ARGS)
 	PG_RETURN_VOID();
 }
=20
+/*
+ * SQL function for waking a condition variable.
+ */
+PG_FUNCTION_INFO_V1(injection_points_wake);
+Datum
+injection_points_wake(PG_FUNCTION_ARGS)
+{
+
+	if (inj_state =3D=3D NULL)
+		injection_init_shmem();
+
+	/* First bump the wait counter */
+	SpinLockAcquire(&inj_state->lock);
+	inj_state->wait_counts++;
+	SpinLockRelease(&inj_state->lock);
+
+	/* And broadcast the change for the waiters */
+	ConditionVariableBroadcast(&inj_state->wait_point);
+	PG_RETURN_VOID();
+}
+
 /*
  * SQL function for dropping an injection point.
  */
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs=
=2Elist
index d808aad8b0..d7eca00502 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1208,6 +1208,7 @@ InitializeDSMForeignScan_function
 InitializeWorkerForeignScan_function
 InjectionPointCacheEntry
 InjectionPointEntry
+InjectionPointSharedState
 InlineCodeBlock
 InsertStmt
 Instrumentation
--=20
2.43.0


--Sv2h70NRUTF47mb6
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="0002-Add-regression-test-for-restart-points-during-promot.patch"
Content-Transfer-Encoding: quoted-printable

=46rom 67797944f91441e0cde1259409eeffcc1bd62e39 Mon Sep 17 00:00:00 2001
=46rom: Michael Paquier <michael@paquier.xyz>
Date: Mon, 19 Feb 2024 14:38:08 +0900
Subject: [PATCH 2/2] Add regression test for restart points during promotion

This test fails when 7863ee4def65 is reverted, checking that a node is
able to properly restart following a crash when a restart point was
finishing across a promotion.

This is an old bug that had no coverage, and injection points make that
cheap to achieve.
---
 src/backend/access/transam/xlog.c             |   7 +
 src/test/recovery/Makefile                    |   7 +-
 src/test/recovery/meson.build                 |   4 +
 .../t/041_invalid_checkpoint_after_promote.pl | 159 ++++++++++++++++++
 4 files changed, 176 insertions(+), 1 deletion(-)
 create mode 100644 src/test/recovery/t/041_invalid_checkpoint_after_promot=
e.pl

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam=
/xlog.c
index 50c347a679..50b045ff08 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -100,6 +100,7 @@
 #include "storage/sync.h"
 #include "utils/guc_hooks.h"
 #include "utils/guc_tables.h"
+#include "utils/injection_point.h"
 #include "utils/memutils.h"
 #include "utils/ps_status.h"
 #include "utils/relmapper.h"
@@ -7536,6 +7537,12 @@ CreateRestartPoint(int flags)
=20
 	CheckPointGuts(lastCheckPoint.redo, flags);
=20
+	/*
+	 * This location needs to be after CheckPointGuts() to ensure that some
+	 * work has already happened during this checkpoint.
+	 */
+	INJECTION_POINT("CreateRestartPoint");
+
 	/*
 	 * Remember the prior checkpoint's redo ptr for
 	 * UpdateCheckPointDistanceEstimate()
diff --git a/src/test/recovery/Makefile b/src/test/recovery/Makefile
index 17ee353735..f57baba5e8 100644
--- a/src/test/recovery/Makefile
+++ b/src/test/recovery/Makefile
@@ -9,12 +9,17 @@
 #
 #-------------------------------------------------------------------------
=20
-EXTRA_INSTALL=3Dcontrib/pg_prewarm contrib/pg_stat_statements contrib/test=
_decoding
+EXTRA_INSTALL=3Dcontrib/pg_prewarm \
+	contrib/pg_stat_statements \
+	contrib/test_decoding \
+	src/test/modules/injection_points
=20
 subdir =3D src/test/recovery
 top_builddir =3D ../../..
 include $(top_builddir)/src/Makefile.global
=20
+export enable_injection_points enable_injection_points
+
 # required for 017_shm.pl and 027_stream_regress.pl
 REGRESS_SHLIB=3D$(abs_top_builddir)/src/test/regress/regress$(DLSUFFIX)
 export REGRESS_SHLIB
diff --git a/src/test/recovery/meson.build b/src/test/recovery/meson.build
index bf087ac2a9..e4e0e2b4cc 100644
--- a/src/test/recovery/meson.build
+++ b/src/test/recovery/meson.build
@@ -6,6 +6,9 @@ tests +=3D {
   'bd': meson.current_build_dir(),
   'tap': {
     'test_kwargs': {'priority': 40}, # recovery tests are slow, start early
+    'env': {
+       'enable_injection_points': get_option('injection_points') ? 'yes' :=
 'no',
+    },
     'tests': [
       't/001_stream_rep.pl',
       't/002_archiving.pl',
@@ -46,6 +49,7 @@ tests +=3D {
       't/038_save_logical_slots_shutdown.pl',
       't/039_end_of_wal.pl',
       't/040_standby_failover_slots_sync.pl',
+      't/041_invalid_checkpoint_after_promote.pl',
     ],
   },
 }
diff --git a/src/test/recovery/t/041_invalid_checkpoint_after_promote.pl b/=
src/test/recovery/t/041_invalid_checkpoint_after_promote.pl
new file mode 100644
index 0000000000..b2e9b526ee
--- /dev/null
+++ b/src/test/recovery/t/041_invalid_checkpoint_after_promote.pl
@@ -0,0 +1,159 @@
+
+# Copyright (c) 2024, PostgreSQL Global Development Group
+
+use strict;
+use warnings;
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Time::HiRes qw(usleep);
+use Test::More;
+
+##################################################
+# Test race condition when a restart point is running during a promotion,
+# checking that WAL segments are correctly removed in the restart point
+# while the promotion finishes.
+#
+# This test relies on an injection point that causes the checkpointer to
+# wait in the middle of a restart point on a standby.  The checkpointer
+# is awaken to finish its restart point only once the promotion of the
+# standby is completed, and the node should be able to restart properly.
+##################################################
+
+if ($ENV{enable_injection_points} ne 'yes')
+{
+	plan skip_all =3D> 'Injection points not supported by this build';
+}
+
+# Initialize primary node
+my $node_primary =3D PostgreSQL::Test::Cluster->new('master');
+$node_primary->init(allows_streaming =3D> 1);
+$node_primary->append_conf(
+	'postgresql.conf', q[
+checkpoint_timeout =3D 30s
+log_checkpoints =3D on
+restart_after_crash =3D on
+]);
+$node_primary->start;
+
+my $backup_name =3D 'my_backup';
+$node_primary->backup($backup_name);
+
+# Setup a standby
+my $node_standby =3D PostgreSQL::Test::Cluster->new('standby1');
+$node_standby->init_from_backup($node_primary, $backup_name,
+	has_streaming =3D> 1);
+$node_standby->start;
+
+# Dummy table for the upcoming tests.
+$node_primary->safe_psql('postgres', 'checkpoint');
+$node_primary->safe_psql('postgres', 'CREATE TABLE prim_tab (a int);');
+
+# Register a injection point on the standby so as the follow-up
+# restart point will wait on it.
+$node_primary->safe_psql('postgres', 'CREATE EXTENSION injection_points;');
+# Wait until the extension has been created on the standby
+$node_primary->wait_for_replay_catchup($node_standby);
+
+# Note that from this point the checkpointer will wait in the middle of
+# a restart point on the standby.
+$node_standby->safe_psql('postgres',
+	"SELECT injection_points_attach('CreateRestartPoint', 'wait');");
+
+# Execute a restart point on the standby, that we will now be waiting on.
+# This needs to be in the background.
+my $logstart =3D -s $node_standby->logfile;
+my $psql_session =3D
+  $node_standby->background_psql('postgres', on_error_stop =3D> 0);
+$psql_session->query_until(
+	qr/starting_checkpoint/, q(
+   \echo starting_checkpoint
+   CHECKPOINT;
+));
+
+# Switch one WAL segment to make the previous restart point remove the
+# segment once the restart point completes.
+$node_primary->safe_psql('postgres', 'INSERT INTO prim_tab VALUES (1);');
+$node_primary->safe_psql('postgres', 'SELECT pg_switch_wal();');
+$node_primary->wait_for_replay_catchup($node_standby);
+
+# Wait until the checkpointer is in the middle of the restart point
+# processing, relying on the custom wait event generated in the
+# wait callback used in the injection point previously attached.
+ok( $node_standby->poll_query_until(
+		'postgres',
+		qq[SELECT count(*) FROM pg_stat_activity
+           WHERE backend_type =3D 'checkpointer' AND wait_event =3D 'injec=
tion_wait' ;],
+		'1'),
+	'checkpointer is waiting in restart point'
+) or die "Timed out while waiting for checkpointer to run restart point";
+
+# Check the logs that the restart point has started on standby.  This is
+# optional, but let's be sure.
+my $log =3D slurp_file($node_standby->logfile, $logstart);
+my $checkpoint_start =3D 0;
+if ($log =3D~ m/restartpoint starting: immediate wait/)
+{
+	$checkpoint_start =3D 1;
+}
+is($checkpoint_start, 1, 'restartpoint has started');
+
+# Trigger promotion during the restart point.
+$node_primary->stop;
+$node_standby->promote;
+
+# Update the start position before waking up the checkpointer!
+$logstart =3D -s $node_standby->logfile;
+
+# Now wake up the checkpointer.
+$node_standby->safe_psql('postgres', "SELECT injection_points_wake();");
+
+# Wait until the previous restart point completes on the newly-promoted
+# standby, checking the logs for that.
+my $checkpoint_complete =3D 0;
+for (my $i =3D 0; $i < 3000; $i++)
+{
+	my $log =3D slurp_file($node_standby->logfile, $logstart);
+	if ($log =3D~ m/restartpoint complete/)
+	{
+		$checkpoint_complete =3D 1;
+		last;
+	}
+	usleep(100_000);
+}
+is($checkpoint_complete, 1, 'restart point has completed');
+
+# Kill with SIGKILL, forcing all the backends to restart.
+my $psql_timeout =3D IPC::Run::timer(3600);
+my ($killme_stdin, $killme_stdout, $killme_stderr) =3D ('', '', '');
+my $killme =3D IPC::Run::start(
+	[
+		'psql', '-XAtq', '-v', 'ON_ERROR_STOP=3D1', '-f', '-', '-d',
+		$node_standby->connstr('postgres')
+	],
+	'<',
+	\$killme_stdin,
+	'>',
+	\$killme_stdout,
+	'2>',
+	\$killme_stderr,
+	$psql_timeout);
+$killme_stdin .=3D q[
+SELECT pg_backend_pid();
+];
+$killme->pump until $killme_stdout =3D~ /[[:digit:]]+[\r\n]$/;
+my $pid =3D $killme_stdout;
+chomp($pid);
+my $ret =3D PostgreSQL::Test::Utils::system_log('pg_ctl', 'kill', 'KILL', =
$pid);
+is($ret, 0, 'killed process with KILL');
+my $stdout;
+my $stderr;
+
+# Wait till server finishes restarting
+$node_standby->poll_query_until('postgres', undef, '');
+
+# After recovery, the server should be able to start.
+($ret, $stdout, $stderr) =3D $node_standby->psql('postgres', 'select 1');
+is($ret, 0, "psql connect success");
+is($stdout, 1, "psql select 1");
+
+done_testing();
--=20
2.43.0


--Sv2h70NRUTF47mb6--

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

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

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmXS7sQACgkQnvQgOdby
QH37tg/9EzyGkFEWXS2LhjH0hffO6f5fgyvs7U9QhoUwU1kQRzWTxF2xw2FDOZQH
aEFjx3RU5L8OhAU6uaqa+V40b6gJsQmbi1SiIs9jOYYYN0gMymhh+0tKiDdsinMC
666X5OjneiFUO63dCBi/vtlORNU7Z7KbmkXmq442D8XjsMvfEFkef3K/veJC6tLf
RmEiefW/3oHkkBPjCq318DQ2gDnEPpXMP+I7fAPkC50Z+gzrAbDQ6UDslOcG2Icj
9AedT3tqFnbgVkukTsPWy9JIB5E5cMbOM8F+Fz4CayQGs12hAz7tVT07mkU2R0KZ
MhHIZFJu2YF99gDs4FI96/knNROgiRQ4F2d5VK5jdhRzYZDvo0WMRNb4xvBwx4VE
ogKv1xYlXaUQyo7VPPk675Leb3+M+LRf3rBnI5GnDHpbEwrqMIvQlNkNi8S5ZyvC
XPC9NDh29mJe+h7Vu/47K1Q0P7qhzakvridIF5tfci2Wf7cOcvu9DM5wlE4nqMrT
rRV0s8FcJJgr91G1Q25KZPq8EZTvN1jOxsbX0K8xo87ll1dC5XcB+OTh0fGAGN97
ldsl6rCJ6pvBVydzXCQzkHkx450bskeF6IAtbS5IsyrhMg9IV1FFnZLKhQAI4/Hc
CRZGwUma67YipXds5jhpC7h7AeJhfZC4CoMbBNaCseYk+cYVXgA=
=YG0Y
-----END PGP SIGNATURE-----

--X0GL1CDiql1g1kUr--