From: ocean_li_996 <ocean_li_996@163.com>
To: Hayato Kuroda (Fujitsu) <kuroda.hayato@fujitsu.com>
Cc: 'Alexander Lakhin' <exclusion@gmail.com>
Cc: pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>
Cc: feichanghong@qq.com <feichanghong@qq.com>
Cc: amit.kapila16@gmail.com
Subject: Re:RE: Re:RE: Re:BUG #18369: logical decoding core on AssertTXNLsnOrder()
Date: Tue, 12 Mar 2024 00:43:01 +0800 (CST)
Message-ID: <5f2487c9.13435.18e2e656942.Coremail.ocean_li_996@163.com> (raw)
In-Reply-To: <TYCPR01MB1207717063D701F597EF98A0CF5272@TYCPR01MB12077.jpnprd01.prod.outlook.com>
References: <18369-ad61699bf91c5bc0@postgresql.org>
<6d0e80d6.c1fc.18deeb8120a.Coremail.ocean_li_996@163.com>
<TYCPR01MB120776F4E85D6066B2FE096C2F5222@TYCPR01MB12077.jpnprd01.prod.outlook.com>
<45809022.60b5.18e11d304cf.Coremail.ocean_li_996@163.com>
<TYCPR01MB12077C2C32B36E311480DBA92F5202@TYCPR01MB12077.jpnprd01.prod.outlook.com>
<TYCPR01MB1207717063D701F597EF98A0CF5272@TYCPR01MB12077.jpnprd01.prod.outlook.com>
Dear Hayato:
At 2024-03-08 15:35:16, "Hayato Kuroda (Fujitsu)" <kuroda.hayato@fujitsu.com> wrote:
>Dear Haiyang, Alexander,
>
>Below part describes the second failure. The issue would be occurred when:
>
>1) Logical decoding starts from the middle of a sub-transaction, and
>2) NEW_CID record is initially decoded in the sub-transaction, and
>3) An arbitrary changes are decoded in the sub-transaction.
>...
## Issue 1
Thanks for your reproducer. I have investigated this issue. The scenario that caused the issue
is indeed as you described above. I had not realized before that a serialized snapshot file from
one replication slot could be utilized by another replication slot to achieve a consistent state.
This issue would not arise with only one replication slot, as SnapBuildXactNeedsSkip ensures that.
Using the spec test case you provided (without any fix patch), I got another Stuck trace on REL_14_STABLE :
```
#0 0x00007f93604e0277 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:55
#1 0x00007f93604e1968 in __GI_abort () at abort.c:90
#2 0x0000000000b084da in ExceptionalCondition (conditionName=0xcc94c8 "prev_first_lsn < cur_txn->first_lsn", errorType=0xcc92c4 "FailedAssertion", fileName=0xcc9310 "reorderbuffer.c",
lineNumber=916) at assert.c:69
#3 0x00000000008df064 in AssertTXNLsnOrder (rb=0x2a48590) at reorderbuffer.c:916
#4 0x00000000008de9a1 in ReorderBufferTXNByXid (rb=0x2a48590, xid=756, create=true, is_new=0x0, lsn=24749416, create_as_top=true) at reorderbuffer.c:669
#5 0x00000000008e2d00 in ReorderBufferAddNewTupleCids (rb=0x2a48590, xid=756, lsn=24749416, node=..., tid=..., cmin=1, cmax=4294967295, combocid=4294967295) at reorderbuffer.c:3198
#6 0x00000000008e7ed7 in SnapBuildProcessNewCid (builder=0x2a44570, xid=757, lsn=24749416, xlrec=0x2a16d38) at snapbuild.c:823
#7 0x00000000008d14b3 in DecodeHeap2Op (ctx=0x2a324f0, buf=0x7ffd886a4bc0) at decode.c:471
#8 0x00000000008d0bfa in LogicalDecodingProcessRecord (ctx=0x2a324f0, record=0x2a328f0) at decode.c:151
#9 0x00000000008d8688 in pg_logical_slot_get_changes_guts (fcinfo=0x2a206b0, confirm=true, binary=false) at logicalfuncs.c:296
#10 0x00000000008d87bd in pg_logical_slot_get_changes (fcinfo=0x2a206b0) at logicalfuncs.c:365
```
Then, I think the simplest process would be:
```
ReorderBufferProcessXid(xid = 757, lsn)
-> A ReorderBufferTXN for subtransaciton (757) was generated.
The first_lsn was the head of NEW_CID record.
DecodeHeap2Op(info = XLOG_HEAP2_NEW_CID)
SnapBuildProcessNewCid()
ReorderBufferAddNewTupleCids(..., xlrec->top_xid = 756,...)
ReorderBufferTXNByXid(xid = 756, lsn)
-> A ReorderBufferTXN for top-transaciton (756) was generated.
The first_lsn was the head of NEW_CID record. It caused an Assertion failure.
```
> I think the straightforward fix is to associate them to top-sub relationship,
> and attached patch did it.
LGFM, I think it is suitable assign subtransaction after calling ReorderBufferAddNewTupleCids().
## Issue 2
Inspired by your spec case, I've reorganized the spec case provided in [2]. The new test in attachment
is able to reproduce the issue mentioned in [1] even before commit 6b77048e5.
The approach in [3] is also LGFM.
[1] https://www.postgresql.org/message-id/18369-ad61699bf91c5bc0@postgresql.org
[2] https://www.postgresql.org/message-id/6d0e80d6.c1fc.18deeb8120a.Coremail.ocean_li_996@163.com
[3] https://www.postgresql.org/message-id/CAA4eK1KpW5pHMwMp9hfXYvOeEU5Rcbhoc7FxtBOGPgKeyYLDmA@mail.gmail...
Best Regards,
Haiyang Li
Attachments:v2-0001-TestCase-Coredump-On-Assert_TXNLsnOrder.patch (application/octet-stream, 3.6K) downloaddiff --git a/contrib/test_decoding/specs/catalog_change_snapshot.spec b/contrib/test_decoding/specs/catalog_change_snapshot.specindex d8b9df97ed..e58770cfd6 100644--- a/contrib/test_decoding/specs/catalog_change_snapshot.spec+++ b/contrib/test_decoding/specs/catalog_change_snapshot.spec@@ -19,6 +19,7 @@ teardown
session "s0"
setup { SET synchronous_commit=on; }
+step "s0_create_temp" { CREATE TEMP TABLE temp_t (id int, data TEXT); }
step "s0_init" { SELECT 'init' FROM pg_create_logical_replication_slot('isolation_slot', 'test_decoding'); }
step "s0_begin" { BEGIN; }
step "s0_savepoint" { SAVEPOINT sp1; }
@@ -27,6 +28,7 @@ step "s0_truncate" { TRUNCATE tbl1; }
step "s0_insert" { INSERT INTO tbl1 VALUES (1); }
step "s0_insert2" { INSERT INTO user_cat VALUES (1); }
step "s0_insert_part" { INSERT INTO tbl1_part VALUES (1); }
+step "s0_insert_temp" { INSERT INTO temp_t VALUES(1); }
step "s0_create_part1" { CREATE TABLE tbl1_part_p1 PARTITION OF tbl1_part FOR VALUES FROM (0) TO (10); }
step "s0_create_part2" { CREATE TABLE tbl1_part_p2 PARTITION OF tbl1_part FOR VALUES FROM (10) TO (20); }
step "s0_commit" { COMMIT; }
@@ -36,6 +38,11 @@ setup { SET synchronous_commit=on; }
step "s1_checkpoint" { CHECKPOINT; }
step "s1_get_changes" { SELECT data FROM pg_logical_slot_get_changes('isolation_slot', NULL, NULL, 'skip-empty-xacts', '1', 'include-xids', '0'); }
+session "s2"+step "s2_init" { SELECT 'init' FROM pg_create_logical_replication_slot('another_slot', 'test_decoding'); }+step "s2_get_changes" { SELECT data FROM pg_logical_slot_get_changes('another_slot', NULL, NULL, 'skip-empty-xacts', '1', 'include-xids', '0'); }+step "s2_stop" { SELECT 'stop' FROM pg_drop_replication_slot('another_slot'); }+
# For the transaction that TRUNCATEd the table tbl1, the last decoding decodes
# only its COMMIT record, because it starts from the RUNNING_XACTS record emitted
# during the first checkpoint execution. This transaction must be marked as
@@ -75,3 +82,18 @@ permutation "s0_init" "s0_begin" "s0_savepoint" "s0_insert" "s1_checkpoint" "s1_
# that the corresponding substransaction is also marked as containing a catalog
# modifying change.
permutation "s0_init" "s0_begin" "s0_savepoint" "s0_create_part1" "s0_savepoint_release" "s1_checkpoint" "s0_create_part2" "s0_commit" "s0_begin" "s0_truncate" "s1_checkpoint" "s1_get_changes" "s0_insert_part" "s1_get_changes" "s0_commit" "s1_get_changes"
++# DML operations on temporary table temp_t consume XIDs, but do not generate WAL records.+# The last decoding restarts from the first checkpoint and doesn't get any information of+# last two substransactions that performed s0_insert_temp. While processing the commit record+# for the corresponding top-level transaction which will be marked as containing catalog+# change even before commit, we ensure that the corresponding substransaction is added into+# ReorderBuffer as subxact.+permutation "s0_create_temp" "s0_init" "s0_begin" "s0_savepoint" "s0_create_part1" "s0_savepoint_release" "s2_init" "s1_checkpoint" "s1_get_changes" "s0_savepoint" "s0_insert_temp" "s0_savepoint_release" "s0_savepoint" "s0_insert_temp" "s0_savepoint_release" "s0_commit" "s2_get_changes" "s2_stop"++# The last decoding restarts from the NEW_CID record in the subtransaction.+# While processing it, a same ReorderBufferChange entry would be associated+# with both the top and the sub transaction, as the first entry. This breaks+# an assumption in AssertTXNLsnOrder() which the first_lsn of entries must be+# strictly higher than previous.+permutation "s0_init" "s0_begin" "s0_savepoint" "s0_insert" "s2_init" "s1_checkpoint" "s1_get_changes" "s0_insert2" "s0_commit" "s2_get_changes" "s2_stop"
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-bugs@postgresql.org
Cc: ocean_li_996@163.com, kuroda.hayato@fujitsu.com, exclusion@gmail.com, pgsql-bugs@lists.postgresql.org, feichanghong@qq.com, amit.kapila16@gmail.com
Subject: Re:RE: Re:RE: Re:BUG #18369: logical decoding core on AssertTXNLsnOrder()
In-Reply-To: <5f2487c9.13435.18e2e656942.Coremail.ocean_li_996@163.com>
* 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