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.