cutover.sh: interactive stale-state cleanup prompt before Phase 0
ci/woodpecker/push/deploy Pipeline was successful

Real incident: a run had both patroni-0 and patroni-1 stuck forever on
"waiting for standby_leader to bootstrap", never even attempting to race
for the role. Root cause was leftover etcd/patroni data on disk from a
prior interrupted run (operator stopped it short) — the postgresqlha
stack itself was gone, but etcd-1/2/3-data still had persisted raft state
including a real /service/postgres-ha/initialize key and old replication
slot records. Fresh Patroni nodes booting against that non-fresh etcd
correctly concluded the cluster already existed and deferred forever
waiting for a leader that could never appear, since nobody actually held
the lock. rollback.sh's own data-dir wipe only fires when it detects the
HA stack IS currently present (Case D/E) — if the stack was already gone
by the time cleanup ran, its Case A path never touches the data dirs,
leaving exactly this trap.

Added a "Pre-Phase-0" check that runs before preflight.sh's ~6+ minute
pg_dumpall: detects a still-present postgresqlha stack OR non-empty
etcd-*/patroni-*-data left over from a prior run, and — since this is
destructive and the operator explicitly wants this to be a deliberate
choice, not silent automatic cleanup — prompts interactively before
tearing down/wiping. Non-interactive sessions (no tty) hard-fail with a
clear message rather than guessing; AUTO_CLEANUP=yes in the environment
skips the prompt for deliberate unattended re-runs. Legacy production
data is never touched by any of this.
This commit is contained in:
2026-08-05 13:37:15 -07:00
parent 4bff5d7104
commit 82a8414ffa
+136 -18
View File
@@ -101,23 +101,21 @@
# standby_leader/replica AFTER the copy fully completes, so both # standby_leader/replica AFTER the copy fully completes, so both
# timeouts could fire (and did) while a completely legitimate # timeouts could fire (and did) while a completely legitimate
# basebackup was still in progress, triggering a false-negative # basebackup was still in progress, triggering a false-negative
# auto-rollback mid-copy. FIXED: both windows extended to 1200s # auto-rollback mid-copy. FIXED: both windows extended (and later
# (20 min) with a per-poll `du -sh` (timeout-guarded, since du has # re-tuned further by direct operator edits in git — see commit
# been observed to hang on CephFS under heavy concurrent write load) # history for exact current values of PHASE1_MAX_WAIT/
# logged on every iteration, so progress is directly observable # PHASE2_MAX_WAIT) with a per-poll `du -sh` (timeout-guarded, since
# instead of a silent binary wait. # du has been observed to hang on CephFS under heavy concurrent
# write load) logged on every iteration, so progress is directly
# observable instead of a silent binary wait.
# #
# 2026 run #3 follow-up (operator request, no new failure observed yet): # 2026 run #3 follow-up (operator request, no new failure observed yet):
# Phase 2's cascade-replica bootstrap adds an EXTRA network/streaming # Phase 2's cascade-replica bootstrap adds an EXTRA network/streaming
# hop on top of the same basebackup workload Phase 1 already does # hop on top of the same basebackup workload Phase 1 already does
# (patroni-0/1's loser bootstraps FROM the winner, not from legacy # (patroni-0/1's loser bootstraps FROM the winner, not from legacy
# directly) — plausibly slower than Phase 1's copy, not just equal to # directly) — plausibly slower than Phase 1's copy, not just equal to
# it. Phase 2's window is extended further, from 1200s (20 min) to # it. Phase 2's window was extended further than Phase 1's for this
# 2100s (35 min), specifically to give more margin on this second hop. # reason (see current PHASE2_MAX_WAIT value below).
# Phase 1's window is intentionally left at 1200s (20 min) — it
# already matches the directly-observed 8-11 min precedent with
# comfortable headroom, and its bootstrap source (legacy directly) is
# the case we actually have real timing data for.
# #
# 2026 run #4 — Phase 2's lag check was a SILENT NO-OP; found after a # 2026 run #4 — Phase 2's lag check was a SILENT NO-OP; found after a
# real run passed Phase 1/2 cleanly (patroni-0 reached standby_leader, # real run passed Phase 1/2 cleanly (patroni-0 reached standby_leader,
@@ -149,6 +147,35 @@
# ADR-0001 note), not just "field happened to be empty because we asked # ADR-0001 note), not just "field happened to be empty because we asked
# the wrong node." Phase 4's (informational, non-gating) lag log line # the wrong node." Phase 4's (informational, non-gating) lag log line
# updated to use the same corrected function for consistency. # updated to use the same corrected function for consistency.
#
# 2026 run #5 — BOTH nodes stuck forever on "waiting for standby_leader
# to bootstrap", never even attempting to race for the role, on a run
# that started completely fresh (operator confirmed no other changes).
# Root cause: a PRIOR run had been interrupted (operator stopped it
# short) without a clean rollback.sh pass, leaving the etcd data
# directories (etcd-1/2/3-data) non-empty on disk even though the
# postgresqlha STACK itself was already gone. etcd's own persisted raft
# state still had /service/postgres-ha/initialize set (a real system
# identifier from the earlier attempt) plus a /service/postgres-ha/status
# key listing old replication slots — so when the new run's patroni-0/1
# containers (with genuinely fresh, empty PGDATA) came up against this
# NOT-actually-fresh etcd, Patroni correctly concluded "this cluster
# already exists, someone else must already be the leader" and both
# nodes deferred forever waiting for a leader that could never appear
# (nobody actually holds the lock). rollback.sh's own data-dir wipe only
# runs when it detects the postgresqlha stack IS currently present (its
# Case D/E paths) — if the stack was already gone by the time rollback
# logic ran (e.g. an operator-initiated stop before rollback.sh got a
# chance to run), its Case A path does NOT wipe data dirs, leaving
# exactly this trap for the next run. FIXED: added a "Pre-Phase-0" check
# (below, before preflight.sh even runs) that detects a still-present
# postgresqlha stack OR non-empty etcd-*/patroni-*-data directories left
# over from a prior run, and — since this is destructive (wipes data) and
# the operator explicitly asked for this to be an interactive decision,
# not silently automatic — PROMPTS before cleaning up. See that section
# for the exact detection logic, the prompt itself, and the
# AUTO_CLEANUP=yes escape hatch for unattended re-runs where the operator
# has already decided cleanup is always wanted.
set -uo pipefail # NOTE: deliberately not -e — every phase below checks set -uo pipefail # NOTE: deliberately not -e — every phase below checks
# its own command's exit status explicitly so we can # its own command's exit status explicitly so we can
@@ -311,6 +338,98 @@ log "a consumer of the DB being migrated. If this script exits nonzero"
log "before completing rollback, follow RUNBOOK.md section 4 manually via" log "before completing rollback, follow RUNBOOK.md section 4 manually via"
log "direct SSH — do not assume this chat will remain usable to help." log "direct SSH — do not assume this chat will remain usable to help."
# ── Pre-Phase-0: stale-state detection & optional interactive cleanup ──
# See header "FIX LOG", 2026 run #5, for the full incident this addresses:
# a prior interrupted run can leave etcd-*/patroni-*-data non-empty on
# disk (or the postgresqlha stack itself still deployed) even after the
# stack is gone — and a fresh Patroni bootstrap against non-fresh etcd
# state hangs BOTH nodes forever waiting for a leader that will never
# appear, since etcd already "remembers" the cluster as initialized.
# This check runs BEFORE preflight.sh's ~6+ minute pg_dumpall so a
# doomed run doesn't waste that time before the operator gets a chance
# to intervene. Destructive (wipes data dirs) — per explicit operator
# request, this is an INTERACTIVE prompt, not silent automatic cleanup.
# For unattended re-runs where cleanup should always happen without a
# human present, set AUTO_CLEANUP=yes in the environment beforehand.
log "--- Pre-Phase-0: checking for stale state from a prior interrupted run ---"
STALE_FOUND=0
STALE_DETAILS=()
if docker stack ls --format '{{.Name}}' 2>/dev/null | grep -qx "${HA_STACK}"; then
STALE_FOUND=1
STALE_DETAILS+=("the ${HA_STACK} stack is already deployed (a previous run may still be in progress, or was stopped without a clean rollback.sh pass)")
fi
for d in etcd-1-data etcd-2-data etcd-3-data patroni-0-data patroni-1-data; do
DIR="/volume1/docker/PostgreSQL/${d}"
if [ -d "$DIR" ] && [ -n "$(ls -A "$DIR" 2>/dev/null)" ]; then
STALE_FOUND=1
STALE_DETAILS+=("${DIR} is non-empty (leftover from a prior run — etcd in particular will remember the old cluster as already-initialized and cause both Patroni nodes to hang forever waiting for a leader)")
fi
done
if [ "$STALE_FOUND" -eq 1 ]; then
warn "Detected possible stale state from a previous cutover attempt:"
for detail in "${STALE_DETAILS[@]}"; do
warn " - ${detail}"
done
warn "Proceeding without cleaning this up is very likely to reproduce the"
warn "2026-08-05 incident where BOTH patroni-0 and patroni-1 sat forever"
warn "on 'waiting for standby_leader to bootstrap', never even attempting"
warn "to race for the role — see the ADR-0001 note, Session Update 9."
AUTO_CLEANUP="${AUTO_CLEANUP:-}"
DO_CLEANUP=""
if [ "$AUTO_CLEANUP" = "yes" ]; then
log "AUTO_CLEANUP=yes set in environment — cleaning up automatically, no prompt."
DO_CLEANUP="y"
elif [ -t 0 ]; then
read -rp "[cutover] Clean up this stale state now before proceeding? This tears down any existing ${HA_STACK} stack and wipes etcd-*/patroni-*-data. Legacy production data (postgresql_postgresql, data-17) is NEVER touched by this. [y/N] " DO_CLEANUP
else
trigger_rollback "Stale state detected from a prior run and this session is non-interactive (no tty to prompt) — refusing to guess. Re-run interactively to be prompted, set AUTO_CLEANUP=yes beforehand to skip the prompt, or clean up manually first (see ADR-0001 note, Session Update 9)."
fi
if [[ "$DO_CLEANUP" =~ ^[Yy] ]]; then
log "Operator confirmed — cleaning up stale state..."
if docker stack ls --format '{{.Name}}' 2>/dev/null | grep -qx "${HA_STACK}"; then
log "Tearing down existing ${HA_STACK} stack..."
docker stack rm "${HA_STACK}"
log "Waiting for tasks to actually finish shutting down (docker stack rm returns immediately)..."
for i in $(seq 1 24); do
REMAINING=$(docker stack ps "${HA_STACK}" 2>/dev/null | grep -c . || true)
if [ "$REMAINING" -eq 0 ]; then
break
fi
sleep 5
done
REMAINING=$(docker stack ps "${HA_STACK}" 2>/dev/null | grep -c . || true)
if [ "$REMAINING" -gt 0 ]; then
trigger_rollback "${HA_STACK} still shows ${REMAINING} task(s) after 120s wait during stale-state cleanup — unsafe to wipe data dirs while tasks may still be shutting down."
fi
log "Confirmed: ${HA_STACK} stack fully removed."
fi
for d in etcd-1-data etcd-2-data etcd-3-data patroni-0-data patroni-1-data; do
DIR="/volume1/docker/PostgreSQL/${d}"
if [ -d "$DIR" ]; then
rm -rf "$DIR"
mkdir -p "$DIR"
log " wiped and recreated: ${DIR}"
fi
done
log "Stale-state cleanup complete — proceeding with a genuinely clean slate."
else
warn "Proceeding WITHOUT cleanup, per operator choice."
warn "If Phase 1 hangs with both nodes stuck on 'waiting for standby_leader"
warn "to bootstrap' and never attempting to race for the role, this stale"
warn "state is almost certainly why — stop this run and re-run choosing"
warn "cleanup, or run manually: docker stack rm ${HA_STACK}; then wipe"
warn "etcd-*/patroni-*-data under /volume1/docker/PostgreSQL/ before retrying."
fi
else
log "No stale state detected from a prior run — proceeding."
fi
# ── Phase 0: preflight ──────────────────────────────────────────────── # ── Phase 0: preflight ────────────────────────────────────────────────
log "--- Phase 0: preflight ---" log "--- Phase 0: preflight ---"
if ! bash "${CUTOVER_DIR}/preflight.sh"; then if ! bash "${CUTOVER_DIR}/preflight.sh"; then
@@ -346,11 +465,11 @@ fi
# winner is nondeterministic — poll BOTH nodes, whichever wins becomes # winner is nondeterministic — poll BOTH nodes, whichever wins becomes
# $LEADER_HOST, the other becomes $REPLICA_HOST. Every later phase uses # $LEADER_HOST, the other becomes $REPLICA_HOST. Every later phase uses
# these two variables instead of a hardcoded hostname. # these two variables instead of a hardcoded hostname.
# FIXED (see header "FIX LOG" item b): window extended from 240s to 1200s # FIXED (see header "FIX LOG" item b): window extended — a full ~42GB
# (20 min) — a full ~42GB basebackup has been observed to take 8-11 # basebackup has been observed to take 8-11 minutes, and the role only
# minutes, and the role only flips AFTER it fully completes. Each poll # flips AFTER it fully completes. Each poll logs both nodes' role AND
# logs both nodes' role AND data-dir size so progress is directly # data-dir size so progress is directly observable instead of a silent
# observable instead of a silent binary wait. # binary wait.
log "Confirming standby_leader bootstrap completes (winner is nondeterministic — polling BOTH patroni-0 and patroni-1; a full ~42GB basebackup has been observed to take 8-11 minutes, so this window is generous)..." log "Confirming standby_leader bootstrap completes (winner is nondeterministic — polling BOTH patroni-0 and patroni-1; a full ~42GB basebackup has been observed to take 8-11 minutes, so this window is generous)..."
LEADER_HOST="" LEADER_HOST=""
REPLICA_HOST="" REPLICA_HOST=""
@@ -387,8 +506,7 @@ log "--- Phase 2: confirm streaming lag = 0 (cascade replica: ${REPLICA_HOST}) -
# FURTHER EXTENDED (see header "FIX LOG", 2026 run #3 follow-up, operator # FURTHER EXTENDED (see header "FIX LOG", 2026 run #3 follow-up, operator
# request): this cascade-replica bootstrap adds an EXTRA network/streaming # request): this cascade-replica bootstrap adds an EXTRA network/streaming
# hop on top of the same basebackup workload, so its window is now longer # hop on top of the same basebackup workload, so its window is now longer
# than Phase 1's rather than merely equal to it — extended from 1200s # than Phase 1's rather than merely equal to it.
# (20 min) to 2100s (35 min), with per-poll data-dir size logging.
# FIXED (see header "FIX LOG", 2026 run #4): the lag check itself was a # FIXED (see header "FIX LOG", 2026 run #4): the lag check itself was a
# silent no-op — see cluster_member_lag_state() above for the real fix. # silent no-op — see cluster_member_lag_state() above for the real fix.
# This gate now queries ${LEADER_HOST}'s /cluster view of ${REPLICA_HOST} # This gate now queries ${LEADER_HOST}'s /cluster view of ${REPLICA_HOST}