BUG #19728: A logical replication apply worker segfaults dereferencing a NULL `MyLogicalRepWorker->stream_filese - Mailing list pgsql-bugs
| From | PG Bug reporting form |
|---|---|
| Subject | BUG #19728: A logical replication apply worker segfaults dereferencing a NULL `MyLogicalRepWorker->stream_filese |
| Date | |
| Msg-id | 19728-8a355c369d31da13@postgresql.org Whole thread |
| Responses |
Re: BUG #19728: A logical replication apply worker segfaults dereferencing a NULL `MyLogicalRepWorker->stream_filese
|
| List | pgsql-bugs |
The following bug has been logged on the website: Bug reference: 19728 Logged by: Robert Schmitt Email address: bob@emrge.ai PostgreSQL version: 18.6 Operating system: Linux Kaitain 7.0.0-1019-nvidia #19~24.04.2-Ubuntu Description: ================================================================================ SUBMIT VIA: https://www.postgresql.org/account/submitbug/ (or email the body below to pgsql-bugs@lists.postgresql.org) Form fields ----------- PostgreSQL version: 18.6 Operating system: Ubuntu 24.04.5 LTS, aarch64 (subscriber) / macOS 26.6.2, arm64 (publisher) Short description: Logical replication apply worker segfaults on a STREAM ABORT for a transaction that was never streamed (NULL stream_fileset) ================================================================================ SUMMARY ------- A logical replication apply worker segfaults dereferencing a NULL `MyLogicalRepWorker->stream_fileset` in subxact_info_read(), reached from apply_handle_stream_abort(). The subscription has `streaming = off`, and I have confirmed from the publisher's pg_stat_activity that the START_REPLICATION command carries no `streaming` option at all. The publisher nevertheless sends a STREAM ABORT message. The apply worker has no streaming state for that xid, so the fileset is NULL and it crashes. Because the postmaster reinitialises the whole cluster when a background worker dies on SIGSEGV, this takes down every database on the subscriber, not just replication. And because the replication origin cannot advance past the offending record, the same message replays on every restart. In our case that was 484 cluster restarts over 8.5 hours, roughly one a minute, until we intervened. ENVIRONMENT ----------- Publisher: PostgreSQL 18.6 (Homebrew) on aarch64-apple-darwin25.6.0, macOS 26.6.2 Subscriber: PostgreSQL 18.6 (Ubuntu 18.6-1.pgdg24.04+2) on aarch64-unknown-linux-gnu, Ubuntu 24.04.5 LTS Both nodes are 18.6; there is no version skew. Output plugin: pgoutput. Slot two_phase = false, failover = false. Subscription: substream = 'f' (streaming = off), verified in pg_subscription. Publisher logical_decoding_work_mem was 64MB (the default) when this occurred. Disclosure of non-vanilla elements, since you will ask: - Both nodes have `timescaledb` in shared_preload_libraries. - However, the affected databases do NOT have the extension installed. The publisher-side source database (traydur_development) has only: plpgsql, pgcrypto, vector, postgres_fdw, pg_trgm, pg_stat_statements, btree_gist. The subscriber-side target has only `vector`. - I have not attempted a minimal reproduction on a build without timescaledb preloaded. See OPEN QUESTIONS below. BACKTRACE --------- Captured twice, from two separate crashes hours apart, with postgresql-18-dbgsym matching the running binary exactly. Identical both times, including the xid. #0 ChooseTablespace (name=0x... "14315996-615875138.subxacts.0", fileset=0x0) at src/backend/storage/file/fileset.c:190 #1 FilePath (path=..., fileset=0x0, name=... "14315996-615875138.subxacts.0") at src/backend/storage/file/fileset.c:201 #2 FileSetOpen (mode=0, name=... "14315996-615875138.subxacts.0", fileset=0x0) at src/backend/storage/file/fileset.c:119 #3 BufFileOpenFileSet (fileset=0x0, name=... "14315996-615875138.subxacts", mode=0, missing_ok=true) at src/backend/storage/file/buffile.c:316 #4 subxact_info_read (subid=<optimized out>, xid=615875138) at src/backend/replication/logical/worker.c:4185 #5 stream_abort_internal (xid=615875138, subxid=615875139) at src/backend/replication/logical/worker.c:1789 #6 apply_handle_stream_abort (s=0x...) at src/backend/replication/logical/worker.c:1876 #7 apply_dispatch (s=0x...) at src/backend/replication/logical/worker.c:3452 #8 LogicalRepApplyLoop (last_received=6035351251824) at src/backend/replication/logical/worker.c:3698 #9 start_apply (origin_startpos=6035349339912) at src/backend/replication/logical/worker.c:4525 #10 run_apply_worker () at src/backend/replication/logical/worker.c:4663 #11 ApplyWorkerMain (main_arg=<optimized out>) at src/backend/replication/logical/worker.c:4839 Locals in frame #6: xid = 615875138 subxid = 615875139 toplevel_xact = false apply_action = TRANS_LEADER_APPLY abort_data = {xid = 615875138, subxid = 615875139, abort_lsn = 6035351251824, ...} `apply_action = TRANS_LEADER_APPLY` is what get_transaction_apply_action() returns when the xid has no streaming state. So the worker is being handed a STREAM ABORT for a transaction it is not streaming, and stream_abort_internal() proceeds to open the subxacts file regardless. Note frame #3 passes `missing_ok=true`: the code guards against the FILE being absent but not against the FILESET being NULL. A NULL check on MyLogicalRepWorker->stream_fileset in subxact_info_read() (or an earlier bail-out in apply_handle_stream_abort when the xid has no streaming state) would turn this crash into a no-op, which is the correct behaviour for an abort of a transaction that was never streamed. EVIDENCE THAT STREAMING WAS NOT NEGOTIATED ------------------------------------------ Captured from the publisher's pg_stat_activity while the apply worker was connected: START_REPLICATION SLOT "traydur_primary_sub" LOGICAL 57D/36DA7F08 (proto_version '4', origin 'any', publication_names '"traydur_primary_pub"') There is no `streaming` option in the list, which is how the subscriber expresses streaming = off (worker.c leaves streaming_str NULL and libpqwalreceiver omits the key). The publisher sends STREAM ABORT anyway. THE WAL RECORD -------------- pg_waldump on the publisher, at the LSN the apply worker died on: rmgr: Transaction len (rec/tot): 250/250, tx: 615875138, lsn: 57D/36F7AA70, desc: ABORT 2026-09-28 21:32:22.080886 PDT; rels: base/52235576/52435013 base/52235576/52435011 base/52235576/52435008 ... It is a plain top-level ABORT of a transaction that created relfilenodes and rolled back. abort_lsn in the crash (6035351251824 = 57D/36F7AB70) is the end of this record. CRITICAL DETAIL: database OID 52235576 is NOT the database this subscription replicates. The subscription's source database is a different one entirely. The aborted transaction belongs to a database that is not published, not subscribed, and has no role in this replication set at all -- it is an unrelated parallel test database on the same cluster. An aborted transaction in a non-replicated database is crashing a subscriber bound to a different database. HOW TO REPRODUCE THE CONDITIONS ------------------------------- This arose from ordinary activity rather than a crafted case: 1. Publisher cluster hosts both a replicated database and unrelated databases. 2. A test suite runs against the unrelated databases using transactional fixtures, so every test rolls back. That produced 6,907 ABORT records in a 20-minute window, 102 of them with a `rels:` list. 3. Some of those aborted transactions exceed logical_decoding_work_mem (64MB default). 4. A subscriber with streaming = off connects and decodes across that WAL range. 5. The apply worker receives a STREAM ABORT and segfaults, taking the cluster with it. 6. The origin cannot advance past the record, so it repeats indefinitely. The correlation with logical_decoding_work_mem is inferred from the workaround below rather than read from the code; a transaction only seems to become poison once the reorder buffer crosses that threshold. IMPACT ------ 1. A crash, not an ERROR, so disable_on_error does not help. 2. The postmaster reinitialises the cluster, so every unrelated database goes down too. 3. It is self-perpetuating: the origin never advances, so it replays forever. 4. ALTER SUBSCRIPTION ... SKIP (lsn = ...) does not apply -- no apply error is ever recorded. 5. Monitoring looks healthy. systemctl reported the service active throughout all 484 crashes, because the postmaster survives and restarts its children. WORKAROUND ---------- Raise logical_decoding_work_mem on the PUBLISHER above the footprint of the aborted transactions: ALTER SYSTEM SET logical_decoding_work_mem = '2GB'; -- was 64MB SELECT pg_reload_conf(); After this the subscriber replayed the entire 6,907-abort range with no crashes and caught up fully. It is a threshold, not a fix: a large enough aborted transaction will cross any value. pg_replication_origin_advance() past a single offending record also works but only for that one record, and it discards any committed transactions in the skipped window. RULED OUT --------- - OOM: SIGSEGV, not the OOM killer; 88GB of 121GB free at the time. - Version skew: both nodes 18.6. - Network: crash is byte-deterministic on the same xid across 484 occurrences; reproduced unchanged after eliminating a dual-homed interface on the publisher. - streaming = on/parallel: the subscription was set to off and verified on the wire. - Recent package changes: none to postgresql on either node in the preceding days. OPEN QUESTIONS / WHAT I HAVE NOT DONE ------------------------------------- I have not built a minimal standalone reproduction on a vanilla PostgreSQL 18.6 without timescaledb in shared_preload_libraries. I am happy to attempt one if that would help, though the abort volume needed (thousands of rolled-back transactions, some exceeding logical_decoding_work_mem) makes it a little awkward to condense. Both core dumps, the full pg_waldump output around the record, and the complete subscriber log are available on request.
pgsql-bugs by date: