MIME-Version: 1.0
References: <19490-9c59c6a583513b99@postgresql.org>
 <46FE61C9-F273-45FD-BED7-0F8CDA6EB992@yandex-team.ru>
 <CAL9smLBMxKBCmsA9UGcmf93bT2_MsZ+POH-oHREuwKdmMU7jfQ@mail.gmail.com>
 <46DB3CAB-EA1C-41A5-9D6D-5F913A2AAF66@yandex-team.ru>
 <CAJgoLkJfFgL-V+pYB7=R81AbURTE6sMhzVHDQDhVGnfXRSJ9Wg@mail.gmail.com>
In-Reply-To: 
 <CAJgoLkJfFgL-V+pYB7=R81AbURTE6sMhzVHDQDhVGnfXRSJ9Wg@mail.gmail.com>
From: Radim Marek <radim@boringsql.com>
Date: Thu, 21 May 2026 11:06:18 +0200
Message-ID: 
 <CAJgoLkKCu0wCwPQZSo5no=XATU-4LMK4QfKBwV928o2uKcxe=g@mail.gmail.com>
Subject: Re: BUG #19490: Streaming standby on 16.14 stops applying WAL on
 MultiXactOffsetSLRU when primary is 16.8
To: Andrey Borodin <x4mmm@yandex-team.ru>
Cc: Marko Tiikkaja <marko@joh.to>,
	PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>
Content-Type: multipart/alternative; boundary="00000000000064d4980652503a71"
Archived-At: 
 <https://www.postgresql.org/message-id/CAJgoLkKCu0wCwPQZSo5no%3DXATU-4LMK4QfKBwV928o2uKcxe%3Dg%40mail.gmail.com>
Precedence: bulk

--00000000000064d4980652503a71
Content-Type: text/plain; charset="UTF-8"

Altough the culprit is known, I've got more data as requested.

#0  0x00007f20e9bdb687 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f20e9bdbc8c in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f20e9be6920 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#3  0x000055a71796e3ca in PGSemaphoreLock (sema=0x7f20de6d0e38) at
./build/src/backend/port/pg_sema.c:327
#4  0x000055a7179f57ed in LWLockAcquire (lock=0x7f20de6d1800,
mode=mode@entry=LW_EXCLUSIVE) at
./build/../src/backend/storage/lmgr/lwlock.c:1314
#5  0x000055a71772dfb2 in SimpleLruWriteAll (ctl=ctl@entry=0x55a717e83040
<MultiXactOffsetCtlData>, allow_redirtied=allow_redirtied@entry=false) at
./build/../src/backend/access/transam/slru.c:1174
#6  0x000055a717727b6f in RecordNewMultiXact (multi=79871, offset=218449,
nmembers=2, members=members@entry=0x7f20de6831ec) at
./build/../src/backend/access/transam/multixact.c:944
#7  0x000055a71772a983 in multixact_redo (record=0x55a73a8d0fc8) at
./build/../src/backend/access/transam/multixact.c:3464
#8  0x000055a71774d9b8 in ApplyWalRecord (xlogreader=<optimized out>,
record=0x7f20de6831b0, replayTLI=<synthetic pointer>) at
./build/../src/backend/access/transam/xlogrecovery.c:1951
#9  PerformWalRecovery () at
./build/../src/backend/access/transam/xlogrecovery.c:1782
#10 0x000055a717740def in StartupXLOG () at
./build/../src/backend/access/transam/xlog.c:5452
#11 0x000055a71797c7e4 in StartupProcessMain () at
./build/../src/backend/postmaster/startup.c:282
#12 0x000055a717972b20 in AuxiliaryProcessMain
(auxtype=auxtype@entry=StartupProcess)
at ./build/../src/backend/postmaster/auxprocess.c:141
#13 0x000055a717977db3 in StartChildProcess (type=StartupProcess) at
./build/../src/backend/postmaster/postmaster.c:5381
#14 0x000055a71797bfb8 in PostmasterMain (argc=argc@entry=1,
argv=argv@entry=0x55a73a8d0590)
at ./build/../src/backend/postmaster/postmaster.c:1463
#15 0x000055a7176a05bc in main (argc=1, argv=0x55a73a8d0590) at
./build/../src/backend/main/main.c:200

and WAL dump

