Catalog tests for the supervisor: a kill during $H, a respawn behind the lid, the fail-tier stop, the 300 ms relock

The daemon's supervisor and engine change (forgectrl: controller death
as a signal, the homing runner and the kernel before a respawn, the
enclosure check before every spawn, the fail tiers ending the
controller). This commit carries the catalog tests that hold them.

forgetest/forgetest/suite/motion.py:
- motion.deadman gains a last phase: SIGKILL of the controller during
  $H (the web-service homing, run only with cloud mode enabled, the
  homing mode set and put back by the test). The homing runner must be
  gone before the respawn, the kernel idle when the new controller
  starts, no halt needed, and the pulse device held by the daemon and
  one controller. The head ends wherever the homing was.
- motion.respawn-gate (kind operator, the lid through the fixture where
  one is wired): the controller killed with the lid open. The
  supervisor safes (latch locked), reports waiting with why naming the
  lid, starts nothing while the lid stays open, and comes back verified
  when it closes, without a second motion probe.

forgetest/forgetest/suite/laser.py:
- laser.armed-kill reads the latch and the kernel state from sysfs
  every few milliseconds after the SIGKILL: the latch must lock within
  300 ms of the kill and the kernel leave running within a second (a
  death is a signal to the supervisor, not a poll). The emission bound
  stays at 2.5 s: the witness counts a window.

forgetest/forgetest/suite/cooling.py:
- cooling.fail-tier-stop (kind operator, one press, no emission): the
  crash watch's thresholds at their lowest make the head's own move
  trip the abort generator inside an armed, dark (S0) job. The engine
  logs the crash signal, the supervisor logs the stop and starts a new
  controller, the latch is locked, the kernel idle, no emission, the
  thresholds put back. The watch exists only inside the armed window,
  so the press is the arm, not a fire.

Proof. Host: the forgetest unit tests. Bench reference: motion.deadman
passed with the new phase (the runner gone in 0.9 s, the kernel idle
at the respawn, holders forgectrl and grblHAL_glowforge),
motion.respawn-gate passed (waiting 1.3 s after the kill with "the lid
is open", running and verified the moment the lid closed, no probe
line), cooling.fail-tier-stop passed (the signal at +0.27 s, the
controller pid 21823 to 22273, latch locked, emission 0).

forgetest/forgetest/suite/cooling.py

@@ -1390,3 +1390,89 @@ def fan_duty_readback(ctx):
     idle = {k: hw.sysfs_int(k) for k in run}
     ev["idle_duties"] = idle
     ctx.log("duties at idle: %s", idle)
