Re: ERROR: subtransaction logged without previous top-level txn record - Mailing list pgsql-bugs

>> I think this will surely test some part of the system which was not
>> tested before, mainly having some subxacts without top-xact getting
>> decoded even though we don't need to send such a transaction.  Can you
>> prepare a complete patch (for
>> Stop-demanding-that-top-xact-must-be-seen-before-sub) having this test
>> as part of it?
>
> Ok, will do.

Here it is.

From 3748a87618dfb7379565884655f4c91b22724595 Mon Sep 17 00:00:00 2001
From: Arseny Sher <sher-ars@yandex.ru>
Date: Wed, 23 Oct 2019 15:56:46 +0300
Subject: [PATCH 2/2] Stop demanding that top xact must be seen before subxact
 in decoding.

Manifested as

ERROR:  subtransaction logged without previous top-level txn record

this check forbids legit behaviours like
 - First xl_xact_assignment record is beyond reading, i.e. earlier
   restart_lsn.
 - After restart_lsn there is some change of a subxact.
 - After that, there is second xl_xact_assignment (for another subxact)
   revealing relationship between top and first subxact.

Such transaction won't be streamed anyway because we hadn't seen it in full;
confirmed_flush_lsn must be past all these records. Saying for sure whether xact
of some record encountered after snapshot was deserialized can be streamed or
not requires to know whether it wrote something before deserialization point --
if yes, it hasn't been seen in full and can't be decoded. Snapshot doesn't have
such info, so there is no easy way to relax the check.
---
 contrib/test_decoding/Makefile                     |  2 +-
 .../test_decoding/expected/subxact_without_top.out | 40 +++++++++++++
 .../test_decoding/specs/subxact_without_top.spec   | 65 ++++++++++++++++++++++
 src/backend/replication/logical/reorderbuffer.c    |  3 -
 4 files changed, 106 insertions(+), 4 deletions(-)
 create mode 100644 contrib/test_decoding/expected/subxact_without_top.out
 create mode 100644 contrib/test_decoding/specs/subxact_without_top.spec

diff --git a/contrib/test_decoding/Makefile b/contrib/test_decoding/Makefile
index 4afb1d963e..f439c582a5 100644
--- a/contrib/test_decoding/Makefile
+++ b/contrib/test_decoding/Makefile
@@ -7,7 +7,7 @@ REGRESS = ddl xact rewrite toast permissions decoding_in_xact \
     decoding_into_rel binary prepared replorigin time messages \
     spill slot truncate
 ISOLATION = mxact delayed_startup ondisk_startup concurrent_ddl_dml \
-    oldest_xmin snapshot_transfer
+    oldest_xmin snapshot_transfer subxact_without_top
 
 REGRESS_OPTS = --temp-config $(top_srcdir)/contrib/test_decoding/logical.conf
 ISOLATION_OPTS = --temp-config $(top_srcdir)/contrib/test_decoding/logical.conf
diff --git a/contrib/test_decoding/expected/subxact_without_top.out
b/contrib/test_decoding/expected/subxact_without_top.out
new file mode 100644
index 0000000000..357e0fd964
--- /dev/null
+++ b/contrib/test_decoding/expected/subxact_without_top.out
@@ -0,0 +1,40 @@
+Parsed test spec with 3 sessions
+
+starting permutation: s0_begin s0_first_subxact s2_checkpoint s1_begin s1_dml s0_many_subxacts s0_commit s2_checkpoint
s2_get_changes_suppress_outputs1_commit s2_get_changes
 
+step s0_begin: BEGIN;
+step s0_first_subxact: 
+    DO LANGUAGE plpgsql $$
+      BEGIN
+        BEGIN
+          INSERT INTO harvest VALUES (41);
+    EXCEPTION WHEN OTHERS THEN RAISE;
+    END;
+      END $$;
+
+step s2_checkpoint: CHECKPOINT;
+step s1_begin: BEGIN;
+step s1_dml: INSERT INTO harvest VALUES (43);
+step s0_many_subxacts: select subxacts();
+subxacts       
+
+               
+step s0_commit: COMMIT;
+step s2_checkpoint: CHECKPOINT;
+step s2_get_changes_suppress_output: SELECT data FROM pg_logical_slot_get_changes('isolation_slot', NULL, NULL,
'include-xids','0', 'skip-empty-xacts', '1') LIMIT 5;
 
+data           
+
+BEGIN          
+table public.harvest: INSERT: apples[integer]:41
+table public.harvest: INSERT: apples[integer]:42
+table public.harvest: INSERT: apples[integer]:42
+table public.harvest: INSERT: apples[integer]:42
+step s1_commit: COMMIT;
+step s2_get_changes: SELECT data FROM pg_logical_slot_get_changes('isolation_slot', NULL, NULL, 'include-xids', '0',
'skip-empty-xacts','1');
 