rmgr: Btree       len (rec/tot):     64/    64, tx:     336098, lsn:
1/32DE75F0, prev 1/32DE7580, desc: INSERT_LEAF off: 244, blkref #0: rel
1663/16384/16432 blk 536
rmgr: MultiXact   len (rec/tot):     54/    54, tx:     336098, lsn:
1/32DE7630, prev 1/32DE75F0, desc: CREATE_ID 79871 offset 218449 nmembers
2: 336089 (keysh)
336098 (keysh)
rmgr: Heap        len (rec/tot):     54/    54, tx:     336098, lsn:
1/32DE7668, prev 1/32DE7630, desc: LOCK xmax: 79871, off: 1, infobits:
[IS_MULTI, LOCK_ONLY,
KEYSHR_LOCK], flags: 0x00, blkref #0: rel 1663/16384/16418 blk 0
rmgr: Heap        len (rec/tot):     72/    72, tx:     336096, lsn:
1/32DE76A0, prev 1/32DE7668, desc: HOT_UPDATE old_xmax: 336096, old_off:
52, old_infobits: [],
flags: 0x20, new_xmax: 0, new_off: 149, blkref #0: rel 1663/16384/16401 blk
22
rmgr: Heap        len (rec/tot):     71/    71, tx:     336096, lsn:
1/32DE76E8, prev 1/32DE76A0, desc: HOT_UPDATE old_xmax: 336096, old_off:
149, old_infobits: [],
flags: 0x60, new_xmax: 0, new_off: 209, blkref #0: rel 1663/16384/16399 blk
6
rmgr: Heap        len (rec/tot):     79/    79, tx:     336096, lsn:
1/32DE7730, prev 1/32DE76E8, desc: INSERT off: 150, flags: 0x00, blkref #0:
rel 1663/16384/16417
blk 741
rmgr: Heap        len (rec/tot):     72/    72, tx:     336097, lsn:
1/32DE7780, prev 1/32DE7730, desc: HOT_UPDATE old_xmax: 336097, old_off:
243, old_infobits: [],
flags: 0x20, new_xmax: 0, new_off: 228, blkref #0: rel 1663/16384/16401 blk
26
rmgr: Transaction len (rec/tot):     34/    34, tx:     336096, lsn:
1/32DE77C8, prev 1/32DE7780, desc: COMMIT 2026-05-21 08:43:07.003572 UTC

Radim

On Thu, 21 May 2026 at 10:34, Radim Marek <radim@boringsql.com> wrote:

> Thank you for the follow-up. In mean-time I can confirm the
> commit 77dff5d937b1 might be the source of the original reported issue.
>
> Unfortunately pinning version down to 16.12 only avoids the
> MultiXactOffsetSLRU self-deadlock, but the standby then fails recovery
> after 12+ hours.
>
> FATAL: could not access status of transaction 24958976 DETAIL: Could not
> read from file "pg_multixact/offsets/017C" at offset 221184: read too few
> bytes. CONTEXT: WAL redo at 14770/873268E8 for MultiXact/CREATE_ID:
> 24958975 offset 61500431 nmembers 2: 3058927188 (fornokeyupd) 3058927189
> (keysh)
>
> We are going to try to pin 16.13 and try that before we can safely upgrade
> of the primary/are confident we have working PITR recovery available should
> we need it.
>
> Radim
>
> PS: Once I have some time I will try to setup a docker based harness to be
> able to replicate original problem for later testing of the fix.
>
> On Thu, 21 May 2026 at 09:25, Andrey Borodin <x4mmm@yandex-team.ru> wrote:
>
>>
>>
>> > On 21 May 2026, at 00:12, Marko Tiikkaja <marko@joh.to> wrote:
>> >
>> > #8  0x0000654c8ae2acba in SimpleLruWriteAll (ctl=0x654c8b63e400
>>
>> Thanks!
>>
>> This clearly points to SimpleLruWriteAll() added in 77dff5d937b1.
>> If by chance you will have a backtrace of another deadlocking process -
>> please post it.
>>
>> But it's not strictly necessary for analysis, I think we can figure out
>> what
>> happened from the backtrace you already posted.
>>
>>
>> Best regards, Andrey Borodin.
>>
>

