Date: Sat, 27 Jan 2024 10:31:09 -0600
From: Nathan Bossart <nathandbossart@gmail.com>
To: Alexander Lakhin <exclusion@gmail.com>
Cc: Robert Haas <robertmhaas@gmail.com>,
	Matthias van de Meent <boekewurm+postgres@gmail.com>,
	PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Subject: Re: cleanup patches for incremental backup
Message-ID: <20240127163109.GA3047116@nathanxps13>
References: 
 <CA+TgmoZd=pYk0owL4W2f4to9qFjwq_NmGJzXg44pEcMxuYriCA@mail.gmail.com>
 <CAEze2WizrxyWg+xeVMuyVqfZc-8U1myy1V4H3zwV-7xXztVf2w@mail.gmail.com>
 <CA+TgmoadPUdt8ZJ_Zem-T2_qZ5OTXVdxH6wGtnaV-TunN+LOHQ@mail.gmail.com>
 <CAEze2Wjbf==0=v+Ck8B2vcCeqD_3_SfDV3HtpEQiP-r3e2fsSA@mail.gmail.com>
 <CA+TgmobTfzrnBesboXutZmrABdP79mO2HhXupY5YOdZ9VLWFog@mail.gmail.com>
 <CAEze2WjhdVCqEe_qqEok3NA6DwUdOGSBjAxzmYdAqiaaH1uRcg@mail.gmail.com>
 <CA+TgmoaQHtGNFczJzSO5sMobUpuikSHphtFPZpdLmjzwdmM1DQ@mail.gmail.com>
 <20240124170846.GA2643050@nathanxps13>
 <CA+TgmoZusu5g3rM1k=UB29Sf53c1OKjm1uFw9uo-sSXBLFZJiQ@mail.gmail.com>
 <8aed364e-f572-4561-b4fc-ff149067b670@gmail.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="/04w6evG8XlLl3ft"
Content-Disposition: inline
In-Reply-To: <8aed364e-f572-4561-b4fc-ff149067b670@gmail.com>
Archived-At: 
 <https://www.postgresql.org/message-id/20240127163109.GA3047116%40nathanxps13>
Precedence: bulk


--/04w6evG8XlLl3ft
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

On Sat, Jan 27, 2024 at 11:00:01AM +0300, Alexander Lakhin wrote:
> 24.01.2024 20:46, Robert Haas wrote:
>> This is weird. There's a little more detail in the log file,
>> regress_log_002_blocks, e.g. from the first failure you linked:
>> 
>> [11:18:20.683](96.787s) # before insert, summarized TLI 1 through 0/14E09D0
>> [11:18:21.188](0.505s) # after insert, summarized TLI 1 through 0/14E0D08
>> [11:18:21.326](0.138s) # examining summary for TLI 1 from 0/14E0D08 to 0/155BAF0
>> # 1
>> ...
>> [11:18:21.349](0.000s) #          got: 'pg_walsummary: error: could
>> not open file "/home/nm/farm/gcc64/HEAD/pgsql.build/src/bin/pg_walsummary/tmp_check/t_002_blocks_node1_data/pgdata/pg_wal/summaries/0000000100000000014E0D0800000000155BAF0
>> # 1.summary": No such file or directory'
>> 
>> The "examining summary" line is generated based on the output of
>> pg_available_wal_summaries(). The way that works is that the server
>> calls readdir(), disassembles the filename into a TLI and two LSNs,
>> and returns the result.
> 
> I'm discouraged by "\n1" in the file name and in the
> "examining summary..." message.
> regress_log_002_blocks from the following successful test run on the same
> sungazer node contains:
> [15:21:58.924](0.106s) # examining summary for TLI 1 from 0/155BAE0 to 0/155E750
> [15:21:58.925](0.001s) ok 1 - WAL summary file exists

Ah, I think this query:

	SELECT tli, start_lsn, end_lsn from pg_available_wal_summaries()
		WHERE tli = $summarized_tli AND end_lsn > '$summarized_lsn'

is returning more than one row in some cases.  I attached a quick sketch of
an easy way to reproduce the issue as well as one way to fix it.

-- 
Nathan Bossart
Amazon Web Services: https://aws.amazon.com

--/04w6evG8XlLl3ft
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment; filename="repro_and_fix.patch"

diff --git a/src/bin/pg_walsummary/t/002_blocks.pl b/src/bin/pg_walsummary/t/002_blocks.pl
index 40908da8cb..5609b1bd14 100644
--- a/src/bin/pg_walsummary/t/002_blocks.pl
+++ b/src/bin/pg_walsummary/t/002_blocks.pl
@@ -64,10 +64,16 @@ SELECT EXISTS (
 )
 EOM
 
+$node1->safe_psql('postgres', <<EOM);
+UPDATE mytable SET b = 'abefghijklmnopqrstuvwxyz' WHERE a = 2;
+CHECKPOINT;
+EOM
+$node1->safe_psql('postgres', 'SELECT pg_sleep(1);');
+
 # 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'
+	WHERE tli = $summarized_tli AND end_lsn > '$summarized_lsn' ORDER BY end_lsn LIMIT 1
 EOM
 my ($tli, $start_lsn, $end_lsn) = split(/\|/, $details);
 note("examining summary for TLI $tli from $start_lsn to $end_lsn");

--/04w6evG8XlLl3ft--