+data           
+
+BEGIN          
+table public.harvest: INSERT: apples[integer]:43
+COMMIT         
+?column?       
+
+stop           
diff --git a/contrib/test_decoding/specs/subxact_without_top.spec
b/contrib/test_decoding/specs/subxact_without_top.spec
new file mode 100644
index 0000000000..1e78c2e8bf
--- /dev/null
+++ b/contrib/test_decoding/specs/subxact_without_top.spec
@@ -0,0 +1,65 @@
+# Forces decoding session to see (and associate with toplevel before commit)
+# subxact with previous top records (first xl_xact_assignment) beyond
+# restart_lsn. Such partially seen xact won't be streamed as it must finish
+# before confirmed_flush_lsn, but nevertheless this harmless schedule used to
+# cause
+#   ERROR: subtransaction logged without previous top-level txn record
+# failures.
+
+setup
+{
+    SELECT 'init' FROM pg_create_logical_replication_slot('isolation_slot', 'test_decoding'); -- must be first write
inxact
 
+    CREATE TABLE harvest(apples integer);
+    CREATE OR REPLACE FUNCTION subxacts() returns void as $$
+    BEGIN
+      FOR i in 1 .. 128 LOOP
+        BEGIN
+          INSERT INTO harvest VALUES (42);
+        EXCEPTION
+        WHEN OTHERS THEN
+      RAISE;
+        END;
+    END LOOP;
+    END; $$LANGUAGE 'plpgsql';
+}
+
+teardown
+{
+    DROP TABLE IF EXISTS harvest;
+    SELECT 'stop' FROM pg_drop_replication_slot('isolation_slot');
+}
+
+session "s0"
+setup { SET synchronous_commit=on; }
+step "s0_begin" { BEGIN; }
+step "s0_first_subxact" {
+    DO LANGUAGE plpgsql $$
+      BEGIN
+        BEGIN
+          INSERT INTO harvest VALUES (41);
+    EXCEPTION WHEN OTHERS THEN RAISE;
+    END;
+      END $$;
+}
+step "s0_many_subxacts" { select subxacts(); }
+step "s0_commit" { COMMIT; }
+
+session "s1"
+setup { SET synchronous_commit=on; }
+step "s1_begin" { BEGIN; }
+step "s1_dml" { INSERT INTO harvest VALUES (43); }
+step "s1_commit" { COMMIT; }
+
+session "s2"
+setup { SET synchronous_commit=on; }
+step "s2_checkpoint" { CHECKPOINT; }
+step "s2_get_changes" { SELECT data FROM pg_logical_slot_get_changes('isolation_slot', NULL, NULL, 'include-xids',
'0','skip-empty-xacts', '1'); }
 
+step "s2_get_changes_suppress_output" { SELECT data FROM pg_logical_slot_get_changes('isolation_slot', NULL, NULL,
'include-xids','0', 'skip-empty-xacts', '1') LIMIT 5; }
 
+
+# First s2_checkpoint serializes snapshot (creates potential restart_lsn point)
+# *after* initial subxact, i.e. first xl_xact_assignment is beyond it.
+# s0_many_subxacts forces second xl_xact_assignment (issues >
+# PGPROC_MAX_CACHED_SUBXIDS) to associate subxact with toplevel before commit.
+# Second s2_checkpoint ensures s2_get_changes directly following it will
+# advance the slot, establishing that restart_lsn.
+permutation "s0_begin" "s0_first_subxact" "s2_checkpoint" "s1_begin" "s1_dml" "s0_many_subxacts" "s0_commit"
"s2_checkpoint""s2_get_changes_suppress_output" "s1_commit" "s2_get_changes"
 
diff --git a/src/backend/replication/logical/reorderbuffer.c b/src/backend/replication/logical/reorderbuffer.c
index aeebbf243a..481277a1fd 100644
--- a/src/backend/replication/logical/reorderbuffer.c
+++ b/src/backend/replication/logical/reorderbuffer.c
@@ -838,9 +838,6 @@ ReorderBufferAssignChild(ReorderBuffer *rb, TransactionId xid,
     txn = ReorderBufferTXNByXid(rb, xid, true, &new_top, lsn, true);
     subtxn = ReorderBufferTXNByXid(rb, subxid, true, &new_sub, lsn, false);
 
-    if (new_top && !new_sub)
-        elog(ERROR, "subtransaction logged without previous top-level txn record");
-
     if (!new_sub)
     {
         if (rbtxn_is_known_subxact(subtxn))
-- 
2.11.0



-- cheers, arseny