+
+
+@test("cooling.fail-tier-stop", title="A fail-tier verdict ends the controller: CRASH stops motion, "
+                                      "locks the laser, and the supervisor restarts the controller",
+      subsystem="cooling", kind="operator", mode="grbl", est_min=4,
+      covers=_COOL_COVERS + [("forgectrl", "src/super.*")],
+      requires=["cooling.crash-watch-plumbing", "motion.deadman"], actions=["button"],
+      steps=["Bed clear, lid closed, 40 mm of free +X travel. Nothing fires: the job is dark (S0).",
+             "Press the physical button when it lights white, once. The head moves and stops on "
+             "its own; the controller restarts."],
+      description="The engine's fail tiers (a lid IR fire signal, a head crash signal) do not "
+                  "leave the job to the controller: after the kernel writes (motion stopped, the "
+                  "latch locked) the engine ends the controller through the supervisor, which "
+                  "starts it again, so no run start can relight what was locked and the sender "
+                  "sees the job end. Provable without emission or a physical crash: the crash "
+                  "watch's thresholds at their lowest (1) make the head's own move trip the abort "
+                  "generator inside an armed, dark (S0) job. Expected: the engine logs the crash "
+                  "signal, the supervisor logs the stop and starts a new controller (new pid), the "
+                  "latch is locked, the kernel idle, no emission, and the thresholds are put back.")
+def fail_tier_stop(ctx):
+    from .laser import prepare, stream, sample
+    from .motion import FORGECTRL_LOG, _log_lines, _log_offset
+    fc = ctx.forgectrl
+    ev = ctx.evidence
+    before = fc.settings()
+    orig = {k: before.get(k, "") for k in CRASH_KEYS}
+    ev["orig"] = orig
+    ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle at the start")
+    st, m0 = fc.get("/mode")
+    ctx.check(st == 200 and isinstance(m0, dict) and m0.get("controller") == "running", "controller not running: %s", m0)
+    pid0 = m0.get("pid")
+    _set_gates(ctx, fc, {k: "1" for k in CRASH_KEYS})
+    off = _log_offset(FORGECTRL_LOG)
+    t_arm = None
+    try:
+        try:
+            with ctx.grbl() as g:
+                prepare(ctx, g)
+                ctx.ready("DARK JOB (S0, nothing fires). Bed clear with 40 mm of free +X travel, lid closed. "
+                          "The head moves 20 mm and the controller restarts on its own.")
+                stream(g, ["G91", "G21", "M3 S0", "G4 P1", "G1 X20 F1200", "G1 X-20 F1200", "M5", "G90", "M2"])
+                ctx.arm_press()
+                t_arm = ctx.wait_for(lambda: bool((sample(ctx) or {}).get("armed")), 240)
+                ctx.clear_notice()
+                ctx.check(t_arm is not None, "the window never opened (arm refused, or no press)")
+                t0 = time.time()
+                tripped = ctx.wait_for(lambda: _cool(fc).get("verdict") == "CRASH"
+                                       or (fc.get("/mode")[1] or {}).get("pid") not in (None, pid0), 30)
+                ctx.log("the crash tier tripped after %s s", tripped)
+        except (hw.HwError, OSError) as e:
+            ctx.log("the Grbl connection ended with the restart: %s", e)
+        t_kill = time.time()
+        m1 = None
+        while time.time() - t_kill < 60:
+            st, m1 = fc.get("/mode")
+            if isinstance(m1, dict) and m1.get("controller") == "running" and m1.get("pid") != pid0:
+                break
+            ctx.sleep(0.5)
+        # the daemon's lines reach the log file through syslog, a moment
+        # after the events they name
+        ctx.wait_for(lambda: bool(_log_lines(FORGECTRL_LOG, off, "HEAD CRASH SIGNAL"))
+                     and bool(_log_lines(FORGECTRL_LOG, off, "head crash signal - the controller is stopped")), 15)
+        engine = _log_lines(FORGECTRL_LOG, off, "HEAD CRASH SIGNAL")
+        super_ = _log_lines(FORGECTRL_LOG, off, "head crash signal - the controller is stopped")
+        smp = sample(ctx)
+        ilk = hw.sysfs_int("cnc/interlock_circuit")
+        ev["result"] = {"mode_after": m1, "engine_lines": [ln[-160:] for ln in engine[-2:]],
+                        "super_lines": [ln[-160:] for ln in super_[-2:]],
+                        "emission": smp and smp["emission"], "kernel": smp and smp["kstate"],
+                        "latch_locked": ilk is not None and bool(ilk & (1 << 3))}
+        ctx.log("after the crash tier: %s", ev["result"])
+        ctx.check(engine, "the engine did not log the crash signal")
+        ctx.check(super_, "the supervisor did not log the fail-tier stop")
+        ctx.check(m1 and m1.get("pid") != pid0, "the controller was not stopped and started again: %s", m1)
+        ctx.check(ev["result"]["latch_locked"], "latch not locked after the crash tier")
+        ctx.check(not (smp and smp["emission"]), "emission during a dark job: %s", smp and smp["emission"])
+        ctx.check(fc.wait_idle(30, abort=ctx.aborted), "machine not idle after the restart")
+    finally:
+        fc.wait_idle(30, abort=ctx.aborted)
+        st, body = fc.post("/settings", params=orig)
+        ctx.log("restore thresholds: POST /settings %s -> %s", orig, st)
+    after = fc.settings()
+    ctx.check(all(after.get(k, "") == orig[k] for k in CRASH_KEYS),
+              "thresholds not restored: %s", {k: after.get(k) for k in CRASH_KEYS})
+    ctx.log("PASS: the crash tier stopped the job, locked the latch, and the supervisor restarted "
+            "the controller (pid %s -> %s)", pid0, m1 and m1.get("pid"))

forgetest/forgetest/suite/laser.py

@@ -252,6 +252,26 @@ def kill_trail(ctx, t0, seconds=5.0):
     return trail
 
 
+def kill_fast_trail(t0, seconds=1.5):
+    """The latch and the kernel state read from sysfs every few
+    milliseconds after a kill: the supervisor's own reaction, which the
+    HTTP samples of kill_trail cannot resolve. A controller death is a
+    signal to the supervisor, not a poll, so the relock lands within
+    milliseconds; the kernel leaves running once its stop ramp is done."""
+    locked_at = stopped_at = None
+    end = t0 + seconds
+    while time.time() < end and (locked_at is None or stopped_at is None):
+        now = time.time() - t0
+        ilk = hw.sysfs_int("cnc/interlock_circuit")
+        if locked_at is None and ilk is not None and ilk & IL_LASER_LATCH:
+            locked_at = round(now, 3)
+        st = hw.sysfs_read("cnc/state")
+        if stopped_at is None and st is not None and st != "running":
+            stopped_at = round(now, 3)
+        time.sleep(0.005)
+    return {"latch_locked_at_s": locked_at, "kernel_stopped_at_s": stopped_at}
+
+
 def judge_kill(ctx, trail, what):
     """(first zero, tail stayed zero, kernel stopped running) from a trail."""
     for t in trail:
