Hi Fujii, Shihao,
Thanks for turning the diagnosis into a patch, Shihao. Fujii, good
question on whether the barrier is needed at all; I went and measured it.
> it's also worth skipping this barrier when wal_level = logical?
Yes, and a bit more. Your WIP skips it for wal_level=logical and that
case promotes (the base hangs there 6/6). But the reported case is
wal_level=replica with no slots, and there the barrier is still emitted
and still hangs (12/12 here).
The wait isn't needed when the new status is "off" either: a process
still caching "on" only writes extra logical info, which is safe, the
same reasoning DisableLogicalDecoding() already uses to emit without
waiting. So the barrier only needs waiting on when promotion turns the
status ON. The attached 0003 (on top of Shihao's 0001) does that:
replica and logical both promote, including the mid-error case v2 can't
reach; logical decoding stays correct (48/48, calibrated against a
no-barrier mutant); the recovery suite and make check pass; and healthy
promotion is unchanged (~5 ms).
It doesn't replace Shihao's patch. When the standby already has logical
slots the wait is real, and there 0003 hangs while v2 fixes it. The two
are complementary.
One note on the v2 test: without the fix the promotion subtest still
passes most of the time (the send buffer has to fill first), so it
doesn't reliably catch that case; the DROP DATABASE subtest fails every
time. On 15 and 16 the test exits early since psql there uses
FETCH_COUNT cursors, and the meson.build hunk doesn't apply on the
stable branches. 0001 itself applies cleanly from 14 to master.
Full measurements attached.
Regards,
Manu
--- a/src/backend/replication/logical/logicalctl.c 2026-10-15 02:35:16.106597017 -0300
+++ b/src/backend/replication/logical/logicalctl.c 2026-10-15 02:35:16.114909269 -0300
@@ -752,10 +752,24 @@
* XLogLogicalInfo even if we've not updated the status above as the
* status have been turned on and off during recovery, having running
* processes have different status on their local caches.
+ *
+ * Only waiting for it when the new status is "on" is necessary, though.
+ * With wal_level = 'logical', XLogLogicalInfoActive() is true regardless
+ * of the cached value, so no barrier is needed at all. When the new
+ * status is "off", a process still caching "on" only writes logical
+ * information that isn't needed, which is always safe (the same reasoning
+ * as in DisableLogicalDecoding()), so emit the barrier without waiting.
+ * Waiting would make promotion depend on every process absorbing it,
+ * including backends blocked on a client that stopped reading.
*/
- if (IsUnderPostmaster)
- WaitForProcSignalBarrier(
- EmitProcSignalBarrier(PROCSIGNAL_BARRIER_UPDATE_XLOG_LOGICAL_INFO));
+ if (IsUnderPostmaster && wal_level != WAL_LEVEL_LOGICAL)
+ {
+ uint64 generation;
+
+ generation = EmitProcSignalBarrier(PROCSIGNAL_BARRIER_UPDATE_XLOG_LOGICAL_INFO);
+ if (new_status)
+ WaitForProcSignalBarrier(generation);
+ }
INJECTION_POINT("startup-logical-decoding-status-change-end-of-recovery", NULL);
}
review of v2 "absorb procsignalbarriers while waiting for the client" (pg19
open item 8)
=========================================================================================
patches: v2-0001 (tcop/postgres.c, +32) and v2-0002
(060_barrier_blocked_client.pl), unmodified.
also measured: fujii's nocfbot-WIP-v1 (skip the end-of-recovery barrier at
wal_level=logical)
and a prototype of ours, ours/0003 (described in axis 6).
builds: origin/REL_19_STABLE dbb9bac5949 (contains 84572589029), REL_18
ebf82fae68b,
REL_17 12f10c25ce3, REL_16 d15ab66f500, REL_15 4f45920f04f, REL_14 3eaa726e7be,
master aadce2c10ff. --enable-cassert --enable-debug --enable-tap-tests, -O1,
injection
points on 17+. one -O2 non-cassert REL_19 build for axis 4. linux 7.2 x86_64,
24 cores.
every variant differs from base only by the postgres binary (md5 checked).
method: a fresh primary+standby pair on tmpfs per run, one stuck client, the
barrier-emitting
operation, a 10 s bound ("hung" = still waiting after 10 s; 18 promotes in ~25
ms on these
builds), then release by pg_terminate_backend() of the stuck backend (or by
killing the client
when terminate does not work) and time to completion. stuck writers are
settled and their
send buffer saturated first (see the previous pass: an unsaturated writer
absorbs by luck).
306 valid runs in 106 cells, 3 runs per cell unless noted; 25 runs excluded as
harness
failures (stuck client never formed: a port collision and a tmpfs quota, both
found and
fixed; an excluded run never counts as "ok"). timings are cassert builds:
order of
magnitude only.
axis 1 - the fix closes the hang
--------------------------------
REL_19_STABLE, stuck client on the standby unless noted (runs ok / runs, max
time):
case base v2
promote, paused reader (select) hung 3/3 ok 3/3 28 ms
promote, paused reader (copy to) hung 3/3 ok 3/3 12 ms
promote, wal_level=logical hung 3/3 ok 3/3 32 ms
crash failover (kill -9 primary) hung 3/3 ok 3/3 29 ms
crash failover, wal_level=logical hung 3/3 ok 3/3 29 ms
promote, paused pg_basebackup hung 3/3 ok 3/3 13 ms
(walsender in ClientWrite)
promote, standby has a logical slot hung 3/3 ok 3/3 26 ms
promote, huge NOTICE being sent hung 3/3 ok 3/3 12 ms
promote, client stalled in password hung 3/3 ok 3/3 25 ms
auth (backend in ClientRead) [new]
first logical slot on primary:
standby replay stopped 3/3 ok 3/3 31 ms
remote_apply commit on primary blocked 3/3 ok 3/3 36 ms
slot creation, stuck reader on prim. blocked 3/3 ok 3/3 18 ms
drop database, stuck writer (primary) blocked 3/3 ok 3/3 40 ms
drop database, stuck COPY FROM reader blocked 3/3 ok 3/3 16 ms
drop database replay (standby) stopped 3/3 ok 3/3 30 ms
controls: idle client / idle in xact ok 3/3 / ok 3/3 ok 3/3 / ok 3/3
promote, huge ERROR being sent hung 3/3 (x2 wal_levels) hung 3/3 (x2)
-> axis 5
- 48 of 48 stuck runs in 16 cells finish with v2, all within 40 ms (shihao
reports 210 ms).
- every "hung" base run completes 13-317 ms after pg_terminate_backend() of the
backend
named in the "still waiting for backend with PID ..." line, so the stuck
backend is the
only thing in the way.
- [new] a client that stops in the middle of password authentication also holds
promotion
on base (the backend is registered for barriers during authentication); v2
covers it.
without v2 it is bounded only by authentication_timeout.
- dead peer (no FIN/RST): not measured. the sandbox has no net namespace to
drop ACKs. the
backend state is the same (blocked in secure_write with EAGAIN), so it
reduces to the
paused-client case. ssl path: not measured.
0002 control on REL_19 (PG_TEST_TIMEOUT_DEFAULT=60): base FAIL 2/2 (122 s), v2
PASS 2/2 (1 s).
make check (patched 19 tree): 239/239. recovery suite, patched 19 tree (make
check,
-j12): 58 files, 792 tests, PASS. 850 server logs from all runs: no TRAP, no
PANIC, no crash.
axis 2 - design correctness
---------------------------
error -> fatal. read in elog.c: errstart() turns ERROR into FATAL when
ExitOnAnyError is set,
before any longjmp, so no PG_CATCH (including the one in
ProcessProcSignalBarrier) runs and
errfinish() calls proc_exit(). output_to_client is computed at errstart() from
whereToSendOutput, which is DestNone, so nothing is sent. ReThrowError()
bypasses errstart(),
but it needs an earlier caught ERROR, which cannot exist here. socket_close()
does not
flush; with ssl, SSL_shutdown() on the non-blocking socket cannot block. what
is left on the
wire is what pg_terminate_backend() of a blocked writer leaves today.
measured with a test-only injection point that throws inside
ProcessProcSignalBarrier()
(ours/testonly-injection-point-in-barrier.patch, attached with
injection_points_set_local()
in the stuck session only), trigger drop database, the client then drains and
parses:
variant drop database stuck backend what the
client gets
v2 + inj (3 runs) done 101-165 ms exits, log: FATAL 339-533
complete DataRows,
"error triggered..." then EOF; no
error bytes
mutant + inj (3 runs) blocked 10 s back in ClientWrite ERROR bytes
inside the
(0001 without the (sending the error partial
DataRow (raw scan:
FATAL/DestNone lines) with interrupts held) ERROR@in_msg
x2, FATAL@in_msg)
both protections are needed, and shihao's "without that, the error lands inside
a DataRow
and the client hangs" holds exactly.
no error (intact.sh, 2+2 runs v2): the barrier is absorbed while the backend
stays blocked,
drop database finishes in 13-25 ms, and once the client reads it gets the full
stream (3000
DataRows, or a 24 MB NoticeResponse) up to ReadyForQuery, no error, backend
alive. on base,
drop database stays blocked until the client reads.
guard (!InterruptHoldoffCount && !CritSectionCount), read in source: it is the
entry
condition of ProcessInterrupts() and of the existing die-while-blocked branch.
LWLockAcquire() holds interrupts, so no LWLock can be held here; no I/O happens
under a
spinlock. barrier types on 19 and 15-18: SMGRRELEASE (smgrreleaseall(), meant
to be safe at
any CHECK_FOR_INTERRUPTS) and, on 19, UPDATE_XLOG_LOGICAL_INFO (deferred while
an xid is
assigned). every blocking flush reachable with holdoff 0 is protocol output
next to a CFI or
a client message, and errfinish() ends with CHECK_FOR_INTERRUPTS() for levels
below ERROR,
so the absorption happens where a CFI was about to run in the same state.
re-entrancy: absorption cannot write to the client (DestNone, and PqCommBusy
makes nested
pq_putmessage a no-op) and does not wait on its own latch. state: restored on
every return;
the only non-returning path exits the process.
note for master only: AbsorbDataChecksumsBarrier() throws an ERROR that is
designed as "retry
later" (comment: "will be caught by the procsignal machinery for a later
retry"). in this
path that becomes FATAL, i.e. the session ends instead of retrying. acceptable
versus a hang,
but worth a line in the comment. this function exists only on master; 19 and
15-18 have no
barrier that throws in normal operation.
axis 3 - scope and backpatch
----------------------------
drop database with a stuck client (primary writer, primary COPY FROM reader,
standby replay):
branch base v2
14 ok 9/9 (14-17 ms) ok 9/9 14 has no SMGRRELEASE barrier:
control
15 stuck 9/9 ok 9/9 (14-17 ms)
16 stuck 9/9 ok 9/9 (14-27 ms)
17 stuck 9/9 ok 9/9 (13-17 ms)
18 stuck 9/9 ok 9/9 (14-26 ms)
19 stuck 9/9 ok 9/9 (15-40 ms)
promotion with a stuck reader on 15-18: ok on base too (no barrier in promotion
before 19).
0001 applies with git apply --check (no fuzz, line offsets only) to 14, 15, 16,
17, 18,
REL_19_STABLE and master, and builds on all of them.
0002 does not backpatch as is:
- its meson.build hunk does not apply on any stable branch, REL_19_STABLE
included (context
line 059_remote_apply_status_interval.pl exists only on master).
- on 15 and 16 the test dies at its first poll ("timed out waiting for a
backend to block in
ClientWrite"), with and without 0001: psql before 17 runs FETCH_COUNT through
a cursor
(ExecQueryUsingCursor), each FETCH fits in the buffers, the backend never
blocks writing.
17 and later use PQsetChunkedRowsMode. so on 15/16 the drop database part
never runs.
- on 17/18: base fails 1/2 (drop database), v2 passes 2/2.
axis 4 - normal path
--------------------
-O2 disassembly: on the normal path (ProcDiePending == 0, blocked == false) v2
adds one
"test %bl,%bl; je" to ProcessClientWriteInterrupt. ProcessClientReadInterrupt
with
DoingCommandRead takes the first branch, unchanged.
instructions:u and cpu time of one backend, perf stat -p, 7 alternating rounds,
median:
workload base v2 delta
copy 2M rows to stdout 4,560,878,071 4,560,900,947 +22,876
(+0.0005%)
20,000 "select 1" round trips 557,348,696 557,427,311 +3.9 per
query (+0.014%)
cpu ms (copy / select) 274 / 176 260 / 177 within noise
instruction counts are stable to +-0.0001% between rounds; times overlap. no
regression.
axis 5 - the uncovered edge (backend blocked sending an ERROR)
--------------------------------------------------------------
reproduced with "do $$ begin raise exception '%', repeat('y', 32000000); end
$$" on a stuck
client: promotion hung on base 6/6 and on v2 6/6 (both wal_levels).
PostgresMain's error
recovery holds interrupts before EmitErrorReport(), so the guard skips, as
andres said.
- pg_terminate_backend() does not release it either, on base or v2 (12/12): the
die path has
the same guard. only the client going away does (45-68 ms after). so this
is an old
limitation of the blocked-write wait, not something v2 introduces.
- the same message size as a NOTICE is covered by v2 (3/3), so the edge is
exactly "error
report with interrupts held".
- for promotion, the 0003 below removes the edge: with v2+0003 this case
promotes 3/3
(10-14 ms) because promotion no longer waits. for drop database and replay
it remains, and
needs andres's idea (a bounded or non-blocking error send). fine as a
follow-up.
axis 6 - fujii's question: is the end-of-recovery barrier necessary?
--------------------------------------------------------------------
read in logicalctl.c (19): XLogLogicalInfoActive() is (wal_level >=
WAL_LEVEL_LOGICAL ||
XLogLogicalInfo), so at wal_level=logical the cache is never consulted: fujii
is right.
UpdateLogicalDecodingStatusEndOfRecovery() emits and waits even when the status
does not
change. measured: base hangs at wal_level=logical too (promote 3/3, crash
failover 3/3).
but the reported configuration is wal_level=replica without slots, and there
the WIP does
not help: fujii WIP hung 12/12 (select, crash failover, basebackup, auth).
what the wait protects: a process caching "off" when the new status is "on". a
process
caching "on" when the status is "off" only writes logical information that is
not needed,
which DisableLogicalDecoding() already accepts ("it's always safe to write
logical
information to WAL records, even when not strictly required"), emitting without
waiting.
so the end-of-recovery wait is needed only when new_status is true.
ours/0003 (logicalctl.c, +16 -3): skip the barrier at wal_level=logical (as
fujii), and when
new_status is false emit it without waiting. keep the wait when enabling.
promotion with a stuck client base fujii WIP 0003 v2
v2+0003
replica: select / crash / hung 12/12 hung 12/12 ok 12/12 ok 12/12
ok 12/12
basebackup / auth
replica: ERROR being sent hung 3/3 hung 3/3 ok 3/3 hung 3/3
ok 3/3
logical: select / crash hung 6/6 ok 6/6 ok 6/6 ok 6/6
ok 6/6
replica, standby has a logical hung 3/3 hung 3/3 hung 3/3 ok 3/3
ok 3/3
slot (new_status = true)
not promotion: slot replay, stuck 6/6 stuck 2/2 stuck 2/2 ok 6/6
ok 2/2
drop database replay
correctness oracle (rt.sh): two standby sessions opened before promotion keep
running; after
promotion a logical slot is created and those sessions run, through
test_decoding: replica
identity full update/delete, alter table + insert in the same transaction, a
toast update.
cases: plain, and "toggled" (the primary enabled then disabled logical decoding
while the
standby replayed, effective_wal_level logical -> replica). calibration: a
mutant that drops
the barrier in EnableLogicalDecoding() is caught (rows lost, deletes without
old tuple).
base, fujii WIP, 0003, v2+0003 x {plain, toggled} x {replica, logical} x 3:
48/48 correct.
v2+0003: recovery suite 792 tests PASS, make check 239/239.
promotion time without a stuck client (standby log, promote request -> ready),
6 runs each:
medians 5-11 ms for base, fujii WIP and 0003, with 0 or 100 idle connections,
ranges
overlap. skipping the barrier does not make a healthy promotion measurably
faster; what it
removes is the dependency on every backend.
verdict: the wait is redundant at wal_level=logical (fujii) and when the new
status is "off"
(the reported case); it is necessary when the status ends "on" (standby with
logical slots,
e.g. synced failover slots), where v2 is what helps. 0003 and v2 are
complementary: 0003
takes promotion off the barrier in the common configurations, including the
error-report
edge v2 cannot reach; v2 is still needed for replay, drop database and slot
creation.
findings on 0002 (the test)
---------------------------
- its promotion subtest passes without 0001 most of the time: 7 of 10 runs (19:
4/5, master
3/5; PG_TEST_TIMEOUT_DEFAULT=20). the psql-based writer is not saturated,
and the
barrier's own SIGUSR1 lets a write complete and the backend absorbs at the
next
CHECK_FOR_INTERRUPTS (the effect described in our previous mail). the drop
database
subtest (read side) failed 10/10 without 0001 and is the reliable one.
waking the blocked
backend a few times before promoting (e.g. pg_log_backend_memory_contexts)
until its send
queue stops growing made our harness 100% deterministic.
- 15/16 and meson: see axis 3.
- minor: the mail says "the attached file has each case and the controls"; the
archived
message carries only the two patches.
files
-----
repro/build_branch.sh, finish_branch.sh, variant.sh builds and variants
repro/cell.sh, runner.sh, plan_main.txt the matrix
(results/matrix_main.csv,
matrix_table.txt)
repro/stall2.py stuck client:
query/copyin/auth, drain
repro/inj.sh, intact.sh axis 2
(results/inj_axis2_run*.txt,
intact_axis2.txt,
evidence/)
repro/rt.sh, ptime.sh axis 6
(results/rt_axis6.txt,
ptime_axis6.txt)
repro/perf_ab.sh axis 4
(results/perf_ab.txt)
repro/run_tap.sh 0002 control
(results/tap060_*.txt)
results/recovery_*.txt, check_v2skip.txt suites
ours/0003-wait-end-of-recovery-barrier-only-when-enabling.patch prototype,
not sent
ours/mutant-*, calib-mutant-*, testonly-* oracles' calibration only
review adds signal: 0002's promotion subtest passes without the fix 7/10 (and
cannot run on
15/16); fujii's skip misses the reported wal_level=replica case, while waiting
only when
enabling (0003) closes it, including the error-report edge, with decoding
verified 48/48;
v2 itself confirms clean across 306 runs / 106 cells + 5 axes, boundary =
ERROR-message path
(held interrupts, also immune to pg_terminate_backend); method: per-run
disposable clusters
with saturated stuck clients, 10 s bound, terminate-release timing,
mutant-calibrated oracles.