--00000000000064d4980652503a71
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div dir=3D"ltr"><div>Altough the culprit is known, I&#39;=
ve got more data as requested.</div><div><br></div><div>#0 =C2=A00x00007f20=
e9bdb687 in ?? () from /lib/x86_64-linux-gnu/libc.so.6<br>#1 =C2=A00x00007f=
20e9bdbc8c in ?? () from /lib/x86_64-linux-gnu/libc.so.6<br>#2 =C2=A00x0000=
7f20e9be6920 in ?? () from /lib/x86_64-linux-gnu/libc.so.6<br>#3 =C2=A00x00=
0055a71796e3ca in PGSemaphoreLock (sema=3D0x7f20de6d0e38) at ./build/src/ba=
ckend/port/pg_sema.c:327<br>#4 =C2=A00x000055a7179f57ed in LWLockAcquire (l=
ock=3D0x7f20de6d1800, mode=3Dmode@entry=3DLW_EXCLUSIVE) at ./build/../src/b=
ackend/storage/lmgr/lwlock.c:1314<br>#5 =C2=A00x000055a71772dfb2 in SimpleL=
ruWriteAll (ctl=3Dctl@entry=3D0x55a717e83040 &lt;MultiXactOffsetCtlData&gt;=
, allow_redirtied=3Dallow_redirtied@entry=3Dfalse) at<br>./build/../src/bac=
kend/access/transam/slru.c:1174<br>#6 =C2=A00x000055a717727b6f in RecordNew=
MultiXact (multi=3D79871, offset=3D218449, nmembers=3D2, members=3Dmembers@=
entry=3D0x7f20de6831ec) at<br>./build/../src/backend/access/transam/multixa=
ct.c:944<br>#7 =C2=A00x000055a71772a983 in multixact_redo (record=3D0x55a73=
a8d0fc8) at ./build/../src/backend/access/transam/multixact.c:3464<br>#8 =
=C2=A00x000055a71774d9b8 in ApplyWalRecord (xlogreader=3D&lt;optimized out&=
gt;, record=3D0x7f20de6831b0, replayTLI=3D&lt;synthetic pointer&gt;) at<br>=
./build/../src/backend/access/transam/xlogrecovery.c:1951<br>#9 =C2=A0Perfo=
rmWalRecovery () at ./build/../src/backend/access/transam/xlogrecovery.c:17=
82<br>#10 0x000055a717740def in StartupXLOG () at ./build/../src/backend/ac=
cess/transam/xlog.c:5452<br>#11 0x000055a71797c7e4 in StartupProcessMain ()=
 at ./build/../src/backend/postmaster/startup.c:282<br>#12 0x000055a717972b=
20 in AuxiliaryProcessMain (auxtype=3Dauxtype@entry=3DStartupProcess) at ./=
build/../src/backend/postmaster/auxprocess.c:141<br>#13 0x000055a717977db3 =
in StartChildProcess (type=3DStartupProcess) at ./build/../src/backend/post=
master/postmaster.c:5381<br>#14 0x000055a71797bfb8 in PostmasterMain (argc=
=3Dargc@entry=3D1, argv=3Dargv@entry=3D0x55a73a8d0590) at ./build/../src/ba=
ckend/postmaster/postmaster.c:1463<br>#15 0x000055a7176a05bc in main (argc=
=3D1, argv=3D0x55a73a8d0590) at ./build/../src/backend/main/main.c:200</div=
><div><br></div></div><div>and WAL dump<br><br>rmgr: Btree =C2=A0 =C2=A0 =
=C2=A0 len (rec/tot): =C2=A0 =C2=A0 64/ =C2=A0 =C2=A064, tx: =C2=A0 =C2=A0 =
336098, lsn: 1/32DE75F0, prev 1/32DE7580, desc: INSERT_LEAF off: 244, blkre=
f #0: rel 1663/16384/16432 blk 536<br>rmgr: MultiXact =C2=A0 len (rec/tot):=
 =C2=A0 =C2=A0 54/ =C2=A0 =C2=A054, tx: =C2=A0 =C2=A0 336098, lsn: 1/32DE76=
30, prev 1/32DE75F0, desc: CREATE_ID 79871 offset 218449 nmembers 2: 336089=
 (keysh)<br>336098 (keysh)<br>rmgr: Heap =C2=A0 =C2=A0 =C2=A0 =C2=A0len (re=
c/tot): =C2=A0 =C2=A0 54/ =C2=A0 =C2=A054, tx: =C2=A0 =C2=A0 336098, lsn: 1=
/32DE7668, prev 1/32DE7630, desc: LOCK xmax: 79871, off: 1, infobits: [IS_M=
ULTI, LOCK_ONLY,<br>KEYSHR_LOCK], flags: 0x00, blkref #0: rel 1663/16384/16=
418 blk 0<br>rmgr: Heap =C2=A0 =C2=A0 =C2=A0 =C2=A0len (rec/tot): =C2=A0 =
=C2=A0 72/ =C2=A0 =C2=A072, tx: =C2=A0 =C2=A0 336096, lsn: 1/32DE76A0, prev=
 1/32DE7668, desc: HOT_UPDATE old_xmax: 336096, old_off: 52, old_infobits: =
[],<br>flags: 0x20, new_xmax: 0, new_off: 149, blkref #0: rel 1663/16384/16=
401 blk 22<br>rmgr: Heap =C2=A0 =C2=A0 =C2=A0 =C2=A0len (rec/tot): =C2=A0 =
=C2=A0 71/ =C2=A0 =C2=A071, tx: =C2=A0 =C2=A0 336096, lsn: 1/32DE76E8, prev=
 1/32DE76A0, desc: HOT_UPDATE old_xmax: 336096, old_off: 149, old_infobits:=
 [],<br>flags: 0x60, new_xmax: 0, new_off: 209, blkref #0: rel 1663/16384/1=
