From 41417f820b878feb796051f24a6a8654e338c2bd Mon Sep 17 00:00:00 2001 From: ScottW514 Date: Tue, 15 Sep 2026 17:35:25 -0400 Subject: [PATCH] forgetest: clear a latched controller error, bound the move-start check, and follow the fail-tier restart Three acceptance tests broke on the WI-4/WI-5 firmware, all from a behavior a change moved and no test tracked. motion: soft limits are armed after a home (the driver's, since the bed has no switches), so a jog past the bed is refused with error:15 - and grblHAL then answers error:15 to every following G-code line, across a fresh connection, until a blank line acknowledges it. A prior test's or the baseline hand-back's rejected jog left that latch, and the next test's first move failed with a stale error unrelated to the move. clean_slate now clears it with a blank line before the first move. The four "send G1, sleep, check Run once" sites are replaced by start_move, which waits for Run on a bound and, when it does not come, names the reply, the state, the drained messages and a forgectrl snapshot - the capture that turned "the move did not start" into "answered error:15". cooling.fire-watch-tiers: the FIRE fail tier now stops the controller through the supervisor and starts it again, so leg 2's Grbl connection dies mid-leg. It now records the pid, reads FIRE from the engine and the latch from sysfs, waits out the restart, proves the supervisor logged the fail-tier stop, and opens a fresh session for the legs that follow; src/super.* added to its covers. Proof: full forgetest host suite green; coverage lint clean (90 tests); bench reference on the dev image, unattended queue: motion.* and cooling.* pass, cooling.fire-watch-tiers and cooling.fail-tier-stop pass with the button-lamp driver fix (grblHAL-glowforge). --- forgetest/forgetest/suite/cooling.py | 43 +++++++++++++--- forgetest/forgetest/suite/motion.py | 75 +++++++++++++++++++++++----- 2 files changed, 99 insertions(+), 19 deletions(-) diff --git a/forgetest/forgetest/suite/cooling.py b/forgetest/forgetest/suite/cooling.py index d2584f2..3932c96 100644 --- a/forgetest/forgetest/suite/cooling.py +++ b/forgetest/forgetest/suite/cooling.py @@ -746,7 +746,7 @@ FIRE_WAIT_S = 25 # settings re-read at run start, two-tick breach, 1 @test("cooling.fire-watch-tiers", title="The lid-IR fire watch pauses at its alert and fails at its critical", subsystem="cooling", kind="auto", mode="grbl", est_min=6, - covers=_COOL_COVERS, requires=["kernel.latch-locked-idle"], + covers=_COOL_COVERS + [("forgectrl", "src/super.*")], requires=["kernel.latch-locked-idle"], steps=["Machine idle, lid closed, lid lamp at its resting level. The test moves the flame " "thresholds under the lamp's own reading and restores them; three M8/M9 sessions, " "no fire."], @@ -759,6 +759,7 @@ FIRE_WAIT_S = 25 # settings re-read at run start, two-tick breach, 1 "read as the four flame gates off and the watch reads watch. Restored, the " "watch reads armed at OK.") def fire_watch_tiers(ctx): + from .motion import FORGECTRL_LOG, _log_lines, _log_offset fc = ctx.forgectrl ev = ctx.evidence before = fc.settings() @@ -810,7 +811,16 @@ def fire_watch_tiers(ctx): ctx.check(c.get("verdict") == "OK", "the alert survived into a fresh session: %s", c) # Leg 2: the fail tier. The q1 critical under the lamp reading - # stops the session and latches FIRE until it ends. + # latches FIRE and locks the laser; the fail tier then stops + # the controller through the supervisor and starts it again, + # so no run start can relight what was locked and the sender + # sees the job end. The Grbl socket dies with the restart - + # FIRE is read from the engine, the latch from sysfs, the stop + # from the supervisor's log, and a fresh session is opened for + # the legs that follow. + st, m0 = fc.get("/mode") + pid0 = m0.get("pid") if isinstance(m0, dict) else None + off = _log_offset(FORGECTRL_LOG) _set_gates(ctx, fc, {"cool_fire_q1_critical": str(max(2, q1 - 5)), "cool_fire_q1_alert": str(max(1, q1 - 10))}) grbl.command("M8") @@ -821,19 +831,38 @@ def fire_watch_tiers(ctx): c = _cool(fc) if c.get("verdict") == "FIRE": break + ilk = hw.sysfs_int("cnc/interlock_circuit") ev["critical"] = c - ctx.log("critical leg: verdict %s fire_watch %s", c.get("verdict"), c.get("fire_watch")) + ev["interlock_circuit"] = ilk + ctx.log("critical leg: verdict %s fire_watch %s interlock_circuit %s", + c.get("verdict"), c.get("fire_watch"), ilk) ctx.check(c.get("verdict") == "FIRE", "q1 critical under the lamp did not latch FIRE: %s", c) ctx.check(c.get("fire_watch") == "ALARM", "fire_watch %r during FIRE, expected ALARM", c.get("fire_watch")) - ilk = hw.sysfs_int("cnc/interlock_circuit") - ev["interlock_circuit"] = ilk ctx.check(ilk is not None and (ilk & 8), "the laser latch is not locked under FIRE (interlock_circuit=%s)", ilk) ctx.check(_tail_wait(ctx, fc, "LID IR FIRE SIGNAL (quartiles "), "the FIRE line is missing from the forgectrl log") + # the fail tier stops the controller and starts it again; the + # Grbl socket dies with it. Wait out the restart, prove the + # supervisor logged the stop, restore the thresholds, and open + # a fresh session on the new controller. + grbl.close() + m1 = None + t0 = time.time() + while time.time() - t0 < 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) + ev["restart"] = {"pid_before": pid0, "mode_after": m1} + ctx.log("after FIRE: %s", ev["restart"]) + ctx.check(m1 and m1.get("controller") == "running" and m1.get("pid") != pid0, + "the controller was not stopped and started again after FIRE: %s", m1) + ctx.check(_log_lines(FORGECTRL_LOG, off, "lid IR fire signal - the controller is stopped"), + "the supervisor did not log the fail-tier stop after FIRE") _set_gates(ctx, fc, {"cool_fire_q1_critical": orig["cool_fire_q1_critical"], "cool_fire_q1_alert": orig["cool_fire_q1_alert"]}) - grbl.command("M9") - _session_ended(ctx, fc, "critical leg") + ctx.check(fc.wait_idle(30, abort=ctx.aborted), "machine not idle after the FIRE restart") + grbl.connect() # a fresh session on the restarted controller # Leg 3: all four at zero: the watch off, said so, session OK. _set_gates(ctx, fc, {k: "0" for k in FIRE_KEYS}) diff --git a/forgetest/forgetest/suite/motion.py b/forgetest/forgetest/suite/motion.py index a5b735d..d569c97 100644 --- a/forgetest/forgetest/suite/motion.py +++ b/forgetest/forgetest/suite/motion.py @@ -136,9 +136,68 @@ def clean_slate(ctx, g): ctx.log("unlock: %s", g.command("$X")) st = g.status_report() ctx.check(st["state"].startswith("Idle"), "controller is %s, expected Idle", st["state"]) + clear_error(ctx, g) return st +def clear_error(ctx, g): + """Clear a latched line error before the test's first move. + + Soft limits are armed after a home (the driver's, since the bed has + no switches), so a jog past the bed is refused with error:15 - and + grblHAL then answers error:15 to every following G-code line, across + a fresh connection, until a blank line acknowledges it ($ commands + and the ? report are unaffected, so a sender that queries on connect + self-clears; a bare G-code stream does not). A prior test's or the + baseline hand-back's rejected jog would otherwise make this test's + first move fail with a stale error unrelated to the move. A blank + line clears it and returns ok. Harmless and idempotent at Idle.""" + r = g.command("") + ctx.check(r and r[-1] == "ok" and not any(x.startswith("error") for x in r), + "the controller answered %s to a blank line at the start - not a clean parser", r) + + +MOVE_START_S = 2.0 # Run is there within 100 ms; a loaded board gets this long + + +def start_move(ctx, g, line): + """Start a travel job with `line` and see the controller in Run. The + wait is bounded, not a fixed sleep. When Run never comes, the failure + names what happened instead: the reply (a refused block answers + error), the state the controller sits in (Hold, Door, Alarm, or an + Idle that never took the block), every line it said meanwhile, and + the machine as forgectrl sees it - the evidence a bare "did not + start" leaves out. Recorded in the evidence either way.""" + reply = g.command(line, timeout=1.0) + end = time.time() + MOVE_START_S + t0 = time.time() + said = "" + st = None + while time.time() < end: + ctx.checkpoint() + st = g.status_report() + if st["state"].startswith("Run"): + break + said += g.drain() + time.sleep(0.1) + rec = {"line": line, "reply": reply, "state": st["state"] if st else None, + "after_s": round(time.time() - t0, 2)} + ctx.evidence.setdefault("move_start", []).append(rec) + if st is not None and st["state"].startswith("Run"): + return st + msgs = [ln.strip() for ln in said.splitlines() if ln.strip()] + rec["said"] = msgs + s = ctx.forgectrl.status() or {} + gr = ((s.get("grbl") or {}).get("report") or {}) + rec["forgectrl"] = {"state": s.get("state"), "switches": s.get("switches"), + "laser_locked": s.get("laser_locked"), "grbl": gr.get("state"), + "alarm": gr.get("alarm"), "sender": (gr.get("sender") or {}).get("connected")} + ctx.check(False, "the move did not start: %s answered %s; controller %s %.1f s later, said %s; " + "forgectrl sees kernel %s, grbl %s (alarm %s), switches %s, laser locked %s", + line, reply, st["state"] if st else "no report", rec["after_s"], msgs or "nothing", + s.get("state"), gr.get("state"), gr.get("alarm"), s.get("switches"), s.get("laser_locked")) + + @test("motion.pacing", title="Protocol-loop pacing (idle, parked, moving) and hold/resume position", subsystem="motion", kind="auto", mode="grbl", est_min=1, covers=_MOTION_COVERS, requires=["kernel.latch-locked-idle"], @@ -1334,9 +1393,7 @@ def button_hold_resume(ctx): "moves; the job holds and the test sees it.") g.command("M5") g.command("G91") - g.command("G1X40F300", timeout=0.5) # an 8 s move - ctx.sleep(0.5) - ctx.check(g.status_report()["state"].startswith("Run"), "the move did not start") + start_move(ctx, g, "G1X40F300") # an 8 s move g.drain() # the message window opens here w = Watch(g) ctx.act("button", "press", until=w.in_state("Hold"), timeout=12, fail=False) @@ -1412,9 +1469,7 @@ def lid_cancel_home(ctx): "leave it open until the head has come back on its own.") g.command("M5") g.command("G91") - g.command("G1X40F300", timeout=0.5) # an 8 s move - ctx.sleep(0.5) - ctx.check(g.status_report()["state"].startswith("Run"), "the move did not start") + start_move(ctx, g, "G1X40F300") # an 8 s move g.drain() # the message window opens here ctx.act("lid", "open", text="Leave it open until the head has come back.", timeout=12) drift = expect_cancel_and_return(ctx, g, ev, start, k0, "lid opened", "running") @@ -1507,9 +1562,7 @@ def interlock_cancel_home(ctx): "moves and leave it open until the head has come back on its own.") g.command("M5") g.command("G91") - g.command("G1X60F300", timeout=0.5) # a 12 s move - ctx.sleep(0.5) - ctx.check(g.status_report()["state"].startswith("Run"), "the move did not start") + start_move(ctx, g, "G1X60F300") # a 12 s move g.drain() ctx.act("interlock", "open", text="Leave it open until the head has come back.", timeout=16) sw = (ctx.forgectrl.status().get("switches") or {}) @@ -1571,9 +1624,7 @@ def lid_policy_hold(ctx): "the job parks in the door state and waits.") g.command("M5") g.command("G91") - g.command("G1X40F300", timeout=0.5) # an 8 s move - ctx.sleep(0.5) - ctx.check(g.status_report()["state"].startswith("Run"), "the move did not start") + start_move(ctx, g, "G1X40F300") # an 8 s move g.drain() ctx.act("lid", "open", timeout=12) st, text = wait_state_text(ctx, g, "Door", 8)