From: Tom Lane <tgl@sss.pgh.pa.us>
To: Thomas Munro <thomas.munro@gmail.com>
Cc: Dagfinn Ilmari Mannsåker <ilmari@ilmari.org>
Cc: Simon Riggs <simon.riggs@enterprisedb.com>
Cc: Julien Rouhaud <rjuju123@gmail.com>
Cc: Ashutosh Sharma <ashu.coek88@gmail.com>
Cc: Daniel Gustafsson <daniel@yesql.se>
Cc: Stephen Frost <sfrost@snowman.net>
Cc: Alvaro Herrera <alvherre@2ndquadrant.com>
Cc: Andres Freund <andres@anarazel.de>
Cc: David Steele <david@pgmasters.net>
Cc: Dmitry Dolgov <9erthalion6@gmail.com>
Cc: Jakub Wartak <Jakub.Wartak@tomtom.com>
Cc: Tomas Vondra <tomas.vondra@2ndquadrant.com>
Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>
Cc: pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: WIP: WAL prefetch (another approach)
Date: Mon, 25 Apr 2022 14:11:49 -0400
Message-ID: <111657.1650910309@sss.pgh.pa.us> (raw)
In-Reply-To: <CA+hUKGLtn-309+p6pFpR7AdQ+ypx7Zy=LhF6Bardie_bm-pb8Q@mail.gmail.com>
References: <CA+hUKG+dE2-BOsZAQJC4miaXhZF3U6WV0cUH6yWJ+ixoiFNOSw@mail.gmail.com>
<20220309064633.woyf53w3odnhltah@jrouhaud>
<CA+hUKGKusWunqOd9En+FkT+US_kuDK-MSZyXHCr=OTwRw8Ah1A@mail.gmail.com>
<20220311082737.bmnlmtzwi2xqrhxl@jrouhaud>
<CA+hUKGKBxHZMVJFELZhC8iD57TBhboHtpmG+rzdOSdRGyxUGeQ@mail.gmail.com>
<20220314071713.v4anmngdi5njaple@jrouhaud>
<CA+hUKG+0Qe2b7eFancRmZcq1wAsFGizFVuq9bSAg5uNy+4wMiQ@mail.gmail.com>
<CA+hUKGL=R4MMEX7DtFefnnT6v5Dun=Y=OWLCgD0_ixK2KkkKRw@mail.gmail.com>
<20220321082916.ysrlw2xst2tpyc5a@jrouhaud>
<CA+hUKGKs7cNkiMyNY9aSn2bF2AQNj9bb_dbY2B_6d_srnx5+mw@mail.gmail.com>
<YkpiH3sFL8XsPBgs@jrouhaud>
<CA+hUKGJ3aq3ZAxfhuPvMkOKwirfqunrV-p8d7kEe_WunjGndDw@mail.gmail.com>
<CANbhV-FsVOXou11teGwPWiHh__yaDUSTG6K2JPRTHgznt2uvpg@mail.gmail.com>
<87tuaynvka.fsf@wibble.ilmari.org>
<CA+hUKGLtn-309+p6pFpR7AdQ+ypx7Zy=LhF6Bardie_bm-pb8Q@mail.gmail.com>
I believe that the WAL prefetch patch probably accounts for the
intermittent errors that buildfarm member topminnow has shown
since it went in, eg [1]:
inline patch 1: /home/nm/ext4/HEAD/pgsql.build/contrib/pg_walinspect/results/pg_walinspect.out (+2/-10 lines) download inline-1.patchdiff -U3 /home/nm/ext4/HEAD/pgsql/contrib/pg_walinspect/expected/pg_walinspect.out /home/nm/ext4/HEAD/pgsql.build/contrib/pg_walinspect/results/pg_walinspect.out
--- /home/nm/ext4/HEAD/pgsql/contrib/pg_walinspect/expected/pg_walinspect.out 2022-04-10 03:05:15.972622440 +0200+++ /home/nm/ext4/HEAD/pgsql.build/contrib/pg_walinspect/results/pg_walinspect.out 2022-04-25 05:09:49.861642059 +0200@@ -34,11 +34,7 @@
(1 row)
SELECT COUNT(*) >= 0 AS ok FROM pg_get_wal_records_info_till_end_of_wal(:'wal_lsn1');
- ok ------ t-(1 row)-+ERROR: could not read WAL at 0/1903E40
SELECT COUNT(*) >= 0 AS ok FROM pg_get_wal_stats(:'wal_lsn1', :'wal_lsn2');
ok
----
@@ -46,11 +42,7 @@
(1 row)
SELECT COUNT(*) >= 0 AS ok FROM pg_get_wal_stats_till_end_of_wal(:'wal_lsn1');
- ok ------ t-(1 row)-+ERROR: could not read WAL at 0/1903E40
-- ===================================================================
-- Test for filtering out WAL records of a particular table
-- ===================================================================
I've reproduced this manually on that machine, and confirmed that the
proximate cause is that XLogNextRecord() is returning NULL because
state->decode_queue_head == NULL, without bothering to provide an errormsg
(which doesn't seem very well thought out in itself). I obtained the
contents of the xlogreader struct at failure:
(gdb) p *xlogreader
$1 = {routine = {page_read = 0x594270 <read_local_xlog_page_no_wait>,
segment_open = 0x593b44 <wal_segment_open>,
segment_close = 0x593d38 <wal_segment_close>}, system_identifier = 0,
private_data = 0x0, ReadRecPtr = 26230672, EndRecPtr = 26230752,
abortedRecPtr = 26230752, missingContrecPtr = 26230784,
overwrittenRecPtr = 0, DecodeRecPtr = 26230672, NextRecPtr = 26230752,
PrevRecPtr = 0, record = 0x0, decode_buffer = 0xf25428 "\240",
decode_buffer_size = 65536, free_decode_buffer = true,
decode_buffer_head = 0xf25428 "\240", decode_buffer_tail = 0xf25428 "\240",
decode_queue_head = 0x0, decode_queue_tail = 0x0,
readBuf = 0xf173f0 "\020\321\005", readLen = 0, segcxt = {
ws_dir = '\000' <repeats 1023 times>, ws_segsize = 16777216}, seg = {
ws_file = 25, ws_segno = 0, ws_tli = 1}, segoff = 0,
latestPagePtr = 26222592, latestPageTLI = 1, currRecPtr = 26230752,
currTLI = 1, currTLIValidUntil = 0, nextTLI = 0,
readRecordBuf = 0xf1b3f8 "<", readRecordBufSize = 40960,
errormsg_buf = 0xef3270 "", errormsg_deferred = false, nonblocking = false}
I don't have an intuition about where to look beyond that, any
suggestions?
What I do know so far is that while the failure reproduces fairly
reliably under "make check" (more than half the time, which squares
with topminnow's history), it doesn't reproduce at all under "make
installcheck" (after removing NO_INSTALLCHECK), which seems odd.
Maybe it's dependent on how much WAL history the installation has
accumulated?
It could be that this is a bug in pg_walinspect or a fault in its
test case; hard to tell since that got committed at about the same
time as the prefetch changes.
regards, tom lane
[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=topminnow&dt=2022-04-25%2001%3A48%3A47
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: tgl@sss.pgh.pa.us, thomas.munro@gmail.com, ilmari@ilmari.org, simon.riggs@enterprisedb.com, rjuju123@gmail.com, ashu.coek88@gmail.com, daniel@yesql.se, sfrost@snowman.net, alvherre@2ndquadrant.com, andres@anarazel.de, david@pgmasters.net, 9erthalion6@gmail.com, Jakub.Wartak@tomtom.com, tomas.vondra@2ndquadrant.com, tomas.vondra@enterprisedb.com
Subject: Re: WIP: WAL prefetch (another approach)
In-Reply-To: <111657.1650910309@sss.pgh.pa.us>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox