#!/bin/bash # # Reproduce: a standby with both primary_conninfo (+ slot) and a slow # restore_command loses its streaming connection, falls back to the archive, # and does not resume streaming while the primary keeps generating WAL. # # Needs an already built and installed PostgreSQL (nothing is built here), bash. # From the source folder, install with the prefix set to ./build: # meson setup build --prefix="$PWD/build" && ninja -C build install # ./configure --prefix="$PWD/build" && make -s -j8 install # autoconf # then run ./repro-standby-stuck-on-archive.sh # # Environment (all optional): # BUILD_PATH install prefix to use (default: ./build next to this script) # PGBIN bin directory to use instead of $BUILD_PATH/bin # OUTAGE seconds the standby is kept off the primary (default 15) # OBSERVE seconds to watch afterwards (default 60) # RESTORE_DELAY seconds restore_command sleeps per segment (default 1) # SLOT_KEEP_MB max_slot_wal_keep_size in MB, to see the slot get invalidated # KEEP=1 keep the scratch directory (logs) on exit # # While it runs, "touch $WORKDIR/pause" blocks restore_command. set -u OUTAGE=${OUTAGE:-15}; OBSERVE=${OBSERVE:-60}; RESTORE_DELAY=${RESTORE_DELAY:-1} SLOT_KEEP_MB=${SLOT_KEEP_MB:-} BUILD_PATH=${BUILD_PATH:-$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)/build} PGBIN=${PGBIN:-$BUILD_PATH/bin} [ -x "$PGBIN/initdb" ] || { echo "error: no initdb in $PGBIN (see header)" >&2; exit 1; } WORKDIR=$(mktemp -d) export PATH="$PGBIN:$PATH" LC_MESSAGES=C # the greps below expect English logs export PGHOST=127.0.0.1 PGUSER=postgres PGDATABASE=postgres PP=54320; SP=54321 # primary and standby ports P=$WORKDIR/primary; S=$WORKDIR/standby; A=$WORKDIR/archive; mkdir -p "$A" pq() { psql -X -At -p $PP -c "$1"; } sq() { psql -X -At -p $SP -c "$1"; } say() { printf '\n[%s] %s\n' "$(date +%H:%M:%S)" "$*"; } cleanup() { trap - EXIT [ -n "${BENCH:-}" ] && kill "$BENCH" 2>/dev/null pg_ctl -D "$S" -m immediate stop >/dev/null 2>&1 pg_ctl -D "$P" -m immediate stop >/dev/null 2>&1 if [ "${KEEP:-0}" = 1 ]; then echo "kept: $WORKDIR"; else rm -rf "$WORKDIR"; fi } trap cleanup EXIT # Slow archive: restore_command blocks while $WORKDIR/pause exists (this lets # the primary build a backlog), sleeps per segment, and fails if the segment is # not archived yet, which is what normally sends the standby back to streaming. cat > "$WORKDIR/restore.sh" <> "$WORKDIR/restore.log" cp "$A/\$1" "\$2" EOF chmod +x "$WORKDIR/restore.sh" # Primary: local WAL archive (1MB segments keep the backlog cheap) and a slot. say "initdb primary, workdir $WORKDIR" initdb -D "$P" -U postgres --wal-segsize=1 --no-sync >/dev/null cat >> "$P/postgresql.conf" <> "$P/pg_hba.conf" pg_ctl -D "$P" -l "$WORKDIR/primary.log" -w start >/dev/null pq "SELECT pg_create_physical_replication_slot('standby1', true)" >/dev/null pgbench -i -s 5 -q -p $PP >/dev/null 2>&1 # Standby: streams from the primary through the slot. The restore_command # above is only enabled later, after the control test. pg_basebackup -D "$S" -h 127.0.0.1 -p $PP -X stream -S standby1 -c fast --no-sync >/dev/null cat >> "$S/postgresql.conf" </dev/null streaming() { pq "SELECT count(*) FROM pg_stat_replication WHERE state='streaming'"; } say "waiting for the standby to stream" for _ in $(seq 60); do [ "$(streaming)" = 1 ] && break; sleep 1; done [ "$(streaming)" = 1 ] || { echo "standby never streamed"; exit 2; } # Load starts only now: with the primary busy from the start, the next segment # is always already archived and the standby would never stream at all. say "STREAMING: baseline established; starting pgbench" pgbench -c 4 -j 4 -P 1 -T $((OUTAGE + OBSERVE + 60)) -p $PP >"$WORKDIR/pgbench.log" 2>&1 & BENCH=$!; disown if [ -n "$SLOT_KEEP_MB" ]; then # set now, or it would hit the slot during pgbench -i pq "ALTER SYSTEM SET max_slot_wal_keep_size = '${SLOT_KEEP_MB}MB'" >/dev/null pq "ALTER SYSTEM SET checkpoint_timeout = '30s'" >/dev/null pq "SELECT pg_reload_conf()" >/dev/null fi report() { local cur; cur=$(pq "SELECT pg_current_wal_lsn()") printf '%s walsenders=%s slot_active=%s wal_status=%s retained=%sMB | standby: receiver=%s lag=%sMB last_restored=%s | tps=%s\n' \ "$(date +%H:%M:%S)" \ "$(pq "SELECT count(*) FROM pg_stat_replication")" \ "$(pq "SELECT active FROM pg_replication_slots WHERE slot_name='standby1'")" \ "$(pq "SELECT wal_status FROM pg_replication_slots WHERE slot_name='standby1'")" \ "$(pq "SELECT round(pg_wal_lsn_diff(pg_current_wal_lsn(), restart_lsn)/1048576) FROM pg_replication_slots WHERE slot_name='standby1'")" \ "$(sq "SELECT count(*) FROM pg_stat_wal_receiver")" \ "$(sq "SELECT round(pg_wal_lsn_diff('$cur', pg_last_wal_replay_lsn())/1048576)")" \ "$(tail -n1 "$WORKDIR/restore.log" 2>/dev/null | cut -d' ' -f2)" \ "$(grep progress "$WORKDIR/pgbench.log" | tail -n1 | awk '{print $4}')" } # Baseline while everything is healthy: one walsender, one receiver, slot active. sleep 2 report # SIGTERM, not SIGKILL: a killed walreceiver would crash-restart the postmaster. killwr() { kill -TERM "$(sq "SELECT pid FROM pg_stat_wal_receiver")"; } # Control test: without a restore_command the archive can never serve anything, # so after losing its connection the standby must go straight back to streaming. say "CONTROL: no restore_command; killing the walreceiver, expecting streaming to resume" killwr for i in $(seq 30); do sleep 1 [ "$(streaming)" = 1 ] && { say "control OK: streaming resumed ${i}s after the kill"; break; } done [ "$(streaming)" = 1 ] || { echo "control failed: standby did not resume streaming"; exit 2; } report # Now give the standby a (slow) restore_command, as in the real setup. say "enabling the slow restore_command on the standby (reload, no restart)" sq "ALTER SYSTEM SET restore_command = '$WORKDIR/restore.sh %f %p'" >/dev/null sq "SELECT pg_reload_conf()" >/dev/null # The problem: pause restore_command first, so that the standby falls back to # the archive and blocks there while the primary archives a backlog. say "TEST: restore_command paused, SIGTERM to the walreceiver; standby off for ${OUTAGE}s" touch "$WORKDIR/pause" killwr for i in $(seq "$OUTAGE"); do sleep 1; [ $((i % 5)) = 0 ] && report; done # Let the restore go on. Archive-first: the standby now replays the whole # backlog at one segment per RESTORE_DELAY; it tries to stream again only when # restore_command fails, i.e. once it has caught up with the archive. say "restore_command resumed; observing up to ${OBSERVE}s with pgbench still running" rm -f "$WORKDIR/pause" RESUMED= for i in $(seq "$OBSERVE"); do sleep 1 [ "$(streaming)" = 1 ] && { RESUMED=$i; break; } [ $((i % 5)) = 0 ] && report done SLOT=$(pq "SELECT 'wal_status=' || wal_status || ', retained=' || coalesce(round(pg_wal_lsn_diff(pg_current_wal_lsn(), restart_lsn)/1048576)::text,'n/a') || 'MB' FROM pg_replication_slots WHERE slot_name='standby1'") if [ -z "$RESUMED" ]; then say "REPRODUCED: no walsender/walreceiver ${OBSERVE}s after restore_command resumed; slot: $SLOT" else say "streaming resumed ${RESUMED}s after restore_command resumed; slot: $SLOT" fi grep -c "restored log file" "$WORKDIR/standby.log" | sed 's/^/segments restored from archive: /' grep -c "started streaming" "$WORKDIR/standby.log" | sed 's/^/times streaming started: /' grep -h "invalidat\|has already been removed" "$WORKDIR/primary.log" "$WORKDIR/standby.log" | head -3