#!/usr/bin/env python3 """chaos.py — Part E, the chaos hour on tonight's work. Guest 9202 (scratch), controller v0.269.1, drill catalog. python3 chaos.py setup # seed wishlist + navidrome through their front doors; note nextcloud's seeds python3 chaos.py round # one round of chaos_schedule.py (seed 20260924), evidence written as it happens EVIDENCE, NOT PRODUCT. Every ACT is the endpoint the UI invokes. The ACCIDENT is NOT fired by this script: at the moment the round is armed it writes `E/arm-NN.json` and waits for `E/done-NN.json`, and the session fires the accident as its own visible command (power cut = pct stop/start 9202; controller kill = kill -9 of the controller's PID; docker restart; disk fill). The one exception is the backup accident, which is a product endpoint (`POST /api/backup/run`) and is pressed here. CHANGED BEFORE ROUND 1 (said in the findings doc): the "whole-box backup" accident is the box's own full backup run, not a vzdump — demo-hp's backup storage (`local`) had ~4 GB free and the host root was 90 % full, so a vzdump of 9202 would have filled the HOST. The five things per round: the household's page in both languages, what the box did (its own log), time to steady, which events fired (9202 has no hub: R-620's DROPPED lines are the witness), and — judged in the findings doc against `08` — what should have fired and did not. Plus the data read back. """ import html as H, json, os, re, sys, threading, time sys.path.insert(0, ".") import walk as w import fixtures as fx import ncfiles as nf from chaos_schedule import schedule HERE = os.path.dirname(os.path.abspath(__file__)) EVD = os.path.join(HERE, "..", "E") os.makedirs(EVD, exist_ok=True) STATE = os.path.join(w.SC, "chaos-state.json") # NOT in the evidence tree: it holds seeded test passwords TARGET = {1: "chaosoom", 2: "n8n", 3: "nextcloud", 4: "wishlist", 5: "gokapi", 6: "navidrome", 7: "chaoscrash", 8: "chaosoomb", 9: "chaoscrash", 10: "n8n", 11: "nextcloud", 12: "chaosoomb"} FAIL = { # failing steps: a real image move + the drill probe on a port the app does not answer "wishlist": ("ghcr.io/cmintey/wishlist:v0.67.1", "ghcr.io/cmintey/wishlist:latest", 3000), "navidrome": ("deluan/navidrome:0.64.1", "deluan/navidrome:latest", 4533), "nextcloud": ("redis:7-alpine", "redis:7.4.0-alpine", 80), } FX = {"wishlist": fx.FIXTURES["wishlist"], "navidrome": fx.FIXTURES["navidrome"], "n8n": fx.FIXTURES["n8n"], "nextcloud": fx.Nextcloud()} SUB = {"wishlist": "c-wish", "navidrome": "c-navi", "n8n": "e-n8n", "nextcloud": "cloud-a1"} def load(): return json.load(open(STATE)) if os.path.exists(STATE) else {} def save(s): json.dump(s, open(STATE, "w"), indent=2, ensure_ascii=False) # ------------------------------------------------------------------------------------------ observing def household(app): st = w.stack(app) out = {"state": {k: st.get(k) for k in ("deployed", "state", "update_phase", "hold_reason", "hold_kind", "update_error", "ladder_steps_left")}} if not st.get("deployed"): return out out["badges"] = w.badges(app) for lang in ("hu", "en"): h = H.unescape(w.page(f"/apps/{app}?lang={lang}")) lines = [] for m in re.finditer(r'
]*)>(.*?)
', h, re.S): t = re.sub(r"\s+", " ", re.sub(r"<[^>]+>", " ", m.group(2))).strip() if t and "' +" not in t and "nem visszavonható" not in t and "cannot undo" not in t \ and "Hub kapcsolat" not in t and "hub connection" not in t: lines.append(t[:400]) out[f"page_{lang}"] = lines return out def events_since(t_iso): code, d = w.ctl("GET", "/api/debug/logs?level=DEBUG&lines=8000") ents = ((d.get("data") or {}).get("entries") or []) if isinstance(d, dict) else [] out = [] for e in ents: m = re.search(r"DROPPED event (\S+) \(severity (\w+)\)", e.get("message", ""), re.I) if m and e.get("timestamp", "") >= t_iso: out.append(f"{e['timestamp']} {m.group(1)} ({m.group(2)})") return out def box_log(t_iso, app): code, d = w.ctl("GET", "/api/debug/logs?level=INFO&lines=5000") ents = ((d.get("data") or {}).get("entries") or []) if isinstance(d, dict) else [] keys = (app, "UNDO", "undo", "HELD", "hold", "restore", "Restore", "deadapp", "STOPPED by the box", "floor", "disk", "space", "backup") return [f"{e['timestamp']} {e.get('level')} {e.get('message', '')[:300]}" for e in ents if e.get("timestamp", "") >= t_iso and any(k in e.get("message", "") for k in keys)][-80:] def readback(app, s): if app not in FX or not w.stack(app).get("deployed"): return None A = (s.get("apps", {}).get(app) or {}).get("A") if app == "nextcloud": S = json.load(open(f"{w.SC}/a1-secret-state.json")) A = S["A"] w.wait_app(SUB[app], "/status.php", want=("200",), tries=90, delay=4) names = sorted(S["files"]) return {"A": bool(FX[app].verify(w, SUB[app], A, w.say)), "files": nf.verify_files(w, SUB[app], A, {names[0]: S["files"][names[0]], names[2]: S["files"][names[2]]}, w.say)} if not A: return {"A": None, "note": "no seed recorded"} w.wait_app(SUB[app], "/", want=("200", "302", "303", "307", "401", "403"), tries=90, delay=4) return {"A": bool(FX[app].verify(w, SUB[app], A, w.say))} def steady(app, t0, cap=1500, want_deployed=True, until=None): last = None while time.time() - t0 < cap: try: st = w.stack(app) except Exception: st = {} cur = (st.get("deployed"), st.get("state"), st.get("updating"), st.get("update_phase"), st.get("hold_kind")) if cur != last: w.say(f" +{time.time()-t0:6.1f}s {app}: deployed={cur[0]} state={cur[1]} updating={cur[2]} phase={cur[3]} hold={cur[4]}") last = cur if until: if until(st): return round(time.time() - t0, 1), st elif st and not st.get("updating") and not st.get("deploying"): if (want_deployed and st.get("deployed") and st.get("state") in ("running", "stopped", "unhealthy", "degraded")) \ or (not want_deployed and not st.get("deployed")) or st.get("hold_kind"): return round(time.time() - t0, 1), st time.sleep(2) return None, w.stack(app) # ------------------------------------------------------------------------------------------ the drill def drill(edit, msg): import fcntl with open(f"{w.SC}/drill.lock", "w") as lk: fcntl.flock(lk, fcntl.LOCK_EX) w.sh(["git", "-C", w.DRILL, "pull", "-q", "--rebase", "origin", "main"], timeout=120) edit() w.sh(["git", "-C", w.DRILL, "commit", "-qam", "NIGHT-E " + msg]) w.sh(["git", "-C", w.DRILL, "push", "-q", "origin", "main"], timeout=120) w.say(" drill: " + msg) def break_step(app): frm, to, port = FAIL[app] comp, fy = f"{w.DRILL}/templates/{app}/docker-compose.yml", f"{w.DRILL}/templates/{app}/.felhom.yml" def edit(): c = open(comp).read() assert f"image: {frm}" in c, (app, frm) open(comp, "w").write(c.replace(f"image: {frm}", f"image: {to}", 1)) f = open(fy).read() f2 = re.sub(r"(healthcheck:\n(?:.*\n){0,8}?\s+port: )" + str(port) + r"\b", r"\g<1>8999", f, count=1) assert f2 != f, (app, "probe port not found") open(fy, "w").write(f2) drill(edit, f"{app}: failing step {frm} -> {to} + probe 8999") def repair_step(app): frm, to, port = FAIL[app] comp, fy = f"{w.DRILL}/templates/{app}/docker-compose.yml", f"{w.DRILL}/templates/{app}/.felhom.yml" def edit(): c = open(comp).read() open(comp, "w").write(c.replace(f"image: {to}", f"image: {frm}", 1)) f = open(fy).read() open(fy, "w").write(re.sub(r"(healthcheck:\n(?:.*\n){0,8}?\s+port: )8999\b", r"\g<1>" + str(port), f, count=1)) drill(edit, f"{app}: back to {frm} and its real probe") # ------------------------------------------------------------------------------------------ the arm class Arm: def __init__(self, n, kind, note): self.n, self.kind, self.note, self.armed = n, kind, note, False def __call__(self, why): if self.armed or self.kind == "none": return self.armed = True self.note["armed_at"] = time.strftime("%H:%M:%S") self.note["armed_why"] = why w.say(f" >>> ARMED accident {self.kind} ({why})") if self.kind == "whole_box_backup": code, d = w.ctl("POST", "/api/backup/run") self.note["accident"] = f"POST /api/backup/run -> {code} {str(d)[:160]} at {time.strftime('%H:%M:%S')}" w.say(" >>> " + self.note["accident"]) return # R-320: the box's log off the machine BEFORE the accident — round 3's power cut replaced the controller # container and took the pre-cut lines with it. Only from the main thread: walk.guest shares one temp file. if threading.current_thread() is threading.main_thread(): open(os.path.join(EVD, f"round-{self.n:02d}-controller-pre.log"), "w").write( w.guest(f"docker logs --since {self.note['started']} felhom-controller 2>&1 | grep -vE 'auth: valid session|router.go:81|Status refresh' | tail -3000")) json.dump({"round": self.n, "kind": self.kind, "at": time.time(), "why": why}, open(os.path.join(EVD, f"arm-{self.n:02d}.json"), "w")) def wait_done(self, cap=900): if self.kind in ("none", "whole_box_backup") or not self.armed: return p = os.path.join(EVD, f"done-{self.n:02d}.json") t0 = time.time() while time.time() - t0 < cap and not os.path.exists(p): time.sleep(2) self.note["accident"] = json.load(open(p)) if os.path.exists(p) else "NOT FIRED (no done file)" w.say(f" >>> accident done: {self.note['accident']}") def wait_controller(cap=900): t0 = time.time() while time.time() - t0 < cap: try: w.login() code, _ = w.ctl("GET", "/api/stacks") if code == "200": return round(time.time() - t0, 1) except SystemExit: pass time.sleep(5) return None # ------------------------------------------------------------------------------------------ actions def a_unhealthy_install(app, note, arm, t0): """crash_loop / oom_app: install the drill app through the product; the box must stop it by itself.""" for _ in range(12): # the drill template must be on the box first (attempt 0 of round 1: "not found") w.sync_rescan() if w.ctl("GET", f"/api/stacks/{app}/deploy-fields")[0] == "200": break time.sleep(5) vals = w.deploy_values(app, app) code, d = w.ctl("POST", f"/api/stacks/{app}/deploy", {"values": vals}) w.say(f" deploy -> {code} {str(d)[:120]}") note["act"] = f"deploy -> {code}" threading.Timer(20, arm, args=("20 s after the install",)).start() return steady(app, t0, cap=1500, until=lambda st: st.get("hold_kind") == "unhealthy_stop") def a_install(app, note, arm, t0, s): """n8n at the ladder's FIRST from, so round 10 has a step to climb.""" sys.path.insert(0, "/mnt/5_hdd/felhom.eu/git/app-catalog-felhom.eu/scripts") import ladder comp = f"{w.DRILL}/templates/{app}/docker-compose.yml" E, _, _ = ladder.parse(open(f"{w.DRILL}/templates/{app}/.felhom.yml").read()) head = open(comp).read() s.setdefault("heads", {})[app] = head save(s) def edit(): c = head for svc, ref in ladder.images_in(head).items(): if E[0]["from"].get(svc) and E[0]["from"][svc] != ref: c = c.replace(f"image: {ref}", f"image: {E[0]['from'][svc]}", 1) open(comp, "w").write(c) drill(edit, f"{app} at the ladder's first from {E[0]['from']}") w.sync_rescan() time.sleep(3) w.sync_rescan() vals = w.deploy_values(app, SUB[app]) threading.Timer(20, arm, args=("20 s after the install press",)).start() code, d = w.ctl("POST", f"/api/stacks/{app}/deploy", {"values": vals}) note["act"] = f"deploy -> {code} {str(d)[:100]}" secs, st = steady(app, t0, until=lambda st: st.get("deployed") and (st.get("app_config") or {}).get("pinned_images") and not st.get("deploying")) if st.get("deployed"): w.wait_app(SUB[app], "/", tries=90, delay=4) A = FX[app].seed(w, SUB[app], w.say) s.setdefault("apps", {}).setdefault(app, {})["A"] = A save(s) def back(): open(comp, "w").write(head) drill(back, f"{app} back to the head (2 steps offered)") w.sync_rescan() return secs, st def a_update(app, note, arm, t0, on_verify=None, arm_at_starting=False): code, d = w.ctl("POST", f"/api/stacks/{app}/update") note["act"] = f"Update -> {code} {str(d)[:140]}" w.say(" " + note["act"]) phases, seen = [], None while time.time() - t0 < 1800: try: st = w.stack(app) except Exception: st = {} ph = st.get("update_phase") if ph != seen and ph: seen = ph phases.append((round(time.time() - t0, 1), ph)) w.say(f" +{phases[-1][0]:6.1f}s phase={ph}") if ph == "verifying": if on_verify: on_verify() arm("at verifying") if ph == "starting" and arm_at_starting: arm("at starting") if st and not st.get("updating") and ph in ("done", "failed", "undone") and time.time() - t0 > 3: break if not st and time.time() - t0 > 3: time.sleep(5) time.sleep(0.5) note["phases"] = phases return steady(app, t0) def cut_newest_copy(app, note): out = w.guest(f"""c=$(docker volume ls -q --filter label=felhom.undo-copy-of={app} | sort | tail -1); echo "copy: $c" docker run --rm -v $c:/c alpine sh -c 'rm -f /c/felhom-undo-complete; ls /c | head -3'""") note["cutoff"] = out.strip() w.say(" >>> finished-marker removed from the NEWEST undo copy:\n" + out) def a_cutoff_file_app(app, note, arm, t0, s): break_step(app) note["badge_catchup_s"] = w.sync_rescan(expect_app=app, expect_ref=FAIL[app][1], tries=60, delay=5) secs, st = a_update(app, note, arm, t0, on_verify=lambda: cut_newest_copy(app, note)) repair_step(app) w.sync_rescan() note["held"] = {k: st.get(k) for k in ("update_phase", "hold_kind", "hold_no_whole_copy", "hold_reason")} note["held_page"] = household(app) if st.get("hold_kind") == "update_failed" and not st.get("hold_no_whole_copy"): sess = open(f"{w.SC}/sess{os.getpid()}.txt").read().strip() csrf = open(f"{w.SC}/csrf{os.getpid()}.txt").read().strip() r = w.sh(["curl", "-sk", "-o", "/dev/null", "-w", "%{http_code}", "-H", w.HOSTHDR, "-H", f"Cookie: {sess}", "-X", "POST", "--data-urlencode", f"_csrf={csrf}", "--data-urlencode", f"stack_name={app}", f"{w.BASE}/backup/tier2/unit-restore"], timeout=120) note["whole_restore_press"] = r.stdout w.say(f" whole restore (the second drive) -> {r.stdout}") last = None for _ in range(600): c2, dd = w.ctl("GET", "/api/backup/restore-status") d2 = (dd.get("data") or {}) if isinstance(dd, dict) else {} if not d2.get("running") and d2.get("last"): last = d2.get("last") break time.sleep(2) note["whole_restore"] = last w.say(f" whole restore: {str(last)[:300]}") return steady(app, t0) return secs, st def a_failing_step(app, note, arm, t0, s): break_step(app) note["badge_catchup_s"] = w.sync_rescan(expect_app=app, expect_ref=FAIL[app][1], tries=60, delay=5) r = a_update(app, note, arm, t0) repair_step(app) w.sync_rescan() return r def a_remove_held(app, note, arm, t0): st = w.stack(app) note["held_before"] = {k: st.get(k) for k in ("deployed", "hold_kind", "hold_reason")} threading.Timer(2, arm, args=("2 s after the remove press",)).start() code, d = w.ctl("POST", f"/api/stacks/{app}/remove", {"remove_hdd_data": True, "remove_backups": True}) note["act"] = f"remove (data + backups) -> {code} {str(d)[:200]}" w.say(" " + note["act"]) return steady(app, t0, want_deployed=False, cap=600) def a_ladder_step(app, note, arm, t0, s): w.sync_rescan() st = w.stack(app) note["steps_left_before"] = st.get("ladder_steps_left") note["pinned_before"] = (st.get("app_config") or {}).get("pinned_images") r = a_update(app, note, arm, t0, arm_at_starting=True) w.sync_rescan() st = w.stack(app) note["steps_left_after"] = st.get("ladder_steps_left") note["pinned_after"] = (st.get("app_config") or {}).get("pinned_images") return r def a_start_after_unhealthy(app, note, arm, t0): st = w.stack(app) note["before"] = {k: st.get(k) for k in ("state", "hold_kind", "hold_reason")} code, d = w.ctl("POST", f"/api/stacks/{app}/start") note["act"] = f"Start -> {code} {str(d)[:140]}" w.say(" " + note["act"]) threading.Timer(5, arm, args=("5 s after Start",)).start() time.sleep(3) note["after_start"] = {k: w.stack(app).get(k) for k in ("state", "hold_kind")} return steady(app, t0, cap=1200, until=lambda st: st.get("hold_kind") == "unhealthy_stop") # ------------------------------------------------------------------------------------------ stages def setup(): s = load() w.login() for app in ("wishlist", "navidrome"): w.wait_app(SUB[app], "/", tries=60, delay=3) A = FX[app].seed(w, SUB[app], w.say) s.setdefault("apps", {}).setdefault(app, {})["A"] = A w.say(f" seeded {app}: {bool(A)}") save(s) s["setup_readback"] = {a: readback(a, s) for a in ("wishlist", "navidrome", "nextcloud")} w.say("setup readback: " + json.dumps(s["setup_readback"])) save(s) open(os.path.join(EVD, "00-setup.log"), "w").write("\n".join(w.LOG) + "\n") def run_round(n): s = load() sched = {r["round"]: r for r in schedule()}[n] app = TARGET[n] w.login() t_iso = time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()) w.say(f"==== ROUND {n}: {sched['action']} on {app} x {sched['accident']} ({t_iso})") note = {"round": n, **sched, "app": app, "started": t_iso, "before": household(app)} arm = Arm(n, sched["accident"], note) t0 = time.time() act = sched["action"] try: if act in ("oom_app", "crash_loop"): secs, st = a_unhealthy_install(app, note, arm, t0) elif act == "install": secs, st = a_install(app, note, arm, t0, s) elif act == "cutoff_undo_file_app": secs, st = a_cutoff_file_app(app, note, arm, t0, s) elif act == "failing_step": secs, st = a_failing_step(app, note, arm, t0, s) elif act == "remove_held": secs, st = a_remove_held(app, note, arm, t0) elif act == "ladder_step": secs, st = a_ladder_step(app, note, arm, t0, s) elif act == "start_after_unhealthy": secs, st = a_start_after_unhealthy(app, note, arm, t0) else: raise SystemExit("unknown action " + act) except Exception as e: note["act_exception"] = repr(e) w.say(" ACT EXCEPTION " + repr(e)) secs, st = None, {} arm.wait_done() if sched["accident"] in ("power_cut", "docker_restart", "controller_killed"): note["controller_back_s"] = wait_controller() if act in ("oom_app", "crash_loop", "start_after_unhealthy"): secs2, st = steady(app, t0, cap=1800, until=lambda st: st.get("hold_kind") == "unhealthy_stop") else: secs2, st = steady(app, t0, want_deployed=(act != "remove_held")) secs = secs2 or secs note["time_to_steady_s"] = round(time.time() - t0, 1) if secs is None else secs note["after"] = household(app) if not w.stack(app).get("deployed"): note["after"]["leftovers"] = w.guest(f"docker ps -a --filter label=com.docker.compose.project={app} --format '{{{{.Names}}}}'; docker volume ls -q | grep '^{app}_' || true; ls -d /opt/docker/stacks/{app}/applied-meta 2>/dev/null || true").strip() note["readback"] = readback(app, s) note["events"] = events_since(t_iso) note["box_log"] = box_log(t_iso, app) note["undo_copies_left"] = w.guest(f"docker volume ls -q --filter label=felhom.undo-copy-of={app} | wc -l").strip() open(os.path.join(EVD, f"round-{n:02d}-controller.log"), "w").write( w.guest(f"docker logs --since {t_iso} felhom-controller 2>&1 | grep -vE 'auth: valid session|router.go:81|Status refresh' | tail -3000")) json.dump(note, open(os.path.join(EVD, f"round-{n:02d}.json"), "w"), indent=2, ensure_ascii=False, default=str) open(os.path.join(EVD, f"round-{n:02d}.log"), "w").write("\n".join(w.LOG) + "\n") w.say(f"==== ROUND {n} END: steady in {note['time_to_steady_s']}s; readback={note['readback']}; events={note['events']}") def collect(n, t_iso, extra): """Finish a round whose runner was stopped: the same five observations, no action.""" s = load() sched = {r["round"]: r for r in schedule()}[n] app = TARGET[n] w.login() note = {"round": n, **sched, "app": app, "started": t_iso, "collected_by_hand": True, **extra} note["after"] = household(app) if not w.stack(app).get("deployed"): note["after"]["leftovers"] = w.guest(f"docker ps -a --filter label=com.docker.compose.project={app} --format '{{{{.Names}}}} {{{{.Status}}}}'; docker volume ls -q | grep '^{app}_' || true; ls /opt/docker/stacks/{app}/ 2>/dev/null || true").strip() note["readback"] = readback(app, s) note["events"] = events_since(t_iso) note["box_log"] = box_log(t_iso, app) open(os.path.join(EVD, f"round-{n:02d}-controller.log"), "w").write( w.guest(f"docker logs --since {t_iso} felhom-controller 2>&1 | grep -vE 'auth: valid session|router.go:81|Status refresh' | tail -3000")) json.dump(note, open(os.path.join(EVD, f"round-{n:02d}.json"), "w"), indent=2, ensure_ascii=False, default=str) w.say(f"==== ROUND {n} COLLECTED: after={json.dumps(note['after'], ensure_ascii=False)[:400]} events={note['events']}") if __name__ == "__main__": if sys.argv[1] == "collect": collect(int(sys.argv[2]), sys.argv[3], json.loads(sys.argv[4]) if len(sys.argv) > 4 else {}) elif sys.argv[1] == "setup": setup() elif sys.argv[1] == "round": run_round(int(sys.argv[2]))