Re: [bug fix] prepared transaction might be lost when max_prepared_transactions is zero on the subscriber

Hello hackers,

23.12.2025 08:42, Zhijie Hou (Fujitsu) wrote:
> On Tuesday, December 23, 2025 12:21 PM Amit Kapila<amit(dot)kapila16(at)gmail(dot)com> wrote:
>> +# Test the ability to re-apply a transaction when a parallel apply
>> +worker fails # to prepare the transaction due to insufficient
>> +max_prepared_transactions # setting.
>> +$node_subscriber->append_conf('postgresql.conf',
>>
>> How does the test ensure that error is raised by parallel apply worker? I see
>> that in the previous test, we set 'debug_logical_replication_streaming =
>> immediate', so that should help to invoke parallel apply worker. But is there a
>> more direct way to ensure the same? Can we test for LOG like: "ERROR:
>> logical replication parallel apply worker exited due to error"?
> OK, I have added a general log test for "ERROR .. logical replication parallel
> apply worker ..." to ensure that it's the parallel apply worker that failed to
> apply the transaction.

Buildfarm animal olingo discovered a way to break this test, [1]:
400/402 subscription - postgresql:subscription/023_twophase_stream ERROR           230.82s   (exit status 255 or 0xff)

[22:24:32.246](0.650s) ok 29 - transaction is committed on subscriber
### Restarting node "subscriber"
# Running: pg_ctl --wait --pgdata
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql.build/testrun/subscription/023_twophase_stream/data/t_023_twophase_stream_subscriber_data/pgdata
--log
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql.build/testrun/subscription/023_twophase_stream/log/023_twophase_stream_subscriber.log
restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "subscriber" is 61596
[22:27:45.401](193.155s) # die: timed out waiting for file
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql.build/testrun/subscription/023_twophase_stream/log/023_twophase_stream_subscriber.log
contents to match: (?^:ERROR: .*logical replication parallel apply worker.*) at
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql/src/test/subscription/t/023_twophase_stream.pl line 460.
[22:27:45.401](0.001s) 1..29
timed out waiting for file
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql.build/testrun/subscription/023_twophase_stream/log/023_twophase_stream_subscriber.log
contents to match: (?^:ERROR: .*logical replication parallel apply worker.*) at
/home/bf/bf-build/olingo/REL_19_STABLE/pgsql/src/test/subscription/t/023_twophase_stream.pl line 460.
# Postmaster PID for node "publisher" is 54199
### Stopping node "publisher" using mode immediate

pgsql.build/testrun/subscription/023_twophase_stream/log/023_twophase_stream_subscriber.log
2026-08-03 22:24:33.209 CEST [62186][logical replication parallel worker][120/4:730] ERROR:  prepared transactions are
disabled
2026-08-03 22:24:33.209 CEST [62186][logical replication parallel worker][120/4:730] HINT:  Set
"max_prepared_transactions" to a nonzero value.
2026-08-03 22:24:33.209 CEST [62186][logical replication parallel worker][120/4:730] CONTEXT:  processing remote data
for replication origin "pg_16397" during message type "STREAM PREPARE" in transaction 719, finished at 0/01810A18
2026-08-03 22:24:33.211 CEST [61742][logical replication apply worker][119/0:0] ERROR:  logical replication parallel
apply worker exited due to error
2026-08-03 22:24:33.211 CEST [61742][logical replication apply worker][119/0:0] CONTEXT:  processing remote data for
replication origin "pg_16397" during message type "STREAM PREPARE" in transaction 719, finished at 0/01810A18
    logical replication parallel apply worker
    processing remote data for replication origin "pg_16397" during message type "STREAM PREPARE" in transaction 719,
finished at 0/01810A18
2026-08-03 22:24:33.227 CEST [61596][postmaster][:0] LOG: background worker "logical replication parallel worker" (PID
62186) exited with exit code 1
2026-08-03 22:24:33.250 CEST [62213][logical replication apply worker][121/2:0] LOG:  logical replication apply worker
for subscription "tap_sub" has started
2026-08-03 22:24:33.267 CEST [61596][postmaster][:0] LOG: background worker "logical replication apply worker" (PID
61742) exited with exit code 1
2026-08-03 22:24:33.552 CEST [62213][logical replication apply worker][121/0:0] ERROR:  prepared transactions are disabled
2026-08-03 22:24:33.552 CEST [62213][logical replication apply worker][121/0:0] HINT:  Set "max_prepared_transactions"
to a nonzero value.
2026-08-03 22:24:33.552 CEST [62213][logical replication apply worker][121/0:0] CONTEXT:  processing remote data for
replication origin "pg_16397" during message type "PREPARE" in transaction 719, finished at 0/01810A18
2026-08-03 22:24:33.569 CEST [61596][postmaster][:0] LOG: background worker "logical replication apply worker" (PID
62213) exited with exit code 1
...
2026-08-03 22:27:44.655 CEST [61596][postmaster][:0] LOG: background worker "logical replication apply worker" (PID
183059) exited with exit code 1
2026-08-03 22:27:45.113 CEST [183345][logical replication apply worker][123/262:0] LOG:  logical replication apply
worker for subscription "tap_sub" has started
2026-08-03 22:27:45.154 CEST [183345][logical replication apply worker][123/0:0] ERROR:  prepared transactions are disabled
2026-08-03 22:27:45.154 CEST [183345][logical replication apply worker][123/0:0] HINT:  Set "max_prepared_transactions"
to a nonzero value.
2026-08-03 22:27:45.154 CEST [183345][logical replication apply worker][123/0:0] CONTEXT:  processing remote data for
replication origin "pg_16397" during message type "PREPARE" in transaction 719, finished at 0/01810A18
2026-08-03 22:27:45.192 CEST [61596][postmaster][:0] LOG: background worker "logical replication apply worker" (PID
183345) exited with exit code 1
2026-08-03 22:27:45.565 CEST [61596][postmaster][:0] LOG:  received immediate shutdown request

That is, there is only one "ERROR:  logical replication parallel apply
worker exited due to error" in the log, all the following errors are
produced not by parallel worker, but by a leader worker...

I'm able to reproduce this failure with:
--- a/src/test/subscription/t/023_twophase_stream.pl
+++ b/src/test/subscription/t/023_twophase_stream.pl
@@ -445,2 +445,3 @@ $node_publisher->safe_psql(
     INSERT INTO test_tab_2 values(2);
+    SELECT pg_sleep(0.5);
     PREPARE TRANSACTION 'xact';

Could you have a look, please?

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=olingo&dt=2026-08-03%2020%3A13%3A19

Best regards,
Alexander