Date: Wed, 7 Apr 2021 13:48:28 +0900
From: Michael Paquier <michael@paquier.xyz>
To: pgsql-committers@lists.postgresql.org
Cc: pchampion@vmware.com
Subject: Re: pgsql: Add some information about authenticated identity via
 log_connec
Message-ID: <YG05nCI8x8B+Ad3G@paquier.xyz>
References: <E1lTwp4-0002l4-L9@gemulon.postgresql.org>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha512;
	protocol="application/pgp-signature"; boundary="4hVcpHcj+chlAQbP"
Content-Disposition: inline
In-Reply-To: <E1lTwp4-0002l4-L9@gemulon.postgresql.org>
Archived-At: 
 <https://www.postgresql.org/message-id/YG05nCI8x8B%2BAd3G%40paquier.xyz>
Precedence: bulk


--4hVcpHcj+chlAQbP
Content-Type: multipart/mixed; boundary="sJRZZxuEWuDRBtA3"
Content-Disposition: inline


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

On Wed, Apr 07, 2021 at 01:17:34AM +0000, Michael Paquier wrote:
> Add some information about authenticated identity via log_connections
>=20
> The "authenticated identity" is the string used by an authentication
> method to identify a particular user.  In many common cases, this is the
> same as the PostgreSQL username, but for some third-party authentication
> methods, the identifier in use may be shortened or otherwise translated
> (e.g. through pg_ident user mappings) before the server stores it.

So, fairywren, that is able to run the SSL tests on Windows, has been
complaining here:
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=3Dfairywren&dt=3D20=
21-04-07 03%3A04%3A44

The issue happens for 4 tests that check if some logs are not
generated in the backend after an authentication failure, but the
origin of the issue is that the truncation of the log file used to
prevent a check of some previous connection's logs does not work
properly, as fairywren shows a full-fledged log file in its output.

The method used by connect_ok() and connect_fails() is the same as
issues_sql_like() in PostgresNode.pm, so it seems to me that there is
a pending issue with the latter, no?  I think that this could lead to
some false positives in tests expecting some general SQL query
patterns, with a risk of overlap.

A safe solution to this stuff is just to rotate the log file once
before restarting the server, like in the attached.  I would do that
just on Windows to not slow down other systems.  Thoughts?
--
Michael

--sJRZZxuEWuDRBtA3
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment; filename="fix-tap-rotate-log.patch"
Content-Transfer-Encoding: quoted-printable

diff --git a/src/test/perl/PostgresNode.pm b/src/test/perl/PostgresNode.pm
index 598906ad64..0773287e59 100644
--- a/src/test/perl/PostgresNode.pm
+++ b/src/test/perl/PostgresNode.pm
@@ -1920,7 +1920,17 @@ sub connect_ok
 	if (@log_like or @log_unlike)
 	{
 		# Don't let previous log entries match for this connection.
-		truncate $self->logfile, 0;
+		# On Windows, the truncation would not work, so rotate the log
+		# file before restarting the server afresh.
+		if ($TestLib::windows_os)
+		{
+			$self->rotate_logfile;
+			$self->restart;
+		}
+		else
+		{
+			truncate $self->logfile, 0;
+		}
 	}
=20
 	# Never prompt for a password, any callers of this routine should
@@ -1994,7 +2004,17 @@ sub connect_fails
 	if (@log_like or @log_unlike)
 	{
 		# Don't let previous log entries match for this connection.
-		truncate $self->logfile, 0;
+		# On Windows, the truncation would not work, so rotate the log
+		# file before restarting the server afresh.
+		if ($TestLib::windows_os)
+		{
+			$self->rotate_logfile;
+			$self->restart;
+		}
+		else
+		{
+			truncate $self->logfile, 0;
+		}
 	}
=20
 	# Never prompt for a password, any callers of this routine should
@@ -2175,7 +2195,9 @@ Run a command on the node, then verify that $expected=
_sql appears in the
 server log file.
=20
 Reads the whole log file so be careful when working with large log outputs.
-The log file is truncated prior to running the command, however.
+The log file is truncated prior to running the command, however.  On Windo=
ws,
+the truncation would not work, so rotate to a new log file and restart the
+server.
=20
 =3Dcut
=20
@@ -2187,7 +2209,16 @@ sub issues_sql_like
=20
 	local %ENV =3D $self->_get_env();
=20
-	truncate $self->logfile, 0;
+	if ($TestLib::windows_os)
+	{
+		$self->rotate_logfile;
+		$self->restart;
+	}
+	else
+	{
+		truncate $self->logfile, 0;
+	}
+
 	my $result =3D TestLib::run_log($cmd);
 	ok($result, "@$cmd exit code 0");
 	my $log =3D TestLib::slurp_file($self->logfile);

--sJRZZxuEWuDRBtA3--

--4hVcpHcj+chlAQbP
Content-Type: application/pgp-signature; name="signature.asc"

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

iQIzBAABCgAdFiEEG72nH6vTowiyblFKnvQgOdbyQH0FAmBtOZwACgkQnvQgOdby
QH3+DQ//VjkC7f/1zkzhDP3+ARSdEtWTuXbXEzQ1y0QbKAOf1UrghmbEsMVPDOsg
t6pwhplAD9azNr56k9LpOOD2cFcWWEoRNg7LXswNRKYPKceztCnSvNJV3SPiSDpn
461LNYNHhq9hWivOQnj/uXOOEBnm4oiy40dfI8Z5w23FrR+XfqpXICwBjdLdMHKs
HXNJO1938DWEma0S2ie77HOwqKaSFnZTP+VElPdGB8GqbxUU05Nx7R0q215FmGjI
36zXTebtpZci7a0duPti6hrKjKUVL0A6bxjtAHLk3GZxUwwvg7WNQC2PXG+JOyz1
bZ9DojiPGj0PCK/Y9gVckHLD4S02CBkhy4q5QK12YpFKPx/i1qokSl+7dSVJdZPH
EnmREetM0PoFmpBv4GlkEtE+3Vm8Yta39Xo8DLSC3nxsWzYRsmua4CCIG56jlo4n
MRzIhSqtomkT72MLVw2hrBxhFkmvBQSosH7Pr4IYnjqBf6Yk1ZfUVTyqSkz/njJR
5eqFTlMurZJMuJa5qFZ48ms2XbbWzm0p7Hg58wRJCxxnKif0fHY256W79S7nUfcv
wHoauXoR+baa39sQKWfHo6iUvFwqcntHN5TPn/si1kkjW2gPTkdTuVHiKhJ1+V0M
6o2/wqctVrsAImi3PHGL9jBD5oaLfle8yv5Zve4SHg92+GzsyFE=
=wtAN
-----END PGP SIGNATURE-----

--4hVcpHcj+chlAQbP--