agora inbox for [email protected]  

help / color / mirror / Atom feed

[PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
49+ messages / 1 participants
[nested] [flat]

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits
@ 2025-03-07 14:44  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2025-03-07 14:44 UTC (permalink / raw)

The test occasionally failed due to unexpected connection limit errors being
encountered after having waited for FATAL errors on another connection. These
spurious failures were caused by the the backend reporting FATAL errors to the
client before detaching from the PGPROC entry. Adding a sleep(1) before
proc_exit() makes it easy to reproduce that problem.

To fix the issue, add a helper function that waits for postmaster to notice
the process having exited. For now this is implemented by waiting for the
DEBUG2 message that postmaster logs in that case. That's not the prettiest
fix, but simple. If we notice this problem elsewhere, it might be worthwhile
to make this more general, e.g. by adding an injection point.

Reported-by: Tomas Vondra <[email protected]>
Diagnosed-by: Heikki Linnakangas <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://postgr.es/m/ggflhkciwdyotpoie323chu2c2idpjk5qimrn462encwx2io7s@thmcxl7i6dpw
---
 .../postmaster/t/002_connection_limits.pl     | 35 +++++++++++++++++--
 1 file changed, 32 insertions(+), 3 deletions(-)

diff --git a/src/test/postmaster/t/002_connection_limits.pl b/src/test/postmaster/t/002_connection_limits.pl
index 8cfa6e0ced5..2c185eef6eb 100644
--- a/src/test/postmaster/t/002_connection_limits.pl
+++ b/src/test/postmaster/t/002_connection_limits.pl
@@ -20,6 +20,7 @@ $node->append_conf('postgresql.conf', "max_connections = 6");
 $node->append_conf('postgresql.conf', "reserved_connections = 2");
 $node->append_conf('postgresql.conf', "superuser_reserved_connections = 1");
 $node->append_conf('postgresql.conf', "log_connections = on");
+$node->append_conf('postgresql.conf', "log_min_messages=debug2");
 $node->start;
 
 $node->safe_psql(
@@ -45,13 +46,39 @@ sub background_psql_as_user
 		extra_params => [ '-U', $user ]);
 }
 
