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


--0HlCyn3BrGvuiy89
Content-Type: multipart/mixed; boundary="35/vbk2XpF9oQRWY"
Content-Disposition: inline


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

On Mon, Feb 19, 2024 at 03:01:40PM +0900, Michael Paquier wrote:
> 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.

The CF bot has been screaming at this one on Windows because the
process started with IPC::Run::start was not properly finished, so
attached is an updated version to bring that back to green.
--
Michael

--35/vbk2XpF9oQRWY
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0001-injection_points-Add-routines-to-wait-and-wake-pr.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 v2 1/2] injection_points: Add routines to wait and wake
 processes

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


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

=46rom c64634c5d1826dab6012d8055b494d807ebc6be7 Mon Sep 17 00:00:00 2001
=46rom: Michael Paquier <michael@paquier.xyz>
Date: Mon, 19 Feb 2024 16:49:36 +0900
Subject: [PATCH v2 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 | 175 ++++++++++++++++++
 4 files changed, 192 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..e4812d569d
--- /dev/null
+++ b/src/test/recovery/t/041_invalid_checkpoint_after_promote.pl
@@ -0,0 +1,175 @@
+
+# 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);
+$killme_stdout =3D '';
+$killme_stderr =3D '';
+
+my $ret =3D PostgreSQL::Test::Utils::system_log('pg_ctl', 'kill', 'KILL', =
$pid);
+is($ret, 0, 'killed process with KILL');
+
+# Wait until the server restarts, finish consuming output.
+$killme_stdin .=3D q[
+SELECT 1;
+];
+ok( pump_until(
+		$killme,
+		$psql_timeout,
+		\$killme_stderr,
+		qr/server closed the connection unexpectedly|connection to server was lo=
st|could not send data to server/m
+	),
+	"psql query died successfully after SIGKILL");
+$killme->finish;
+
+# Wait till server finishes restarting
+$node_standby->poll_query_until('postgres', undef, '');
+
+# After recovery, the server should be able to start.
+my $stdout;
+my $stderr;
+($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


--35/vbk2XpF9oQRWY--

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

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

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmXTCJEACgkQnvQgOdby
QH0q0Q//S/WeFDI78piB9adlafiWXAGkiDHBnMa1ymIgo7edFTaIshROloE//HVX
sgHQRZATutSog8l3ohK8lIYIVk+P7B+Ys3mO29/BTMkfSF29vq2E0GwIpKL4Vqxc
SajMwDvoQYbJWvQ96V1ZZascXRIDGzolae+JqsMtW/lgLJZ5HzsKqczr8RXIZAan
n4lbQ2636ytA7H0gC7xiRXLSnlRA6Ll7ug1bZspfWjGLwhyTcyb5cx6KY5mqozYP
A70zGE4BNQraGPvqhQ7XEHxuh4SWKU6cB1lEEgulJmC3M/bs0KHqCDMv3GAruPqV
64L+0epHaoSlaHIba9uC0el/dRXpwpnzPvSasXnY8a1LEXvIMawa1IMDbzfxVwCa
KSq9qKHcIHIMIcK96R6NRkw8C2WjvYbJqk6ZGHzPmicExZX0tZWc19/3Y/St/SZD
/ZE6ZlAoo6O55EjweNBFvbSF2Xr2EOzZzHTndNvFWXcu8IpFrJ8xHKKuWo3hRUmi
OsEUW0xb8l3f3RuHHUmVK0R/Ez6PHrX7KEIHcUAuxEfxtp/mTigtLbSrkRvgDzIW
DUFyF2Zlf7RVGKRRyZlYW0IeNmJZOv0huIZRhRTV6RoiLe7pSVwf4ogymwO2g0tw
VjW/RSxhhcVLkbQ7C6VenKC5wMZd2yDu2zouhdBikE8+eixKLYE=
=thBb
-----END PGP SIGNATURE-----

--0HlCyn3BrGvuiy89--