Campaign 10: two run-2a violations were HARNESS defects, not product defects — fixed

Run 2a hit its first two violations at cycle 10 and BOTH trace to my harness, not
the product. Recorded in full because a check that fails for the wrong reason is
as corrosive as one that passes for the wrong reason.

  HARD-RESET  VM returned=True canaries_intact=False
  I7          want=C10-C010-A-194530 got=C10-C009-A-192929 restore_ok=True

Root cause, evidenced: the cc_proof table's highest row is C10-C009-A — there is
NO C010-A row at all, so the seed never landed. The hard-reset atom ran earlier in
the same cycle and left rallly Exited(255); atom_restore_verify called seed() and
never checked its return value, so an unwritten generation became a fake stale
This commit is contained in:
2026-08-01 19:51:57 +02:00
parent ac6c05bd7b
commit 9ca57e591b
8 changed files with 1973 additions and 11 deletions
@@ -96,8 +96,11 @@ def _psql(sql, timeout=180):
return rc, out.strip(), err.strip()
def seed(gen):
"""Write the generation marker into every app. Returns {app: ok}."""
def seed(gen, verify=True):
"""Write the generation marker into every app. Returns {app: ok}.
With verify=True the value is READ BACK — a write that reported success but did not
land is the failure mode that turned a dead app into a fake 'stale restore' in run 2a."""
res = {}
_psql("CREATE TABLE IF NOT EXISTS cc_proof (id serial primary key, gen text, at timestamptz default now())")
rc, out, err = _psql(f"INSERT INTO cc_proof (gen) VALUES ('{gen}') RETURNING gen")
@@ -109,6 +112,10 @@ def seed(gen):
rc, out, err = guest(
f"docker exec -u 0 {cont} sh -c {shq(f'echo {gen} > {d}/cc_proof.txt && cat {d}/cc_proof.txt')}", 180)
res[app] = (gen in out)
if verify:
back = read_canaries()
for a in list(res):
res[a] = res[a] and (back.get(a) == gen)
return res
@@ -124,6 +131,36 @@ def read_canaries():
return res
def apps_ready(names=None, timeout=600):
"""Wait until the named app containers are RUNNING (healthy where they report health).
Load-bearing: a canary lives inside an app container, so reading one before the app is
back does not measure the product — it measures the harness. Two false violations in
run 2a came from exactly that (a seed that never landed, then a 'stale' restore)."""
names = names or (ALL_APPS + [DRIVE_APP])
t0 = time.time()
while time.time() - t0 < timeout:
c = containers()
ok = True
for n in names:
probe = "rallly-postgres" if n == "rallly" else n
st = c.get(n) or ""
st2 = c.get(probe) or ""
if not st or "Up" not in st or "starting" in st:
ok = False
break
if n == "rallly" and ("Up" not in st2 or "starting" in st2):
ok = False
break
if ok:
return True
time.sleep(10)
return False
DRIVE_APP = "calibre-web"
def containers():
rc, out, _ = guest("docker ps --format '{{.Names}}|{{.Status}}'", 120)
d = {}
@@ -118,12 +118,24 @@ def atom_backup():
def atom_restore_verify():
"""I7 — the whole point: a restore must return the discriminator asked for."""
app = "rallly" # the DB app; its canary is a real DB row
# PRECONDITION, not politeness: a canary lives inside an app container. Reading or writing
# one before the app is back measures the harness, not the product. Run 2a produced a fake
# "stale restore" this exact way, after a hard reset left rallly down.
if not L.apps_ready([app]):
rec("I7-SKIP", True, "apps not ready before seed — atom skipped, NOT counted as a violation")
return
genA = "C10-C%03d-A-%s" % (CYCLE, time.strftime("%H%M%S"))
L.seed(genA)
sa = L.seed(genA)
if not sa.get(app):
rec("I7-SKIP", True, "seed of %s did not land (app unhealthy) — atom skipped, not a violation" % genA)
return
if not atom_backup():
return
genB = "C10-C%03d-B-%s" % (CYCLE, time.strftime("%H%M%S"))
L.seed(genB) # must NOT survive the restore
sb = L.seed(genB) # must NOT survive the restore
if not sb.get(app):
rec("I7-SKIP", True, "seed of %s did not land — cannot distinguish stale from unwritten" % genB)
return
snaps = L.jparse(L.api("GET", "/api/backup/snapshots?stack=%s" % app)) or {}
pts = snaps.get("data") or []
if not pts:
@@ -216,6 +228,142 @@ def atom_redeploy_app():
rec("REDEPLOY", app in L.containers(), "%s redeployed" % app)
RAW_ADATOK = "/mnt/adatok"
ADATOK_UUID = "13a43656-b393-4879-8d05-37de560def5f"
def _adatok_row():
for d in disks():
if str(d.get("guest_path", "")).endswith("adatok"):
return d
return {}
def atom_abort_fs_inplace():
"""R-117 Q7 / I4 second clause — the filesystem dies WITHOUT the device disappearing.
Before agent v0.117.0 this state reported healthy and restarted apps onto it with
nothing emitted on any channel. Assert it SURFACES and does not silently retry."""
L.box("mount -o remount,abort %s" % RAW_ADATOK)
opts = L.box("grep ' %s ' /proc/mounts" % RAW_ADATOK)[1].strip()
if not ("abort" in opts or "emergency_ro" in opts):
rec("I4-abort", False, "could not abort the fs in place; /proc/mounts=%s" % opts[:120])
return
settle(150)
row = _adatok_row()
dev_present = "sd" in L.box("lsblk -dno NAME | tr '\\n' ' '")[1]
rec("I4-abort", row.get("bound_under_parent") is False and dev_present,
"aborted-in-place: bound=%s (want False), device still present=%s, opts=%s"
% (row.get("bound_under_parent"), dev_present, opts.split("ext4")[-1][:60]))
# the gate must STOP the app whose data is on the dead namespace, not restart it onto it
rec("I3-abort", DRIVE_APP not in L.containers(),
"%s must be stopped while its namespace is aborted; running=%s"
% (DRIVE_APP, DRIVE_APP in L.containers()))
# recovery needs a full device close — a remount lands on the same aborted superblock
L.hp("qm set 311 --delete %s" % NONTGT_DISK)
time.sleep(8)
L.hp("qm set 311 --%s %s" % (NONTGT_DISK, NONTGT_VOL))
settle(150)
row = _adatok_row()
rec("I4-abort-recover", row.get("bound_under_parent") is True and DRIVE_APP in L.containers(),
"after re-seat: bound=%s app_up=%s" % (row.get("bound_under_parent"), DRIVE_APP in L.containers()))
def atom_kill_agent_mid_backup():
"""Kill the AGENT while a backup runs, then prove the next backup still succeeds."""
L.api("POST", "/api/backup/run", {})
time.sleep(6)
L.box("systemctl kill -s KILL felhom-agent || true")
time.sleep(20)
L.box("systemctl start felhom-agent || true")
wait_backup()
time.sleep(20)
up = "active" in L.box("systemctl is-active felhom-agent")[1]
ok2 = atom_backup()
rec("KILL-AGENT", up and ok2, "agent active after kill=%s; subsequent backup ok=%s" % (up, ok2))
def atom_hard_reset_mid_write():
"""Hard-reset the VM mid-backup. Assert it returns AND the canaries survive intact."""
before = L.read_canaries()
L.api("POST", "/api/backup/run", {})
time.sleep(8)
L.hp("qm reset 311")
ok = False
for _ in range(40):
time.sleep(20)
if "felhom-controller" in L.containers():
ok = True
break
# the canaries live in the APP containers — wait for those, or this measures startup latency
ready = L.apps_ready() if ok else False
after = L.read_canaries() if ready else {}
intact = all(after.get(a) == before.get(a) for a in before) if ready else None
detail = "VM returned=%s apps_ready=%s canaries_intact=%s" % (ok, ready, intact)
if not ready:
rec("HARD-RESET", False, detail + " — apps did not return within 10 min (that IS the failure)")
else:
rec("HARD-RESET", bool(intact), detail + " (a hard reset mid-write must not corrupt them)")
def atom_reboot_vm():
L.hp("qm reboot 311")
ok = False
for _ in range(40):
time.sleep(20)
if "felhom-controller" in L.containers():
ok = True
break
rec("REBOOT-VM", ok, "controller back after full VM reboot")
def atom_concurrent_backup_restore():
"""The controller must REFUSE the second op, not run both over the same data."""
L.api("POST", "/api/backup/run", {})
time.sleep(3)
out = L.guest('/root/c10api.sh POST /backup/restore "stack_name=rallly&snapshot_id=helyi" 2>/dev/null')[1]
st = ((L.jparse(L.api("GET", "/api/backup/restore-status")) or {}).get("data") or {})
wait_backup(); wait_restore()
# either the restore was refused, or it queued behind the backup — never both mutating at once
rec("CONCURRENCY", True, "backup+restore raced; restore-status op=%s running=%s (recorded, not asserted)"
% (st.get("op"), st.get("running")))
def atom_concurrent_backup_detach():
"""Pull the backup TARGET out from under a running backup."""
L.api("POST", "/api/backup/run", {})
time.sleep(5)
L.hp("qm set 311 --delete %s" % TARGET_DISK)
settle()
evs = [e for e in hub_events("4m") if e[0] in ("backup_target_absent", "storage_disconnected")]
got = evs[-1][0] if evs else None
rec("I1-under-load", got == "backup_target_absent",
"target pulled DURING a backup -> got=%s (want backup_target_absent)" % got)
L.hp("qm set 311 --%s %s" % (TARGET_DISK, TARGET_VOL))
settle()
wait_backup()
ts = target_state()
rec("I1-under-load-recover", ts.get("degraded") is False,
"after return degraded=%s target=%s" % (ts.get("degraded"), ts.get("target")))
def atom_fill_drive():
"""Fill the backup target to near-full and back up. A refusal is a PASS; a silent
success that writes nothing is the failure this looks for."""
avail = L.box("df --output=avail -BM /mnt/mentes | tail -1")[1].strip().rstrip("M")
try:
keep = max(int(avail) - 300, 50)
except Exception:
keep = 50
L.box("fallocate -l %dM /mnt/mentes/c10-filler 2>&1 || dd if=/dev/zero of=/mnt/mentes/c10-filler bs=1M count=%d 2>/dev/null" % (keep, keep))
free_after = L.box("df -h /mnt/mentes | tail -1")[1].strip()
d = ((L.jparse(L.api("GET", "/api/backup/status")) or {}).get("data") or {})
L.api("POST", "/api/backup/run", {})
res = wait_backup()
L.box("rm -f /mnt/mentes/c10-filler")
ok = res.get("db_dump", {}).get("success") is not None
rec("FILL-DRIVE", ok, "near-full (%s) backup outcome recorded: %s" % (free_after[-24:], json.dumps(res)[:200]))
# ------------------------------------------------------------------ per-cycle invariants
def check_healthy_baseline():
@@ -285,9 +433,16 @@ def watchdog():
# ------------------------------------------------------------------ main
# LIGHT atoms run every cycle. HEAVY ones are slow (VM reboots, fills, aborts), so a
# rotating slice joins each cycle and is SHUFFLED IN with the rest — the v1 runner appended
# reboot after the shuffle, so it never interleaved with a detach. That is fixed here.
ATOMS = [atom_backup, atom_restore_verify, atom_detach_target,
atom_detach_nontarget, atom_kill_controller, atom_redeploy_app]
HEAVY = [atom_abort_fs_inplace, atom_kill_agent_mid_backup, atom_hard_reset_mid_write,
atom_reboot_vm, atom_reboot_guest, atom_concurrent_backup_restore,
atom_concurrent_backup_detach, atom_fill_drive]
def main():
global CYCLE
log("=== Campaign 10 Phase B start — max %d cycles, deadline %s ==="
@@ -302,10 +457,10 @@ def main():
if not watchdog():
break
order = ATOMS[:]
rng.shuffle(order) # permutation, not a fixed catalogue
# a reboot is expensive; fold it in every 7th cycle only
if CYCLE % 7 == 0:
order.append(atom_reboot_guest)
# ONE heavy atom per cycle: every heavy atom is seen every 8 cycles, and the cycle
# stays short enough to reach the tail the brief cares about (drift at ~38).
order += [HEAVY[CYCLE % len(HEAVY)]]
rng.shuffle(order) # permutation INCLUDING the heavy atoms
log("cycle %d: %s" % (CYCLE, " -> ".join(a.__name__.replace("atom_", "") for a in order)))
for a in order:
heartbeat(a.__name__)