+# Like connect_fails(), except that we also wait for the failed backend to
+# have exited.
+#
+# This tests needs to wait for client processes to exit because the error
+# message for a failed connection is reported before the backend has detached
+# from shared memory. If we didn't wait, subsequent tests might hit connection
+# limits spuriously.
+#
+# This can't easily be generalized, as detecting process exit requires
+# log_min_messages to be at least DEBUG2 and is not concurrency safe, as we
+# can't easily be sure the right process exited. In this test that's not a
+# problem though, we only have one new connection at a time.
+sub connect_fails_wait
+{
+	local $Test::Builder::Level = $Test::Builder::Level + 1;
+	my ($node, $connstr, $test_name, %params) = @_;
+
+	my $log_location = -s $node->logfile;
+
+	$node->connect_fails($connstr, $test_name, %params);
+	$node->wait_for_log(qr/DEBUG:  client backend.*exited with exit code 1/,
+		$log_location);
+	ok(1, "$test_name: client backend process exited");
+}
+
 my @sessions = ();
 my @raw_connections = ();
 
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
 push(@sessions, background_psql_as_user('regress_regular'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -60,7 +87,8 @@ $node->connect_fails(
 
 push(@sessions, background_psql_as_user('regress_reserved'));
 push(@sessions, background_psql_as_user('regress_reserved'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_regular",
 	"reserved_connections limit",
 	expected_stderr =>
@@ -68,7 +96,8 @@ $node->connect_fails(
 );
 
 push(@sessions, background_psql_as_user('regress_superuser'));
-$node->connect_fails(
+connect_fails_wait(
+	$node,
 	"dbname=postgres user=regress_superuser",
 	"superuser_reserved_connections limit",
 	expected_stderr => qr/FATAL:  sorry, too many clients already/);
-- 
2.48.1.76.g4e746b1a31.dirty


--q4d36jgrlhdhudrc
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
	filename="v2-0004-tests-Don-t-fail-due-to-high-default-timeout-in-p.patch"



^ permalink  raw  reply  [nested|flat] 49+ messages in thread

* [PATCH v26a 2/2] fixup! instrumentation: Show additional TSC clock source info in pg_test_timing
@ 2026-04-09 15:55  Andres Freund <[email protected]>
  0 siblings, 0 replies; 49+ messages in thread

From: Andres Freund @ 2026-04-09 15:55 UTC (permalink / raw)

---
 src/include/portability/instr_time.h    |  2 ++
 src/common/instr_time.c                 | 18 +++++++++++++++--
 src/port/pg_cpu_x86.c                   |  3 ---
 src/bin/pg_test_timing/pg_test_timing.c | 27 +++++++++++++++++--------
 4 files changed, 37 insertions(+), 13 deletions(-)

diff --git a/src/include/portability/instr_time.h b/src/include/portability/instr_time.h
index 4917728afc3..46307fd47a9 100644
--- a/src/include/portability/instr_time.h
+++ b/src/include/portability/instr_time.h
@@ -161,6 +161,7 @@ extern PGDLLIMPORT bool timing_tsc_enabled;
  */
 extern PGDLLIMPORT int32 timing_tsc_frequency_khz;
 
+
 #if PG_INSTR_TSC_CLOCK
 
 extern void pg_initialize_timing_tsc(void);
@@ -178,6 +179,7 @@ extern const TscClockSourceInfo *pg_timing_tsc_clock_source_info(void);
 
 #endif							/* PG_INSTR_TSC_CLOCK */
 
+
 /*
  * Returns the current timing clock source effectively in use, resolving
  * TIMING_CLOCK_SOURCE_AUTO to either TIMING_CLOCK_SOURCE_SYSTEM or
diff --git a/src/common/instr_time.c b/src/common/instr_time.c
index 2523d6a0df6..0db19673490 100644
--- a/src/common/instr_time.c
+++ b/src/common/instr_time.c
@@ -208,9 +208,23 @@ tsc_detect_frequency(void)
 	tsc_info.frequency_khz = 0;
 	tsc_info.frequency_source[0] = '\0';
 
+	strlcat(tsc_info.frequency_source, "x86",
+			sizeof(tsc_info.frequency_source));
+
 	/* We require RDTSCP support and an invariant TSC, bail if not available */
-	if (!x86_feature_available(PG_RDTSCP) || !x86_feature_available(PG_TSC_INVARIANT))
+	if (!x86_feature_available(PG_RDTSCP))
+	{
+		strlcat(tsc_info.frequency_source, ", no rdtscp",
+				sizeof(tsc_info.frequency_source));
 		return;
+	}
+
+	if (!x86_feature_available(PG_TSC_INVARIANT))
+	{
+		strlcat(tsc_info.frequency_source, ", not invariant",
+				sizeof(tsc_info.frequency_source));
+		return;
+	}
 
 	/* Determine speed at which the TSC advances */
 	timing_tsc_frequency_khz = x86_tsc_frequency_khz(tsc_info.frequency_source,
@@ -231,7 +245,7 @@ tsc_detect_frequency(void)
 	timing_tsc_frequency_khz = tsc_info.calibrated_frequency_khz;
 	if (timing_tsc_frequency_khz > 0)
 	{
-		strlcpy(tsc_info.frequency_source, "x86, calibration",
+		strlcat(tsc_info.frequency_source, ", calibration",
 				sizeof(tsc_info.frequency_source));
 		tsc_info.frequency_khz = timing_tsc_frequency_khz;
 	}
diff --git a/src/port/pg_cpu_x86.c b/src/port/pg_cpu_x86.c
index c097807fc7f..56925e9aa51 100644
--- a/src/port/pg_cpu_x86.c
+++ b/src/port/pg_cpu_x86.c
@@ -169,9 +169,6 @@ x86_tsc_frequency_khz(char *source, size_t source_len)
 {
 	unsigned int reg[4] = {0};
 
-	if (source)
-		strlcpy(source, "x86", source_len);
-
 	/*
 	 * If we're inside a virtual machine, try to fetch the TSC frequency from
 	 * the hypervisor, using a hypervisor specific method.
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index ef5dd90c41f..5cb551fa7b0 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -197,17 +197,28 @@ test_tsc_timing(void)
 		loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_TSC, true);
 		output(loop_count);
 		printf("\n");
+	}
 
-		info = pg_timing_tsc_clock_source_info();
-		printf(_("TSC frequency in use: %d kHz\n"), info->frequency_khz);
-		if (info->frequency_source[0] != '\0')
-			printf(_("TSC frequency source: %s\n"), info->frequency_source);
+	/*
+	 * Report TSC information regardless of whether it was usable, makes
+	 * debugging a lot easier.
+	 */
+	info = pg_timing_tsc_clock_source_info();
+	if (info->frequency_source[0] != '\0')
+		printf(_("TSC frequency source: %s\n"), info->frequency_source);
+	printf(_("TSC frequency in use: %d kHz\n"), info->frequency_khz);
 
-		if (info->calibrated_frequency_khz > 0)
-			printf(_("TSC frequency from calibration: %d kHz\n"), info->calibrated_frequency_khz);
-		else
-			printf(_("TSC calibration did not converge\n"));
+	if (info->calibrated_frequency_khz > 0)
+		printf(_("TSC frequency from calibration: %d kHz\n"), info->calibrated_frequency_khz);
+	else
+		printf(_("TSC calibration did not converge\n"));
 
+	/*
+	 * Report whether TSC was usable and, if so, whether it will be used
+	 * automatically.
+	 */
+	if (loop_count > 0)
+	{
 		pg_set_timing_clock_source(TIMING_CLOCK_SOURCE_AUTO);
 		if (pg_current_timing_clock_source() == TIMING_CLOCK_SOURCE_TSC)
 			printf(_("TSC clock source will be used by default, unless timing_clock_source is set to 'system'.\n"));
-- 
2.53.0.1.gb2826b52eb


--5ynaw2hkmtmijn2o--





^ permalink  raw  reply  [nested|flat] 49+ messages in thread

end of thread, other threads:[~2026-04-09 15:55 UTC | newest]

Thread overview: 49+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2025-03-07 14:44 [PATCH v2 3/4] tests: Fix race condition in postmaster/002_connection_limits Andres Freund <[email protected]>
2026-04-09 15:55 [PATCH v26a 2/2] fixup! instrumentation: Show additional TSC clock source info in pg_test_timing Andres Freund <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox