Simplify TAP tests of kerberos with expected log file contents

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/[email protected]

diff --git a/src/test/kerberos/t/001_auth.pl b/src/test/kerberos/t/001_auth.pl
index 079321bbfc2954b8d6deb8d871072b744bd316dd..38e9ef7b1f4a7b079193257d0660c5dff9dc1ab8 100644 (file)
--- a/src/test/kerberos/t/001_auth.pl
+++ b/src/test/kerberos/t/001_auth.pl
@@ -20,7 +20,7 @@ use Time::HiRes qw(usleep);
 
 if ($ENV{with_gssapi} eq 'yes')
 {
-   plan tests => 34;
+   plan tests => 26;
 }
 else
 {
@@ -170,10 +170,7 @@ $node->append_conf(
    '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;
 }