@@ -715,7 +735,9 @@ def disarm_in_hold(ctx):
                   "SIGTERM, so emission drops within 2.5 s and stays 0, the kernel is not running, "
                   "and the restart is a separate operator-judged step. Unexpected: mid-burn SIGKILL "
                   "of the controller - the supervisor's exit safing must end the fire tail inside "
-                  "the ring's in-flight window, leave the latch locked, and respawn the controller.")
+                  "the ring's in-flight window, leave the latch locked, and respawn the controller. "
+                  "The death is a signal to the supervisor, not a poll: the latch relocks within "
+                  "300 ms of the kill and the kernel is out of running within a second.")
 def armed_kill(ctx):
     ev = ctx.evidence
     fc = ctx.forgectrl
@@ -769,13 +791,20 @@ def armed_kill(ctx):
         ctx.log("emission live (%s) - SIGKILL controller pid %s NOW", smp["emission"], pid)
         t_kill = time.time()
         _os.kill(pid, _signal.SIGKILL)
+        fast = kill_fast_trail(t_kill)
         trail = kill_trail(ctx, t_kill)
+    ctx.log("after the kill (sysfs): %s", fast)
     zero_at, tail_zero, not_running = judge_kill(ctx, trail, "kill")
     ilk = hw.sysfs_int("cnc/interlock_circuit")
     locked = ilk is not None and bool(ilk & (1 << 3))
     ev["sigkill"] = {"pid": pid, "zero_at_s": zero_at, "tail_zero": tail_zero,
-                     "kernel_not_running": not_running, "latch_locked": locked, "trail": trail}
+                     "kernel_not_running": not_running, "latch_locked": locked, "trail": trail,
+                     "fast": fast}
     ctx.log("latch locked after the kill: %s", locked)
+    ctx.check(fast["latch_locked_at_s"] is not None and fast["latch_locked_at_s"] < 0.3,
+              "the latch was not locked within 300 ms of the kill: %s", fast)
+    ctx.check(fast["kernel_stopped_at_s"] is not None and fast["kernel_stopped_at_s"] < 1.0,
+              "the kernel was still running 1 s after the kill: %s", fast)
     ctx.check(zero_at is not None and zero_at < 2.5,
               "emission did not drop within 2.5 s of the kill (first 0 at %s)", zero_at)
     ctx.check(tail_zero, "emission returned after the kill")

forgetest/forgetest/suite/motion.py

@@ -753,11 +753,14 @@ def _return_x(ctx, delta_mm):
     machine_idle(ctx)
 
 
-@test("motion.deadman", title="Dead-man: controller kill, controller hang, forgectrl restart mid-move",
+@test("motion.deadman", title="Dead-man: controller kill, controller hang, forgectrl restart mid-move, "
-      subsystem="motion", kind="auto", mode="grbl", est_min=4,
+                             "a kill during the web-service homing",
+      subsystem="motion", kind="auto", mode="grbl", est_min=6,
       covers=_MOTION_COVERS + [("forgectrl", "src/main.c"), ("forgectrl", "init/**")],
       requires=["motion.cancel-abort", "kernel.k1-k2"],
-      steps=["Bed clear; the head needs 40 mm of free +X travel and must not be at the left rail."],
+      steps=["Bed clear; the head needs 40 mm of free +X travel and must not be at the left rail. "
+             "With cloud mode enabled the test also homes through the web service and kills the "
+             "controller mid-homing (about a minute); the head ends wherever the homing was."],
       description="SIGKILL of the controller mid-move: the supervisor reaps it, safes (cnc/stop, "
                   "latch relocked - it never unlocked), and respawns within seconds. SIGSTOP (a "
                   "hang) mid-move: the ring drains into a kernel underrun (fast halt, latch "
@@ -770,7 +773,10 @@ def _return_x(ctx, delta_mm):
                   "move completes with every step (the armed case faults, proven on the host). "
                   "forgectrl restart mid-move: the busy controller finishes the move unmanaged "
                   "and the new daemon retakes supervision at idle. After each drill the head is "
-                  "jogged back by the kernel-measured distance.")
+                  "jogged back by the kernel-measured distance. SIGKILL during $H (the web-service "
+                  "homing, with cloud mode enabled): the homing runner the controller left behind "
+                  "is ended before the respawn, the kernel is idle when the new controller starts, "
+                  "and the pulse device has one controller on it.")
 def deadman(ctx):
     import os as _os
     import signal as _signal
