# PG19: standby promotion (and standby replay) waits on a client that stopped reading Independent reproduction of item 8 (High) in Shihao Zhong's list "[PG19] Bugs found comparing 19 with 18, list before I open threads" (, 2026-10-13), plus blast-radius checks he did not mention. Builds: REL_19_STABLE at 0b8bff042a9 (19rc1) and REL_18_6 (724edf9bde9), both `--enable-cassert --enable-debug --with-icu -O1`, Linux 7.2 x86_64. All clusters are throwaway pairs on tmpfs, ports 5618x/5629x. Timings come from cassert builds and are only there for the order of magnitude; what counts is the HUNG/PROMOTED outcome. Everything below comes from the third full pass (`results/*.csv`). Earlier passes are kept in `results/run1/` and `results/run2/`. Section 2 explains why the third pass changed the harness. ## 1. Reproduction Per run: a fresh primary and hot standby, `wal_level = replica`, **no replication slots**. One client on the standby sends `select repeat('x', 8000) from generate_series(1, 100000000)` and never reads again (`repro/stall_client.py`, a ~70-line v3 protocol client that stays connected and keeps ACKing). `stall()` in `repro/lib.sh` waits for the backend to be in `ClientWrite` with a frozen `bytes_acked`, then **saturates** its local send buffer (section 2). Then `pg_promote(wait => false)`. HUNG means the standby was still in recovery after 15 s. | version | runs | HUNG | promotion | after `pg_terminate_backend()` of the stalled backend | |---|---|---|---|---| | 19rc1 | 10 | **10** | n/a | promoted in 102-128 ms | | 18.6 | 10 | 0 | 9-13 ms | n/a | Controls on 19rc1, 3 runs each, all promoted in 10-24 ms: an idle connected client, and an `idle in transaction` session. So it takes a backend that is blocked in a socket write. `COPY ... TO STDOUT` not being read: HUNG 3/3 on 19, promoted 3/3 on 18. **How long it lasts.** A promotion held behind a live, paused client was still hung after 450 s (`results/D_long_hang_19.txt`): 90 "still waiting for backend with PID ..." lines, backend in `ClientWrite`, `bytes_acked` frozen, the kernel's zero-window persist timer backing off from 4 to 11. The connection never died. We read Shihao's 949 s as the case where the probes stopped being answered (TCP retries run out). With a client that is still alive, for example a paused application thread or a `psql` sitting in a pager, nothing on the TCP side ends the wait. **949 s is not an upper bound.** ## 2. Mechanism, and why it is not 100% in the field From a hung run (`results/evidence/19-select-run1.*`): - `pg_stat_activity`: startup process `IPC / ProcSignalBarrier`, stalled backend `Client / ClientWrite`. - Standby log: `still waiting for backend with PID to accept ProcSignalBarrier` every 5 s, right after `received promote request`. - Startup backtrace: `WaitForProcSignalBarrier (generation=1) <- UpdateLogicalDecodingStatusEndOfRecovery (logicalctl.c:757) <- StartupXLOG (xlog.c:6279)`. The barrier is emitted on every promotion, even with `wal_level = replica` and no slots. - Stalled backend backtrace: `secure_write (be-secure.c:347) <- internal_flush <- socket_putmessage <- printtup <- ExecutePlan`. - gdb on the stalled backend: `ProcSignalBarrierPending = 1`, its slot's `pss_barrierGeneration = 0` against a global 1. In `secure_write()` the latch wakes the wait and `ProcessClientWriteInterrupt(true)` runs, but that function only acts on `ProcDiePending`. The code goes back to `WaitEventSetWait`, and `CHECK_FOR_INTERRUPTS()` is never reached. **Whether a given stalled backend blocks promotion depends on its local send buffer.** Our first two passes, without the saturation step, hung 28/28 when run in one CPU lane but 0/11 in another lane or unpinned (`results/run2/`, and `results/A_promote_select.csv` rows `select_unsaturated_laneB`: 0/5). In the runs that promoted, gdb shows the stalled backend **did** absorb the barrier (slot generation 1, nothing pending) and is still in `secure_write` / `ClientWrite` afterwards. The send queue shows how (`repro/diag/sendq.sh`, 3 runs, identical): | server socket | before `pg_promote` | 2 s after | |---|---|---| | Send-Q (bytes queued, not acked) | 4 028 416 | 4 129 792 | | sndbuf (`tb`) | 4 194 304 | 4 194 304 | The peer window stays at zero, yet the backend queued ~100 KB more after the promote request. The kernel frees room in the local send buffer after the backend's last `EAGAIN` without reporting the socket writable, because epoll waits for a threshold. The barrier's own SIGUSR1 wakes the backend, the retried `write()` fits, the message completes, `printtup` returns to `ExecutePlan`, `CHECK_FOR_INTERRUPTS()` absorbs the barrier, and the backend blocks again on the next row. Promotion goes through by luck. `stall()` therefore wakes the stalled backend with a harmless signal (`pg_log_backend_memory_contexts()`) until its Send-Q stops growing, which is the state of a client that has been stuck for a while. With that step: 10/10 unpinned, 5/5 + 10/10 in a lane, 0/10 on 18. For the thread: the failure is certain once the backend's send buffer is full, which is the steady state of a stuck client. A reproduction that sees "sometimes" is seeing this buffer effect, not a different bug. The same reasoning says that `secure_write()` should absorb barriers while it waits; relying on a write completing is what makes it racy. Repro trap: shrinking the client's `SO_RCVBUF` makes the bug **not** reproduce. The tiny window keeps reopening, so the backend keeps completing flushes. ## 3. Blast radius Stalled client as above, 15 s limit, 3 runs per cell unless noted (`results/B_blast_barrier_users.csv`, `results/C_promotion_variants.csv`). ### 3a. New in 19, not in the report: standby **replay** stops, and can freeze the primary `EnableLogicalDecoding()` also waits for the barrier when the standby **replays** `XLOG_LOGICAL_DECODING_STATUS_CHANGE` (xlog.c:8793). The first logical slot created on a `wal_level = replica` primary therefore stops replay on every hot standby that has a stalled reader. | case | 19rc1 | 18.6 | |---|---|---| | first logical slot on primary, stalled client on **standby**: replay | **stopped 3/3** (startup in `ProcSignalBarrier`) | replayed in 11-12 ms [1] | | same + `synchronous_commit = remote_apply`: a plain `INSERT` on the **primary** | **commit blocked 3/3** in `SyncRep` until the standby backend is killed | returned in 15-17 ms [1] | | same, standby with `max_standby_streaming_delay = 1s` | **still stopped 3/3**: not a recovery conflict, nothing is cancelled | - | | first logical slot on primary, stalled client on **primary**: `pg_create_logical_replication_slot()` | **blocked 3/3** | returned in 15-16 ms [1] | [1] 18 cannot create a logical slot at `wal_level = replica`, so the 18 column runs with `wal_level = logical`, the configuration a user needed on 18 to do the same thing. In practice: someone creates a CDC or logical replication slot on the primary. From then on, one paused reader on a hot standby is enough to stop that standby's replay with no timeout. If the standby is a `remote_apply` synchronous standby, every commit on the primary waits too. Only the deactivation path (`DisableLogicalDecoding()`) emits without waiting. ### 3b. Other ProcSignalBarrier users: blocked too, but already in 18 | case | 19rc1 | 18.6 | |---|---|---| | `DROP DATABASE` on primary, stalled client on primary | blocked 3/3 | blocked 3/3 | | `DROP DATABASE` replayed on standby, stalled client on standby | replay stopped 3/3 | replay stopped 3/3 | Same root cause (`PROCSIGNAL_BARRIER_SMGRRELEASE`, since 15). A fix that makes `secure_write()` absorb barriers while blocked would cover these as well. ### 3c. Promotion variants | case | 19rc1 | 18.6 | |---|---|---| | **failover after `kill -9` of the primary**, then promote | **HUNG 3/3** | promoted, 12-13 ms | | paused `pg_basebackup` reading from the standby (walsender in `ClientWrite`, saturated) | **HUNG 4/4**, released 11-12 ms after terminating the walsender | promoted 3/3, 12-30 ms | | cascaded standby SIGSTOPped (its walsender on the standby) | promoted 3/3, 11-13 ms | promoted 3/3, 12-29 ms | | `tcp_user_timeout = 20s` on the standby | promoted after **16.9-17.4 s** 3/3: the backend dies with `could not send data to client: Connection timed out` | promoted, 12-29 ms | - A real failover hangs the same way. The trigger is the end of recovery, not `pg_promote()`. - A base-backup walsender is a stalled writer like any other. In the first passes it looked harmless (2 hangs out of 17) because of the send-buffer effect in section 2. A streaming walsender (cascade) does not block: it writes without blocking and handles interrupts in its own loop. - Operator workaround that we measured to work: `tcp_user_timeout` bounds the wait to about its value (TCP keepalives do not, since they do not fire while data is unacknowledged). Killing the backend named in the "still waiting for backend with PID ..." log line also works. ## 4. What this adds to Shihao's item 8 1. Independent confirmation: 10/10 vs 0/10, mechanism confirmed with backtraces and barrier generations. 2. **New:** why the failure is not deterministic in the field: the barrier's own signal can squeeze one more message through a partly freed send buffer. This is measured. It also means the fix belongs in `secure_write()`'s wait. 3. **New:** replay of the logical-decoding status change on a standby has the same wait. A stalled reader on a hot standby stops replay with no timeout, and under `remote_apply` it blocks commits on the primary. `max_standby_streaming_delay` does not help. Creating a logical slot on a replica-level primary also blocks behind a stalled reader on the primary. 4. The 949 s figure is not a ceiling: with a live paused client the hang did not end in 450 s. 5. Crash failover and base-backup walsenders are affected. `tcp_user_timeout` bounds it. 6. `DROP DATABASE` (primary and replay) has had the same failure since the SMGRRELEASE barrier. It is not a 19 regression, but it argues for fixing the absorb side. ## 5. How the three passes compare - Pass 1 (before a reboot wiped tmpfs), pass 2 and pass 3 agree on every case in sections 3a and 3b. - Pass 2 found the "sometimes" behaviour: it rarely hung outside one CPU lane, the base-backup walsender hung only sometimes, and one 450 s hold promoted at once. Section 2 explains all three, and pass 3 adds the saturation step. - Harness failures we caught and excluded: - Twice the standby did not start, which looked like a hang; `pair_up` now reports `SETUP_FAILED` and keeps the logs. - Two cells ran after their shell lost write access when an act went to the background. - A `tcp_user_timeout` of 3 s expired before the promotion once saturation added seconds; it is now 20 s. - `results/evidence/` holds the per-run activity, logs and backtraces of passes 2 and 3. ## Files - `build/build.sh`: the two builds - `repro/stall_client.py`: client that stops reading - `repro/lib.sh`: ephemeral primary/standby/cascade harness; `stall()` with settle and saturation (`STALL_SATURATE=0` to see the luck) - `repro/promote_hang.sh VER RUNS [HANG] [select|copyout|none|idletx]`: section 1 - `repro/blast.sh VER CASE [HANG]`: sections 3a-3c; `STANDBY_GUCS=` for extra settings - `repro/cells.sh`: runs cells with a 120 s cap each - `repro/basebackup_stall.sh VER RUNS`: the paused base backup - `repro/long_hang.sh VER SECS`: the long hold with TCP sampling - `repro/diag/why_promoted.sh`, `repro/diag/sendq.sh`: section 2 diagnostics - `results/`: CSVs, `D_long_hang_19.txt`, `evidence/`, `run1/`, `run2/` - `shihao_thread.txt`: the source message