Wrong LSN in WAL decoding error messages

From: rahul(at)rhyadav(dot)dev
To: Pgsql Hackers <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Thomas Munro <thomas(dot)munro(at)gmail(dot)com>, Ju Grigorev <ju(dot)grigorev(at)ftdata(dot)ru>
Subject: Wrong LSN in WAL decoding error messages
Date: 2026-10-01 07:17:46
Message-ID: P2qIkq4--F-9@rhyadav.dev
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers


Hi,

DecodeXLogRecord() is passed the LSN of the record it decodes, but its
error messages print state->ReadRecPtr instead.  Before the circular
WAL decoding buffer went in (3f1ce97346, v15), the two were the same.
Now records are decoded ahead of the one the reader last returned, so
these messages name an earlier record.  0001 makes them use the lsn
argument.

I noticed this while testing Yuriy's fix for bug #19599 [1], and he
suggested sending it separately.  These checks only see records that
passed the CRC check, so they fire when some code writes a malformed
record, which is when you most want the right LSN.

To trigger one, I set hole_offset to 0 in a full-page image that has
BKPIMAGE_HAS_HOLE set, and recomputed the record CRC.  For that
record, at 0/01C03DC0, master reports:

  pg_waldump: error in WAL record at 0/01C03D38: BKPIMAGE_HAS_HOLE
    set, but hole offset 0 length 4208 block image length 3984 at
    0/01C03D38

  crash recovery: BKPIMAGE_HAS_HOLE set, but hole offset 0 length
    4208 block image length 3984 at 0/01C03CD8

0/01C03D38 is the record just before it and 0/01C03CD8 is three
records back.  With the patches applied, both report 0/01C03DC0, and
crash recovery still ends at the same place.

0002 is separate because it changes long-standing output.
pg_waldump's "error in WAL record at" prefix also uses ReadRecPtr,
which is the last record read successfully rather than where reading
failed.  At the normal end of WAL that gives:

  error in WAL record at 0/017AC370: invalid record length at
  0/017AC3F8: expected at least 24, got 0

With 0002 both LSNs are 0/017AC3F8.  It uses EndRecPtr, as pg_rewind
does.  v14 behaves the same at the end of WAL, so if 0002 is wanted
at all I'd keep it to master.  I can add a check to pg_waldump's TAP
test that the two LSNs match.

0001 applies to REL_19_STABLE as is.  On 15 to 18 the messages still
use %X/%X, so the context needs a small adjustment.

[1] https://postgr.es/m/cd00a0536c674fac9e5dd9f4e27ae868@localhost.localdomain

Regards,
Rahul

Attachment Content-Type Size
v1-0002-pg_waldump-Report-the-position-of-a-WAL-read-erro.patch application/octet-stream 1.4 KB
v1-0001-Report-the-decoded-record-s-LSN-in-DecodeXLogReco.patch application/octet-stream 4.4 KB

Browse pgsql-hackers by date

  From Date Subject
Previous Message wenhui qiu 2026-10-01 07:15:10 Re: ZSTD TOAST compression, and an extensible compression method encoding