chore(wolf): session trail + xce-test-ha cross-run collision guard

run-ha-soak.sh: scope every pgrep/pkill to this run's --workdir, not just
binary name + --myname. An unscoped pkill -9 -x xce_controller (old
cleanup()) killed every xce_controller on the machine, including a
different concurrently-running soak's live primary — root cause of the
first bug-1436 misdiagnosis (a killed-out-from-under-it primary produced
a genuine, correctly-reported ECONNRESET that looked like a libxce bug).

.wolf/*: anatomy/cerebrum/buglog updated for bug-1435/1436, session and
token-ledger trail.
This commit is contained in:
Rongsong Shen 2026-07-13 07:19:00 +00:00
parent 40c2351578
commit b3219635b5
7 changed files with 2415 additions and 41 deletions

View file

@ -180,17 +180,44 @@ FACTSTREAM_ALL_JOBIDS=() # every jobid ever driven through the fact stream, acro
log() { echo "[xce-test-ha] $*"; } log() { echo "[xce-test-ha] $*"; }
fail() { echo "[xce-test-ha] FAIL: $*" >&2; cleanup; exit 1; } fail() { echo "[xce-test-ha] FAIL: $*" >&2; cleanup; exit 1; }
cleanup() { pkill -9 -x xce_controller 2>/dev/null; sleep 0.3; } # ── Cross-run collision guard (bug-1436) ─────────────────────────────────────
# Every pgrep/pkill in this script MUST be scoped to THIS run's own --workdir,
# not just the binary name / --myname. Two run-ha-soak.sh invocations (e.g. a
# sequential and a chaotic soak, or two soaks in different deploy dirs) share
# the same xce_controller binary and the same hardcoded ctrl-1/ctrl-2/ctrl-3
# node names — pgrep/pkill matched on binary name or "--myname ctrl-N" alone
# cannot tell them apart. An unscoped `pkill -9 -x xce_controller` (the old
# cleanup(), called unconditionally at the START of every deploy, at every
# EXIT/INT/TERM via the trap, and on every fail()) kills EVERY xce_controller
# process on the machine — including a DIFFERENT run's live, healthy,
# freshly-elected primary. Root cause of bug-1436: a second soak's cleanup/
# deploy step fired while an earlier soak's round was mid-verify, silently
# SIGKILLing the primary the earlier run's `wait-primary` had just confirmed
# moments before — the client's very next request then hit a genuine,
# correctly-reported ECONNRESET (the process was really gone), not a libxce or
# controller defect. `--workdir "$TOP/controller"` is present in every node's
# argv (see start_node) and is unique per deploy dir, so scoping every match to
# it makes each run's process lifecycle fully independent of any other
# concurrently-running invocation (same or different deploy dir, same node
# names). Two runs sharing a deploy dir AND therefore the same ports
# (9991-9993) still cannot usefully coexist — the second run's start_node will
# fail loudly with a bind error instead of silently killing the first run's
# cluster, which is the correct "fail loud, not silently corrupt" behavior.
node_pattern() { echo "xce_controller --myname $1 .*--workdir $TOP/controller"; }
run_pattern() { echo "xce_controller .*--workdir $TOP/controller"; }
cleanup() { pkill -9 -f -- "$(run_pattern)" 2>/dev/null; sleep 0.3; }
# Record that a node has acted as primary at least once (leadership-coverage # Record that a node has acted as primary at least once (leadership-coverage
# tracking — the run asserts all three nodes lead, see the verdict). # tracking — the run asserts all three nodes lead, see the verdict).
record_primary() { [ -n "$1" ] && SEEN_PRIMARY["$1"]=1; } record_primary() { [ -n "$1" ] && SEEN_PRIMARY["$1"]=1; }
# kill -9 a controller by node name. Match on BINARY + --myname so the pattern # kill -9 a controller by node name. Match on BINARY + --myname + --workdir so
# cannot hit this driver's own shell snapshot (its argv carries "--myname ctrl-N"). # the pattern cannot hit this driver's own shell snapshot NOR a different
# run-ha-soak.sh invocation's same-named node (bug-1436).
kill_node() { kill_node() {
local node="$1" pid local node="$1" pid
pid="$(pgrep -f -- "xce_controller --myname $node ")" pid="$(pgrep -f -- "$(node_pattern "$node")")"
[ -n "$pid" ] || return 1 [ -n "$pid" ] || return 1
kill -9 $pid 2>/dev/null kill -9 $pid 2>/dev/null
return 0 return 0
@ -221,7 +248,7 @@ start_node() {
# on the same --myname/port without ever killing the first. Guard here # on the same --myname/port without ever killing the first. Guard here
# (not by "fixing" DOWN's bookkeeping) so every call site is covered: # (not by "fixing" DOWN's bookkeeping) so every call site is covered:
# refuse to launch a duplicate if one is already running. # refuse to launch a duplicate if one is already running.
if [ -n "$(pgrep -f -- "xce_controller --myname $1 ")" ]; then if [ -n "$(pgrep -f -- "$(node_pattern "$1")")" ]; then
log "start_node: $1 already running — skipping duplicate launch (bug-1418)" log "start_node: $1 already running — skipping duplicate launch (bug-1418)"
return 0 return 0
fi fi
@ -435,7 +462,7 @@ wait_for_full_convergence() {
local i alive stable=0 local i alive stable=0
local STABLE_TICKS=2 # 2 consecutive converged probes ⇒ settled local STABLE_TICKS=2 # 2 consecutive converged probes ⇒ settled
for i in $(seq 1 30); do for i in $(seq 1 30); do
alive="$(pgrep -c -f -- "xce_controller --myname ctrl-")" alive="$(pgrep -c -f -- "$(run_pattern)")"
if [ "$alive" -lt 3 ]; then if [ "$alive" -lt 3 ]; then
stable=0; sleep 2; continue stable=0; sleep 2; continue
fi fi
@ -754,7 +781,7 @@ run_chaotic_rounds() {
submit_jobs "$NJOBS" || log "round $round: submit shortfall (transient — not a loss)" submit_jobs "$NJOBS" || log "round $round: submit shortfall (transient — not a loss)"
# Kill the current primary, landing inside the next election window. # Kill the current primary, landing inside the next election window.
pid="$(pgrep -f -- "xce_controller --myname $PRIMARY ")" pid="$(pgrep -f -- "$(node_pattern "$PRIMARY")")"
if [ -n "$pid" ]; then if [ -n "$pid" ]; then
log "round $round: killing primary $PRIMARY (term=$PREV_TERM, pid=$(echo $pid | tr '\n' ' '))" log "round $round: killing primary $PRIMARY (term=$PREV_TERM, pid=$(echo $pid | tr '\n' ' '))"
kill -9 $pid 2>/dev/null kill -9 $pid 2>/dev/null
@ -1357,11 +1384,12 @@ for round in $(seq 1 "$ROUNDS"); do
PREV_TERM="$(latest_primary_term)" PREV_TERM="$(latest_primary_term)"
PREV_TERM="${PREV_TERM:-0}" PREV_TERM="${PREV_TERM:-0}"
# Step 6: kill the current primary. Match on the BINARY + --myname so the # Step 6: kill the current primary. Match on the BINARY + --myname + --workdir
# pattern cannot also hit this driver's own shell snapshot (which carries the # so the pattern cannot also hit this driver's own shell snapshot (which
# "--myname ctrl-N" substring in its argv and would otherwise be matched by a # carries the "--myname ctrl-N" substring in its argv and would otherwise be
# bare `pgrep -f -- "--myname ctrl-N"`, returning extra PIDs). # matched by a bare `pgrep -f -- "--myname ctrl-N"`, returning extra PIDs)
PID="$(pgrep -f -- "xce_controller --myname $PRIMARY ")" # NOR a different run-ha-soak.sh invocation's same-named node (bug-1436).
PID="$(pgrep -f -- "$(node_pattern "$PRIMARY")")"
[ -n "$PID" ] || fail "round $round: could not find pid for $PRIMARY" [ -n "$PID" ] || fail "round $round: could not find pid for $PRIMARY"
log "round $round: killing primary $PRIMARY (term=$PREV_TERM, pid=$(echo $PID | tr '\n' ' '))" log "round $round: killing primary $PRIMARY (term=$PREV_TERM, pid=$(echo $PID | tr '\n' ' '))"
kill -9 $PID 2>/dev/null kill -9 $PID 2>/dev/null

View file

@ -1,7 +1,14 @@
# anatomy.md # anatomy.md
> Auto-maintained by OpenWolf. Last scanned: 2026-07-11T13:58:37.442Z > Auto-maintained by OpenWolf. Last scanned: 2026-07-12T16:47:48.239Z
> Files: 637 tracked | Anatomy hits: 0 | Misses: 0 > Files: 643 tracked | Anatomy hits: 0 | Misses: 0
## ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/00c9b3f1-df3c-4ce0-a997-5c6a316be4ec/scratchpad/
- `hammer.sh` — Tight repro loop for bug-1436: hammer verify_no_loss-style REPL sessions (~570 tok)
- `hammer2.sh` — Tight repro loop v2 for bug-1436: hammer verify_no_loss-style REPL sessions (~807 tok)
- `hammer3.sh` — Tight repro loop v3 for bug-1436: test the LARGE-PAYLOAD hypothesis. (~975 tok)
- `run-chaotic-soak.sh` (~61 tok)
## ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/5e55cf26-d05d-4a2e-8196-d2c70e0c063c/scratchpad/ ## ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/5e55cf26-d05d-4a2e-8196-d2c70e0c063c/scratchpad/
@ -247,7 +254,7 @@
## .claude/skills/xce-test-ha/ ## .claude/skills/xce-test-ha/
- `run-ha-soak.sh` — run-ha-soak.sh — driver for /xce-test-ha: deploy a 3-node XCE HA cluster, then (~19673 tok) - `run-ha-soak.sh` — driver for /xce-test-ha: deploy a 3-node XCE HA cluster, then repeatedly kill/restart/verify. bug-1436 fix (2026-07-12): all pgrep/pkill process-matching scoped to this run's own --workdir via node_pattern()/run_pattern(), so one invocation can never kill a different invocation's cluster (~21600 tok)
- `SKILL.md` — XCE HA Failover Soak Test (~5002 tok) - `SKILL.md` — XCE HA Failover Soak Test (~5002 tok)
- `soak-verdict-selftest.sh` — soak-verdict-selftest.sh — deterministic unit test for the verdict parser in (~1857 tok) - `soak-verdict-selftest.sh` — soak-verdict-selftest.sh — deterministic unit test for the verdict parser in (~1857 tok)
- `soak-verdict.sh` — soak-verdict.sh — pure (side-effect-free) verdict helpers for run-ha-soak.sh. (~1383 tok) - `soak-verdict.sh` — soak-verdict.sh — pure (side-effect-free) verdict helpers for run-ha-soak.sh. (~1383 tok)
@ -943,13 +950,13 @@
## src/controller/ ## src/controller/
- `CLAUDE.md` — XCE Controller (~3373 tok) - `CLAUDE.md` — XCE Controller (~3373 tok)
- `cluster.c` — include "config.h" (~18444 tok) - `cluster.c` — include "config.h" (~18669 tok)
- `commit.c` — Declares is (~12825 tok) - `commit.c` — Declares is (~12825 tok)
- `config_repl.c` — define _GNU_SOURCE (~30643 tok) - `config_repl.c` — define _GNU_SOURCE (~30643 tok)
- `config_repl.h` — pragma once (~6155 tok) - `config_repl.h` — pragma once (~6155 tok)
- `ha_convergence.c` — Declares char (~5779 tok) - `ha_convergence.c` — Declares char (~5779 tok)
- `ha.c` — define _GNU_SOURCE (~109219 tok) - `ha.c` — define _GNU_SOURCE (~110421 tok)
- `ha.h` — ifndef HA_H (~27080 tok) - `ha.h` — ifndef HA_H (~27638 tok)
- `job.c` — include <errno.h> (~18619 tok) - `job.c` — include <errno.h> (~18619 tok)
- `join.c` — include "config.h" (~2795 tok) - `join.c` — include "config.h" (~2795 tok)
- `main.c` — include <argp.h> (~3035 tok) - `main.c` — include <argp.h> (~3035 tok)
@ -1021,6 +1028,8 @@
## src/lib/ ## src/lib/
- `client_internal.h` — if !defined(_CLIENT_INTERNAL_H_) (~4475 tok)
- `client.c` — include <errno.h> (~6767 tok)
- `delay.c` — include <errno.h> (~1520 tok) - `delay.c` — include <errno.h> (~1520 tok)
- `jobj.c` — include <errno.h> (~4867 tok) - `jobj.c` — include <errno.h> (~4867 tok)
- `meson.build` (~1643 tok) - `meson.build` (~1643 tok)

File diff suppressed because one or more lines are too long

File diff suppressed because one or more lines are too long

View file

@ -1,21 +1,12 @@
{ {
"session_id": "session-2026-07-11-0654", "session_id": "session-2026-07-13-0012",
"started": "2026-07-11T13:54:32.676Z", "started": "2026-07-13T07:12:53.464Z",
"files_read": {}, "files_read": {},
"files_written": [ "files_written": [],
{ "edit_counts": {},
"file": "/home/rshen/projects/xce/worktrees/raft_tla/.kiro/specs/ha-elect-ctx-lifecycle/tasks.md",
"action": "edit",
"tokens": 117,
"at": "2026-07-11T13:58:37.453Z"
}
],
"edit_counts": {
".kiro/specs/ha-elect-ctx-lifecycle/tasks.md": 1
},
"anatomy_hits": 0, "anatomy_hits": 0,
"anatomy_misses": 0, "anatomy_misses": 0,
"repeated_reads_warned": 0, "repeated_reads_warned": 0,
"cerebrum_warnings": 0, "cerebrum_warnings": 0,
"stop_count": 3 "stop_count": 1
} }

View file

@ -4440,3 +4440,55 @@
| 06:58 | Edited .kiro/specs/ha-elect-ctx-lifecycle/tasks.md | 5→5 lines | ~109 | | 06:58 | Edited .kiro/specs/ha-elect-ctx-lifecycle/tasks.md | 5→5 lines | ~109 |
| 06:58 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok | | 06:58 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok |
| 21:23 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok | | 21:23 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok |
| 21:26 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok |
| 21:28 | Session end: 1 writes across 1 files (tasks.md) | 0 reads | ~117 tok |
| 21:31 | Session end: 1 writes across 1 files (tasks.md) | 1 reads | ~117 tok |
| 21:50 | Session end: 1 writes across 1 files (tasks.md) | 4 reads | ~19790 tok |
| 02:49 | Session end: 1 writes across 1 files (tasks.md) | 4 reads | ~19790 tok |
| 03:08 | Edited src/controller/ha.h | modified 1435() | ~533 |
| 03:08 | Edited src/controller/ha.c | 1→4 lines | ~66 |
| 03:08 | Edited src/controller/ha.c | 2→3 lines | ~32 |
| 03:09 | Edited src/controller/ha.c | expanded (+18 lines) | ~400 |
| 03:09 | Edited src/controller/ha.c | 8→12 lines | ~96 |
| 03:09 | Edited src/controller/ha.c | modified raft_election_start_vtask_entry() | ~104 |
| 03:09 | Edited src/controller/ha.c | 18→22 lines | ~192 |
| 03:10 | Edited src/controller/ha.c | 3→8 lines | ~142 |
| 03:10 | Edited src/controller/ha.c | 4→8 lines | ~143 |
| 03:11 | Edited src/controller/ha.c | expanded (+13 lines) | ~276 |
| 03:11 | Edited src/controller/ha.h | modified PTHREAD_MUTEX_RECURSIVE() | ~153 |
| 03:12 | Edited src/controller/ha.c | 3→8 lines | ~125 |
| 03:12 | Edited src/controller/ha.c | modified pre_vote_reply_dispatch() | ~179 |
| 03:13 | Edited src/controller/ha.c | expanded (+7 lines) | ~147 |
| 03:13 | Edited src/controller/cluster.c | modified if() | ~200 |
| 03:14 | Edited src/controller/cluster.c | expanded (+6 lines) | ~187 |
| 03:19 | bug-1435 FIXED: raft_state_t data race (concurrent pool-dispatched vote-reply processing flips PRIMARY back to STANDBY mid-election) — added ha->raft_lock (RECURSIVE mutex) around 12 raft_state_t entry points in ha.c/cluster.c; build clean, controller_unit_test Ok:1 Fail:0; buglog.json + cerebrum.md updated | src/controller/ha.c, ha.h, cluster.c, .wolf/buglog.json, .wolf/cerebrum.md | done, not yet live-soaked | ~28000 |
| 03:21 | Session end: 17 writes across 4 files (tasks.md, ha.h, ha.c, cluster.c) | 12 reads | ~277854 tok |
| 03:57 | Session end: 17 writes across 4 files (tasks.md, ha.h, ha.c, cluster.c) | 13 reads | ~277854 tok |
| 07:14 | Session end: 17 writes across 4 files (tasks.md, ha.h, ha.c, cluster.c) | 13 reads | ~277854 tok |
| 07:43 | Edited .claude/skills/xce-test-ha/run-ha-soak.sh | modified log() | ~707 |
| 07:43 | Edited .claude/skills/xce-test-ha/run-ha-soak.sh | 4→4 lines | ~45 |
| 07:43 | Edited .claude/skills/xce-test-ha/run-ha-soak.sh | inline fix | ~14 |
| 07:43 | Edited .claude/skills/xce-test-ha/run-ha-soak.sh | 2→2 lines | ~36 |
| 07:43 | Edited .claude/skills/xce-test-ha/run-ha-soak.sh | 5→6 lines | ~121 |
| 07:45 | bug-1436 root-caused via controller-log archaeology: NOT a product bug — run-ha-soak.sh's unscoped pgrep/pkill let a second concurrent soak invocation SIGKILL the first run's live primary right after wait-primary confirmed it | .claude/skills/xce-test-ha/run-ha-soak.sh, .wolf/buglog.json, .wolf/cerebrum.md | fixed: scoped all process matches to --workdir | ~large |
| 07:58 | Session end: 22 writes across 5 files (tasks.md, ha.h, ha.c, cluster.c, run-ha-soak.sh) | 23 reads | ~308403 tok |
| 08:10 | Session end: 22 writes across 5 files (tasks.md, ha.h, ha.c, cluster.c, run-ha-soak.sh) | 23 reads | ~308403 tok |
| 08:40 | Created ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/00c9b3f1-df3c-4ce0-a997-5c6a316be4ec/scratchpad/hammer.sh | — | ~570 |
| 08:41 | Created ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/00c9b3f1-df3c-4ce0-a997-5c6a316be4ec/scratchpad/hammer2.sh | — | ~807 |
| 08:51 | Created ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/00c9b3f1-df3c-4ce0-a997-5c6a316be4ec/scratchpad/hammer3.sh | — | ~975 |
| 09:21 | Edited src/lib/client_internal.h | expanded (+55 lines) | ~1057 |
| 09:21 | Edited src/lib/client.c | 2→3 lines | ~59 |
| 09:21 | Edited src/lib/client.c | 2→3 lines | ~62 |
| 09:21 | Edited src/lib/client.c | expanded (+6 lines) | ~152 |
| 09:21 | Edited src/lib/client.c | 2→3 lines | ~62 |
| 09:22 | Edited src/lib/client.c | 3→8 lines | ~134 |
| 09:46 | Session end: 31 writes across 10 files (tasks.md, ha.h, ha.c, cluster.c, run-ha-soak.sh) | 26 reads | ~321152 tok |
| 09:46 | Session end: 31 writes across 10 files (tasks.md, ha.h, ha.c, cluster.c, run-ha-soak.sh) | 26 reads | ~321152 tok |
| 09:47 | Created ../../../../../../tmp/claude-1000/-home-rshen-projects-xce-worktrees-raft-tla/00c9b3f1-df3c-4ce0-a997-5c6a316be4ec/scratchpad/run-chaotic-soak.sh | — | ~61 |
| 17:01 | 40-round CHAOTIC /xce-test-ha soak vs bug-1435/1436 fixed binary (xce_controller+xce_test) — VERDICT rounds=40 jobs=123 committed_divergence=0 committed_job_loss=0 excluded_bug854=0 excluded_bug924=0 result=PASS; all 3 nodes served primary (13/14/13); no ASAN/crash/abort in ctrl-{1,2,3}.log/.stderr | .wolf/memory.md | regression validation clean, bug-1435/1436 fixes confirmed | ~1200 |
| 10:01 | Session end: 32 writes across 11 files (tasks.md, ha.h, ha.c, cluster.c, run-ha-soak.sh) | 26 reads | ~321218 tok |
## Session: 2026-07-13 00:12
| Time | Action | File(s) | Outcome | ~Tokens |
|------|--------|---------|---------|--------|

File diff suppressed because it is too large Load diff