Simplify TAP tests of kerberos with expected log file contents

michaelpq · michaelpq · commit 11e1577a576f · 2021-03-22T08:59:43.000+09:00
The TAP tests of kerberos rely on the logs generated by the backend to check various connection scenarios. In order to make sure that a given test does not overlap with the log contents generated by a previous test, the test suite relied on a logic with the logging collector and a rotation of the log files to ensure the uniqueness of the log generated with a wait phase. Parsing the log contents for expected patterns is a problem that has been solved in a simpler way by PostgresNode::issues_sql_like() where the log file is truncated before checking for the contents generated, with the backend sending its output to a log file given by pg_ctl instead. This commit switches the kerberos test suite to use such a method, removing any wait phase and simplifying the whole logic, resulting in less code. If a failure happens in the tests, the contents of the logs are still showed to the user at the moment of the failure thanks to like(), so this has no impact on debugging capabilities. I have bumped into this issue while reviewing a different patch set aiming at extending the kerberos test suite to check for multiple log patterns instead of one now. Author: Michael Paquier Reviewed-by: Stephen Frost, Bharath Rupireddy Discussion: https://postgr.es/m/YFXcq2vBTDGQVBNC@paquier.xyz
diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl
@@ -20,7 +20,7 @@
 
 if ($ENV{with_gssapi} eq 'yes')
 {
-	plan tests => 34;
+	plan tests => 26;
 }
 else
 {
@@ -170,10 +170,7 @@ END
 	'postgresql.conf', qq{
 listen_addresses = '$hostaddr'
 krb_server_keyfile = '$keytab'
-logging_collector = on
 log_connections = on
-# these ensure stability of test results:
-log_rotation_age = 0
 lc_messages = 'C'
 });
 $node->start;
@@ -212,29 +209,15 @@ sub test_access
 	# Verify specified log message is logged in the log file.
 	if ($expect_log_msg ne '')
 	{
-		my $current_logfiles = slurp_file($node->data_dir . '/current_logfiles');
-		note "current_logfiles = $current_logfiles";
-		like($current_logfiles, qr|^stderr log/postgresql-.*log$|,
-			 'current_logfiles is sane');
-
-		my $lfname = $current_logfiles;
-		$lfname =~ s/^stderr //;
-		chomp $lfname;
-
-		# might need to retry if logging collector process is slow...
-		my $max_attempts = 180 * 10;
-		my $first_logfile;
-		for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
-		{
-			$first_logfile = slurp_file($node->data_dir . '/' . $lfname);
-			last if $first_logfile =~ m/\Q$expect_log_msg\E/;
-			usleep(100_000);
-		}
+		my $first_logfile = slurp_file($node->logfile);
 
 		like($first_logfile, qr/\Q$expect_log_msg\E/,
 			 'found expected log file content');
 	}
 
+	# Clean up any existing contents in the node's log file so as
+	# future tests don't step on each other's generated contents.
+	truncate $node->logfile, 0;
 	return;
 }
 
