Improve logrotate test so that it meaningfully exercises syslogger.

Discussion of bug #15804 reveals that this test didn't really prove
that the syslogger child process ever launched successfully, much
less did anything.  It was only checking that the expected log file
gets created, and that's done in the postmaster.  Moreover, the
test assumed it could rename the log file, which is likely to fail
on Windows (cf. commit d611175e5).

Instead, use the default log file name pattern, which should result
in a new file name being chosen after 1 second, and verify that
rotation has occurred by checking for a new file name.  Also add code
to test that messages actually do propagate through the syslogger.

In theory this version of the test should work on Windows, so
revert d611175e5.

Discussion: https://postgr.es/m/15804-3721117bf40fb654@postgresql.org

diff --git a/src/bin/pg_ctl/t/004_logrotate.pl b/src/bin/pg_ctl/t/004_logrotate.pl
index e84319d36586fd5851c2aba56bb05db44fbeecc2..e8b60b769f63a988062f8d11ddf7bcfd9b31917b 100644 (file)
--- a/src/bin/pg_ctl/t/004_logrotate.pl
+++ b/src/bin/pg_ctl/t/004_logrotate.pl
@@ -3,51 +3,86 @@ use warnings;
 
 use PostgresNode;
 use TestLib;
-use Test::More;
+use Test::More tests => 4;
 use Time::HiRes qw(usleep);
 
-if ($windows_os)
-{
-       plan skip_all => 'logrotate test not supported on Windows';
-       exit;
-}
-else
-{
-       plan tests => 1;
-}
-
-
-my $tempdir = TestLib::tempdir;
-
+# Set up node with logging collector
 my $node = get_new_node('primary');
-$node->init(allows_streaming => 1);
+$node->init();
 $node->append_conf(
        'postgresql.conf', qq(
 logging_collector = on
-log_directory = 'log'
-log_filename = 'postgresql.log'
+lc_messages = 'C'
 ));
 
 $node->start();
 
-# Rename log file and rotate log.  Then log file should appear again.
+# Verify that log output gets to the file
 
-my $logfile = $node->data_dir . '/log/postgresql.log';
-my $old_logfile = $node->data_dir . '/log/postgresql.old';
-rename($logfile, $old_logfile);
+$node->psql('postgres', 'SELECT 1/0');
 
-$node->logrotate();
+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;
 
-# pg_ctl logrotate doesn't wait until rotation request being completed.  So
-# we have to wait some time until log file appears.
-my $attempts = 0;
+# might need to retry if logging collector process is slow...
 my $max_attempts = 180 * 10;
-while (not -e $logfile and $attempts < $max_attempts)
+
+my $first_logfile;
+for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
+{
+       $first_logfile = slurp_file($node->data_dir . '/' . $lfname);
+       last if $first_logfile =~ m/division by zero/;
+       usleep(100_000);
+}
+
+like($first_logfile, qr/division by zero/,
+        'found expected log file content');
+
+# Sleep 2 seconds and ask for log rotation; this should result in
+# output into a different log file name.
+sleep(2);
+$node->logrotate();
+
+# pg_ctl logrotate doesn't wait for rotation request to be completed.
+# Allow a bit of time for it to happen.
+my $new_current_logfiles;
+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);
+}
+
+note "now current_logfiles = $new_current_logfiles";
+
+like($new_current_logfiles, qr|^stderr log/postgresql-.*log$|,
+        'new current_logfiles is sane');
+
+$lfname = $new_current_logfiles;
+$lfname =~ s/^stderr //;
+chomp $lfname;
+
+# Verify that log output gets to this file, too
+
+$node->psql('postgres', 'fee fi fo fum');
+
+my $second_logfile;
+for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
 {
+       $second_logfile = slurp_file($node->data_dir . '/' . $lfname);
+       last if $second_logfile =~ m/syntax error/;
        usleep(100_000);
-       $attempts++;
 }
 
-ok(-e $logfile, "log file exists");
+like($second_logfile, qr/syntax error/,
+        'found expected log file content in new log file');
 
 $node->stop();