v2-0003-oauth_validator-Avoid-races-in-log_check.patch

From 953c743f6926a638a6888d00e33c7592c660c9e2 Mon Sep 17 00:00:00 2001
From: Jacob Champion <jacob.champion@enterprisedb.com>
Date: Thu, 4 Dec 2025 16:34:09 -0800
Subject: [PATCH v2 3/7] oauth_validator: Avoid races in log_check()

Commit e0f373ee4 fixed up races in Cluster::connect_fails when using
log_like. t/002_client.pl didn't get the memo, though, because it
doesn't use Test::Cluster to perform its custom hook tests. (This is
probably not an issue at the moment, since the log check is only done
after authentication success and not failure, but there's no reason to
wait for someone to hit it.)

Introduce the fix, based on debug2 logging, to its use of log_check() as
well, and move the logic into the test() helper so that any additions
don't need to continually duplicate it.

Reviewed-by: Chao Li <li.evan.chao@gmail.com>
Discussion: https://postgr.es/m/CAOYmi%2BmrGg%2Bn_X2MOLgeWcj3v_M00gR8uz_D7mM8z%3DdX1JYVbg%40mail.gmail.com
Backpatch-through: 18
---
 .../modules/oauth_validator/t/002_client.pl   | 24 ++++++++++++++-----
 1 file changed, 18 insertions(+), 6 deletions(-)

diff --git a/src/test/modules/oauth_validator/t/002_client.pl b/src/test/modules/oauth_validator/t/002_client.pl
index aac0220d215..e6c91fc911c 100644
--- a/src/test/modules/oauth_validator/t/002_client.pl
+++ b/src/test/modules/oauth_validator/t/002_client.pl
@@ -29,6 +29,8 @@ $node->init;
 $node->append_conf('postgresql.conf', "log_connections = all\n");
 $node->append_conf('postgresql.conf',
 	"oauth_validator_libraries = 'validator'\n");
+# Needed to inspect postmaster log after connection failure:
+$node->append_conf('postgresql.conf', "log_min_messages = debug2");
 $node->start;
 
 $node->safe_psql('postgres', 'CREATE USER test;');
@@ -47,7 +49,7 @@ local all test oauth issuer="$issuer" scope="$scope"
 });
 $node->reload;
 
-my $log_start = $node->wait_for_log(qr/reloading configuration files/);
+$node->wait_for_log(qr/reloading configuration files/);
 
 $ENV{PGOAUTHDEBUG} = "UNSAFE";
 
@@ -73,6 +75,7 @@ sub test
 	my @cmd = ("oauth_hook_client", @{$flags}, $common_connstr);
 	note "running '" . join("' '", @cmd) . "'";
 
+	my $log_start = -s $node->logfile;
 	my ($stdout, $stderr) = run_command(\@cmd);
 
 	if (defined($params{expected_stdout}))
@@ -88,6 +91,18 @@ sub test
 	{
 		is($stderr, "", "$test_name: no stderr");
 	}
+
+	if (defined($params{log_like}))
+	{
+		# See Cluster::connect_fails(). To avoid races, we have to wait for the
+		# postmaster to flush the log for the finished connection.
+		$node->wait_for_log(
+			qr/DEBUG:  (?:00000: )?forked new client backend, pid=(\d+) socket.*DEBUG:  (?:00000: )?client backend \(PID \1\) exited with exit code \d/s,
+			$log_start);
+
+		$node->log_check("$test_name: log matches",
+			$log_start, log_like => $params{log_like});
+	}
 }
 
 test(
@@ -97,11 +112,8 @@ test(
 		"--expected-uri", "$issuer/.well-known/openid-configuration",
 		"--expected-scope", $scope,
 	],
-	expected_stdout => qr/connection succeeded/);
-
-$node->log_check("validator receives correct token",
-	$log_start,
-	log_like => [ qr/oauth_validator: token="my-token", role="$user"/, ]);
+	expected_stdout => qr/connection succeeded/,
+	log_like => [qr/oauth_validator: token="my-token", role="$user"/]);
 
 if ($ENV{with_libcurl} ne 'yes')
 {
-- 
2.34.1