From aa87f11588301996fed5af61e37de12684421be0 Mon Sep 17 00:00:00 2001 From: admin Date: Sat, 8 Aug 2026 14:01:57 -0700 Subject: [PATCH] cutover: fix missing PGPASSWORD on all remote psql -h calls (Phases 3/5/8) Root cause of the "Canary row did not propagate" Phase 3 failure (run #7): legacy's pg_hba.conf requires scram-sha-256 for any non-local connection, and every remote `psql -h ` call in this script had never supplied a password at all. This was masked until the prior stderr-capture fix (run #7) surfaced the real error: "fe_sendauth: no password supplied" on every single attempt. patroni-0/patroni-1 use the SAME PGadmin superuser + SAME postgresql_password secret as legacy itself (per postgresql-ha-staging.yaml), so the fix reads that secret once via `docker exec "$LEGACY_CID" cat /run/secrets/postgresql_password` early in Phase 3, then passes it to every remote psql call via `docker exec -e PGPASSWORD=...` (not spliced into the bash -c string, to avoid quoting hazards). Found and fixed the identical missing-password pattern in THREE places, all with the same root cause: - Phase 3: the canary-propagation SELECT (where it was first caught) - Phase 5: the post-promotion pg_is_in_recovery() check - Phase 8: the alias write + both leader/replica visibility checks Added "2026 run #8" entry to the script's own header FIX LOG. Not yet re-validated by a run reaching past Phase 3. See ADR-0001 note, Session Update 11 (to be added). --- postgresql/cutover/cutover.sh | 87 +++++++++++++++++++++++++++++------ 1 file changed, 73 insertions(+), 14 deletions(-) diff --git a/postgresql/cutover/cutover.sh b/postgresql/cutover/cutover.sh index 4bdfea9..bb18632 100644 --- a/postgresql/cutover/cutover.sh +++ b/postgresql/cutover/cutover.sh @@ -218,9 +218,35 @@ # or a real connection-level error. The final trigger_rollback() message # on failure also now includes the last non-empty stderr seen, so it's # visible directly in the FAIL line without needing to scroll back. -# NOT yet re-validated by an actual failure recurrence — this fix has -# not yet been exercised for real; if Phase 3 fails again, the log should -# finally explain why. +# +# 2026 run #8 — The 2026 run #7 stderr-capture fix immediately paid off: +# the very next run's Phase 3 failure log showed, on every single one of +# 5 attempts: +# Password for user PGadmin: +# psql: error: connection to server at "patroni-1" (...), port 5432 +# failed: fe_sendauth: no password supplied +# This was NEVER a replication/timing issue at all. ROOT CAUSE: legacy's +# pg_hba.conf requires scram-sha-256 for any non-local connection ("host +# all all all scram-sha-256"), and patroni-0/patroni-1 (per +# postgresql-ha-staging.yaml) use PGUSER_SUPERUSER=PGadmin with the SAME +# postgresql_password Docker secret as legacy's own PGadmin. Every remote +# `psql -h -U "$POSTGRES_USER" ...` call in this script +# had ALWAYS omitted a password entirely — this bug existed from the +# script's very first version, it simply had never been reached with +# working diagnostics until the run #7 fix exposed it. Checked the WHOLE +# script for this pattern, not just Phase 3 — found the IDENTICAL missing +# password in Phase 5 (the post-promotion `pg_is_in_recovery()` check on +# $LEADER_HOST) and Phase 8 (the alias write + both visibility checks on +# $LEADER_HOST/$REPLICA_HOST) — all three would have failed the exact +# same way if ever reached. FIXED: read the postgresql_password secret +# ONCE (via `docker exec "$LEGACY_CID" cat /run/secrets/postgresql_password`, +# same secret/mechanism legacy itself already uses) into $ADMIN_PGPASSWORD +# early in Phase 3, then pass it to every remote `psql -h ` call via +# `docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" ...` — using docker exec's +# own -e flag rather than splicing the password into the bash -c string, +# specifically to avoid quoting/escaping hazards and to avoid the value +# ever needing to appear inside this script's own string-construction +# logic. NOT yet re-validated by an actual successful run past Phase 3. set -uo pipefail # NOTE: deliberately not -e — every phase below checks # its own command's exit status explicitly so we can @@ -630,6 +656,24 @@ LEGACY_CID="$(legacy_cid)" if [ -z "$LEGACY_CID" ]; then trigger_rollback "Could not find legacy container for canary write." fi + +# FIXED (see header "FIX LOG", 2026 run #8): every remote `psql -h +# ` call in Phases 3/5/8 below needs a password — legacy's +# pg_hba.conf requires scram-sha-256 for any non-local connection, and +# patroni-0/patroni-1 use the SAME PGadmin superuser + SAME +# postgresql_password secret as legacy itself (per +# postgresql-ha-staging.yaml). This was previously never supplied at all, +# so every one of these remote calls had always failed with +# "fe_sendauth: no password supplied" — masked until the run #7 +# stderr-capture fix exposed it. Read the secret ONCE here (same +# secret/mechanism legacy already uses) and pass it to every remote call +# below via `docker exec -e PGPASSWORD=...` (NOT spliced into the bash -c +# string, to avoid quoting hazards). +ADMIN_PGPASSWORD=$(docker exec "$LEGACY_CID" cat /run/secrets/postgresql_password 2>/dev/null) +if [ -z "$ADMIN_PGPASSWORD" ]; then + trigger_rollback "Could not read postgresql_password secret needed for remote psql -h calls in Phases 3/5/8. Nothing changed yet." +fi + CANARY_VAL="cutover-$(date +%s)" # FIXED (see header "FIX LOG", 2026 run #7): this write's stderr used to # be discarded entirely; now captured and logged on failure so a genuine @@ -646,17 +690,20 @@ fi # replication delay and an outright connection/auth error to # ${REPLICA_HOST} indistinguishable in the log, and this exact failure # ("Canary row did not propagate ... within 5s") had already been seen -# TWICE (2026 run #4, root-caused as the lag-check bug; this run, cause -# still unconfirmed at the time of this fix) with no way to tell which -# kind of failure either one actually was after the fact. Each attempt's -# stderr is now captured to a numbered file (same pattern already used by -# Phase 8 below) AND echoed into the log per-attempt, so a future failure -# should be self-explanatory from the log alone. +# TWICE (2026 run #4, root-caused as the lag-check bug; 2026 run #7, +# root-caused as the missing PGPASSWORD below — see run #8) with no way +# to tell which kind of failure either one actually was after the fact. +# Each attempt's stderr is now captured to a numbered file (same pattern +# already used by Phase 8 below) AND echoed into the log per-attempt, so +# a future failure should be self-explanatory from the log alone. +# FIXED (see header "FIX LOG", 2026 run #8): added +# `-e PGPASSWORD="$ADMIN_PGPASSWORD"` to the docker exec — this remote +# psql -h call had NEVER had a password supplied before. FOUND=0 LAST_CANARY_CHECK_ERR="" for i in $(seq 1 5); do rm -f "/tmp/cutover_phase3_attempt_${i}.stderr" - RESULT=$(docker exec "$LEGACY_CID" bash -c "psql -h ${REPLICA_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY_VAL}';\"" 2>"/tmp/cutover_phase3_attempt_${i}.stderr") + RESULT=$(docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" "$LEGACY_CID" bash -c "psql -h ${REPLICA_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY_VAL}';\"" 2>"/tmp/cutover_phase3_attempt_${i}.stderr") CANARY_CHECK_ERR="$(cat "/tmp/cutover_phase3_attempt_${i}.stderr" 2>/dev/null)" if [ -n "$CANARY_CHECK_ERR" ]; then log " attempt ${i}/5 on ${REPLICA_HOST}: result='${RESULT:-}' stderr: ${CANARY_CHECK_ERR}" @@ -727,7 +774,12 @@ if [ "$PROMOTED" -ne 1 ]; then trigger_rollback "${LEADER_HOST} did not reach 'leader' role within 60s of the promotion PATCH. Last observed role: '${ROLE}'. Manual etcdctl fallback is documented in this script's header / RUNBOOK.md if the operator wants to investigate before accepting the automatic rollback." fi -IN_RECOVERY=$(docker exec "$LEGACY_CID" bash -c "psql -h ${LEADER_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT pg_is_in_recovery();\"" 2>/dev/null | tr -d '[:space:]') +# FIXED (see header "FIX LOG", 2026 run #8): added +# `-e PGPASSWORD="$ADMIN_PGPASSWORD"` — this remote psql -h call had +# NEVER had a password supplied before (would have failed with +# "fe_sendauth: no password supplied" exactly like Phase 3's did, had it +# ever been reached). +IN_RECOVERY=$(docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" "$LEGACY_CID" bash -c "psql -h ${LEADER_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT pg_is_in_recovery();\"" 2>/dev/null | tr -d '[:space:]') if [ "$IN_RECOVERY" != "f" ]; then trigger_rollback "${LEADER_HOST} reports role=leader but pg_is_in_recovery() = '${IN_RECOVERY}' (expected 'f'). Not trusting this as a genuine promotion." fi @@ -767,10 +819,17 @@ log "--- Phase 8: canary write/propagation THROUGH the shared alias ---" log "Note: during this window 'postgresql' round-robins between legacy (read-only)" log "and haproxy (writable). Write attempts landing on legacy will correctly fail" log "with a read-only error — that is EXPECTED, not a hard failure by itself." +# FIXED (see header "FIX LOG", 2026 run #8): added +# `-e PGPASSWORD="$ADMIN_PGPASSWORD"` to all three docker exec calls in +# this phase — writes/reads that round-robin onto haproxy (i.e. land on +# the promoted leader) are remote, non-local connections and had NEVER +# had a password supplied before. (Writes/reads that happen to land on +# legacy itself go through the "local ... trust" pg_hba.conf rule and +# don't strictly need this, but supplying it is harmless either way.) CANARY2_VAL="cutover-alias-$(date +%s)" ALIAS_WRITE_OK=0 for i in $(seq 1 10); do - docker exec "$LEGACY_CID" bash -c "psql -h postgresql -U \"\$POSTGRES_USER\" -c \"INSERT INTO _cutover_canary(val) VALUES ('${CANARY2_VAL}');\"" >/tmp/cutover_phase8_attempt_$i.log 2>&1 + docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" "$LEGACY_CID" bash -c "psql -h postgresql -U \"\$POSTGRES_USER\" -c \"INSERT INTO _cutover_canary(val) VALUES ('${CANARY2_VAL}');\"" >/tmp/cutover_phase8_attempt_$i.log 2>&1 if [ $? -eq 0 ]; then ALIAS_WRITE_OK=1 break @@ -781,8 +840,8 @@ if [ "$ALIAS_WRITE_OK" -ne 1 ]; then trigger_rollback "Never succeeded writing through the 'postgresql' alias after 10 attempts (~20s). See /tmp/cutover_phase8_attempt_*.log on docker-2 for the read-only/connection errors encountered." fi log "Alias write succeeded on attempt ${i}. Confirming visibility on BOTH ${LEADER_HOST} and ${REPLICA_HOST}..." -VLEADER=$(docker exec "$LEGACY_CID" bash -c "psql -h ${LEADER_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY2_VAL}';\"" 2>/dev/null) -VREPLICA=$(docker exec "$LEGACY_CID" bash -c "psql -h ${REPLICA_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY2_VAL}';\"" 2>/dev/null) +VLEADER=$(docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" "$LEGACY_CID" bash -c "psql -h ${LEADER_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY2_VAL}';\"" 2>/dev/null) +VREPLICA=$(docker exec -e PGPASSWORD="$ADMIN_PGPASSWORD" "$LEGACY_CID" bash -c "psql -h ${REPLICA_HOST} -U \"\$POSTGRES_USER\" -tAc \"SELECT 1 FROM _cutover_canary WHERE val = '${CANARY2_VAL}';\"" 2>/dev/null) if [ "$VLEADER" != "1" ] || [ "$VREPLICA" != "1" ]; then trigger_rollback "Alias-written canary row not visible on both nodes (${LEADER_HOST}='${VLEADER}' ${REPLICA_HOST}='${VREPLICA}')." fi