Обсуждение: BUG #19109: catalog lookup with the wrong snapshot during logical decoding causes coredump
BUG #19109: catalog lookup with the wrong snapshot during logical decoding causes coredump
От
PG Bug reporting form
Дата:
The following bug has been logged on the website:
Bug reference: 19109
Logged by: haiyang li
Email address: mohen.lhy@alibaba-inc.com
PostgreSQL version: 18.0
Operating system: any
Description:
Hi all,
I got some similar core-dump files when running logical decoding test in
PostgreSQL 14.19 (2
times in debug mode) and PostgreSQL 18.0(1 time in release mode). All the
provided information
is based on 14.19 due to more information about the core-dump.
The stack trace is as follows:
```
Program terminated with signal SIGSEGV, Segmentation fault.
...
#2 <signal handler called>
#3 0x00000000007f41c6 in nocachegetattr (tuple=0x6ddd578, attnum=3,
tupleDesc=0x7fb4586e8e48) at heaptuple.c:698
#4 0x00007fb4589d579d in tuple_to_stringinfo (s=0x2fb0bb0,
tupdesc=0x7fb4586e8e48, tuple=0x6ddd578, skip_nulls=false) at
test_decoding.c:560
#5 0x00007fb4589d5b2d in pg_decode_change (ctx=0x2fac888, txn=0x2fea668,
relation=0x7fb4586db898, change=0x7145cf8) at test_decoding.c:645
#6 0x0000000000e66be6 in change_cb_wrapper (cache=0x2fbc8f8, txn=0x2fea668,
relation=0x7fb4586db898, change=0x7145cf8) at logical.c:1076
#7 0x0000000000e72d2a in ReorderBufferApplyChange (rb=0x2fbc8f8,
txn=0x2fea668, relation=0x7fb4586db898, change=0x7145cf8, streaming=false)
at reorderbuffer.c:2020
#8 0x0000000000e73712 in ReorderBufferProcessTXN (rb=0x2fbc8f8,
txn=0x2fea668, commit_lsn=36675124736, snapshot_now=0x2fc4580, command_id=0,
streaming=false) at reorderbuffer.c:2319
#9 0x0000000000e743e8 in ReorderBufferReplay (txn=0x2fea668, rb=0x2fbc8f8,
xid=10798, commit_lsn=36675124736, end_lsn=36675124784,
commit_time=815706623738566, origin_id=0, origin_lsn=0) at
reorderbuffer.c:2773
#10 0x0000000000e74466 in ReorderBufferCommit (rb=0x2fbc8f8, xid=10798,
commit_lsn=36675124736, end_lsn=36675124784, commit_time=815706623738566,
origin_id=0, origin_lsn=0) at reorderbuffer.c:2797
#11 0x0000000000e614fb in DecodeCommit (ctx=0x2fac888, buf=0x7ffd647e7ea0,
parsed=0x7ffd647e7d40, xid=10798, two_phase=false) at decode.c:848
#12 0x0000000000e605b2 in DecodeXactOp (ctx=0x2fac888, buf=0x7ffd647e7ea0)
at decode.c:303
#13 0x0000000000e600d1 in LogicalDecodingProcessRecord (ctx=0x2fac888,
record=0x2facc48) at decode.c:144
#14 0x0000000000e69981 in pg_logical_slot_get_changes_guts
(fcinfo=0x2fa0808, confirm=true, binary=false) at logicalfuncs.c:296
#15 0x0000000000e69b88 in pg_logical_slot_get_changes (fcinfo=0x2fa0808) at
logicalfuncs.c:365
...
#35 0x0000000000f8df2b in exec_simple_query (query_string=0x2d732e8 "SELECT
* FROM pg_logical_slot_get_changes("test_logical_decode_slot_0", NULL, NULL,
"stream-changes", "on")") at postgres.c:1360
...
(gdb) f 3
#3 0x00000000007f41c6 in nocachegetattr (tuple=0x6ddd578, attnum=3,
tupleDesc=0x7fb4586e8e48) at heaptuple.c:698
698 off = att_align_pointer(off,
att->attalign, -1,
(gdb) p tupleDesc->attrs[0]
$3 = {attrelid = 35727, attname = {data = "id", '\000' <repeats 61 times>},
atttypid = 23, attstattarget = -1, attlen = 4, attnum = 1, attndims = 0,
attcacheoff = 0, atttypmod = -1, attbyval = true, attalign = 105 'i',
attstorage = 112 'p', attcompression = 0 '\000', attnotnull = true,
atthasdef = false,
atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
attisinvisible = false}
(gdb) p tupleDesc->attrs[1]
$4 = {attrelid = 35727, attname = {data = "unique1", '\000' <repeats 56
times>}, atttypid = 23, attstattarget = -1, attlen = 4, attnum = 2, attndims
= 0,
attcacheoff = 4, atttypmod = -1, attbyval = true, attalign = 105 'i',
attstorage = 112 'p', attcompression = 0 '\000', attnotnull = false,
atthasdef = false,
atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
attisinvisible = false}
(gdb) p tupleDesc->attrs[2]
$5 = {attrelid = 35727, attname = {data = "hundred", '\000' <repeats 56
times>}, atttypid = 1700, attstattarget = -1, attlen = -1, attnum = 3,
attndims = 0,
attcacheoff = 8, atttypmod = -1, attbyval = false, attalign = 105 'i',
attstorage = 120 'x', attcompression = 0 '\000', attnotnull = false,
atthasdef = false,
atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
attisinvisible = false}
(gdb) f 7
#7 0x0000000000e72d2a in ReorderBufferApplyChange (rb=0x2fbc8f8,
txn=0x2fea668, relation=0x7fb4586db898, change=0x7145cf8, streaming=false)
at reorderbuffer.c:2020
2020 rb->apply_change(rb, txn, relation, change);
(gdb) p change->lsn
$16 = 36675122736
(gdb) f 8
#8 0x0000000000e73712 in ReorderBufferProcessTXN (rb=0x2fbc8f8,
txn=0x2fea668, commit_lsn=36675124736, snapshot_now=0x2fc4580, command_id=0,
streaming=false)
at reorderbuffer.c:2319
2319
ReorderBufferApplyChange(rb, txn, relation, change,
(gdb) p *snapshot_now->xip@20
$17 = {10713, 10731, 10744, 10745, 10746, 10747, 10748, 10749, 10753, 10754,
10757, 10758, 10766, 10770, 10771, 10773, 10785, 10786, 10789, 10790}
(gdb) p *snapshot_now
$18 = {snapshot_type = SNAPSHOT_HISTORIC_MVCC, xmin = 10713, xmax = 10791,
xip = 0x2fc4658, xcnt = 20, subxip = 0x0, subxcnt = 0, suboverflowed =
false,
takenDuringRecovery = false, copied = false, curcid = 0, speculativeToken
= 0, vistest = 0x0, active_count = 5, regd_count = 0
...
```
After further investigation, I found that the immediate cause of the crash
was that the unique1
column is actually of type numeric (atttypid = 1700), but here it was
mistakenly treated as
int4 (atttypid = 23). This type mismatch led to a segmentation fault when
retrieving the data.
(After restoring from backup to the next LSN after txn 10798 commit
(8/8A01FE30), I was able to
confirm that the unique1 column is indeed of type numeric.)
logical slot information：
-[ RECORD 1 ]-------+---------------------------
slot_name | test_logical_decode_slot_0
plugin | test_decoding
slot_type | logical
datoid | 33795
database | ddl_full0
temporary | f
active | f
active_pid |
xmin |
catalog_xmin | 10713
restart_lsn | 8/3C425D18
confirmed_flush_lsn | 8/7B80FBA0
wal_status | extended
safe_wal_size |
two_phase | f
Between txn 10713 and 10798, txn 10716 and 10722 successfully executed the
column type change SQL:
ALTER TABLE IF EXISTS t1 ALTER COLUMN unique1 SET DATA TYPE NUMERIC;
Relevant WAL records:
```
-- 10716
rmgr: Standby len (rec/tot): 42/ 42, tx: 10716, lsn:
8/4259E558, prev 8/4259C6C0, desc: LOCK xid 10716 db 33795 rel 35727
rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
8/4259E588, prev 8/4259E558, desc: NEW_CID rel 1663/33795/1249; tid 84/1;
cmin: 4294967295, cmax: 0, combo: 4294967295
rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
8/4259E5C8, prev 8/4259E588, desc: NEW_CID rel 1663/33795/1249; tid 84/2;
cmin: 0, cmax: 4294967295, combo: 4294967295
rmgr: Heap len (rec/tot): 105/ 105, tx: 10716, lsn:
8/4259E608, prev 8/4259E5C8, desc: HOT_UPDATE off 1 xmax 10716 flags 0x60 ;
new off 2 xmax 0, blkref #0: rel 1663/33795/1249 blk 84
rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
8/4259E678, prev 8/4259E608, desc: NEW_CID rel 1663/33795/2619; tid 6/24;
cmin: 4294967295, cmax: 0, combo: 4294967295
rmgr: Heap len (rec/tot): 54/ 54, tx: 10716, lsn:
8/4259E6B8, prev 8/4259E678, desc: DELETE off 24 flags 0x00 KEYS_UPDATED ,
blkref #0: rel 1663/33795/2619 blk 6
...
rmgr: Transaction len (rec/tot): 4505/ 4505, tx: 10716, lsn:
8/4323DB78, prev 8/4323BCE0, desc: COMMIT 2025-11-06 01:10:08.196860 UTC;
rels: base/33795/1632572 base/33795/1632575 base/33795/1632576
base/33795/1632606 base/33795/1632604 base/33795/1632603 base/33795/1632602
base/33795/1632601; inval msgs: catcache 51 catcache 50 catcache 51 catcache
50 catcache 50 catcache 51 catcache 50 catcache 50 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 51 catcache
50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 51 catcache 50 catcache 32 catcache 7
catcache 6 catcache 7 catcache 6 catcache 51 catcache 50 catcache 76
catcache 75 catcache 76 catcache 75 catcache 51 catcache 50 catcache 51
catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
catcache 50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 32 catcache
51 catcache 50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 76 catcache
75 catcache 76 catcache 75 catcache 51 catcache 50 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 59 relcache
1640003 relcache 1640003 relcache 1640004 relcache 1640000 snapshot 2608
snapshot 1214 relcache 1632575 snapshot 2608 relcache 1632576 relcache
1632575 snapshot 2608 snapshot 2608 snapshot 2608 relcache 35727 relcache
1622119 relcache 1622119 relcache 35727 relcache 1606414 relcache 1606414
relcache 35727 relcache 1545373 relcache 1545373 relcache 35727 relcache
1537952 relcache 1537952 relcache 35727 relcache 35733 relcache 35733
relcache 35727 relcache 1640000 snapshot 2608 relcache 1640000 snapshot 2608
relcache 1640003 relcache 1640004 relcache 1640004 relcache 1640003 snapshot
2608 relcache 1640003 snapshot 2608 relcache 1640000 snapshot 1214 relcache
35727
-- 10722
rmgr: Standby len (rec/tot): 42/ 42, tx: 10722, lsn:
8/4946A640, prev 8/4946A468, desc: LOCK xid 10722 db 33795 rel 35727
rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10722, lsn:
8/4946A670, prev 8/4946A640, desc: NEW_CID rel 1663/33795/1249; tid 84/2;
cmin: 4294967295, cmax: 0, combo: 4294967295
rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10722, lsn:
8/4946A6B0, prev 8/4946A670, desc: NEW_CID rel 1663/33795/1249; tid 84/6;
cmin: 0, cmax: 4294967295, combo: 4294967295
rmgr: Heap len (rec/tot): 76/ 76, tx: 10722, lsn:
8/4946A6F0, prev 8/4946A6B0, desc: HOT_UPDATE off 2 xmax 10722 flags 0x20 ;
new off 6 xmax 0, blkref #0: rel 1663/33795/1249 blk 84
rmgr: Transaction len (rec/tot): 78/ 78, tx: 10722, lsn:
8/4946A740, prev 8/4946A6F0, desc: INVALIDATION ; inval msgs: catcache 7
catcache 6 relcache 35727
rmgr: Transaction len (rec/tot): 98/ 98, tx: 10722, lsn:
8/4946A790, prev 8/4946A740, desc: COMMIT 2025-11-06 01:10:09.687549 UTC;
inval msgs: catcache 7 catcache 6 relcache 35727
-- 10798
rmgr: Heap len (rec/tot): 1211/ 1211, tx: 10798, lsn:
8/8A01F630, prev 8/8A01F560, desc: INSERT off 11 flags 0x08, blkref #0: rel
1663/33795/1677447 blk 0
rmgr: Btree len (rec/tot): 64/ 64, tx: 10798, lsn:
8/8A01FAF0, prev 8/8A01F630, desc: INSERT_LEAF off 5, blkref #0: rel
1663/33795/1695353 blk 1
rmgr: Gin len (rec/tot): 174/ 174, tx: 10798, lsn:
8/8A01FB30, prev 8/8A01FAF0, desc: UPDATE_META_PAGE , blkref #0: rel
1663/33795/1695354 blk 0, blkref #1: rel 1663/33795/1695354 blk 2
rmgr: Btree len (rec/tot): 64/ 64, tx: 10798, lsn:
8/8A01FBE0, prev 8/8A01FB30, desc: INSERT_LEAF off 5, blkref #0: rel
1663/33795/1695355 blk 1
rmgr: Hash len (rec/tot): 72/ 72, tx: 10798, lsn:
8/8A01FC20, prev 8/8A01FBE0, desc: INSERT off 6, blkref #0: rel
1663/33795/1695356 blk 2, blkref #1: rel 1663/33795/1695356 blk 0
rmgr: Gist len (rec/tot): 322/ 322, tx: 10798, lsn:
8/8A01FC68, prev 8/8A01FC20, desc: PAGE_UPDATE , blkref #0: rel
1663/33795/1695357 blk 0
rmgr: Btree len (rec/tot): 80/ 80, tx: 10798, lsn:
8/8A01FDB0, prev 8/8A01FC68, desc: INSERT_LEAF off 3, blkref #0: rel
1663/33795/1695358 blk 2
rmgr: Transaction len (rec/tot): 46/ 46, tx: 10798, lsn:
8/8A01FE00, prev 8/8A01FDB0, desc: COMMIT 2025-11-06 01:10:23.738566 UTC
-- ALL RUNING_XACTS WAL RECORD
rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
8/3C425D18, prev 8/3C425CD8, desc: RUNNING_XACTS nextXid 10674
latestCompletedXid 10673 oldestRunningXid 10639; 2 xacts: 10639 10664
...
rmgr: Standby len (rec/tot): 62/ 62, tx: 0, lsn:
8/66737378, prev 8/66736B80, desc: RUNNING_XACTS nextXid 10742
latestCompletedXid 10741 oldestRunningXid 10713; 3 xacts: 10731 10713 10729
...
rmgr: Standby len (rec/tot): 66/ 66, tx: 0, lsn:
8/89C23500, prev 8/89C234A0, desc: RUNNING_XACTS nextXid 10798
latestCompletedXid 10797 oldestRunningXid 10767; 4 xacts: 10780 10769 10795
10767
```
From the snapshot_now information for txn 10798, txn 10716 and 10722 are not
present in xip,
which appears unexpected.
I have not yet figured out the root cause and will continue analyzing.
If you need the complete WAL log from 8/3C425D18 to 8/8A01FE30, please let
me know — I can provide it.
regards,
Haiyang Li
Hi Haiyang,
On Tue, Nov 11, 2025 at 12:53 AM PG Bug reporting form
<noreply@postgresql.org> wrote:
>
> The following bug has been logged on the website:
>
> Bug reference: 19109
> Logged by: haiyang li
> Email address: mohen.lhy@alibaba-inc.com
> PostgreSQL version: 18.0
> Operating system: any
> Description:
>
> Hi all,
> I got some similar core-dump files when running logical decoding test in
> PostgreSQL 14.19 (2
> times in debug mode) and PostgreSQL 18.0(1 time in release mode). All the
> provided information
> is based on 14.19 due to more information about the core-dump.
>
> The stack trace is as follows:
> ```
> Program terminated with signal SIGSEGV, Segmentation fault.
> ...
> #2 <signal handler called>
> #3 0x00000000007f41c6 in nocachegetattr (tuple=0x6ddd578, attnum=3,
> tupleDesc=0x7fb4586e8e48) at heaptuple.c:698
> #4 0x00007fb4589d579d in tuple_to_stringinfo (s=0x2fb0bb0,
> tupdesc=0x7fb4586e8e48, tuple=0x6ddd578, skip_nulls=false) at
> test_decoding.c:560
> #5 0x00007fb4589d5b2d in pg_decode_change (ctx=0x2fac888, txn=0x2fea668,
> relation=0x7fb4586db898, change=0x7145cf8) at test_decoding.c:645
> #6 0x0000000000e66be6 in change_cb_wrapper (cache=0x2fbc8f8, txn=0x2fea668,
> relation=0x7fb4586db898, change=0x7145cf8) at logical.c:1076
> #7 0x0000000000e72d2a in ReorderBufferApplyChange (rb=0x2fbc8f8,
> txn=0x2fea668, relation=0x7fb4586db898, change=0x7145cf8, streaming=false)
> at reorderbuffer.c:2020
> #8 0x0000000000e73712 in ReorderBufferProcessTXN (rb=0x2fbc8f8,
> txn=0x2fea668, commit_lsn=36675124736, snapshot_now=0x2fc4580, command_id=0,
> streaming=false) at reorderbuffer.c:2319
> #9 0x0000000000e743e8 in ReorderBufferReplay (txn=0x2fea668, rb=0x2fbc8f8,
> xid=10798, commit_lsn=36675124736, end_lsn=36675124784,
> commit_time=815706623738566, origin_id=0, origin_lsn=0) at
> reorderbuffer.c:2773
> #10 0x0000000000e74466 in ReorderBufferCommit (rb=0x2fbc8f8, xid=10798,
> commit_lsn=36675124736, end_lsn=36675124784, commit_time=815706623738566,
> origin_id=0, origin_lsn=0) at reorderbuffer.c:2797
> #11 0x0000000000e614fb in DecodeCommit (ctx=0x2fac888, buf=0x7ffd647e7ea0,
> parsed=0x7ffd647e7d40, xid=10798, two_phase=false) at decode.c:848
> #12 0x0000000000e605b2 in DecodeXactOp (ctx=0x2fac888, buf=0x7ffd647e7ea0)
> at decode.c:303
> #13 0x0000000000e600d1 in LogicalDecodingProcessRecord (ctx=0x2fac888,
> record=0x2facc48) at decode.c:144
> #14 0x0000000000e69981 in pg_logical_slot_get_changes_guts
> (fcinfo=0x2fa0808, confirm=true, binary=false) at logicalfuncs.c:296
> #15 0x0000000000e69b88 in pg_logical_slot_get_changes (fcinfo=0x2fa0808) at
> logicalfuncs.c:365
> ...
> #35 0x0000000000f8df2b in exec_simple_query (query_string=0x2d732e8 "SELECT
> * FROM pg_logical_slot_get_changes("test_logical_decode_slot_0", NULL, NULL,
> "stream-changes", "on")") at postgres.c:1360
> ...
>
> (gdb) f 3
> #3 0x00000000007f41c6 in nocachegetattr (tuple=0x6ddd578, attnum=3,
> tupleDesc=0x7fb4586e8e48) at heaptuple.c:698
> 698 off = att_align_pointer(off,
> att->attalign, -1,
> (gdb) p tupleDesc->attrs[0]
> $3 = {attrelid = 35727, attname = {data = "id", '\000' <repeats 61 times>},
> atttypid = 23, attstattarget = -1, attlen = 4, attnum = 1, attndims = 0,
> attcacheoff = 0, atttypmod = -1, attbyval = true, attalign = 105 'i',
> attstorage = 112 'p', attcompression = 0 '\000', attnotnull = true,
> atthasdef = false,
> atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
> attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
> attisinvisible = false}
> (gdb) p tupleDesc->attrs[1]
> $4 = {attrelid = 35727, attname = {data = "unique1", '\000' <repeats 56
> times>}, atttypid = 23, attstattarget = -1, attlen = 4, attnum = 2, attndims
> = 0,
> attcacheoff = 4, atttypmod = -1, attbyval = true, attalign = 105 'i',
> attstorage = 112 'p', attcompression = 0 '\000', attnotnull = false,
> atthasdef = false,
> atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
> attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
> attisinvisible = false}
> (gdb) p tupleDesc->attrs[2]
> $5 = {attrelid = 35727, attname = {data = "hundred", '\000' <repeats 56
> times>}, atttypid = 1700, attstattarget = -1, attlen = -1, attnum = 3,
> attndims = 0,
> attcacheoff = 8, atttypmod = -1, attbyval = false, attalign = 105 'i',
> attstorage = 120 'x', attcompression = 0 '\000', attnotnull = false,
> atthasdef = false,
> atthasmissing = false, attidentity = 0 '\000', attgenerated = 0 '\000',
> attisdropped = false, attislocal = true, attinhcount = 0, attcollation = 0,
> attisinvisible = false}
>
> (gdb) f 7
> #7 0x0000000000e72d2a in ReorderBufferApplyChange (rb=0x2fbc8f8,
> txn=0x2fea668, relation=0x7fb4586db898, change=0x7145cf8, streaming=false)
> at reorderbuffer.c:2020
> 2020 rb->apply_change(rb, txn, relation, change);
> (gdb) p change->lsn
> $16 = 36675122736
>
> (gdb) f 8
> #8 0x0000000000e73712 in ReorderBufferProcessTXN (rb=0x2fbc8f8,
> txn=0x2fea668, commit_lsn=36675124736, snapshot_now=0x2fc4580, command_id=0,
> streaming=false)
> at reorderbuffer.c:2319
> 2319
> ReorderBufferApplyChange(rb, txn, relation, change,
> (gdb) p *snapshot_now->xip@20
> $17 = {10713, 10731, 10744, 10745, 10746, 10747, 10748, 10749, 10753, 10754,
> 10757, 10758, 10766, 10770, 10771, 10773, 10785, 10786, 10789, 10790}
> (gdb) p *snapshot_now
> $18 = {snapshot_type = SNAPSHOT_HISTORIC_MVCC, xmin = 10713, xmax = 10791,
> xip = 0x2fc4658, xcnt = 20, subxip = 0x0, subxcnt = 0, suboverflowed =
> false,
> takenDuringRecovery = false, copied = false, curcid = 0, speculativeToken
> = 0, vistest = 0x0, active_count = 5, regd_count = 0
> ...
> ```
>
> After further investigation, I found that the immediate cause of the crash
> was that the unique1
> column is actually of type numeric (atttypid = 1700), but here it was
> mistakenly treated as
> int4 (atttypid = 23). This type mismatch led to a segmentation fault when
> retrieving the data.
> (After restoring from backup to the next LSN after txn 10798 commit
> (8/8A01FE30), I was able to
> confirm that the unique1 column is indeed of type numeric.)
>
> logical slot information：
> -[ RECORD 1 ]-------+---------------------------
> slot_name | test_logical_decode_slot_0
> plugin | test_decoding
> slot_type | logical
> datoid | 33795
> database | ddl_full0
> temporary | f
> active | f
> active_pid |
> xmin |
> catalog_xmin | 10713
> restart_lsn | 8/3C425D18
> confirmed_flush_lsn | 8/7B80FBA0
> wal_status | extended
> safe_wal_size |
> two_phase | f
>
> Between txn 10713 and 10798, txn 10716 and 10722 successfully executed the
> column type change SQL:
> ALTER TABLE IF EXISTS t1 ALTER COLUMN unique1 SET DATA TYPE NUMERIC;
>
> Relevant WAL records:
> ```
> -- 10716
> rmgr: Standby len (rec/tot): 42/ 42, tx: 10716, lsn:
> 8/4259E558, prev 8/4259C6C0, desc: LOCK xid 10716 db 33795 rel 35727
> rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
> 8/4259E588, prev 8/4259E558, desc: NEW_CID rel 1663/33795/1249; tid 84/1;
> cmin: 4294967295, cmax: 0, combo: 4294967295
> rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
> 8/4259E5C8, prev 8/4259E588, desc: NEW_CID rel 1663/33795/1249; tid 84/2;
> cmin: 0, cmax: 4294967295, combo: 4294967295
> rmgr: Heap len (rec/tot): 105/ 105, tx: 10716, lsn:
> 8/4259E608, prev 8/4259E5C8, desc: HOT_UPDATE off 1 xmax 10716 flags 0x60 ;
> new off 2 xmax 0, blkref #0: rel 1663/33795/1249 blk 84
> rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10716, lsn:
> 8/4259E678, prev 8/4259E608, desc: NEW_CID rel 1663/33795/2619; tid 6/24;
> cmin: 4294967295, cmax: 0, combo: 4294967295
> rmgr: Heap len (rec/tot): 54/ 54, tx: 10716, lsn:
> 8/4259E6B8, prev 8/4259E678, desc: DELETE off 24 flags 0x00 KEYS_UPDATED ,
> blkref #0: rel 1663/33795/2619 blk 6
> ...
> rmgr: Transaction len (rec/tot): 4505/ 4505, tx: 10716, lsn:
> 8/4323DB78, prev 8/4323BCE0, desc: COMMIT 2025-11-06 01:10:08.196860 UTC;
> rels: base/33795/1632572 base/33795/1632575 base/33795/1632576
> base/33795/1632606 base/33795/1632604 base/33795/1632603 base/33795/1632602
> base/33795/1632601; inval msgs: catcache 51 catcache 50 catcache 51 catcache
> 50 catcache 50 catcache 51 catcache 50 catcache 50 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 51 catcache
> 50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 51 catcache 50 catcache 32 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 51 catcache 50 catcache 76
> catcache 75 catcache 76 catcache 75 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 51 catcache 50 catcache 51 catcache 50 catcache 51
> catcache 50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 32 catcache
> 51 catcache 50 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 76 catcache
> 75 catcache 76 catcache 75 catcache 51 catcache 50 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6
> catcache 7 catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 7
> catcache 6 catcache 7 catcache 6 catcache 7 catcache 6 catcache 59 relcache
> 1640003 relcache 1640003 relcache 1640004 relcache 1640000 snapshot 2608
> snapshot 1214 relcache 1632575 snapshot 2608 relcache 1632576 relcache
> 1632575 snapshot 2608 snapshot 2608 snapshot 2608 relcache 35727 relcache
> 1622119 relcache 1622119 relcache 35727 relcache 1606414 relcache 1606414
> relcache 35727 relcache 1545373 relcache 1545373 relcache 35727 relcache
> 1537952 relcache 1537952 relcache 35727 relcache 35733 relcache 35733
> relcache 35727 relcache 1640000 snapshot 2608 relcache 1640000 snapshot 2608
> relcache 1640003 relcache 1640004 relcache 1640004 relcache 1640003 snapshot
> 2608 relcache 1640003 snapshot 2608 relcache 1640000 snapshot 1214 relcache
> 35727
>
> -- 10722
> rmgr: Standby len (rec/tot): 42/ 42, tx: 10722, lsn:
> 8/4946A640, prev 8/4946A468, desc: LOCK xid 10722 db 33795 rel 35727
> rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10722, lsn:
> 8/4946A670, prev 8/4946A640, desc: NEW_CID rel 1663/33795/1249; tid 84/2;
> cmin: 4294967295, cmax: 0, combo: 4294967295
> rmgr: Heap2 len (rec/tot): 60/ 60, tx: 10722, lsn:
> 8/4946A6B0, prev 8/4946A670, desc: NEW_CID rel 1663/33795/1249; tid 84/6;
> cmin: 0, cmax: 4294967295, combo: 4294967295
> rmgr: Heap len (rec/tot): 76/ 76, tx: 10722, lsn:
> 8/4946A6F0, prev 8/4946A6B0, desc: HOT_UPDATE off 2 xmax 10722 flags 0x20 ;
> new off 6 xmax 0, blkref #0: rel 1663/33795/1249 blk 84
> rmgr: Transaction len (rec/tot): 78/ 78, tx: 10722, lsn:
> 8/4946A740, prev 8/4946A6F0, desc: INVALIDATION ; inval msgs: catcache 7
> catcache 6 relcache 35727
> rmgr: Transaction len (rec/tot): 98/ 98, tx: 10722, lsn:
> 8/4946A790, prev 8/4946A740, desc: COMMIT 2025-11-06 01:10:09.687549 UTC;
> inval msgs: catcache 7 catcache 6 relcache 35727
>
> -- 10798
> rmgr: Heap len (rec/tot): 1211/ 1211, tx: 10798, lsn:
> 8/8A01F630, prev 8/8A01F560, desc: INSERT off 11 flags 0x08, blkref #0: rel
> 1663/33795/1677447 blk 0
> rmgr: Btree len (rec/tot): 64/ 64, tx: 10798, lsn:
> 8/8A01FAF0, prev 8/8A01F630, desc: INSERT_LEAF off 5, blkref #0: rel
> 1663/33795/1695353 blk 1
> rmgr: Gin len (rec/tot): 174/ 174, tx: 10798, lsn:
> 8/8A01FB30, prev 8/8A01FAF0, desc: UPDATE_META_PAGE , blkref #0: rel
> 1663/33795/1695354 blk 0, blkref #1: rel 1663/33795/1695354 blk 2
> rmgr: Btree len (rec/tot): 64/ 64, tx: 10798, lsn:
> 8/8A01FBE0, prev 8/8A01FB30, desc: INSERT_LEAF off 5, blkref #0: rel
> 1663/33795/1695355 blk 1
> rmgr: Hash len (rec/tot): 72/ 72, tx: 10798, lsn:
> 8/8A01FC20, prev 8/8A01FBE0, desc: INSERT off 6, blkref #0: rel
> 1663/33795/1695356 blk 2, blkref #1: rel 1663/33795/1695356 blk 0
> rmgr: Gist len (rec/tot): 322/ 322, tx: 10798, lsn:
> 8/8A01FC68, prev 8/8A01FC20, desc: PAGE_UPDATE , blkref #0: rel
> 1663/33795/1695357 blk 0
> rmgr: Btree len (rec/tot): 80/ 80, tx: 10798, lsn:
> 8/8A01FDB0, prev 8/8A01FC68, desc: INSERT_LEAF off 3, blkref #0: rel
> 1663/33795/1695358 blk 2
> rmgr: Transaction len (rec/tot): 46/ 46, tx: 10798, lsn:
> 8/8A01FE00, prev 8/8A01FDB0, desc: COMMIT 2025-11-06 01:10:23.738566 UTC
>
> -- ALL RUNING_XACTS WAL RECORD
> rmgr: Standby len (rec/tot): 58/ 58, tx: 0, lsn:
> 8/3C425D18, prev 8/3C425CD8, desc: RUNNING_XACTS nextXid 10674
> latestCompletedXid 10673 oldestRunningXid 10639; 2 xacts: 10639 10664
> ...
> rmgr: Standby len (rec/tot): 62/ 62, tx: 0, lsn:
> 8/66737378, prev 8/66736B80, desc: RUNNING_XACTS nextXid 10742
> latestCompletedXid 10741 oldestRunningXid 10713; 3 xacts: 10731 10713 10729
> ...
> rmgr: Standby len (rec/tot): 66/ 66, tx: 0, lsn:
> 8/89C23500, prev 8/89C234A0, desc: RUNNING_XACTS nextXid 10798
> latestCompletedXid 10797 oldestRunningXid 10767; 4 xacts: 10780 10769 10795
> 10767
> ```
>
> From the snapshot_now information for txn 10798, txn 10716 and 10722 are not
> present in xip,
> which appears unexpected.
Thanks for your report and analysis!
> I have not yet figured out the root cause and will continue analyzing.
> If you need the complete WAL log from 8/3C425D18 to 8/8A01FE30, please let
> me know — I can provide it.
That would be helpful. Could you also share the test or script that
reproduces the core dump?
Hi Xuneng,
Xuneng Zhou <xunengzhou@gmail.com> 2025-11-11 09:12 write:
>> I have not yet figured out the root cause and will continue analyzing.
>> If you need the complete WAL log from 8/3C425D18 to 8/8A01FE30, please let
>> me know — I can provide it.
>
> That would be helpful. Could you also share the test or script that
> reproduces the core dump?
>> If you need the complete WAL log from 8/3C425D18 to 8/8A01FE30, please let
>> me know — I can provide it.
>
> That would be helpful. Could you also share the test or script that
> reproduces the core dump?
>
The WAL are provided in attachment. Unfortunately, I can not share the script.
The testing scenario is rather complex, and the executed SQL statements can
only be tracked via the logs. At this point, I have not been able to obtain a
reproducible case, which is the challenging part. However, I can provide the
actions carried out by a specific transaction if you need.
Re: BUG #19109: catalog lookup with the wrong snapshot during logical decoding causes coredump
От
Michael Paquier
Дата:
On Tue, Nov 11, 2025 at 09:42:29AM +0800, Haiyang Li wrote: > The WAL are provided in attachment. Unfortunately, I can not share the script. > The testing scenario is rather complex, and the executed SQL statements can > only be tracked via the logs. At this point, I have not been able to obtain a > reproducible case, which is the challenging part. However, I can provide the > actions carried out by a specific transaction if you need. That's unfortunate. Having a reproducible test case that works with upstream would speed up the analysis of the problem a lot. -- Michael
Вложения
From:Michael Paquier <michael@paquier.xyz> 2025-11-11日 10:12 wrote:
> That's unfortunate. Having a reproducible test case that works with
> upstream would speed up the analysis of the problem a lot.
Indeed. I can reproduce the core in original instance by using pg_logical_slot_peek_changes
fucntion. But I can’t reproduce in other new instances. I will try to reproduce this issue again later.
While debugging the original instance using gdb, I found that txn 10722 was skipped due to
SnapBuildCurrentState(builder) < SNAPBUILD_FULL_SNAPSHOT, causing the catalog snapshot
to miss its commit. This suggests that the root cause may be in the new transaction handling
logic during snapshot building.
Regards,
Haiyang Li
Haiyang Li <mohen.lhy@alibaba-inc.com> 2025-11-11日 10:46 I wrote:
> From:Michael Paquier <michael@paquier.xyz> 2025-11-11日 10:12 wrote:
>
>> That's unfortunate. Having a reproducible test case that works with
>> upstream would speed up the analysis of the problem a lot.
>
>> That's unfortunate. Having a reproducible test case that works with
>> upstream would speed up the analysis of the problem a lot.
>
>
> Indeed. I can reproduce the core in original instance by using pg_logical_slot_peek_changes
> fucntion. But I can’t reproduce in other new instances. I will try to reproduce this issue again later.
I can’t reproduce the core yet. But I think the fowllowing script can make the similar scene. The
differentnce is we will get a “could not map filenumber xxx ” ERROR finally.
Script：
```
-- Please extend the checkpoint and background writer intervals to avoid additional RUNNING_XACT WAL
-- being generated during testing. I have done this by modifying the LOG_SNAPSHOT_INTERVAL_MS
-- and CheckPointTimeout GUC settings.
-- s1(session 1)
CREATE TABLE t1 (
id integer NOT NULL,
unique1 integer,
hundred numeric,
tenthous numeric)
WITH (toast_tuple_target='128');
ALTER TABLE ONLY t1 ALTER COLUMN hundred SET STORAGE EXTENDED;
ALTER TABLE ONLY t1 REPLICA IDENTITY FULL;
CREATE TABLE t2 (
id integer NOT NULL,
unique1 integer,
hundred numeric,
tenthous numeric)
WITH (toast_tuple_target='128');
ALTER TABLE ONLY t2 ALTER COLUMN hundred SET STORAGE EXTENDED;
ALTER TABLE ONLY t2 REPLICA IDENTITY FULL;
select pg_create_logical_replication_slot('test', 'test_decoding’);
begin;
insert into t1 values (1,1,1,1);
select pg_log_standby_snapshot();
commit;
begin;
insert into t2 values (1,1,1,1);
-- s2
ALTER TABLE IF EXISTS t1 ALTER COLUMN unique1 SET DATA TYPE NUMERIC;
-- s1
select pg_log_standby_snapshot();
commit;
select pg_logical_slot_get_changes('test', NULL, NULL);
begin;
insert into t1 values (1,1,1,1);
select pg_log_standby_snapshot();
commit;
\q
-- remove saved snapshot
rm -rf {data_directory}/pg_logical/snapshots/*.snap
-- s1
-- error
select pg_logical_slot_peek_changes('test', NULL, NULL);```
>
> While debugging the original instance using gdb, I found that txn 10722 was skipped due to
> SnapBuildCurrentState(builder) < SNAPBUILD_FULL_SNAPSHOT, causing the catalog snapshot
> to miss its commit. This suggests that the root cause may be in the new transaction handling
> logic during snapshot building.
>
The key point is saved useful snapshot files are removed (It does not occur during normal running,
But we did this in our testing). It resulted in a case where logical decoding was running with a
confirmed_flush_lsn that was lower than the LSN at which builder->state reached the
SNAPBUILD_CONSISTENT state. Then, decoding will generate an incorrect catalog snapshot,
which can lead to a variety of unintended consequences — including core dumps, errors, data loss,
or, in some cases, no visible effect at all.
I agree that removing valid snapshot files is not a sensible approach. However, if this condition can
be detected and reported with a clear and consistent error message, rather than allowing undefined
or unexpected behavior, it would provide a much better and more user‑friendly experience.
----------
Regards,
Haiyang Li
Hi all,
After further analysis, I think that if the slot's confirm_lsn is less than the LSN where
the consistent snapshot is built, the result should only be potential data loss, and should
not cause unexpected core dumps or errors.
From my investigation, the root cause seems to be that transactions committed after we reach
the consistent snapshot are using a wrong catalog snapshot.
Although I reproduced the issue manually by deleting the .snap file, I believe the same problem
could occur in a failover slot scenario, where a hot standby might encounter a similar situation.
Modified reproduction steps:
```
-- Please extend the checkpoint and background writer intervals to avoid additional RUNNING_XACT WAL
-- being generated during testing. I have done this by modifying the LOG_SNAPSHOT_INTERVAL_MS
-- and CheckPointTimeout GUC settings.
-- s1(session 1)
CREATE TABLE t1 (
id integer NOT NULL,
unique1 integer,
hundred numeric,
tenthous numeric)
WITH (toast_tuple_target='128');
ALTER TABLE ONLY t1 ALTER COLUMN hundred SET STORAGE EXTENDED;
ALTER TABLE ONLY t1 REPLICA IDENTITY FULL;
CREATE TABLE t2 (
id integer NOT NULL,
unique1 integer,
hundred numeric,
tenthous numeric)
WITH (toast_tuple_target='128');
ALTER TABLE ONLY t2 ALTER COLUMN hundred SET STORAGE EXTENDED;
ALTER TABLE ONLY t2 REPLICA IDENTITY FULL;
select pg_create_logical_replication_slot('test', 'test_decoding');
begin;
insert into t1 values (1,1,1,1);
select pg_log_standby_snapshot();
commit;
begin;
insert into t2 values (1,1,1,1);
-- s2
ALTER TABLE IF EXISTS t1 ALTER COLUMN unique1 SET DATA TYPE NUMERIC;
-- s1
select pg_log_standby_snapshot();
commit;
select pg_logical_slot_get_changes('test', NULL, NULL);
begin;
insert into t2 values (1,1,1,1);
select pg_log_standby_snapshot();
commit;
--s2
insert into t1 values (1,1,1,1);
\q
-- remove saved snapshot
rm -rf {data_directory}/pg_logical/snapshots/*.snap
-- s1
-- error
select pg_logical_slot_peek_changes('test', NULL, NULL);
```
Analysis:
```
WAL logs obtained:
-- RUNNING_XACTS
rmgr: Standby len (rec/tot): 54/ 54, tx: 827, lsn: 0/40C9A418, prev 0/40C9A3C8, desc: RUNNING_XACTS nextXid 828 latestCompletedXid 826 oldestRunningXid 827; 1 xacts: 827
rmgr: Standby len (rec/tot): 54/ 54, tx: 828, lsn: 0/40CA0910, prev 0/40C9FEF0, desc: RUNNING_XACTS nextXid 830 latestCompletedXid 829 oldestRunningXid 828; 1 xacts: 828
rmgr: Standby len (rec/tot): 54/ 54, tx: 830, lsn: 0/40CA09C8, prev 0/40CA0978, desc: RUNNING_XACTS nextXid 831 latestCompletedXid 829 oldestRunningXid 830; 1 xacts: 830
-- error xid WAL
rmgr: Heap len (rec/tot): 74/ 74, tx: 831, lsn: 0/40CA0A30, prev 0/40CA0A00, desc: INSERT off: 2, flags: 0x08, blkref #0: rel 1663/5/16484 blk 0
rmgr: Transaction len (rec/tot): 46/ 46, tx: 831, lsn: 0/40CA0A80, prev 0/40CA0A30, desc: COMMIT 2025-11-16 17:15:31.778871 UTC
When parsing the xid 831 commit record, changes are replayed. At this point, the transaction's snapshot_now is:
$1 = {snapshot_type = SNAPSHOT_HISTORIC_MVCC, xmin = 828, xmax = 828, xip = 0x29631e8, xcnt = 0, subxip = 0x0, subxcnt = 0, suboverflowed = false,
takenDuringRecovery = false, copied = false, curcid = 0, speculativeToken = 0, vistest = 0x0, active_count = 2, regd_count = 0, ph_node = {first_child = 0x0,
next_sibling = 0x0, prev_or_parent = 0x0}, whenTaken = 0, lsn = 0, snapXactCompletionCount = 0, polar_snapshot_csn = 0, polar_csn_xid_snapshot = false}
```
We can see that snapshot_now has xmin = 828 and contains no committed transactions,
so xid 829 is considered invisible, which triggers an error. However, after the snapshot builder
reaches the consistent state, builder->xmin = 830, and xid 829 is already known to be committed.
The root cause is that after the snapshot builder reaches the consistent state, it does not refresh
builder->snapshot, which may leads to subsequent transactions obtaining an incorrect catalog snapshot.
Possible fix suggestion:
When the snapshot builder reaches the consistent state, rebuild builder->snapshot and propagate
the updated snapshot to the transactions in the reorder buffer.
Looking forward to your review and feedback.
--
regards,
Haiyang Li
Hi, all!
I reported this bug before, and there is a commitfest entry for it:
https://commitfest.postgresql.org/patch/5029/
The attached patches are the latest patches taken from the commitfest.
They seem to need a rebase, but I'd like to see your thoughts on these patches first.
This bug seem to affect a lot of PG major versions.
--
Regards,
ChangAo Chen
Вложения
Hi ChangAo,
At 2025-11-19 11:23:19, "cca5507" <cca5507@qq.com> wrote:
> I reported this bug before, and there is a commitfest entry for it:
>
>
> The attached patches are the latest patches taken from the commitfest.
Thanks for your report and patches.
> This bug seem to affect a lot of PG major versions.
Absolutely. I can reproduced it from 11 to 19. Then, I researched the source code. IMUC, this bug exists since
logical replication intrduced(v9.4). It seems that snapshot builder does nothing except update builder->xmin in
SNAPBUILD_BUILDING_SNAPSHOT state. But, tracking xid which >= builder->next_pahse_at is reasonable
for me. BTW, this bug can result in unpredictable behavior, ranging from various error reports to core dumps.
It deserves some extra attention, I think.
It’s somewhat unfortunate that the issue remains unresolved so far. Hopefully we can address it in the
upcoming discussion or commitfest.
> They seem to need a rebase, but I'd like to see your thoughts on these patches first.
Some comments:
1 ====
@@ -1301,6 +1338,7 @@ DecodeTXNNeedSkip(LogicalDecodingContext *ctx, XLogRecordBuffer *buf,
Oid txn_dbid, RepOriginId origin_id)
{
if (SnapBuildXactNeedsSkip(ctx->snapshot_builder, buf->origptr) ||
+ SnapBuildCurrentState(ctx->snapshot_builder) < SNAPBUILD_CONSISTENT ||
(txn_dbid != InvalidOid && txn_dbid != ctx->slot->data.database) ||
FilterByOrigin(ctx, origin_id))
return true;
It seems that this change will cause unexpected bahavior. For expample, it will make the xact commited in SNAPBUILD_FULL_SNAPSHOT
to be skipped in DecodeCommit(). Do you mean "SnapBuildCurrentState(ctx->snapshot_builder) < SNAPBUILD_FULL_SNAPSHOT"?
2 ===
@@ -282,9 +287,11 @@ xact_decode(LogicalDecodingContext *ctx, XLogRecordBuffer *buf)
{
TransactionId xid;
xl_xact_invals *invals;
+ bool has_snapshot;
...
+ else if (!ctx->fast_forward && has_snapshot)
ReorderBufferImmediateInvalidation(ctx->reorder,
invals->nmsgs,
invals->msgs);
May be the following change is more clear for me:
if (TransactionIdIsValid(xid) &&
SnapBuildCurrentState(builder) >= SNAPBUILD_FULL_SNAPSHOT)
{
ReorderBufferXidSetCatalogChanges(ctx->reorder, xid,
buf->origptr);
break;
}
3===
@@ -416,7 +423,22 @@ heap2_decode(LogicalDecodingContext *ctx, XLogRecordBuffer *buf)
*/
if (SnapBuildCurrentState(builder) < SNAPBUILD_FULL_SNAPSHOT ||
ctx->fast_forward)
+ {
+ /*
+ * Note that during or after BUILDING_SNAPSHOT, we need handle the xlog
+ * that might mark a transaction as catalog modifying because the snapshot
+ * only tracks catalog modifying transactions. The transaction before
+ * BUILDING_SNAPSHOT will not be tracked anyway(see SnapBuildCommitTxn()
+ * for details), so just return.
+ */
+ if (SnapBuildCurrentState(builder) >= SNAPBUILD_BUILDING_SNAPSHOT)
+ {
+ /* Currently only XLOG_HEAP2_NEW_CID means a catalog modifying */
+ if (info == XLOG_HEAP2_NEW_CID && TransactionIdIsValid(xid))
+ ReorderBufferXidSetCatalogChanges(ctx->reorder, xid, buf->origptr);
+ }
return;
+ }
It should be removed from v18 and master because commit 243e9b4 intrduced.
4===
IMUC, v4-0001 patch is to only mark transactions with catalog changes during the buildsnapshot phase,
without performing any other actions. I’m wondering if we should make the behavior of snapshot building
the same in both SNAPBUILD_BUILDING_SNAPSHOT and SNAPBUILD_FULL_SNAPSHOT states,
except in cases where a base snapshot is needed. If so, the attached patch is for the master version.
Regards,
Haiyang Li
Вложения
Hi Haiyang,
1 ====@@ -1301,6 +1338,7 @@ DecodeTXNNeedSkip(LogicalDecodingContext *ctx, XLogRecordBuffer *buf,Oid txn_dbid, RepOriginId origin_id){if (SnapBuildXactNeedsSkip(ctx->snapshot_builder, buf->origptr) ||+ SnapBuildCurrentState(ctx->snapshot_builder) < SNAPBUILD_CONSISTENT ||(txn_dbid != InvalidOid && txn_dbid != ctx->slot->data.database) ||FilterByOrigin(ctx, origin_id))return true;It seems that this change will cause unexpected bahavior. For expample, it will make the xact commited in SNAPBUILD_FULL_SNAPSHOTto be skipped in DecodeCommit(). Do you mean "SnapBuildCurrentState(ctx->snapshot_builder) < SNAPBUILD_FULL_SNAPSHOT"?
I think it's correct. Note that we only decode txns commited after SNAPBUILD_CONSISTENT, txns commited before SNAPBUILD_CONSISTENT will not be decoded even if they start after SNAPBUILD_FULL_SNAPSHOT. I add this for safe because we now need handle xlog records in xact_decode() when building snapshot, but we didn't handle them before. We should make sure that processing those xlog records has no side effects.
3===@@ -416,7 +423,22 @@ heap2_decode(LogicalDecodingContext *ctx, XLogRecordBuffer *buf)*/if (SnapBuildCurrentState(builder) < SNAPBUILD_FULL_SNAPSHOT ||ctx->fast_forward)+ {+ /*+ * Note that during or after BUILDING_SNAPSHOT, we need handle the xlog+ * that might mark a transaction as catalog modifying because the snapshot+ * only tracks catalog modifying transactions. The transaction before+ * BUILDING_SNAPSHOT will not be tracked anyway(see SnapBuildCommitTxn()+ * for details), so just return.+ */+ if (SnapBuildCurrentState(builder) >= SNAPBUILD_BUILDING_SNAPSHOT)+ {+ /* Currently only XLOG_HEAP2_NEW_CID means a catalog modifying */+ if (info == XLOG_HEAP2_NEW_CID && TransactionIdIsValid(xid))+ ReorderBufferXidSetCatalogChanges(ctx->reorder, xid, buf->origptr);+ }return;+ }It should be removed from v18 and master because commit 243e9b4 intrduced.
Agreed. (But it seems to come from an outdated patch (before v4-0001))
4===IMUC, v4-0001 patch is to only mark transactions with catalog changes during the buildsnapshot phase,without performing any other actions. I’m wondering if we should make the behavior of snapshot buildingthe same in both SNAPBUILD_BUILDING_SNAPSHOT and SNAPBUILD_FULL_SNAPSHOT states,except in cases where a base snapshot is needed. If so, the attached patch is for the master version.
My thought is marking transactions with catalog changes and call DecodeCommit() to build the snapshot correctly when we are in SNAPBUILD_BUILDING_SNAPSHOT.
The v5-0001 seems to based on an outdated master.
--
Regards,
ChangAo Chen
Hi,
I attach the rebased patches in this:
https://www.postgresql.org/message-id/tencent_21E152AD504A814C071EDF41A4DD7BA84D06%40qq.com
--
Regards,
ChangAo Chen