6399 blk 6<br>rmgr: Heap =C2=A0 =C2=A0 =C2=A0 =C2=A0len (rec/tot): =C2=A0 =
=C2=A0 79/ =C2=A0 =C2=A079, tx: =C2=A0 =C2=A0 336096, lsn: 1/32DE7730, prev=
 1/32DE76E8, desc: INSERT off: 150, flags: 0x00, blkref #0: rel 1663/16384/=
16417<br>blk 741<br>rmgr: Heap =C2=A0 =C2=A0 =C2=A0 =C2=A0len (rec/tot): =
=C2=A0 =C2=A0 72/ =C2=A0 =C2=A072, tx: =C2=A0 =C2=A0 336097, lsn: 1/32DE778=
0, prev 1/32DE7730, desc: HOT_UPDATE old_xmax: 336097, old_off: 243, old_in=
fobits: [],<br>flags: 0x20, new_xmax: 0, new_off: 228, blkref #0: rel 1663/=
16384/16401 blk 26<br>rmgr: Transaction len (rec/tot): =C2=A0 =C2=A0 34/ =
=C2=A0 =C2=A034, tx: =C2=A0 =C2=A0 336096, lsn: 1/32DE77C8, prev 1/32DE7780=
, desc: COMMIT 2026-05-21 08:43:07.003572 UTC<br><br></div><div>Radim</div>=
<div><br></div><div class=3D"gmail_quote gmail_quote_container"><div dir=3D=
"ltr" class=3D"gmail_attr">On Thu, 21 May 2026 at 10:34, Radim Marek &lt;<a=
 href=3D"mailto:radim@boringsql.com">radim@boringsql.com</a>&gt; wrote:<br>=
</div><blockquote class=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;b=
order-left:1px solid rgb(204,204,204);padding-left:1ex"><div dir=3D"ltr"><d=
iv>Thank you for the follow-up. In mean-time I can confirm the commit=C2=A0=
77dff5d937b1 might be the source of the original reported issue.</div><div>=
<br></div><div>Unfortunately pinning version down to 16.12 only=C2=A0avoids=
 the MultiXactOffsetSLRU self-deadlock, but the standby then fails recovery=
 after 12+ hours.</div><div><br></div><div><div style=3D"font-family:monosp=
ace;white-space:pre-wrap">  FATAL:  could not access status of transaction =
24958976
  DETAIL:  Could not read from file &quot;pg_multixact/offsets/017C&quot; a=
t offset 221184: read too few bytes.
  CONTEXT:  WAL redo at 14770/873268E8 for MultiXact/CREATE_ID: 24958975 of=
fset 61500431 nmembers 2: 3058927188 (fornokeyupd) 3058927189 (keysh)</div>=
<div style=3D"font-family:monospace;white-space:pre-wrap"><br></div>We are =
going to try to pin 16.13 and try that before we can safely upgrade of the =
primary/are confident we have working PITR recovery available should we nee=
d it.</div><div><br></div><div>Radim</div><div><br></div><div>PS: Once I ha=
ve some time I will try to setup a docker based harness to be able to repli=
cate original problem for later testing of the fix.</div></div><br><div cla=
ss=3D"gmail_quote"><div dir=3D"ltr" class=3D"gmail_attr">On Thu, 21 May 202=
6 at 09:25, Andrey Borodin &lt;<a href=3D"mailto:x4mmm@yandex-team.ru" targ=
et=3D"_blank">x4mmm@yandex-team.ru</a>&gt; wrote:<br></div><blockquote clas=
s=3D"gmail_quote" style=3D"margin:0px 0px 0px 0.8ex;border-left:1px solid r=
gb(204,204,204);padding-left:1ex"><br>
<br>
&gt; On 21 May 2026, at 00:12, Marko Tiikkaja &lt;<a href=3D"mailto:marko@j=
oh.to" target=3D"_blank">marko@joh.to</a>&gt; wrote:<br>
&gt; <br>
&gt; #8=C2=A0 0x0000654c8ae2acba in SimpleLruWriteAll (ctl=3D0x654c8b63e400=
<br>
<br>
Thanks!<br>
<br>
This clearly points to SimpleLruWriteAll() added in 77dff5d937b1.<br>
If by chance you will have a backtrace of another deadlocking process -<br>
please post it.<br>
<br>
But it&#39;s not strictly necessary for analysis, I think we can figure out=
 what<br>
happened from the backtrace you already posted.<br>
<br>
<br>
Best regards, Andrey Borodin.<br>
</blockquote></div>
</blockquote></div></div>

--00000000000064d4980652503a71--