@@ -978,8 +984,155 @@ def deadman(ctx):
     x1 = _kernel_x_mm(ctx)
     _return_x(ctx, (x1 - x0) if (x0 is not None and x1 is not None) else None)
     machine_idle(ctx)
+
+    # ---- 4. SIGKILL during $H: the homing runner is ended, the kernel idle, one writer
+    homing_kill(ctx, wait_running)
+
     ctx.log("PASS: kill respawned in %s s, hang -> underrun in %s s, short stall warned and completed, "
-            "restart retook supervision (pid %s)", respawn_s, halt_s, m3.get("pid"))
+            "restart retook supervision (pid %s), the kill during $H ended the runner (%s)",
+            respawn_s, halt_s, m3.get("pid"), ev.get("homing_kill", {}).get("runner_gone_s", "skipped"))
+
+
+def _pulse_holders():
+    """The processes holding the pulse device open, by name."""
+    out = []
+    for pid in os.listdir("/proc"):
+        if not pid.isdigit():
+            continue
+        try:
+            for fd in os.listdir("/proc/%s/fd" % pid):
+                if os.readlink("/proc/%s/fd/%s" % (pid, fd)) == "/dev/glowforge":
+                    with open("/proc/%s/comm" % pid) as f:
+                        out.append(f.read().strip())
+                    break
+        except OSError:
+            continue
+    return out
+
+
+def homing_kill(ctx, wait_running):
+    """SIGKILL the GRBL controller while gfhome (the web-service homing
+    runner, its own process group on the inherited pulse fd) is moving
+    the head. The supervisor must end the runner before it starts another
+    controller, or two processes write the ring. Skipped when cloud mode
+    is not enabled on the machine (the runner needs the service)."""
+    import os as _os
+    import signal as _signal
+    fc = ctx.forgectrl
+    ev = ctx.evidence
+    before = fc.settings()
+    if str(before.get("cloud_enabled", "")).lower() not in ("1", "true", "yes", "on"):
+        ctx.log("kill during $H: skipped, cloud mode is not enabled on this machine")
+        return
+    hm = before.get("homing_mode", "")
+    ev["homing_kill"] = {"homing_mode": hm}
+    if hm != "gfcloud":
+        st, body = fc.post("/settings", data={"homing_mode": "gfcloud"})
+        ctx.check(st == 200, "homing_mode=gfcloud -> %s %s", st, body)
+    try:
+        m4 = wait_running(10)
+        ctx.check(m4, "controller not running before the homing drill")
+        pid4 = m4["pid"]
+        off = _log_offset(FORGECTRL_LOG)
+        runner_up = None
+        try:
+            with ctx.grbl() as g:
+                clean_slate(ctx, g)
+                g.send_raw(b"$H\n")
+                runner_up = ctx.wait_for(lambda: bool(hw.pidof("gfhome.py")), 30)
+                ctx.check(runner_up is not None, "the homing runner never started for $H")
+                ctx.sleep(3.0)                  # into the session: the runner drives the head
+                ctx.log("SIGKILL sent to controller pid %d during $H (runner pid %s)",
+                        pid4, hw.pidof("gfhome.py"))
+                _os.kill(pid4, _signal.SIGKILL)
+        except (hw.HwError, OSError) as e:
+            ctx.log("the Grbl connection ended with the kill: %s", e)
+        t_kill = time.time()
+        gone_s = ctx.wait_for(lambda: not hw.pidof("gfhome.py"), 15)
+        ev["homing_kill"]["runner_gone_s"] = gone_s
+        ctx.check(gone_s is not None, "the homing runner outlived its controller")
+        m5 = None
+        while time.time() - t_kill < 60:
+            st, m5 = fc.get("/mode")
+            if isinstance(m5, dict) and m5.get("controller") == "running" and m5.get("pid") != pid4:
+                break
+            ctx.sleep(0.5)
+        kstate = hw.sysfs_read("cnc/state")
+        holders = _pulse_holders()
+        lines = _log_lines(FORGECTRL_LOG, off, "homing runner")
+        halted = _log_lines(FORGECTRL_LOG, off, "halting it")
+        ev["homing_kill"].update({"respawn_s": round(time.time() - t_kill, 1), "mode_after": m5,
+                                  "kernel_state_at_respawn": kstate, "pulse_holders": holders,
+                                  "super_lines": [ln[-160:] for ln in lines[-3:]]})
+        ctx.log("kill during $H: runner gone in %s s, respawned as %s, kernel %s, pulse held by %s",
+                gone_s, m5 and m5.get("pid"), kstate, holders)
+        ctx.check(m5 and m5.get("pid") != pid4, "no respawn after the kill during $H: %s", m5)
+        ctx.check(lines, "the supervisor did not log the runner's end")
+        ctx.check(not halted, "the kernel had to be halted for the respawn: %s", halted[-1:])
+        ctx.check(kstate in ("idle", "disabled"), "the kernel was %s when the new controller started", kstate)
+        ctx.check("gfhome.py" not in holders and holders.count("grblHAL_glowfor") <= 1,
+                  "more than one controller on the pulse device: %s", holders)
+        ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle after the drill")
+    finally:
+        if hm != "gfcloud":
+            st, body = (fc.post("/settings", params={"homing_mode": ""}) if not hm
+                        else fc.post("/settings", data={"homing_mode": hm}))
+            ctx.log("restore homing_mode=%r -> %s", hm, st)
+
+
+@test("motion.respawn-gate", title="A respawn waits for the lid the way a first spawn does",
+      subsystem="motion", kind="operator", mode="grbl", est_min=2,
+      covers=_MOTION_COVERS, requires=["motion.deadman", "motion.gate-waits-for-lid"], actions=["lid"],
+      steps=["Bed clear. Open the lid when told and close it when told; nothing moves."],
+      description="The enclosure check runs before every controller spawn, respawns included. "
+                  "With the lid open, the controller is killed: the supervisor safes the machine "
+                  "(latch locked), reports waiting with why naming the lid, and starts no controller "
+                  "while the lid stays open. When the lid closes the controller comes back verified, "
+                  "without a second motion probe (the probe is once per broker hold).")
+def respawn_gate(ctx):
+    import os as _os
+    import signal as _signal
+    fc = ctx.forgectrl
+    ev = ctx.evidence
+    ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle at the start")
+    st, m0 = fc.get("/mode")
+    ctx.check(st == 200 and isinstance(m0, dict) and m0.get("controller") == "running", "controller not running: %s", m0)
+    pid0 = m0.get("pid")
+    off = _log_offset(FORGECTRL_LOG)
+    ctx.act("lid", "open")
+    try:
+        ctx.sleep(1.0)
+        _os.kill(pid0, _signal.SIGKILL)
+        t_kill = time.time()
+        ctx.log("SIGKILL sent to controller pid %d with the lid open", pid0)
+        waited = ctx.wait_for(lambda: (fc.get("/mode")[1] or {}).get("controller") == "waiting", 15)
+        st, m1 = fc.get("/mode")
+        ev["after_kill"] = {"waiting_s": waited, "mode": m1}
+        ctx.log("mode %.1f s after the kill: %s", time.time() - t_kill, m1)
+        ctx.check(waited is not None, "the supervisor did not report waiting for the lid: %s", m1)
+        ctx.check("lid" in (m1.get("why") or ""), "why does not name the lid: %r", m1.get("why"))
+        ilk = hw.sysfs_int("cnc/interlock_circuit")
+        ctx.check(ilk is not None and ilk & (1 << 3), "latch not locked after the kill")
+        ctx.sleep(4.0)
+        st, m2 = fc.get("/mode")
+        ctx.check(isinstance(m2, dict) and m2.get("controller") == "waiting" and not m2.get("pid"),
+                  "the wait did not hold with the lid open: %s", m2)
+    finally:
+        ctx.act("lid", "close")
+    t_close = time.time()
+    came = ctx.wait_for(lambda: ((fc.get("/mode")[1] or {}).get("controller") == "running"
+                                 and (fc.get("/mode")[1] or {}).get("pid") != pid0), 60)
+    st, m3 = fc.get("/mode")
+    ev["after_close"] = {"running_s": came, "mode": m3}
+    ctx.log("mode %.1f s after the lid closed: %s", time.time() - t_close, m3)
+    ctx.check(came is not None and m3.get("motion") == "verified",
+              "the controller did not come back verified after the lid closed: %s", m3)
+    lines = _probe_lines(FORGECTRL_LOG, off)
+    ev["probe_lines"] = lines[-2:]
+    ctx.check(not lines, "the motion probe ran again for the respawn: %s", lines[:1])
+    ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle at the end")
+    ctx.log("PASS: the respawn waited %.1f s for the lid, then came back verified in %.1f s with no probe",
+            t_close - t_kill, came)
 
 
 @test("motion.soft-limits", title="After a home the bed is the X/Y envelope",