public inbox for [email protected]
help / color / mirror / Atom feedFrom: Srinath Reddy Sadipiralla <[email protected]>
To: pgsql-hackers <[email protected]>
Subject: Fwd: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation
Date: Fri, 10 Jul 2026 09:52:38 +0530
Message-ID: <CAFC+b6rD3c9-s0ZcodAeJB+UTYTV4tPzrgLzJzzDj0QYuBGZJQ@mail.gmail.com> (raw)
In-Reply-To: <CAFC+b6oYzmAgp7F0ivrhfZT46-CjvCTrU9pWuMNcem-52YjOTw@mail.gmail.com>
References: <CAFC+b6oYzmAgp7F0ivrhfZT46-CjvCTrU9pWuMNcem-52YjOTw@mail.gmail.com>
---------- Forwarded message ---------
From: Srinath Reddy Sadipiralla <[email protected]>
Date: Fri, Jul 10, 2026 at 9:48 AM
Subject: Fix "unexpected logical decoding status change" error; from
concurrent logical decoding activation
To: PostgreSQL Hackers <[email protected]>
Cc: Masahiko Sawada <[email protected]>
Hi,
While stress-testing REPACK CONCURRENTLY, I was in that
area looking at BUG #19519 (REPACK failing with "missingchunk
number N for toast value" [0]; note that one reproduces with plain
REPACK too, since it's the shared copy_table_data() path, so
it's independent of what follows), I hit a different, reproducible
failure under high concurrency:
ERROR: unexpected logical decoding status change 1
I believe this is a race bug in the on-demand logical decoding
activation machinery (logicalctl.c), exposed by
REPACK CONCURRENTLY but not actually specific to it, as
this can be reproduced using pg_create_logical_replication_slot
and CREATE_REPLICATION_SLOT.
At wal_level = 'replica', logical decoding is toggled on the first time a
logical slot is created. EnableLogicalDecoding() sets the shared
logical_decoding_enabled flag and writes an
XLOG_LOGICAL_DECODING_STATUS_CHANGE record so standbys
learn about the change. On the decoding side, xlog_decode() treats
that record as unreachable:
elog(ERROR, "unexpected logical decoding status change %d", ...);
The reasoning (per the comment there) is that no running decoder can ever
have such a record within the LSN range it scans: there is exactly one
enable record per disabled->enabled transition, and it precedes the
decoding start point reserved by any slot.
That case does not hold under concurrency. EnableLogicalDecoding()
does:
LWLockAcquire(LogicalDecodingControlLock, EXCLUSIVE);
if (logical_decoding_enabled) /* already on? -> done */
{ ... return; }
LWLockRelease(...);
WaitForProcSignalBarrier(...); /* lock released here */
LWLockAcquire(LogicalDecodingControlLock, EXCLUSIVE);
logical_decoding_enabled = true;
write_logical_decoding_status_update_record(true); /* the record */
LWLockRelease(...);
The "already enabled?" check and the record write happen under two
separate lock acquisitions, with the barrier wait in between. The lock
must be dropped across the barrier; backends absorbing the barrier
take LogicalDecodingControlLock in shared mode (via
IsXLogLogicalInfoEnabled()), so holding it across WaitForProcSignalBarrier()
would deadlock.
So if two backends create the first logical slot(s) at the same time,
both can pass the initial check while the flag is still false, and both
end up writing a status-change record. The second (redundant) record
lands after the decoding start point the other slot already reserved,
so that slot scans it and trips the elog() above.
REPACK CONCURRENTLY makes this easy to hit because each operation
creates a temporary logical slot (max_repack_replication_slots), so firing
many REPACKs in parallel from the disabled state gives you many backends
racing to perform the very first activation. But nothing here is
REPACK-specific.
To reproduce this i have added a test using logical-decoding-activation
injection point in 051_effective_wal_level.pl
I also hit it with a stress script [1] which was again related to the
BUG #19519, instead of vacuum full i replaced it with REPACK (concurrently).
To fix this I re-checked the flag after re-acquiring the lock and skipped
the state change/WAL write if another backend had already completed
the transition.
LWLockAcquire(LogicalDecodingControlLock, EXCLUSIVE);
if (LogicalDecodingCtl->logical_decoding_enabled)
{
LogicalDecodingCtl->pending_disable = false;
LWLockRelease(LogicalDecodingControlLock);
return;
}
START_CRIT_SECTION();
With this, only the backend that actually performs the disabled->enabled
transition writes a record, and every slot's start point stays at or after
it, restoring the case xlog_decode() depends on.
Patch attached. It fixes logicalctl.c and adds a regression test to
051_effective_wal_level.pl reusing the existing injection-point
infrastructure. With the fix the test passes; without it it fails with
the exact error above.
[0] -
https://www.postgresql.org/message-id/flat/19519-fe02d8ff679d834d%40postgresql.org
[1] -
https://www.postgresql.org/message-id/18351-f6e06364b3a2e669%40postgresql.org
--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/
--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/
Attachments:
[application/x-patch] v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patch (7.5K, ../CAFC+b6rD3c9-s0ZcodAeJB+UTYTV4tPzrgLzJzzDj0QYuBGZJQ@mail.gmail.com/3-v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patch)
download | inline diff:
From 235a1c590cf85636bce155c3092b1e0f95a48fc0 Mon Sep 17 00:00:00 2001
From: Srinath Reddy Sadipiralla <[email protected]>
Date: Fri, 10 Jul 2026 09:12:19 +0530
Subject: [PATCH 1/1] Avoid writing a redundant logical-decoding status-change
record
When wal_level = 'replica', logical decoding is enabled on demand the
first time a logical slot is created.EnableLogicalDecoding() flips the
shared logical_decoding_enabled flag and writes an
XLOG_LOGICAL_DECODING_STATUS_CHANGE record to propagate the change to
standbys. xlog_decode() treats that record as unreachable and errors
out, on the assumption that exactly one such record is written per
disabled->enabled transition and that it always precedes the decoding
start point of every slot.
That assumption can be violated.EnableLogicalDecoding() checks
logical_decoding_enabled, then releases LogicalDecodingControlLock to
wait on a ProcSignalBarrier, then re-acquires the lock to write the
record.The lock must be released across the barrier wait, because the
backends absorbing the barrier take it in shared mode.If two backends
create the first logical slot(s) concurrently, both can observe the flag
still unset before either writes the record, so both perform the
transition and both emit a status-change record.The second, redundant
record is written after the decoding start point that the other slot has
already reserved, so that slot decodes it and fails with:
ERROR: unexpected logical decoding status change 1
Fix by re-checking logical_decoding_enabled after re-acquiring the lock,
and skipping the state change and the WAL write if another backend has
already completed the transition.This mirrors the existing fast-path
check at the top of the function.
Add a regression test to 051_effective_wal_level.pl that drives the race
deterministically using the logical-decoding-activation injection point.
Reported-by: Srinath Reddy Sadipiralla
Author: Srinath Reddy Sadipiralla
---
src/backend/replication/logical/logicalctl.c | 22 ++++++
.../recovery/t/051_effective_wal_level.pl | 71 +++++++++++++++++++
2 files changed, 93 insertions(+)
diff --git a/src/backend/replication/logical/logicalctl.c b/src/backend/replication/logical/logicalctl.c
index c11d1316450..40e86086954 100644
--- a/src/backend/replication/logical/logicalctl.c
+++ b/src/backend/replication/logical/logicalctl.c
@@ -384,6 +384,28 @@ EnableLogicalDecoding(void)
LWLockAcquire(LogicalDecodingControlLock, LW_EXCLUSIVE);
+ /*
+ * Re-check whether logical decoding got enabled while we waited for the
+ * barrier above. We had to release the lock across the barrier wait (the
+ * backends absorbing the barrier take this lock in shared mode, so holding
+ * it here would deadlock), which means a concurrent activator may have
+ * completed the disabled->enabled transition in the meantime. In that
+ * case the WAL record has already been written and we must not write
+ * another one: a second, redundant XLOG_LOGICAL_DECODING_STATUS_CHANGE
+ * record could fall within the WAL range that a concurrently-created slot
+ * has already reserved as its decoding start point, and xlog_decode()
+ * treats such a record as unreachable and errors out.
+ *
+ * This mirrors the fast-path check at the top of this function; we simply
+ * have to repeat it now that we hold the lock again.
+ */
+ if (LogicalDecodingCtl->logical_decoding_enabled)
+ {
+ LogicalDecodingCtl->pending_disable = false;
+ LWLockRelease(LogicalDecodingControlLock);
+ return;
+ }
+
START_CRIT_SECTION();
/*
diff --git a/src/test/recovery/t/051_effective_wal_level.pl b/src/test/recovery/t/051_effective_wal_level.pl
index d4bc7f0aa40..6a31a25e4a8 100644
--- a/src/test/recovery/t/051_effective_wal_level.pl
+++ b/src/test/recovery/t/051_effective_wal_level.pl
@@ -381,6 +381,77 @@ if ( $ENV{enable_injection_points} eq 'yes'
test_wal_level($primary, "replica|replica",
"effective_wal_level got decreased to 'replica' on primary");
+ # A redundant activation must not leave a stray status-change record that a
+ # concurrently-created slot later decodes. Two backends racing to enable
+ # logical decoding can both pass the "already enabled?" check in
+ # EnableLogicalDecoding() while the flag is still off (the lock is released
+ # across the barrier wait) and each write an
+ # XLOG_LOGICAL_DECODING_STATUS_CHANGE record. The second, redundant record
+ # lands after the decoding start point already reserved by the first slot,
+ # which then decodes it and errors out in xlog_decode() with "unexpected
+ # logical decoding status change". Logical decoding is disabled here, and
+ # this runs before the cancellation tests below so that no stale waiter is
+ # left registered on the injection point (a canceled waiter is not cleaned
+ # up, which would misdirect injection_points_wakeup()).
+
+ # Park one activator right after the barrier wait but before it flips the
+ # flag and writes the record.
+ my $psql_stray = $primary->background_psql('postgres');
+ $psql_stray->query_until(
+ qr/create_slot_stray/,
+ q(\echo create_slot_stray
+select injection_points_set_local();
+select injection_points_attach('logical-decoding-activation', 'wait');
+select pg_create_logical_replication_slot('slot_stray', 'test_decoding');
+));
+ $primary->wait_for_event('client backend', 'logical-decoding-activation');
+ note("injection_point 'logical-decoding-activation' is reached");
+
+ # A second backend enables logical decoding and finishes creating its slot,
+ # reserving its decoding start point after its own status-change record (so
+ # it never decodes its own record).
+ $primary->safe_psql('postgres',
+ qq[select pg_create_logical_replication_slot('slot_first', 'test_decoding')]
+ );
+ test_wal_level($primary, "replica|logical",
+ "logical decoding enabled by the first of two concurrent activations");
+
+ # Release the parked activator so it runs the rest of the activation code.
+ # Logical decoding is already enabled by now, so it must NOT write a second,
+ # redundant status-change record. In the buggy case it writes one here,
+ # just after slot_first's reserved decoding start point.
+ $primary->safe_psql('postgres',
+ qq[select injection_points_wakeup('logical-decoding-activation')]);
+
+ # Let the released backend finish creating its slot: feed running-xacts
+ # records until it reaches a consistent point (poll_query_until re-runs the
+ # query, so pg_log_standby_snapshot() is called until the slot is created).
+ $primary->poll_query_until(
+ 'postgres', qq[
+select (pg_log_standby_snapshot() is not null)
+ and exists (select 1 from pg_replication_slots
+ where slot_name = 'slot_stray' and confirmed_flush_lsn is not null)
+]);
+ $psql_stray->quit;
+
+ # Decoding the first slot must not stumble over a stray status-change record.
+ my ($decode_rc, $decode_out, $decode_err) = $primary->psql(
+ 'postgres',
+ qq[select count(*) from pg_logical_slot_get_changes('slot_first', null, null)],
+ on_error_die => 0);
+ is($decode_rc, 0, "decoding a concurrently-created slot succeeds");
+ unlike(
+ $decode_err,
+ qr/unexpected logical decoding status change/,
+ "no redundant status-change record was decoded");
+
+ # Restore the disabled state for the tests that follow.
+ $primary->safe_psql('postgres',
+ qq[select pg_drop_replication_slot('slot_stray')]);
+ $primary->safe_psql('postgres',
+ qq[select pg_drop_replication_slot('slot_first')]);
+ wait_for_logical_decoding_disabled($primary);
+
# Start a psql session to test the case where the activation process is
# interrupted.
my $psql_create_slot = $primary->background_psql('postgres');
--
2.43.0
view thread (39+ messages)
reply
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: [email protected]
Cc: [email protected]
Subject: Re: Fwd: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation
In-Reply-To: <CAFC+b6rD3c9-s0ZcodAeJB+UTYTV4tPzrgLzJzzDj0QYuBGZJQ@mail.gmail.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox