Fix race in TAP test 002_archiving.pl when restoring history file

This test, introduced in df86e52, uses a second standby to check that
it is able to remove correctly RECOVERYHISTORY and RECOVERYXLOG at the
end of recovery.  This standby uses the archives of the primary to
restore its contents, with some of the archive's contents coming from
the first standby previously promoted.  In slow environments, it was
possible that the test did not check what it should, as the history file
generated by the promotion of the first standby may not be stored yet on
the archives the second standby feeds on.  So, it could be possible that
the second standby selects an incorrect timeline, without restoring a
history file at all.

This commits adds a wait phase to make sure that the history file
required by the second standby is archived before this cluster is
created.  This relies on poll_query_until() with pg_stat_file() and an
absolute path, something not supported in REL_10_STABLE.

While on it, this adds a new test to check that the history file has
been restored by looking at the logs of the second standby.  This
ensures that a RECOVERYHISTORY, whose removal needs to be checked,
is created in the first place.  This should make the test more robust.

This test has been introduced by df86e52, but it came in light as an
effect of the bug fixed by acf1dd42, where the extra restore_command
calls made the test much slower.

Reported-by: Andres Freund
Discussion: https://postgr.es/m/YlT23IvsXkGuLzFi@paquier.xyz
Backpatch-through: 11

diff --git a/src/test/recovery/t/002_archiving.pl b/src/test/recovery/t/002_archiving.pl
index 683c33b5100083ee50555191cedcba63de545a90..4d784bdf554a757290bd67e8d9a22755beb04f0b 100644 (file)
--- a/src/test/recovery/t/002_archiving.pl
+++ b/src/test/recovery/t/002_archiving.pl
@@ -3,7 +3,7 @@ use strict;
 use warnings;
 use PostgresNode;
 use TestLib;
-use Test::More tests => 3;
+use Test::More tests => 4;
 use File::Copy;
 
 # Initialize master node, doing archives
@@ -21,6 +21,8 @@ $node_master->backup($backup_name);
 
 # Initialize standby node from backup, fetching WAL from archives
 my $node_standby = get_new_node('standby');
+# Note that this makes the standby store its contents on the archives
+# of the primary.
 $node_standby->init_from_backup($node_master, $backup_name,
    has_restoring => 1);
 $node_standby->append_conf('postgresql.conf',
@@ -55,19 +57,39 @@ is($result, qq(1000), 'check content from archives');
 # file, switch to a timeline large enough to allow a standby to recover
 # a history file from an archive.  As this requires at least two timeline
 # switches, promote the existing standby first.  Then create a second
-# standby based on the promoted one.  Finally, the second standby is
-# promoted.
+# standby based on the primary, using its archives.  Finally, the second
+# standby is promoted.
 $node_standby->promote;
 
+# Wait until the history file has been stored on the archives of the
+# primary once the promotion of the standby completes.  This ensures that
+# the second standby created below will be able to restore this file,
+# creating a RECOVERYHISTORY.
+my $primary_archive = $node_master->archive_dir;
+$caughtup_query =
+  "SELECT size IS NOT NULL FROM pg_stat_file('$primary_archive/00000002.history')";
+$node_master->poll_query_until('postgres', $caughtup_query)
+  or die "Timed out while waiting for archiving of 00000002.history";
+
 my $node_standby2 = get_new_node('standby2');
 $node_standby2->init_from_backup($node_master, $backup_name,
    has_restoring => 1);
 $node_standby2->start;
 
+my $log_location = -s $node_standby2->logfile;
+
 # Now promote standby2, and check that temporary files specifically
 # generated during archive recovery are removed by the end of recovery.
 $node_standby2->promote;
+
+# Check the logs of the standby to see that the commands have failed.
+my $log_contents       = slurp_file($node_standby2->logfile, $log_location);
 my $node_standby2_data = $node_standby2->data_dir;
+
+like(
+   $log_contents,
+   qr/restored log file "00000002.history" from archive/s,
+   "00000002.history retrieved from the archives");
 ok( !-f "$node_standby2_data/pg_wal/RECOVERYHISTORY",
    "RECOVERYHISTORY removed after promotion");
 ok( !-f "$node_standby2_data/pg_wal/RECOVERYXLOG",