Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation

Started by Srinath Reddy Sadipiralla6 days ago5 messageshackers
Jump to latest
#1Srinath Reddy Sadipiralla
srinath2133@gmail.com

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]/messages/by-id/19519-fe02d8ff679d834d@postgresql.org; 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]/messages/by-id/18351-f6e06364b3a2e669@postgresql.org 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]: /messages/by-id/19519-fe02d8ff679d834d@postgresql.org
/messages/by-id/19519-fe02d8ff679d834d@postgresql.org
[1]: /messages/by-id/18351-f6e06364b3a2e669@postgresql.org
/messages/by-id/18351-f6e06364b3a2e669@postgresql.org

--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/

Attachments:

v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patchapplication/octet-stream; name=v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patchDownload+93-1
#2Srinath Reddy Sadipiralla
srinath2133@gmail.com
In reply to: Srinath Reddy Sadipiralla (#1)
Fwd: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation

---------- Forwarded message ---------
From: Srinath Reddy Sadipiralla <srinath2133@gmail.com>
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 <pgsql-hackers@lists.postgresql.org>
Cc: Masahiko Sawada <sawada.mshk@gmail.com>

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]/messages/by-id/19519-fe02d8ff679d834d@postgresql.org; 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]/messages/by-id/18351-f6e06364b3a2e669@postgresql.org 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]: /messages/by-id/19519-fe02d8ff679d834d@postgresql.org
/messages/by-id/19519-fe02d8ff679d834d@postgresql.org
[1]: /messages/by-id/18351-f6e06364b3a2e669@postgresql.org
/messages/by-id/18351-f6e06364b3a2e669@postgresql.org

--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/

--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/

Attachments:

v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patchapplication/x-patch; name=v1-0001-Avoid-writing-a-redundant-logical-decoding-status-ch.patchDownload+93-1
#3Masahiko Sawada
sawada.mshk@gmail.com
In reply to: Srinath Reddy Sadipiralla (#2)
Re: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation

On Thu, Jul 9, 2026 at 9:23 PM Srinath Reddy Sadipiralla
<srinath2133@gmail.com> wrote:

---------- Forwarded message ---------
From: Srinath Reddy Sadipiralla <srinath2133@gmail.com>
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 <pgsql-hackers@lists.postgresql.org>
Cc: Masahiko Sawada <sawada.mshk@gmail.com>

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.

Thank you for the report and the patch!

I agree with your analysis and the patch basically looks good to me.
Here are some review comments:

+ # 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)
+]);

I don't think we need to call pg_log_standby_snapshot() until the slot
is created since the slot creation writes the running-xacts record
during the slot creation.

---
+ # 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");

We can use safe_psql() to check if the query successfully completes.

I've made some cosmetic changes to the comment and the new test
including the above comments. Please review it.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

Attachments:

v2-0001-Fix-race-condition-when-enabling-logical-decoding.patchapplication/x-patch; name=v2-0001-Fix-race-condition-when-enabling-logical-decoding.patchDownload+69-4
#4Masahiko Sawada
sawada.mshk@gmail.com
In reply to: Masahiko Sawada (#3)
Re: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation

On Tue, Jul 14, 2026 at 2:02 PM Masahiko Sawada <sawada.mshk@gmail.com> wrote:

On Thu, Jul 9, 2026 at 9:23 PM Srinath Reddy Sadipiralla
<srinath2133@gmail.com> wrote:

---------- Forwarded message ---------
From: Srinath Reddy Sadipiralla <srinath2133@gmail.com>
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 <pgsql-hackers@lists.postgresql.org>
Cc: Masahiko Sawada <sawada.mshk@gmail.com>

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.

Thank you for the report and the patch!

I agree with your analysis and the patch basically looks good to me.
Here are some review comments:

+ # 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)
+]);

I don't think we need to call pg_log_standby_snapshot() until the slot
is created since the slot creation writes the running-xacts record
during the slot creation.

---
+ # 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");

We can use safe_psql() to check if the query successfully completes.

I've made some cosmetic changes to the comment and the new test
including the above comments. Please review it.

While reviewing concurrency aspects of this code before pushing the
fix, I found other race conditions in the same area: logical decoding
can be deactivated while a logical slot is being created on a standby.

On standbys, logical decoding can be deactivated while a logical slot
is being created: either by replaying an
XLOG_LOGICAL_DECODING_STATUS_CHANGE record, or by the end-of-recovery
transition upon promotion, which deactivates logical decoding if no
valid logical slot exists. When logical decoding is deactivated, all
logical slots on the standby are invalidated, but this cannot find a
slot that is not visible yet. Therefore, a slot creation whose status
check interleaved with the deactivation could continue based on a
stale status. This affects two paths:

For regular slot creation, EnsureLogicalDecodingEnabled() assumed that
logical decoding must still be enabled during recovery since the
caller had already checked it. If a promotion interleaves as described
above, the backend creating the slot fails with:

TRAP: failed Assert("IsLogicalDecodingEnabled()"), File: "logicalctl.c"

For slot synchronization, the local slot could be created and
persisted based on the remote slot information fetched before the
deactivation was replayed, leaving a valid slot whose restart_lsn
precedes the deactivation. Decoding such a slot after a failover fails
with:

ERROR: unexpected logical decoding status change 0

These races are confined to the narrow window between checking the
logical decoding status and the new slot becoming visible; once the
slot is visible, the invalidation performed by the deactivation
already covers it. So the fix is simple: re-check the logical decoding
status after the new slot becomes visible. Regular slot creation
raises an error and slot synchronization skips persisting the slot. If
the deactivation happens after the recheck instead, it is guaranteed
to invalidate the now-visible slot as usual. The attached 0002
implements this.

0001 is the fix for the originally reported issue, unchanged from the
previous version.

Regards,

--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

Attachments:

v3-0002-Fix-races-between-deactivation-of-logical-decodin.patchtext/x-patch; charset=US-ASCII; name=v3-0002-Fix-races-between-deactivation-of-logical-decodin.patchDownload+237-16
v3-0001-Fix-race-condition-when-enabling-logical-decoding.patchtext/x-patch; charset=US-ASCII; name=v3-0001-Fix-race-condition-when-enabling-logical-decoding.patchDownload+69-4
#5Srinath Reddy Sadipiralla
srinath2133@gmail.com
In reply to: Masahiko Sawada (#3)
Re: Fix "unexpected logical decoding status change" error; from concurrent logical decoding activation

Hi Masahiko-San,

On Wed, Jul 15, 2026 at 2:33 AM Masahiko Sawada <sawada.mshk@gmail.com>
wrote:

+ # 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)
+]);

I don't think we need to call pg_log_standby_snapshot() until the slot
is created since the slot creation writes the running-xacts record
during the slot creation.

---
+ # 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");

We can use safe_psql() to check if the query successfully completes.

makes sense.

I've made some cosmetic changes to the comment and the new test
including the above comments. Please review it.

LGTM.

--
Thanks :)
Srinath Reddy Sadipiralla
EDB: https://www.enterprisedb.com/