pgaftest: DSL/runner improvements + monitor fixes - #1150
Merged
Conversation
dimitri
force-pushed
the
pgaftest-improvements
branch
2 times, most recently
from
July 16, 2026 16:19
e7e89d4 to
d9e27ac
Compare
- Dockerfile: trailing backslash from debug edit made the next FROM line get appended to the RUN command, breaking make build entirely. Remove the stray continuation backslash. - expected/upgrade_1.out: PG18 added a 'Default version' column to \dx output; upgrade_1.out is the PG18+ variant. Still showed '2.2' as the default version; update all four rows to '2.3'. - expected/pg19/expected/monitor.out: mirror of monitor.out for PG19 (different pg_lsn display format). Did not include the ORDER BY nodeid clause added to monitor.sql; add it to keep the echoed SQL in the expected output in sync with the query file.
- test_runner.c (runner_compose_generate): after writing docker-compose.yml and node ini files, copy the spec file to <workdir>/spec.pgaf. This lets 'pgaftest step' reload the spec without the user supplying the original path again. - test_runner.c (runner_init): derive the Docker Compose project name from the work-directory basename (e.g. replication_stall_3dc) rather than the spec filename basename. When the spec is loaded from the in-workdir copy spec.pgaf the old code yielded 'spec', which did not match the running stack and caused 'no such container: spec-node2-1' errors. COMPOSE_PROJECT_NAME env var still takes precedence (used inside the compose network). - replication_stall_3dc.pgaf: add 'ssl off' to the cluster block. Without it pgaftest defaults to self-signed SSL, which requires certificate generation before Postgres starts; node1 failed with 'could not load server certificate file server.crt'.
parseCurrentNodeState already parsed 17 columns (0-16), including noderegion at column 14 added with the --region / issue-997 work. The guard check above it still said 16, causing pg_autoctl watch to log 'Query returned 17 columns, expected 16' in a tight loop and refuse to display any node state.
…ries The old Makefile had a phony 'common' target that ran make -C common, then both pg_autoctl and pgaftest depended on it. However, because 'common' was .PHONY, make always considered it out of date and rebuilt it on every invocation — and a parallel make -j could still race the two sub-makes against each other's common/*.o output files since both include Makefile.common and carry the same compile rules. Fix: make a real file target. Both pg_autoctl and pgaftest depend on it, so make builds the archive once serially first, then the two binaries in parallel without contention.
In --tmux mode the bottom pane previously exec'd into the first data node container, which had no pgaftest binary, no docker CLI, and no knowledge of the spec file. New approach: the pgaftest service (already emitted by compose_gen for CI) is reused as the interactive shell target. That container has: - the pgaftest binary - docker + docker compose (DooD via /var/run/docker.sock) - /spec.pgaf bind-mounted from the host workDir - COMPOSE_PROJECT_NAME, PGAFTEST_HOST_WORK_DIR, PG_AUTOCTL_MONITOR set compose_gen_write gains an 'interactive' parameter: when true the pgaftest service uses 'sleep infinity' instead of 'pgaftest run /spec.pgaf', keeping it alive for a shell. The interactive flag is set when runner_setup is called with withTmux=true. The bottom pane command changes from: docker compose exec -it <node1> bash to: docker compose exec -it pgaftest sh -c 'pgaftest _setup_ ... && exec bash' Four new sub-commands mirror the DSL keywords, callable directly from the interactive shell (context resolved from PGAFTEST_SPEC / PGAFTEST_HOST_WORK_DIR env vars injected by the compose stack): pgaftest wait until <node> state = <state> [timeout <N>s] pgaftest sql <node> "<query>" pgaftest network connect|disconnect <node> pgaftest assert <node> state = <state> After setup the bottom pane prints a hint listing available steps and example commands so the user knows immediately what they can type.
Two bugs in the previous commit:
1. hintCmd[256] was smaller than the literal format string (292 bytes)
before even inserting the step list, triggering sformat's BUG assert.
2. The bottom pane command used sh -c "..." with single-quote delimiters
inside; step names or other text containing apostrophes would break
the shell syntax, causing 'unexpected EOF' on startup.
Fix: drop hintCmd and the sh -c wrapper entirely. The bottom pane now
runs pgaftest _setup_ directly via docker compose exec (no sh -c), and
cli_run_setup_only prints the hint to stdout (the pane tty) after the
setup block completes, then execlp("bash") to hand the pane over to an
interactive shell. No string embedding, no quoting concerns.
…TEST_SPEC - pgaftest help (and bare pgaftest) now prints usage instead of "unknown command" - pgaftest show is now a sub-command set: show compose|spec|steps|services - pgaftest step accepts optional <spec.pgaf> second arg; when omitted it falls back to PGAFTEST_SPEC env var, /spec.pgaf in CWD, or <workDir>/spec.pgaf - compose_gen emits PGAFTEST_SPEC=/spec.pgaf into the pgaftest service env so all interactive sub-commands (step, wait, assert, network, sql) can discover the spec without explicit path arguments inside the container - resolve_interactive_context() helper centralises the env fallback logic
- pgaftest show step: lists sequence steps with:
* next step to run
! last failed step (will retry)
(space) completed steps
- pgaftest step (no args): auto-advances to the next step using a state
file at <workDir>/pgaftest.state. On failure current stays at the
failed step so the next no-arg invocation retries it.
- pgaftest step <name>: still works; also updates the state file and
advances current when the named step matches the cursor position.
- TestRunnerState struct + runner_state_read / runner_state_write /
runner_step_next added to test_runner.c/h; state is JSON for easy
inspection with a text editor.
- show_resolve_spec() now derives workDir when it is not set, so
pgaftest show step <spec.pgaf> picks up the state file automatically.
getopt permutes argv to move flags before positionals when optind is reset to 0 (full re-initialisation). Without this, the library's first getopt pass at the root level stopped at the first non-option (the subcommand name), leaving any flags that appeared before the spec file — e.g. "setup --tmux spec.pgaf" — unprocessed by the sub-command's getopt, which then saw an empty positional list and printed the usage error. Setting optind=0 (as every pg_autoctl getopts function does) tells getopt to reorder the argument vector so all options are seen before non-option positionals, regardless of the order the user typed them. Also simplify cli_setup back to its original form now that ordering is handled at the getopt level instead of by hand.
Replaces commandline_help() (one-level flat listing) with commandline_print_command_tree() so that pgaftest help renders the full command tree with sub-command groups expanded, matching the output style of pg_autoctl help.
The workDir bind-mount was :ro, preventing runner_state_write from creating pgaftest.state inside the container. The state file belongs in workDir alongside the generated compose files, so drop the :ro flag.
The pgaftest image already creates a 'docker' user with HOME=/var/lib/postgres. Switch the pgaftest compose service from root to that user: user: docker working_dir: /var/lib/postgres spec mounted at /var/lib/postgres/spec.pgaf This lands the interactive shell in the docker user's HOME with the spec file right there, and aligns the SSL cert paths with ~/.postgresql/.
…file Adds: - Host vs. container command table with descriptions - Typical interactive session walkthrough - DooD architecture section explaining the pgaftest service container - Step state file section - Updated synopsis and sub-command reference to match current CLI (show compose|spec|step|services, step auto-advance, etc.)
runner_state_path() picks the state file location based on whether PGAFTEST_COMPOSE_SERVICE is set: - inside container → $HOME/pgaftest.state (always writable by docker user) - on host → <workDir>/pgaftest.state (alongside compose files) The bind-mounted workDir may not be writable by the container's docker user on Linux hosts where UIDs don't align. $HOME (/var/lib/postgres) is owned by the docker user in the image, so it is unconditionally writable. Update docs/ref/pgaftest.rst to reflect the new state file locations.
…ate/step Command table changes: - setup / prepare / down moved under new 'cluster' subcommand group (pgaftest cluster setup|prepare|down) - pgaftest tmux <spec.pgaf> replaces pgaftest setup --tmux; --tmux option removed from pgaftest_getopts entirely - pgaftest wait and pgaftest assert removed (not useful interactively) show subcommand changes: - show steps (plural, restored) — sequence list with */ ! progress markers - show step (singular, new) — prints the DSL commands of the next step to run - show state (new) — 'Step X/N: name' header then pg_autoctl show state output - show services removed New functions in test_runner.c: - test_cmd_print(): prints a TestCmd in DSL form to a FILE* - runner_show_state(): prints step progress header then pg_autoctl show state
The old name implied the variable held a service name. It is actually a boolean flag (set to "1") that tells the binary it is running inside the pgaftest container — which determines where to write the step state file (container $HOME vs host workDir). Also complete the docs/ref/pgaftest.rst update: Synopsis and Sub-commands sections now reflect the restructured CLI (cluster setup/prepare/down, tmux, show steps/step/state, removal of wait/assert/show services).
…eady When the monitor container is still starting up, 'pg_autoctl watch' fails on its first connection attempt and exits, closing the tmux pane. Add --wait to pg_autoctl watch: it calls pgsql_set_monitor_interactive_retry_policy() before entering the main loop, which makes the internal pgsql_open_connection() retry for up to 15 minutes with exponential back-off (same policy used by the demo app and enable/disable maintenance commands). pgaftest now passes --wait in the tmux middle pane so the watch pane stays alive while the monitor container initialises.
…r startup Makefile.common: replace individual -Werror=implicit-* flags with a single -Werror so all -Wall warnings are fatal on both macOS and Linux. The generated bison/flex files already carry -Wno-error in the pgaftest Makefile so those remain unaffected. test_runner.c: the tmux bottom pane (docker compose exec -it pgaftest) exited immediately when the container wasn't yet running, closing the pane before the user could see it. Fix: probe with a no-TTY 'docker compose exec -T pgaftest true' loop until the container accepts exec, then hand off to the interactive command. Same timing issue as the watch pane (fixed earlier with --wait). Also log the manual exec command on startup so the user can reattach to the pgaftest shell from the host tmux pane if needed: docker compose -p <project> -f <workdir>/docker-compose.yml exec -it pgaftest bash
Convenience command for opening a new interactive shell in the running pgaftest container from a host tmux pane: pgaftest cluster sh [--work-dir <dir>] Equivalent to: docker compose -p <project> -f <workdir>/docker-compose.yml exec -it pgaftest bash Resolves the project name and workdir the same way as the other cluster subcommands (--work-dir flag, PGAFTEST_HOST_WORK_DIR env, or derived from the spec file path).
The 'sleep infinity + exec' model caused a timing race: tmux opens the
pane before the pgaftest container is in 'running' state, so exec fails
and the pane closes immediately. The probe-loop workaround was a band-
aid; the real fix is to not require a background service at all.
docker compose run starts a fresh container on demand from the service
definition (same image, bind-mounts, env, network) without needing the
service to already be running. No timing race, no probe loop.
Changes:
- runner_compose_up: pass --scale pgaftest=0 in interactive mode so the
image is built but no background container is started
- tmux session now has 4 panes when the spec has a setup{} block:
pane 0 docker compose logs -f
pane 1 pg_autoctl watch --wait
pane 2 pgaftest _setup_ via docker compose run --rm (closes when done)
pane 3 interactive bash via docker compose run --rm -it
Without setup{}: 3 panes (pane 2 is the interactive shell directly)
- cluster sh: updated to use docker compose run --rm -it as well
…est/.last) pgaftest cluster setup / tmux write the active work directory to $TMPDIR/pgaftest/.last on startup. resolve_interactive_context() reads it as the final fallback when neither --work-dir nor PGAFTEST_HOST_WORK_DIR nor a spec file is available. Effect: after 'pgaftest tmux tests/.../foo.pgaf', all subsequent host commands work without arguments: pgaftest cluster sh pgaftest cluster down pgaftest show steps pgaftest show state
runner_down() now kills the tmux session (named after the project) after compose down, so a subsequent 'pgaftest tmux' for the same spec does not hit 'duplicate session: <name>'. The kill is best-effort (2>/dev/null || true) so it is harmless when no tmux session exists.
The pgaftest container runs as the 'docker' user but /var/run/docker.sock is owned by a host group (GID 1 on macOS Docker Desktop, typically 999 on Linux) that does not match any group inside the container. This caused: permission denied while trying to connect to the docker API at unix:///var/run/docker.sock Fix: stat /var/run/docker.sock at compose-generation time and emit 'group_add: [<gid>]' in the pgaftest service so the container user gains the socket's group as a supplementary group, regardless of what numeric GID the host assigns to it.
- runner_setup: check 'tmux -V' before doing anything when withTmux is
true; log the version at NOTICE level, error out cleanly if tmux is
not on PATH. Uses run_cmd_capture, the same helper used everywhere
else in the runner.
- Setup container renamed from <project>-pgaftest-run-<hash> to
<project>-setup so compose logs show a short, readable name.
Interactive shell container named <project>-sh for the same reason.
Both still carry --rm so they are removed when they exit.
docker socket permission history
---------------------------------
Previously the pgaftest service ran as 'user: root'. Root bypasses the
socket's group-ownership check, so DooD worked without any group
membership.
We changed to 'user: docker' (an unprivileged UID) to avoid running
test commands as root inside the container. /var/run/docker.sock is
typically owned root:docker with mode 0660 (or root:<N> where N is the
host docker GID, which varies: 1 on macOS Docker Desktop, ~999 on most
Linux distros). The container's 'docker' user is not in that group, so
every docker CLI call got EACCES.
The previous commit added 'group_add: ["<gid>"]' by statting the
socket at compose-generation time. 'group_add' is honoured by both
'docker compose up' and 'docker compose run', so it applies to the
setup and shell containers started via 'run --rm' as well. The compose
file must be regenerated ('pgaftest cluster down && pgaftest tmux') for
the fix to take effect on an existing cluster.
…ude from up
Root cause of monitor not running
-----------------------------------
In interactive mode, runner_compose_up passed --scale pgaftest=0 to
prevent the sleep-infinity container from starting. Docker Compose v2
still rebuilds ALL service images when --build is present, even for
scaled-to-zero services. On a re-run (stack already up from a previous
pgaftest tmux invocation), 'up --build -d --scale pgaftest=0' rebuilds
and recreates the monitor/node containers, causing a brief downtime
window during which runner_wait_for_monitor could time out, tear the
stack down, and leave the cluster gone — hence 'monitor not running'.
Fix
---
In interactive mode the service is now named 'setup' and carries
'profiles: [setup]'. Services with a profile are completely invisible
to 'docker compose up' (no build, no start, no scale interaction).
'docker compose run setup' still works and starts the container on
demand. This means:
- 'docker compose up --build -d' only builds and starts cluster
services (monitor, nodes) — never touches the setup image.
- Subsequent pgaftest tmux runs on an already-running stack are
non-destructive: up is a no-op for running healthy containers.
- --scale pgaftest=0 removed; no longer needed.
Service naming
--------------
Interactive mode: service named 'setup' — appears as '<project>-setup'
in logs and docker ps. The --name flag on docker compose run gives
containers the stable names '<project>-setup' (setup pane) and
'<project>-sh' (interactive shell pane).
CI mode: service still named 'pgaftest', no profile, command set to
'pgaftest run <spec.pgaf>' so 'docker compose up --exit-code-from
pgaftest' continues to work unchanged.
…y ensures readiness) In tmux mode the host process does not use the monitor LISTEN connection at all — it just starts the stack and hands off to the tmux session. docker compose up -d already waits for the full depends_on: service_healthy chain before returning, so the monitor is provably ready when up exits. runner_wait_for_monitor from the host is both unnecessary and the source of the intermittent 'monitor not running' failure: on Docker Desktop for Mac, published-port connections appear as 192.168.65.1, which is outside the monitor's pg_hba trust CIDR. The fallback pg_hba patch and the 120s timeout loop both ran on the critical path before tmux launched, creating a wide window for races. runner_apply_formation_settings only needs docker compose exec (internal network) — no host->monitor libpq — so it works fine without the wait. runner_wait_for_monitor is still called in CI mode (runner_run) where the host process genuinely drives steps via LISTEN/NOTIFY.
…ke build The setup container runs Docker-out-of-Docker (DooD) by bind-mounting /var/run/docker.sock. Running as root eliminates GID mismatch between macOS Docker Desktop and Linux CI, where the docker socket group ID varies by host. Changes: - Dockerfile: remove docker user, sudo, entrypoint.sh; add WORKDIR /root - Makefile.docker: add build-pgaftest and force-build-pgaftest targets, include build-pgaftest in the default 'make build' target
Groups it with the other citus_*.pgaf specs alphabetically and by name; "nonha_citus" read as "non-HA Citus" but sorted away from its siblings. Updates tests/tap/schedule, tests/tap/schedules/citus-2.sch, docs/ref/pgaftest.rst, and src/bin/pgaftest/README.md accordingly. Verified the renamed spec still runs under the new path/schedule entry.
Every pgaftest compose stack previously ran a dedicated dnsmasq container
(_dns) that served a static hosts file over DNS, with every other service
pointed at it via `dns: [...]`, specifically to work around Docker's
embedded 127.0.0.11 resolver dropping queries under container churn on
GitHub Actions runners.
That workaround is no longer needed: since every node's IP is already
static (hashed from the project name at compose-gen time), the same
name-to-IP mapping can be written directly into each service's
`extra_hosts:` list in the generated docker-compose.yml. That resolves
names via a local /etc/hosts read (NSS "files") instead of a DNS query,
which can't drop a packet or time out the way a UDP lookup can, and
removes an entire container plus the depends_on/healthiness dependency
every other service had on it being up first.
compose_gen.c changes:
- compose_dns_ip() removed; IP offsets renumbered now that there's no
_dns container to reserve .2 for (monitor=.2, secondMonitor=.3, data
nodes=.4+, was .3/.4/.5+).
- New compose_write_extra_hosts() writes the same mapping as an
`extra_hosts:` block instead of compose_gen_write_hosts()'s file.
- compose_gen_write_hosts() (the pgaf-hosts file) is kept: it's no
longer read by any container, but pgaftest itself still reads it back
(runner_hosts_lookup in test_runner.c) to reconnect a node to its
original static IP after `network disconnect`/`connect`, independent
of how name resolution works.
- The containerized "pgaftest"/"setup" compose service (used for
Docker-in-Docker CI wrapper invocations and `docker compose run
setup`) previously had neither `dns:` nor `networks:` set despite
needing to resolve "monitor" via PG_AUTOCTL_MONITOR -- a latent gap,
unrelated to dnsmasq specifically. It now gets extra_hosts and joins
pgafnet like every other service.
Removed entirely: the `dnsmasq` Dockerfile target, the `build_dnsmasq` CI
job and its artifact upload/download/load steps in test_pgaftest and
upgrade, and PGAF_DNS_IMAGE.
Verified locally: citus_nonha_operation.pgaf and citus_cluster_name.pgaf
both pass end-to-end, including the network disconnect/reconnect steps
(coordinator and worker failovers) that depend on the static-IP lookup
still working correctly with extra_hosts instead of dnsmasq.
New src/monitor/sql/drop_node.sql, driven directly via SQL (register_node /
node_active / remove_node), to check the monitor-side half of Bug C: the
citus_nonha_operation.pgaf test_008_remove_old_primaries stall where, after
dropping a two-node group's last standby, the primary is intermittently
observed stuck at "wait_primary" instead of moving to "single", and
"pg_autoctl drop node" times out after 60s waiting for the standby's row to
disappear (root-caused via ~13 local Docker reproductions this session, at
roughly a 15% hit rate).
This test isolates the monitor's own bookkeeping from the real keeper
processes and proves it correct on every run:
- remove_node() on the standby sets its goal to "dropped" and, in the
same call, moves the primary straight to "single" -- never
"wait_primary". AutoFailoverNodeGroup()'s "goalstate <> 'dropped'"
filter means RemoveNode()'s inline ProceedGroupState(primaryNode)
already sees a one-node group by the time it runs.
- A stale/racing node_active() report from the about-to-be-dropped node
(simulating a keeper report that hasn't caught up with the new
"dropped" goal) does not corrupt the primary or resurrect the
standby: ProceedGroupState()'s early-return for goalState=DROPPED
means no new goal gets assigned, though reportedstate is still
updated as unconditional bookkeeping -- this is the exact shape of
the "New state for this node ... : single -> single" line seen in
CI, where the about-to-be-dropped node reports something other than
"dropped" and the row is left pending until it complies.
- remove_node() called again before the standby complies is a safe,
idempotent no-op (goal already "dropped", number_sync_standbys not
decremented twice).
- Once the standby reports "dropped", its row is actually removed and
the primary is left alone, unaffected.
Net effect: this rules out a monitor-side sequencing bug in RemoveNode()
itself as the explanation for the observed "wait_primary" symptom -- that
path is correct on every call. The remaining, narrower suspect is a real
concurrency window between RemoveNode()'s transaction and the primary's
own independent node_active() call: NodeActive() (node_active_protocol.c)
reads the node via GetAutoFailoverNodeById() before acquiring
LockFormation/LockNodeGroup, so a primary's own concurrent poll could in
principle observe pre-drop state before blocking on the lock. Confirming
that requires true multi-session concurrency (e.g. an isolation-tester
spec), which this codebase doesn't currently have infrastructure for; not
pursued further here.
Placed last in REGRESS, after fast_forward: pgautofailover.node has a
global (nodehost, nodeport) unique constraint (not scoped per formation),
so node names must be unique across every test file in the same
database -- used dn_p/dn_s rather than the bare p/s that collided with
guard_data_loss.sql's own 'p' node on first attempt. Running after every
existing test avoids shifting their hardcoded assigned_node_id
expectations, which are global-sequence values.
Wires PGXS's ISOLATION variable into src/monitor/Makefile alongside the
existing REGRESS variable -- `make installcheck` now runs both. Isolation
specs live in src/monitor/specs/*.spec; their accepted output lives in
the same expected/ directory REGRESS already uses (pg_isolation_regress's
--expecteddir defaults to --inputdir, so no new directory convention is
needed). No Dockerfile change: `make -C src/monitor/ installcheck` already
runs both once ISOLATION is set, and pg_isolation_regress/isolationtester
ship in the same postgresql-server-dev package pg_regress already comes
from.
Two specs, in order of what they're building toward:
- concurrent_remove_node.spec: two sessions call remove_node() on the
same standby concurrently. This finds a real bug: remove_node_by_nodeid()
reads the target node via GetAutoFailoverNodeById() *before*
RemoveNode() acquires LockFormation(ExclusiveLock). The second,
blocked session resumes with a pre-lock snapshot once the first
commits, so RemoveNode()'s "goalState == DROPPED -> return early"
idempotency check doesn't fire and it redundantly reruns the whole
removal. The standby side is a harmless no-op re-write, but on the
primary side RemoveNode()'s "if ProceedGroupState(primary) didn't
change its goal, force APPLY_SETTINGS" fallback fires on this second,
redundant call and pushes a primary that had already correctly
settled at "single" into "apply_settings" for no reason. Not fixed
here -- the fix is moving the node lookup to happen after the lock
(inside RemoveNode(), taking a nodeId instead of a resolved
AutoFailoverNode*) -- documented in the spec's header for whoever
picks it up.
- concurrent_remove_standby_and_primary_report.spec: the Bug C spec.
Tests whether the primary's own node_active() call -- what its real
keeper sends on every ~1s poll, independent of any drop -- can be
tricked into the wrong decision by blocking behind a concurrent
remove_node() on the standby and resuming after it commits.
NodeActive() has the same "read before lock" shape as
remove_node_by_nodeid(). Result: ruled out. The primary's node_active()
correctly returns "single" every time, because the decision depends
on AutoFailoverNodeGroup()'s nodesCount, a fresh SPI query issued
after LockFormation is acquired, not on the stale pre-lock read (which
only affects the calling node's own previously-known fields, not
group membership). This is different from remove_node()'s bug, which
trusts a stale field for its idempotency check specifically.
Net effect on the Bug C investigation (see drop_node.sql and this
session's ~13 Docker reproductions, ~15% hit rate): RemoveNode()'s own
synchronous sequencing is proven correct (drop_node.sql), and this rules
out the primary's own concurrent poll as the trigger for the observed
"wait_primary" hang. The next concurrency shape to test is whatever could
cause more than one remove_node() call for the same node from a single
"pg_autoctl drop node" invocation -- the only shape proven so far to
produce a wrong primary goal state, even though the wrong state it
produces (apply_settings) isn't yet a proven match for the "wait_primary"
symptom from CI.
RemoveNode() used to take a pre-resolved AutoFailoverNode*, looked up by its caller (remove_node_by_nodeid/remove_node_by_host) via GetAutoFailoverNodeById()/GetAutoFailoverNode() *before* RemoveNode() acquired LockFormation(ExclusiveLock). Two concurrent remove_node() calls on the same node would serialize on that lock correctly, but the second call, once unblocked by the first's commit, was still working from the snapshot it read before it ever tried to acquire the lock -- stale by exactly the transaction it had just waited on. That broke the "goalState == DROPPED -> return early" idempotency check: the second call's stale currentNode still showed the pre-drop goalState, so it skipped the early return and redundantly redid the entire removal. The standby side was a harmless no-op re-write, but the primary side was not: RemoveNode()'s "if ProceedGroupState(primary) didn't change its goal, force APPLY_SETTINGS" fallback fired on that second, redundant call -- the primary was already correctly "single" by then, so its goal genuinely didn't change on the re-run -- and pushed a primary that had already settled at "single" into "apply_settings" for no reason. Fix: RemoveNode() now takes a nodeId instead of a pre-resolved pointer. It does an initial unlocked lookup only to learn which formation to lock (a node's formationId is immutable, so that read being racy is harmless), acquires LockFormation, and only then does the authoritative re-read of the node that all decision-making is based on. A caller blocked behind a concurrent RemoveNode() call on the same node now resumes with fresh, post-commit state instead of whatever it read before it ever tried to acquire the lock. remove_node_by_nodeid()/ remove_node_by_host() keep their own unlocked existence checks (for a precise "node not found" error message); a benign TOCTOU race there is already handled by RemoveNode() itself, which now returns true (already gone) if its own fresh lookup finds nothing. concurrent_remove_node.spec, which caught this, is updated in place to document and guard the fixed behavior instead of the bug: crn_p now stays "single" instead of drifting to "apply_settings". Verified: all 10 REGRESS + both ISOLATION specs pass via `make installcheck` against a fresh local instance.
concurrent_remove_standby_and_standby_report.spec (new) asks whether the node being dropped's OWN concurrent node_active() call -- its real keeper's regular ~1s poll, re-reporting its last known role, unaware a drop is in flight -- sees the fresh goalState = DROPPED once it blocks behind a concurrent remove_node() and resumes after that transaction commits. It does not, and this is the actual root cause of Bug C (citus_nonha_operation.pgaf's intermittent test_008_remove_old_primaries stall, ~15% hit rate across this session's Docker reproductions). NodeActive() reads the node via GetAutoFailoverNodeById() before acquiring LockFormation()/LockNodeGroup(), the same pre-lock-read shape already fixed in RemoveNode() (previous commit). A node's own node_active() call that blocks behind a concurrent remove_node() on itself resumes, once unblocked, still using the struct it read before ever trying to acquire the lock -- stale by exactly the transaction it was waiting on. ProceedGroupState()'s "already dropped, do nothing" checks compare against that stale goalState/reportedState and never fire. Execution falls through to ordinary FSM logic, where AutoFailoverNodeGroup()'s nodesCount -- a fresh SPI query, unaffected by the staleness -- correctly sees a one-node group (the dropped node's own row already excluded by its just-committed goalState = 'dropped'), and the nodesCount == 1 case reassigns the node's OWN goal to SINGLE: its own concurrent report undoes the drop it had just been given. This exactly reproduces the original CI log line for the node being dropped, "New state for this node ...: single -> single", instead of ever reaching "dropped -> dropped" -- which is why "pg_autoctl drop node" timed out waiting for a row that could never disappear. (concurrent_remove_standby_and_primary_report.spec, committed earlier this session, asked the same question about the PRIMARY's concurrent poll instead and ruled it out: the primary's decision depends only on the fresh nodesCount, not on any of its own stale fields, so it isn't susceptible to this. Its header comment is updated to point at this spec's result instead of leaving the "still open" note stale.) Fix: NodeActive() now re-reads the node after acquiring LockFormation()/LockNodeGroup(), mirroring the RemoveNode() fix -- same root defect (decide-before-lock instead of decide-after-lock), same remedy, second place it was hiding. Verified: all 10 REGRESS + all 3 ISOLATION specs pass via `make installcheck` against a fresh local instance. Docker-level re-verification of citus_nonha_operation.pgaf with this fix was attempted but the run was confounded by a transient, self-healing local Docker networking blip (a live TCP timeout connecting to the monitor, gone seconds later) unrelated to this fix, matching the same class of environmental flakiness flagged earlier this session before a Docker Desktop restart -- not treated as a real data point either way. The isolation-test reproduction above is deterministic and doesn't depend on Docker networking at all, which is why it's the basis for this fix rather than the Docker run.
…ess test Investigates the 6th CI failure: pytest/monitor PG16, test_003_002_stop_primary, "node3 failed to reach prepare_promotion or report_lsn after 90 seconds". Initial hypothesis was a BuildCandidateList() bug: a primary hard-killed via DataNode.fail() never reports its own demotion, so its reportedstate stays frozen at "primary" while only its goalstate advances to "demoted" via the monitor's own timeout. The "skip this node, it's a primary (old or new)" branch in BuildCandidateList() only excludes a node from the skip when its *reportedstate* (not goalstate) is draining/demoted, so a node frozen at reportedstate=primary/goalstate=demoted matches the skip and is dropped from missingNodesCount entirely -- suspected to let the sole remaining standby be promoted without real quorum. Added src/monitor/sql/stale_primary_report.sql to test this directly: manufacture two consecutive dead primaries in exactly that state (reportedstate frozen at primary, goalstate=demoted) and check whether the sole surviving standby gets incorrectly promoted. It does not: the separate quorumCandidateCount < minCandidates guard in ProceedGroupStateForMSFailover (minCandidates = number_sync_standbys + 1) still correctly blocks promotion regardless of the missingNodesCount bookkeeping gap. Kept as permanent regression coverage for this edge case. Rereading the actual pytest exception clarifies the real bug: node3 "failed to reach" report_lsn/prepare_promotion within 90 seconds -- it never reached further than expected, it was simply slow to get there. The monitor events log confirms the FSM did eventually reach the correct state (report_lsn -> prepare_promotion -> stop_replication -> wait_primary) after the pytest assertion had already timed out. This matches a timing budget problem, not a promotion-safety bug: reaching this point requires health-check detection of node2's death (node_considered_unhealthy_timeout, 20s default) plus a full primary_demote_timeout (30s default), and test_003_001 immediately before this test already drove node1 through the identical sequence, so a loaded CI runner can push the combined wait past the default 90s STATE_CHANGE_TIMEOUT. Bumped the three affected waits in test_003_002_stop_primary to timeout=120, matching the margin already used for the equivalent waits in test_005_001/test_005_002 elsewhere in this file. Locally reproduced via `make -C tests run-test PGVERSION=16 TEST=test_multi_alternate_primary_failures` (Docker, same as CI): both runs passed 15/15, consistent with this being a low-probability CI-only timing flake rather than a deterministic failure.
pgaftest indent already detects and strips a sequence{} block when it
exactly matches step declaration order (cli_indent.c: "Emit the sequence
block only when it differs from definition order... the block is
redundant noise; drop it"), and test_runner.c falls back to declaration
order whenever no sequence block is present at all. Most specs already
rely on this default and never write an explicit sequence.
Six specs still carried an explicit sequence block added when they were
authored, none of which was ever actually needed: in every case the listed
order is identical, step for step, to the step declaration order already
in the file. Verified with `pgaftest indent`, which independently confirms
each file's sequence is redundant and drops it when re-serializing.
Removed the redundant sequence{} block from:
- debug_citus_worker_switchover.pgaf
- debug_failover_pg19.pgaf
- drop_node_destroy.pgaf
- fast_forward.pgaf
- guard_data_loss.pgaf
- launch_deferred_set_metadata.pgaf
No behavior change: all six now rely on the same declaration-order default
already used elsewhere. Confirmed each file still parses cleanly via
`pgaftest indent` after the edit.
dimitri
changed the title
The tmux session was meant to have 3 panes (logs, watch, shell), with the
setup{} block running in the shell pane and closing/handing off once done.
Instead it had grown to 4: a "transient" setup pane plus a separate,
always-open shell pane.
The setup pane was never actually transient. cli_run_setup_only()
(cli_root.c) already execlp()s into bash once the setup block finishes --
by design, so the pane becomes an interactive shell without an extra
process layer. But test_runner.c also opened a second, independent shell
pane (docker compose run --rm --name <proj>-sh -it setup bash) right next
to it, so both the setup-turned-shell pane and the dedicated shell pane
ended up live at once: 4 panes instead of 3, with the setup pane
"becoming" a second interactive shell rather than closing.
Fixed by using a single bottom pane: when spec->setup is present, run
`pgaftest _setup_` (which execs into bash on completion); otherwise run
bash directly. Moved the --name <proj>-sh and -it flags onto this pane in
both cases, so `pgaftest cluster down`'s existing `docker rm -f <proj>-sh`
cleanup and stale-container precleaning still apply. Also cleaned up
several stale comments describing an old "sleep infinity" / always-up
pgaftest-service design that compose_gen.c no longer uses (the setup
service only ever runs via `docker compose run`, gated by the "setup"
compose profile).
Verified: rebuilds cleanly, citus_indent --check and ci/banned.h.sh both
pass. Simulated the pane lifecycle directly in tmux (sleep stand-ins for
logs/watch, "sleep; exec bash" stand-in for setup): confirms exactly 3
panes throughout, with the bottom pane transitioning from the setup
command into a live bash shell in place, never spawning a 4th pane.
`pgaftest step` (no args, auto-advance) and `pgaftest show steps` read
spec->sequence[]/sequenceLength directly from a freshly parse_test_spec()'d
TestSpec. But the "default to step declaration order when the file has no
explicit sequence{} block" fallback only existed inside runner_run()
(the CI `pgaftest run` code path) -- so for any spec without an explicit
sequence{} block, sequenceLength was 0 outside of that one path, and
`pgaftest step` immediately reported "All 0 steps completed" without
running anything.
This affects every spec that doesn't write an explicit sequence{} block:
most of tests/tap/specs/ already relied on the default, and the six specs
that still had a redundant explicit block (fixed in 42e07a4) were an
exception to this bug, not additional instances of it -- removing their
explicit blocks widened exposure to this same pre-existing bug rather than
introducing a new one.
Moved the fallback into parse_test_spec() itself (test_spec_parse.y), so
every caller -- `pgaftest step`, `pgaftest show steps`, `pgaftest indent`,
`pgaftest run` -- sees a consistently populated sequence[] right after
parsing, rather than duplicating (or missing) the same logic per call
site. Removed the now-redundant copy from runner_run().
cli_indent.c's redundancy check (drop the sequence{} block from output
when it matches declaration order) is unaffected: verified `pgaftest
indent` still emits no sequence{} block for auth.pgaf (never had one) and
guard_data_loss.pgaf / fast_forward.pgaf (recently had the redundant one
removed).
Verified: `pgaftest show steps tests/tap/specs/auth.pgaf` now lists all 5
steps (previously would have shown none). citus_indent --check and
ci/banned.h.sh both pass.
CI failure: pgaftest/citus-1 (PG17 and PG18), test_001_init_coordinator,
"timeout: conditions not met: coordinator1a=primary and
coordinator1b=secondary" after 90s -- deterministic on every run, not a
flake.
setup{} performed "exec coordinator1a pg_autoctl perform switchover" (plus
the same for worker1a and worker2a) before any named step ran. This
demotes whichever node is currently primary -- coordinator1a at that
point -- making coordinator1b the new primary. test_001_init_coordinator
then asserts the pre-switchover arrangement (coordinator1a=primary,
coordinator1b=secondary), which can never be true again once setup
completes: guaranteed timeout, not a race.
The predecessor test (tests/test_citus_force_failover.py) never calls
switchover at all -- confirmed by grep, zero matches. test_001_init_coordinator
there just registers the two coordinator nodes and asserts the natural
post-creation state (first-created node is primary). test_005_drop_primary_coordinator
further confirms this: it calls coordinator1a.drop() directly, which only
makes sense if coordinator1a is still the original, never-switched-over
primary at that point. The switchover-priming block in setup{} has no
corresponding step in the Python original -- it was almost certainly
copied from a different spec by mistake.
Removed the switchover exec/wait steps for coordinator1a, worker1a, and
worker2a from setup{}. setup now only brings the formation up to its
natural initial state (matching the Python predecessor), which is what
test_001/test_002 already assert.
Verified: `pgaftest indent` parses the file cleanly with no diff beyond
the removed block.
Continues the Bug 6 investigation (test_003_002_stop_primary, node3
promoted past report_lsn/prepare_promotion despite number_sync_standbys=1
requiring 2 quorum reporters). Two prior single-session attempts drove no
closer to a repro:
- stale_primary_report.sql manufactured the frozen-primary end state
directly via UPDATE (goalstate=demoted, reportedstate stuck at
primary). Correctly stayed blocked.
- A more faithful attempt (same session, not committed) drove every
transition through real node_active() calls instead of raw UPDATEs,
replicating the exact test_003_001+002 sequence: first primary
hard-killed, second node promoted through the genuine
report_lsn -> prepare_promotion -> stop_replication -> wait_primary
-> primary path, then the second primary also hard-killed. Also
correctly stayed blocked once the sole survivor confirmed report_lsn --
ruling out "the raw-UPDATE shortcut skipped some real-FSM side effect"
as the explanation.
This spec tests the one mechanism neither attempt touched:
SetNodeHealthState() (the health-check background worker's write path)
runs in its own SPI transaction with no LockFormation()/LockNodeGroup()
call at all -- unlike every other node-mutating entry point, including
NodeActive(). It is completely unsynchronized with FSM decision-making.
Verified via LockFormation/LockNodeGroup's actual implementation
(metadata.c) that they're advisory locks under custom lock-tag classoids
(ADV_LOCKTAG_CLASS_AUTO_FAILOVER_FORMATION/_NODE_GROUP), not reachable
from plain SQL pg_advisory_lock() -- and confirmed empirically that a
concurrent uncommitted UPDATE mimicking the health-check writer does NOT
block a concurrent node_active() call the way a real remove_node()/
node_active() race does (which is exactly why Bug C's fix used
LockNodeGroup as the deterministic blocking point, and exactly why the
same technique can't reach this specific race).
Concretely testable instead: node_active() calls for two different nodes
in the same group DO contend on LockNodeGroup(formationId, groupId).
This spec exploits that to test the dying second primary's own last
self-report ("I'm still primary", sent before it's actually killed but
after health-check already marked it unhealthy) racing the survivor's
routine report. Result: the self-report legitimately "resurrects" the
node (a real, successful report is reasonable evidence of liveness) and
no failover starts at all in that interleaving -- correct behavior, not
the bug, and not truly representative of the real scenario either (a
SIGKILL'd process sends no further reports).
Net result: the concurrency angle is real (SetNodeHealthState's
unsynchronized writes) but not reproducible through pg_isolation_regress's
standard lock-blocking technique, because there's no lock to block on.
Confirming or refuting it as Bug 6's actual mechanism needs either
temporary C-level instrumentation (a synchronization point added to
BuildCandidateList/ProceedGroupStateForMSFailover, or an artificial delay)
combined with many repeated Docker reproductions, or accepting this as an
open question pending a future targeted investigation.
Verified: all 11 REGRESS + all 4 ISOLATION specs pass via `make
installcheck` against a fresh local instance. citus_indent --check and
ci/banned.h.sh both pass (no C changes in this commit).
Root-caused by comparing lock discipline before and after d5a159b ("monitor: extract GroupStateContext + pure health predicates", origin/main), the commit the user pointed at for this investigation. Before d5a159b, ProceedGroupStateForMSFailover() fetched the group's node list itself, immediately before building candidates. That commit replaced this with a single upfront read: BuildGroupStateContext() (called once, at the top of ProceedGroupState()) fetches ctx->groupNodeList via AutoFailoverNodeGroup(), and every FSM decision downstream -- including BuildCandidateList()'s per-node skip/missing/candidate bookkeeping -- reads from that one cached snapshot instead of re-querying. But ProceedGroupStateFromContext() *also* calls GetPrimaryOrDemotedNodeInGroup() separately, moments later, to resolve primaryNode -- an independent, fresh AutoFailoverNodeGroup() read, not drawn from ctx->groupNodeList. NodeIsUnhealthy(primaryNode, ctx) at the outer MS-failover gate sees whatever is freshest as of that second read. BuildCandidateList()'s own per-node NodeIsUnhealthy() checks, inside ProceedGroupStateForMSFailover(ctx, primaryNode), are applied to ctx->groupNodeList's older copy of that same node. The refactor collapsed two adjacent, consistent reads into two reads separated by real elapsed time and unrelated FSM logic, and nothing closes that window. Nothing needed to: SetNodeHealthState() (the real health-check worker's write -- health, healthchecktime) took no LockFormation()/LockNodeGroup() at all, unlike NodeActive(), RemoveNode(), and every other node-mutating entry point. A health-check write marking the second primary unhealthy could commit in exactly that gap -- after ctx->groupNodeList was read, before BuildCandidateList() evaluates it -- leaving BuildCandidateList() to see a stale, still-"healthy primary" copy of a node that has, by the time the decision is actually made, already gone unhealthy. That stale copy falls through the "skip old/new primary" branch uncounted instead of being recognized as newly unhealthy and counted toward missingNodesCount, letting a single remaining standby look sufficient when number_sync_standbys requires two quorum reporters. This is the actual mechanism behind test_003_002_stop_primary's occasional PG16 CI failure (node3 promoted past report_lsn/ prepare_promotion), and explains why two earlier attempts this session to reproduce it via a single serial session -- stale_primary_report.sql (raw UPDATE) and concurrent_second_primary_death_report.spec (real node_active() calls throughout, no concurrency) -- both correctly stayed blocked: neither exercised genuine concurrency between the health-check write and an in-flight FSM evaluation, which is exactly what the bug needs. Fix: SetNodeHealthState() now takes LockFormation(ShareLock) + LockNodeGroup(ExclusiveLock) before writing, the same lock discipline already applied to RemoveNode() and NodeActive() earlier this session for the same class of defect (a writer that doesn't hold the lock a reader assumes is held). The pre-lock GetAutoFailoverNodeById() lookup only determines which lock to take (formationId/groupId are stable for an existing node); it makes no FSM decision. New testing-only SQL functions (not granted to autoctl_node): - pgautofailover.testing_lock_formation(formation_id) - pgautofailover.testing_lock_node_group(formation_id, group_id) Let an isolation test hold the monitor's own advisory locks directly from plain SQL, to construct deterministic blocking scenarios against any other lock-taking entry point without needing a second real FSM call in flight. - pgautofailover.testing_set_node_health(node_id, health, report_time_ago, state_change_time_ago, health_check_time_ago) Simulates a health-check-worker write and/or backdates timestamps (compressing UnhealthyTimeoutMs/DrainTimeoutMs into an instant) through the same lock discipline SetNodeHealthState() now uses, in one call -- replacing the raw multi-column UPDATE every earlier attempt in this investigation needed, and (unlike a raw UPDATE) actually exercising the fixed lock path so a test can prove it's in effect. New isolation test, concurrent_health_check_and_report.spec, proves the fix two ways: (1) a concurrent node_active() call for a different node in the same group now provably blocks behind testing_set_node_health() (the isolation tester's "<waiting ...>" marker) -- before the fix, a plain UPDATE simulating the same write did not block at all, confirmed empirically; (2) the full test_003_001 -> test_003_002 sequence (first primary killed, second promoted through the real report_lsn -> ... -> primary path, second primary then also killed via testing_set_node_health() racing the survivor's routine report) still ends with the sole survivor correctly stuck at report_lsn, exactly as number_sync_standbys=1 requires. Verified: all 11 REGRESS + all 5 ISOLATION specs pass via `make installcheck` against a fresh local instance. citus_indent --check and ci/banned.h.sh both pass.
…ints
Implements the two follow-ups agreed after the Bug 6 root-cause writeup:
a single internal lock-and-fetch entry point every SQL-callable function
should use, and the redundant-read cleanup in ProceedGroupStateFromContext.
## Unified lock-and-fetch API
Static audit of every SQL-callable entry point that locks
(LockFormation()/LockNodeGroup()) found six -- perform_promotion,
start_maintenance, stop_maintenance, set_node_candidate_priority,
set_node_replication_quorum, update_node_metadata -- reading a node
before locking and then using mutable fields of that same pre-lock
struct for decisions after locking: the identical defect shape already
fixed in RemoveNode()/NodeActive() (Bug C) and SetNodeHealthState()
(Bug 6), just not yet hit by a concrete reproducer.
Added LockNodeGroupAndFetch(nodeId) and
LockNodeGroupAndFetchByName(formationId, nodeName) (node_metadata.c/.h):
each resolves the node, acquires LockFormation(ShareLock) +
LockNodeGroup(ExclusiveLock), and returns a freshly re-read struct --
lock and fetch as one unit, so there is no longer a hand-rolled
"remember to re-fetch" step to forget. All six entry points migrated to
use it.
RemoveNode() and NodeActive() were deliberately NOT migrated:
RemoveNode() needs a formation-wide ExclusiveLock (it can affect
sync-standby bookkeeping across the whole formation), not the
ShareLock-formation + ExclusiveLock-nodegroup pair; NodeActive() needs
its pre-lock read to validate the caller-supplied formationId/groupId
over the wire before ever taking a lock, and locks on the caller-supplied
groupId rather than the row's own. Both are commented explaining why.
SetNodeHealthState() was migrated to LockNodeGroupAndFetch() (replacing
last commit's inline lock-only version) for consistency.
## Cleanup: redundant independent reads
GetPrimaryOrDemotedNodeInGroup() and GetPrimaryNodeInGroup() each split
into a pure, no-SPI *FromList() variant (operating on an already-fetched
List) plus a thin SPI-fetching wrapper for callers with no list in hand
(e.g. get_primary(), a standalone unlocked query).
Applied where a caller already holds a fetched list under its lock, with
no state-changing write in between (verified case by case -- two nearby
call sites, in set_node_candidate_priority/set_node_replication_quorum,
were deliberately left alone because they read the primary again
*after* their own ReportAutoFailoverNode* write, and correctly need
that fresher read):
- group_state_machine.c: ProceedGroupStateFromContext() now derives
primaryNode from ctx->groupNodeList (the exact double-read that
made Bug 6 possible when SetNodeHealthState() didn't yet share its
lock) instead of a second AutoFailoverNodeGroup() query.
- node_active_protocol.c: stop_maintenance() and
JoinAutoFailoverFormation() (register_node's group-join path)
likewise derive from their own already-fetched lists.
These were already safe once every writer shared the same lock (this
session's Bug 6 fix), but removing the redundant reads closes the door
on a future writer reintroducing the same risk by relying on one of them
instead of the shared list.
## Tests
lock_and_fetch_migration.sql (REGRESS): exercises the happy path for all
six migrated functions against a fresh 3-node formation -- perform_promotion
rejecting an already-primary target, set_node_candidate_priority's "≥2
non-zero candidates" NOTICE firing on fresh (not stale) counts,
set_node_replication_quorum's FormationNumSyncStandbyIsValid check,
update_node_metadata's rename, and a full start_maintenance/
stop_maintenance round trip. Only start_maintenance had any prior
coverage (node_active_protocol.sql, for an unrelated regression); the
other five had none.
concurrent_candidate_priority_and_quorum.spec (ISOLATION): proves the
fix with a genuine lost-update reproducer. set_node_replication_quorum()
writes ReportAutoFailoverNodeReplicationSetting(..., currentNode->
candidatePriority, ...) -- reasserting candidatePriority alongside the
new quorum setting. Session cp sets a node's candidatePriority 100->0 and
holds the lock; session rq (blocked behind it, confirmed via the
isolation tester's "<waiting ...>" marker) re-asserts the node's
replicationQuorum once unblocked. Before the fix, rq's pre-lock read
would have carried the stale candidatePriority=100 and silently reverted
cp's change on write. After the fix, the node ends with
candidatepriority=0 preserved.
Verified: all 12 REGRESS + all 6 ISOLATION specs pass via `make
installcheck` against a fresh local instance. citus_indent --check and
ci/banned.h.sh both pass.
test_003b_wait_keeper_restart restarts node1/node2/node3 containers after the documented v2.1 supervisor crash-and-give-up. If node1's container takes long enough to come back, it can cross the monitor's unhealthy/demote thresholds and lose the primary role to node2 before it reconnects as a secondary -- a legitimate failover, not a bug. test_004_wait_convergence and test_007_verify_data_intact both hardcoded "node1 state is primary and node2/node3 state is secondary", so this race made them fail whenever the swap actually happened in CI. Switch both to the existing role-agnostic "wait until primary, secondary, secondary in group 0" form (already used by the citus_*.pgaf specs for their own primary/secondary waits), which only asserts the shape of convergence -- exactly one primary, the other two secondary -- regardless of which node ends up holding which role. test_008_failover_post_upgrade's "promote node2" needs no change: perform promotion on an already-primary node is a documented no-op (NOTICE only), so it degrades gracefully whether node1 or node2 held the primary role going in.
concurrent_health_check_and_report.spec's setup{} block set
pgautofailover.startup_grace_period = 1 (session-local) expecting it to
suppress IsUnhealthy()'s PgStartTime-vs-StartupGracePeriodMs gate for the
whole test. But pg_isolation_regress gives every named session (s3, hc,
s2, s4) its own separate connection, and plain SET only affects the
connection that ran it -- setup{}'s. Session s2, where the actual proof
(s2_report / s2_report_again) runs, never saw the override and kept the
10s default.
Against a long-lived local dev postgres this was invisible: PgStartTime
was always many minutes in the past, so the gate was wide open regardless
of the grace-period value. Against a freshly initdb'd cluster -- exactly
what pg_virtualenv hands `make installcheck` inside the Docker build/CI --
postgres is only seconds old when this test runs, the 10s default gate
stays shut, crsp3_s1 never reads as unhealthy from s2's point of view, and
the race hc_mark_dead/s2_report exist to prove goes unexercised: crsp3_s2
sails past report_lsn to secondary instead of getting stuck there.
Verified by building the Docker "build" stage (which runs installcheck
against a fresh pg_virtualenv cluster, matching CI) both at HEAD and at
acc3a22 (the original SetNodeHealthState fix, before the later
LockNodeGroupAndFetch cleanup) -- both failed identically, ruling out the
intervening commits as the cause and confirming this is a pre-existing
test-design defect, not a regression.
Fix: add a new step, s2_set_grace, that re-issues the SET on session s2's
own connection before it touches crsp3_s1, alongside the existing setup{}
SET which still covers generation 1 (all on the setup connection).
Verified green across 3 consecutive from-scratch Docker builds.
CI (pgaftest / upgrade, PG16) failed at test_003_upgrade_monitor: ERROR: could not find function "testing_lock_formation" in file ".../pgautofailover.so" pgautofailover is loaded via shared_preload_libraries, so the running postmaster keeps the old .so mapped in memory even after install-extension overwrites the file on disk -- new backends forked from it still see the pre-restart library image. The step ran "ALTER EXTENSION ... UPDATE TO '2.2'" *before* restarting the monitor container, so the upgrade script's CREATE FUNCTION statements were validated (dlsym'd) against the still-old, already-loaded library. testing_lock_formation/testing_lock_node_group/ testing_set_node_health are new in this branch with no v2.1 equivalent, so their symbols genuinely don't exist there yet -- unlike a plain function redefinition, which would resolve fine against an already-loaded library since the symbol predates the upgrade. Fix: reorder test_003_upgrade_monitor so the monitor restart (compose stop + start) happens before ALTER EXTENSION UPDATE, not after. That makes the new postmaster load the next pgautofailover.so (already staged on disk by install-extension) via shared_preload_libraries, so the upgrade script's new symbols resolve normally. The monitor's healthcheck (pg_autoctl status) makes "compose start" block until pg_autoctl itself reports running, but that can fire slightly before postgres finishes its own restart -- reproduced locally as "the database system is starting up" from the immediately-following psql call. Added a pg_isready retry loop (30x1s) right after the restart to close that last race window before running ALTER EXTENSION. Verified locally: built pgaf:next/pgaf:current for PG16 and ran `pgaftest run tests/tap/specs/upgrade.pgaf` end to end twice in a row, all 10 steps green both times (previously failed at step 3 on every run).
Replace the hand-rolled "for i in $(seq 1 30); do pg_isready ...; done" shell polling loop (added in f014b44 to close the race between the monitor's healthcheck returning and postgres actually finishing its restart) with the project's own native primitive for the same job: "pg_autoctl inspect pgsetup wait --read-write --timeout N". It implements the identical retry-with-timeout semantics without reaching outside the project for a shell construct. Verified locally: rebuilt pgaf:next/pgaf:current for PG16 and ran `pgaftest run tests/tap/specs/upgrade.pgaf` twice in a row, all 10 steps green both times.
Root-caused the pytest/monitor PG14 CI flake in
test_multi_alternate_primary_failures.py::test_003_002_stop_primary.
Confirmed via bisection that this is a real, pre-existing race condition,
not a regression from this branch's own work:
- Reproduced the exact CI failure locally (node3 races straight through
report_lsn -> prepare_promotion -> stop_replication -> wait_primary
instead of correctly stalling at report_lsn).
- Verified the same race reproduces identically against a pure,
unmodified origin/main checkout (56bf6d6) in an isolated worktree --
ruling out anything introduced by Bug 6, Bug A, Bug C, or the
LockNodeGroupAndFetch unification earlier in this branch's history.
- Bisected acc3a22 and dc006c3 in separate worktrees: both pass cleanly,
as does a fresh run of our own branch HEAD with the unmodified test --
confirming this is genuinely non-deterministic (timing-dependent)
rather than tied to any single commit.
Root cause: pg_autoctl's graceful shutdown reporting
(keeper_node_active_shutdown_loop(), added in #1146, on origin/main since
2026-07-13) makes the node-active service keep calling the full
node_active() protocol every second for up to 30s after SIGTERM, racing
against how long PostgreSQL's own shutdown checkpoint takes to complete.
test_003_002_stop_primary is the only scenario in this file where node3 is
the *sole* surviving standby when node2 fails (node1 is already dead from
test_003_001), so it depends on node2 never being able to report anything
again. If node2's shutdown loop manages to confirm "draining" (both goal
and reported state) before PostgreSQL actually stops,
BuildCandidateList()'s "skip old/new primary unless draining/demoted"
exemption stops excluding it, letting it contribute a second quorum
report alongside node3 -- satisfying number_sync_standbys=1's
minCandidates=2 and promoting node3 immediately instead of leaving it
correctly stuck at report_lsn until node2 restarts. Whether this happens
depends entirely on how long the checkpoint takes on a given run, which
is exactly the kind of thing that varies under CI load.
Fix: thread an optional `sig` parameter through PGAutoCtl.stop() ->
DataNode.stop_pg_autoctl() -> DataNode.fail() (default stays
signal.SIGTERM, so all 36 other .fail() call sites across the suite are
unaffected), and use node2.fail(sig=signal.SIGINT) in this one test.
SIGINT (asked_to_stop_fast) makes the node-active service skip the
shutdown loop and exit immediately, matching what fail() is meant to
simulate -- an abrupt crash, not a graceful operator-initiated stop.
Verified: 3 consecutive full runs of test_multi_alternate_primary_failures.py
against PG14 in Docker, all 15 tests passing every time (previously
flaky/non-deterministic at test_003_002).
dimitri
added
bug
This was referenced Jul 21, 2026
dimitri
added a commit
that referenced
this pull request
Jul 27, 2026
) (#1171) perform_failover() on the monitor takes the same LockFormation()/ LockNodeGroup() advisory locks every other node-mutating entry point does, so it can hit a genuine Postgres deadlock racing a concurrent node_active()/health-check write -- exactly the SQLSTATE 40P01 signature reported in #1004: ERROR Monitor ERROR: deadlock detected ERROR Monitor Process ... waits for ExclusiveLock on advisory lock ERROR Monitor CONTEXT: while updating tuple ... in relation "node" ERROR SQL query: SELECT pgautofailover.perform_failover($1, $2) FATAL Failed to perform failover/switchover, see above for details pg_autoctl has had a retry policy for exactly this class of transient error since 2020 (monitor_retryable_error(), covering deadlock_detected, serialization_failure, and a few others) -- monitor_start_maintenance, monitor_stop_maintenance, and monitor_register_node all use it. But monitor_perform_failover() and monitor_perform_failover_allow_data_loss() were never wired into it: both just ran their query once and failed the whole command on any error, deadlock or not. That gap is why #1004's `pg_autoctl perform switchover` failed outright on the first deadlock instead of retrying -- confirmed still present by reading current `main`, not just historical. (The lock-ordering root cause of the deadlock itself is a separate, already-fixed story: PR #1150 unified every node-mutating SQL function onto a single LockNodeGroupAndFetch() helper with a consistent lock order, closing that class of AB-BA deadlock -- just without referencing #1004, so it never got linked back to this issue.) Fix: both monitor_perform_failover() and monitor_perform_failover_allow_data_loss() now take a `bool *mayRetry` out-parameter, following the exact convention already used by start/stop_maintenance -- set it and return false when monitor_retryable_error() says the failure is transient, so the caller can retry rather than treating it as fatal. cli_perform.c's cli_perform_failover() (backing both `pg_autoctl perform failover` and `perform switchover`) now wraps the call in the same ConnectionRetryPolicy loop enable/disable maintenance already use. demoapp.c's own call site is updated for the new signature (it already retries on its own schedule via its outer loop, so no behavior change there). Verified: clean build, citus_indent clean, banned.h.sh clean, and a full Docker run of basic_operation.pgaf (27/27, including test_020_multiple_manual_failover_verify_replication_slots which exercises perform_failover directly) confirms no regression to the normal, non-deadlock path.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Continues
pgaftest(the Docker-based DSL test runner merged in #1137) withnew runner functionality and DSL commands, and bundles a set of
monitor/pg_autoctl correctness fixes found while using the tool to
reproduce and diagnose flaky/failing CI runs. Also migrates most of the
Python test suite to
.pgafspecs and rewrites the pgaftest docs.pgaftest tool
dockeruser,sudo, andentrypoint.sh; run the setup container as root so the Docker-socketbind mount works without GID-matching games on macOS/CI
docker exec monitor pg_autoctl ...round-trips with direct calls over the existing LISTEN connection(
monitor_get_node_state,runner_promote_one, newrunner_perform_failover,exec_sql_on_service)perform failoverDSL command (untargeted failover; monitorpicks the best secondary), distinct from
promote nodeXcluster/tmuxsubcommands,show state|step,pgaftest indent(canonical spec formatter, plus a couple of realformatting-corruption fixes in it),
helpteardown for the setup container, periodic SQL poll inside the LISTEN
loop, fixed
tmuxopening a redundant 4th pane, fixedpgaftest step/show stepsreporting "All 0 steps completed" when a spec has noexplicit
sequence{}blockMonitor / pg_autoctl fixes found via pgaftest
Several of these came directly out of using pgaftest/pytest to chase down
CI flakes:
NodeActive()/RemoveNode()stale-read races — newconcurrent_remove_node/concurrent_remove_standby_and_*isolationsuite added to reproduce and pin down the race, then fixed
SetNodeHealthState()racing theGroupStateContextrefactor: thereal health-check-worker write path took no lock at all, unlike every
other node-mutating entry point, so a health-check write marking a node
unhealthy could land in the exact window between
BuildGroupStateContext()caching the group's node list and
BuildCandidateList()evaluating it —letting a stale "still healthy" copy of a just-turned-unhealthy primary
fall through uncounted. Fixed by giving
SetNodeHealthState()the sameLockFormation()/LockNodeGroup()discipline every other writer alreadyhas. Proved two ways: a new
testing_lock_node_group()/testing_set_node_health()pair of testing-only SQL functions that let anisolation test hold the exact locks a real writer would, and a full
concurrent_health_check_and_reportisolation spec driving the realreport_lsn → prepare_promotion → stop_replicationsequence with aconcurrent health-check write racing a routine report.
LockNodeGroupAndFetch()/LockNodeGroupAndFetchByName()API:a static audit of every SQL-callable entry point that locks found six more
(
perform_promotion,start_maintenance,stop_maintenance,set_node_candidate_priority,set_node_replication_quorum,update_node_metadata) with the identical read-before-lock defect shape asthe bugs above, just not yet hit by a concrete reproducer. All six migrated
to the new shared lock-and-fetch helper. Also removed two now-redundant
independent re-reads (
GetPrimaryOrDemotedNodeInGroup/GetPrimaryNodeInGroupsplit into pure*FromList()+ thin SPI wrapper)where a caller already held a fetched list under its own lock.
coordinator_update_node_preparecurrent_statecolumn-count guard fixed (16, not 17)lock_timeout/statement_timeoutset beforemaster_update_nodewaitpid()afterpg_ctl stopto reap the postgres zombieenable maintenance --allow-failoverkeeper_pg_init: init the monitor connection before checking whetherthe node was dropped
New regression/isolation coverage for these:
src/monitor/sql/drop_node.sql,src/monitor/sql/stale_primary_report.sql,src/monitor/sql/lock_and_fetch_migration.sql, and five new isolation specs(
concurrent_remove_node,concurrent_remove_standby_and_primary_report,concurrent_remove_standby_and_standby_report,concurrent_health_check_and_report,concurrent_candidate_priority_and_quorum), all passing locally(12/12 REGRESS, 6/6 ISOLATION).
Upgrade test (
tests/tap/specs/upgrade.pgaf) fixesThree separate, real bugs found while getting this spec to pass reliably:
ALTER EXTENSION ... UPDATEordering:pgautofailoverloads viashared_preload_libraries, so the running postmaster keeps the old.somapped in memory even after the new one is staged on disk — the monitor
restart (
compose stop/start) now happens beforeALTER EXTENSION ... UPDATE, not after, so brand-new C symbols in theupgrade script (e.g. the new
testing_*functions above) actually resolve.A
pg_autoctl inspect pgsetup wait --read-writecall closes the remainingshort race where the healthcheck reports the process up slightly before
Postgres itself finishes restarting.
dance this test exercises can legitimately swap which node ends up primary
depending on exact container-restart timing; the test's convergence
assertions now check "exactly one primary, two secondaries" instead of
hardcoding which node it is.
startup_grace_periodisolation-tester scoping: a spec'ssetup{}block ran on its own connection and set
pgautofailover.startup_grace_periodsession-locally, but
pg_isolation_regressgives every named session itsown separate connection — the override never reached the session that
actually needed it. Fixed by setting it on the session that needs it.
Test spec migration
tests/tap/specs/*.pgafpromote nodeX(targetsnodeX) was being confused with
perform switchover(hands off fromthe current primary) — corrected throughout
basic_citus_operation.pgaf,citus_nonha_operation.pgaf)sequence{}blocks from 6 specs where theorder already matched step-declaration order (the tool's default)
citus_force_failover.pgaf: removed a spurious switchover-priming blockleft over in
setup{}that was causing PG17/PG18 failuresThe flake was a real race, not a timing issue
An earlier iteration of this PR bumped
test_003_002_stop_primary's timeout(90s → 120s), attributing the flake to a timing budget issue. Chasing a
fresh PG14 CI failure found the real cause:
keeper_node_active_shutdown_loop()(#1146, already on
main) makes a node keep participating in real FSMtransitions for up to 30s after SIGTERM while Postgres's own shutdown
checkpoint completes. This test is the one scenario in the file where node3
is the sole surviving standby when node2 fails, so it depends on node2
never being able to report anything again — if node2's shutdown loop manages
to confirm
drainingbefore Postgres actually stops,BuildCandidateList()'s "skip old/new primary unless draining/demoted"exemption stops excluding it, letting it contribute a second quorum report
and promoting node3 immediately instead of leaving it correctly stuck at
report_lsn. Confirmed via bisection (including against a clean,unmodified
origin/maincheckout) that this is a genuine pre-existing race,not a regression introduced by this branch. Fixed at the test level: an
optional
sigparameter threaded throughPGAutoCtl.stop()→.fail()(default unchanged, so the other 36.fail()call sites acrossthe suite are unaffected), with this one test using
node2.fail(sig=signal.SIGINT)to simulate a true hard crash instead of agraceful stop. Verified deterministic across multiple full local runs.
A design doc for a deeper, product-level fix (route a primary's graceful
SIGTERM shutdown through the existing
maintenanceFSM path, so a nodestops being a failover candidate immediately instead of relying on
timing) is written up for a follow-up PR — out of scope here.
Docs
Rewrote
docs/ref/pgaftest.rst, addeddocs/testing.rstanddocs/reporting-bugs.rst, expanded the pgaftestREADME.md.Testing
basic_operation.pgaf27/27 PASS,multi_standbys.pgaf27/27 PASSsrc/monitorregression + isolation suites: 12/12 + 6/6 PASS locallytest_multi_alternate_primary_failures.pyreproduced locally viamake run-test(Docker, matches CI) — 15/15 PASS across 3 consecutiveruns (previously non-deterministic)
tests/tap/specs/upgrade.pgafreproduced locally viapgaftest runagainst PG16 — 10/10 PASS across 2 consecutive runs
versions ×6 groups, pgaftest ×6 PG versions ×6+ groups, upgrade)
citus_indent --check) and banned-API check(
ci/banned.h.sh) both cleanFollow-up
PR #1149 (issue #997 monitor stall fix) will be rebased on top of this
once merged. A design doc for routing a primary's graceful shutdown through
the
maintenanceFSM path (see above) is ready for a separate follow-up PR.Note on diff size
A large share of the reported diff (~3,600 lines, ~34%) is the
bison/flex-generated
test_spec_parse.c/.handtest_spec_scan.c, whichfully regenerate — including internal line/state numbering — from small
edits to the 51-line
test_spec_parse.ygrammar and 6-linetest_spec_scan.llexer. These are committed so the tool builds withoutbison/flex installed; the actual hand-written diff is much smaller than
the raw line count suggests.