Re: Proposal: Save user's original authenticated identity for logging

[Michael Paquier]

On Thu, Mar 18, 2021 at 05:14:24PM +0900, Michael Paquier wrote:
> Looking at 0001, I am not much a fan of relying on the position of the
> matching pattern in the log file.  Instead of relying on the logging
> collector and one single file, why not just changing the generation of
> the logfile and rely on the output of stderr by restarting the server?
> That means less tests, no need to wait for the logging collector to do
> its business, and it solves your problem.  Please see the idea with
> the patch attached.  Thoughts?

While looking at 0003, I have noticed that the new kerberos tests
actually switch from a logic where one message pattern matches, to a
logic where multiple message patterns match, but I don't see a problem
with what I sent previously, as long as one consume once a log file
and matches all the patterns once, say like the following in
test_access():
    my $first_logfile = slurp_file($node->logfile);

    # Verify specified log messages are logged in the log file.
    while (my $expect_log_msg = shift @expect_log_msgs)
    {
            like($first_logfile, qr/\Q$expect_log_msg\E/,
                 'found expected log file content');
    }

    # Rotate to a new file, for any next check.
    $node->rotate_logfile;
    $node->restart; 

A second solution would be a logrotate, relying on the contents of
current_logfiles to know what is the current file, with an extra wait
after $node->logrotate to check if the contents of current_logfiles
have changed.  That's slower for me as this requires a small sleep to
make sure that the new log file name has changed, and I find the
restart solution simpler and more elegant.  Please see the attached
based on HEAD for this logrotate idea.

Jacob, what do you think?
--
Michael

diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl
index 079321bbfc..dc0f772834 100644
--- a/src/test/kerberos/t/001_auth.pl
+++ b/src/test/kerberos/t/001_auth.pl
@@ -233,6 +233,22 @@ sub test_access
 
 		like($first_logfile, qr/\Q$expect_log_msg\E/,
 			 'found expected log file content');
+
+		# Rotate to a new file, for any next check.  Note that
+		# pg_ctl does not wait for the operation to complete
+		# so wait for the result to change first.  Sleep a bit
+		# to have a new log file name.
+		sleep(2);
+		$node->logrotate;
+		my $new_current_logfiles;
+
+		# Wait until the contents of current_logfiles have changed.
+		for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
+		{
+			$new_current_logfiles = slurp_file($node->data_dir . '/current_logfiles');
+			last if $new_current_logfiles ne $current_logfiles;
+			usleep(100_000);
+		}
 	}
 
 	return;

signature.asc
Description: PGP signature