Revise pg_walsummary's 002_blocks test to avoid spurious failures.

robertmhaas · robertmhaas · commit ea18eb7d6255 · 2024-01-31T10:12:53.000-05:00
Analysis of buildfarm results showed that the code that was intended to wait for the inserts performed by this test to complete did not actually do so. Try to make that logic more robust. Improve error checking elsewhere in the script, too, so that we don't miss things like poll_query_until failing. Along the way, fix a bit of pgindent damage introduced by commit 5ddf997, which aimed to help us debug the failures that this commit is trying to fix. It's making the buildfarm sad. Discussion: http://postgr.es/m/CA+TgmobWFb8NqyfC31YnKAbZiXf9tLuwmyuvx=iYMXMniPQ4nw@mail.gmail.com
diff --git a/src/backend/backup/walsummary.c b/src/backend/backup/walsummary.c
@@ -258,7 +258,7 @@ RemoveWalSummaryIfOlderThan(WalSummaryFile *ws, time_t cutoff_time)
 #else
 	ereport(LOG,
 			(errmsg_internal("removing file \"%s\" cutoff_time=%llu", path,
-			 (unsigned long long) cutoff_time)));
+							 (unsigned long long) cutoff_time)));
 #endif
 }
 
diff --git a/src/bin/pg_walsummary/t/002_blocks.pl b/src/bin/pg_walsummary/t/002_blocks.pl
@@ -13,13 +13,6 @@
 $node1->append_conf('postgresql.conf', 'summarize_wal = on');
 $node1->start;
 
-# See what's been summarized up until now.
-my $progress = $node1->safe_psql('postgres', <<EOM);
-SELECT summarized_tli, summarized_lsn FROM pg_get_wal_summarizer_state()
-EOM
-my ($summarized_tli, $summarized_lsn) = split(/\|/, $progress);
-note("before insert, summarized TLI $summarized_tli through $summarized_lsn");
-
 # Create a table and insert a few test rows into it. VACUUM FREEZE it so that
 # autovacuum doesn't induce any future modifications unexpectedly. Then
 # trigger a checkpoint.
@@ -31,22 +24,33 @@
 FROM
 	generate_series(1, 400) g;
 VACUUM FREEZE;
+EOM
+
+# Record the current WAL insert LSN.
+my $base_lsn = $node1->safe_psql('postgres', <<EOM);
+SELECT pg_current_wal_insert_lsn()
+EOM
+note("just after insert, WAL insert LSN is $base_lsn");
+
+# Now perform a CHECKPOINT.
+$node1->safe_psql('postgres', <<EOM);
 CHECKPOINT;
 EOM
 
-# Wait for a new summary to show up.
-$node1->poll_query_until('postgres', <<EOM);
+# Wait for a new summary to show up, one that includes the inserts we just did.
+my $result = $node1->poll_query_until('postgres', <<EOM);
 SELECT EXISTS (
     SELECT * from pg_available_wal_summaries()
-    WHERE tli = $summarized_tli AND end_lsn > '$summarized_lsn'
+    WHERE end_lsn >= '$base_lsn'
 )
 EOM
+ok($result, "WAL summarization caught up after insert");
 
-# Again check the progress of WAL summarization.
-$progress = $node1->safe_psql('postgres', <<EOM);
+# Get a list of what summaries we now have.
+my $progress = $node1->safe_psql('postgres', <<EOM);
 SELECT summarized_tli, summarized_lsn FROM pg_get_wal_summarizer_state()
 EOM
-($summarized_tli, $summarized_lsn) = split(/\|/, $progress);
+my ($summarized_tli, $summarized_lsn) = split(/\|/, $progress);
 note("after insert, summarized TLI $summarized_tli through $summarized_lsn");
 note_wal_summary_dir("after insert", $node1);
 
@@ -56,20 +60,23 @@
 CHECKPOINT;
 EOM
 
-# Again wait for a new summary to show up.
-$node1->poll_query_until('postgres', <<EOM);
+# Wait for a new summary to show up.
+$result = $node1->poll_query_until('postgres', <<EOM);
 SELECT EXISTS (
     SELECT * from pg_available_wal_summaries()
     WHERE tli = $summarized_tli AND end_lsn > '$summarized_lsn'
 )
 EOM
+ok($result, "got new WAL summary after update");
 
 # Figure out the exact details for the new summary file.
 my $details = $node1->safe_psql('postgres', <<EOM);
 SELECT tli, start_lsn, end_lsn from pg_available_wal_summaries()
 	WHERE tli = $summarized_tli AND end_lsn > '$summarized_lsn'
 EOM
-my ($tli, $start_lsn, $end_lsn) = split(/\|/, $details);
+my @lines = split(/\n/, $details);
+is(0+@lines, 1, "got exactly one new WAL summary");
+my ($tli, $start_lsn, $end_lsn) = split(/\|/, $lines[0]);
 note("examining summary for TLI $tli from $start_lsn to $end_lsn");
 note_wal_summary_dir("after new summary", $node1);
 
@@ -81,12 +88,14 @@
 ok(-f $filename, "WAL summary file exists");
 note_wal_summary_dir("after existence check", $node1);
 
-# Run pg_walsummary on it. We expect block 0 to be modified, but depending
-# on where the new tuple ends up, block 1 might also be modified, so we
-# pass -i to pg_walsummary to make sure we don't end up with a 0..1 range.
+# Run pg_walsummary on it. We expect exactly two blocks to be modified,
+# block 0 and one other.
 my ($stdout, $stderr) = run_command([ 'pg_walsummary', '-i', $filename ]);
+note($stdout);
+@lines = split(/\n/, $stdout);
 like($stdout, qr/FORK main: block 0$/m, "stdout shows block 0 modified");
 is($stderr, '', 'stderr is empty');
+is(0+@lines, 2, "UPDATE modified 2 blocks");
 note_wal_summary_dir("after pg_walsummary run", $node1);
 
 done_testing();

Original file line number	Diff line number	Diff line change
`@@ -258,7 +258,7 @@ RemoveWalSummaryIfOlderThan(WalSummaryFile *ws, time_t cutoff_time)`
`258`	`258`	`#else`
`259`	`259`	`ereport(LOG,`
`260`	`260`	`(errmsg_internal("removing file \"%s\" cutoff_time=%llu", path,`
`261`		`- (unsigned long long) cutoff_time)));`
	`261`	`+ (unsigned long long) cutoff_time)));`
`262`	`262`	`#endif`
`263`	`263`	`}`
`264`	`264`