Streaming decoding fails with "unexpected table_index_fetch_tuple call during logical decoding" when a relation has a TOASTed conbin (follow-up to BUG #18641) - Mailing list pgsql-bugs

From Jiří Kavalík
Subject Streaming decoding fails with "unexpected table_index_fetch_tuple call during logical decoding" when a relation has a TOASTed conbin (follow-up to BUG #18641)
Date
Msg-id CAF7a2M-OF+TjYUBvkSV2oyZNYuPm=EqTApcMDOC+aevBFPuWrg@mail.gmail.com
Whole thread
List pgsql-bugs

Version and platform

PostgreSQL 18.3 (Debian 18.3-1.pgdg13+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 14.2.0-19) 14.2.0, 64-bit Official postgres:18 Docker image: Debian GNU/Linux 13 (trixie), glibc 2.41, Linux 6.17 x86_64. Seen in production on the same version with pgoutput / built-in logical replication (subscriptions with streaming = parallel). In production, the table with the TOASTed conbin (followed by 34 more pg_constraint rows) is modified by the streamed transaction but is not a member of the subscribed publication. The same holds in the reproducer: with pgoutput and a publication containing only "filler", decoding still fails, because the relcache entry is built for every changed relation.

Non-default settings:

wal_level = logical
logical_decoding_work_mem = 64kB

Steps to reproduce

The attached repro.sh runs these steps with psql against an empty database:

CREATE TABLE t (id int PRIMARY KEY, v text,
CONSTRAINT a_big CHECK (v <> ALL (ARRAY[ <400 md5() literals> ])));
-- the conbin of a_big is stored out of line:
-- pg_column_toast_chunk_id(conbin) IS NOT NULL
CREATE TABLE filler (id int, pad text);
SELECT pg_create_logical_replication_slot('repro', 'test_decoding');
-- session 1, kept open:
BEGIN;
INSERT INTO t VALUES (1, 'y');
INSERT INTO filler SELECT i, repeat('x', 200) FROM generate_series(1, 10000) i;
SELECT pg_sleep(10);
COMMIT;
-- session 2, a new backend, while session 1 is in pg_sleep:
\set VERBOSITY verbose
SELECT count(*) FROM pg_logical_slot_peek_changes('repro', NULL, NULL, 'stream-changes', '1');
-- after session 1 has committed:
SELECT count(*) FROM pg_logical_slot_peek_changes('repro', NULL, NULL, 'stream-changes', '1');

Actual output

Session 2, while session 1 is still open (3 out of 3 runs on a fresh container):

ERROR: XX000: unexpected table_index_fetch_tuple call during logical decoding
LOCATION: table_index_fetch_tuple, tableam.h:1218

The same peek after session 1 has committed: 10106 rows, no error.

The same error occurs with pgoutput (proto_version '4', streaming 'parallel').

Expected output

The in-progress transaction is streamed without error, as it is when the relation has no TOASTed catalog data.

Variations (same procedure, different table definitions)

pg_constraint rows of the table, in conname orderResult
a_big (TOASTed), b_small, t_id_not_null, t_pkeyERROR
a_big (TOASTed), t_only_id_not_null, t_only_pkeyERROR
a_small, t_last_id_not_null, t_last_pkey, z_big (TOASTed)no error
no TOASTed conbinno error

The error occurs only when the TOASTed row is not the last one the scan returns. Because NOT NULL constraints are pg_constraint rows in PG18, most tables have rows after any given CHECK constraint.

Backtrace

Captured with backtrace_functions = 'table_index_fetch_tuple'. The server has no debug symbols, so static functions show as offsets:

(+0xebb28)
index_getnext_slot+0x45
systable_getnext+0x38
(+0x66feae)
RelationIdGetRelation+0x8d
(+0x4a304e)
(+0x4a42b5)
ReorderBufferQueueChange+0x301
heap_decode+0x1df
LogicalDecodingProcessRecord+0x76
(+0x49afa5)
pg_logical_slot_peek_changes+0x11

Possible cause (a suggestion only)

bsysscan is a plain bool, set and cleared in systable_{begin,end}scan[_ordered]. Since 8175a7d11 (the fix for BUG #18641), the TOAST fetch that detoasts conbin inside the outer pg_constraint scan clears bsysscan on its end-scan. The outer scan's next systable_getnext() then reaches table_index_fetch_tuple() while CheckXidAlive is still valid. That would also explain why a TOASTed row in the last position does not fail. Restoring the previous value of bsysscan, or counting nesting depth, instead of clearing it might fix this.

Attachment

pgsql-bugs by date:

Previous
From: Tom Lane
Date:
Subject: Re: BUG #19727: pg-combinebackup fails to link
Next
From: Andrey Rachitskiy
Date:
Subject: Re: BUG #19732: first_value/last_value/nth_value return NULL with EXCLUDE TIES when the current row is outside its f