forgetest: the lid lamp idles at forgectrl's lid_lamp_idle; the liveness test masks and restarts

The lid lamp now has a resting policy in forgectrl (lid_lamp_idle,
default 236, asserted at start and at every spawn), so the baseline
expects it there instead of preserving whatever level a boot left, and
forgectrl.settings-bounds proves it: resting at the setting, 256 / -1 /
'bright' refused, a new level applied to the lamp at once, the cleared
key back to the default. Clearing a key goes through the query-string
form (an empty JSON value reads as no setting).

motion.liveness-probe adds the regression the bench needed: with every
axis masked (cnc/motor_lock=15, as a bench tool may leave it) forgectrl
is restarted and its fresh probe must read MOTION OK on the first try -
the probe unmasks the axes itself - and the controller comes up with the
mask cleared. Bench 2026-08-16: MOTION OK at p2p 2047/1341 against the
800 threshold, no ladder.

The baseline's settle no longer counts 'probe verified, spawn pending' as
settled (the post pass ran between the probe's own writes and the
controller's init writes and mis-flagged motor_lock/step_freq): it waits
for the controller to be running, with a bounded allowance for a respawn
backoff.
This commit is contained in:
ScottW514
2026-08-16 15:07:34 -04:00
parent 8654c36e99
commit d0291ec7cb
6 changed files with 179 additions and 42 deletions
+11 -11
View File
@@ -112,11 +112,12 @@ items: **fixed** resting values the boot establishes (the kernel module
defaults, forgectrl's start-up writes, the GRBL controller's init writes: defaults, forgectrl's start-up writes, the GRBL controller's init writes:
`motor_lock=8`, `x/y_mode=8`, `x/y_decay=1`, `step_freq=28160`, `motor_lock=8`, `x/y_mode=8`, `x/y_decay=1`, `step_freq=28160`,
`ramp_rate=125000`, `streaming=0`, `state=idle`, latch locked, hold `ramp_rate=125000`, `streaming=0`, `state=idle`, latch locked, hold
currents, camera lamps and button LEDs off, heater and TEC off; forgectrl: currents, head lamp and button LEDs off, heater and TEC off, the lid lamp
the controller running with motion verified, no diagnostic, the camera at forgectrl's `lid_lamp_idle` setting; forgectrl: the controller running
engine and cooling engine idle), and **preserved** state with no resting with motion verified, no diagnostic, the camera engine and cooling engine
policy that a run must hand back as it found it (the lid lamp level, the idle), and **preserved** state with no resting policy that a run must
position counters, the settings map, the controller mode). Deviations are hand back as it found it (the position counters, the settings map, the
controller mode). Deviations are
**leftovers**: logged in the run pane, kept in the result's `evidence` **leftovers**: logged in the run pane, kept in the result's `evidence`
(`baseline.pre` / `baseline.post`), and surfaced in the page's message (`baseline.pre` / `baseline.post`), and surfaced in the page's message
line - a leftover found before a run is attributed to the previous run; one line - a leftover found before a run is attributed to the previous run; one
@@ -129,12 +130,11 @@ verified, or the ladder's verdict) before and after every takeover.
**Power-cycle before a campaign.** forgetest takes a **fresh-boot **Power-cycle before a campaign.** forgetest takes a **fresh-boot
reference** once per boot (`/data/forgetest/boot-<boot_id>.json`, taken reference** once per boot (`/data/forgetest/boot-<boot_id>.json`, taken
only within the first ten minutes after boot, after the supervisor only within the first ten minutes after boot, after the supervisor
settles): the whole idle picture of this machine as the image boots it. It settles): the whole idle picture of this machine as the image boots it,
is the session's resting lid-lamp level and the check on the fixed values; the check on the fixed values, and the record a leftover is judged
without one the lamp level is unknown and the page says so. Take it after against. Take it after a **power cycle**, not a warm `reboot` - the
a **power cycle**, not a warm `reboot`: the PIC lights the lid lamp at machine's true fresh state is the powered-on one (the PIC's own lamp and
power-on (132), and a warm reboot leaves it dark because the module's sensor defaults, then forgectrl's start-up writes on top).
remove path turns it off - the machine's true fresh state is the lit one.
A displaced head is jogged back along its own path by the kernel-measured A displaced head is jogged back along its own path by the kernel-measured
X/Y delta (bounded to 100 mm; Z is never touched); beyond that the X/Y delta (bounded to 100 mm; Z is never touched); beyond that the
counters are reported and the run must be fixed. A run that legitimately counters are reported and the run must be fixed. A run that legitimately
+44 -10
View File
@@ -9,9 +9,12 @@ restores it after (on every exit path), so a test cannot hand the next one
the GRBL controller's init writes. Verified against the value, the GRBL controller's init writes. Verified against the value,
restored by writing it back. restored by writing it back.
preserved state with no resting policy that a run must hand back as it preserved state with no resting policy that a run must hand back as it
found it: the lid lamp level, the position counters, the found it: the position counters, the settings map, the
settings map, the controller mode. Captured before the run, controller mode. Captured before the run, compared after,
compared after, restored where the interface allows. restored where the interface allows.
The lid lamp is fixed too, at forgectrl's `lid_lamp_idle` setting (unset =
236): the daemon asserts it at start and at every controller spawn.
Everything found off-baseline is a "leftover": logged, kept in the run's Everything found off-baseline is a "leftover": logged, kept in the run's
evidence, and surfaced on the page. The pre-run pass attributes leftovers evidence, and surfaced on the page. The pre-run pass attributes leftovers
@@ -63,7 +66,10 @@ LATCH_BIT = 0x08 # interlock_circuit bit 3: latch locked
BUTTON_LEDS = ("button_led_1", "button_led_2", "button_led_3") BUTTON_LEDS = ("button_led_1", "button_led_2", "button_led_3")
PRESERVED_SYSFS = ["pic/lid_led"] # captured before, restored after PRESERVED_SYSFS = [] # sysfs attrs captured before, restored after
LID_LAMP_ATTR = "pic/lid_led"
LID_LAMP_DEFAULT = "236" # forgectrl's lid_lamp_idle default
BOOT_MAX_AGE_S = 600 # a boot reference is taken only this soon after boot BOOT_MAX_AGE_S = 600 # a boot reference is taken only this soon after boot
SETTLE_S = 150 # the supervisor's probe + rail-off ladder SETTLE_S = 150 # the supervisor's probe + rail-off ladder
@@ -165,6 +171,7 @@ class Baseline:
t0 = time.time() t0 = time.time()
deadline = t0 + timeout deadline = t0 + timeout
last = seen = heard = None last = seen = heard = None
pending_since = None # verified but not running: the spawn follows
while time.time() < deadline and not self.abort(): while time.time() < deadline and not self.abort():
try: try:
st, body = self.fc().get("/mode") st, body = self.fc().get("/mode")
@@ -181,12 +188,20 @@ class Baseline:
if key != seen: if key != seen:
seen = key seen = key
self.log("/mode controller=%s motion=%s" % key) self.log("/mode controller=%s motion=%s" % key)
if (body.get("motion") == "verified" ctl = body.get("controller")
or body.get("controller") in ("motion-fault", "standby")): if ctl in ("motion-fault", "standby") or (ctl == "running" and body.get("motion") == "verified"):
if body.get("controller") == "motion-fault": if ctl == "motion-fault":
self.log("WARNING - motion liveness ladder failed, controllers are " self.log("WARNING - motion liveness ladder failed, controllers are "
"down (motion-fault); retry via POST /mode") "down (motion-fault); retry via POST /mode")
return body return body
if body.get("motion") == "verified":
# the probe passed; the spawn (or a respawn backoff of up to
# 30 s) is in flight - give it a bounded moment
pending_since = pending_since or time.time()
if time.time() - pending_since > 35:
return body
else:
pending_since = None
time.sleep(1.0) time.sleep(1.0)
self.log("WARNING - forgectrl did not settle within %d s (last /mode: %s)" % (timeout, last)) self.log("WARNING - forgectrl did not settle within %d s (last /mode: %s)" % (timeout, last))
return last return last
@@ -214,6 +229,7 @@ class Baseline:
left = [] left = []
self._forgectrl_side(left) self._forgectrl_side(left)
self._kernel_side(left) self._kernel_side(left)
self._lamp_side(left)
self._preserved(left, captured) self._preserved(left, captured)
if left: if left:
self.log("%s: %d leftover(s): %s" % (phase, len(left), "; ".join(str(x) for x in left))) self.log("%s: %d leftover(s): %s" % (phase, len(left), "; ".join(str(x) for x in left)))
@@ -305,6 +321,23 @@ class Baseline:
left.append(Leftover("cool", found, "idle/unarmed/no hold", left.append(Leftover("cool", found, "idle/unarmed/no hold",
"waited" if w is not None else "failed: still %s" % found)) "waited" if w is not None else "failed: still %s" % found))
def _lamp_side(self, left):
"""The lid lamp at forgectrl's idle level (the lid_lamp_idle setting)."""
st, body = self.fc_get("/settings")
if st != 200 or not isinstance(body, dict):
return
want = (body.get("lid_lamp_idle") or "").strip() or LID_LAMP_DEFAULT
got = hw.sysfs_read(LID_LAMP_ATTR)
if got is None or got == want:
return
try:
hw.sysfs_write(LID_LAMP_ATTR, want)
back = hw.sysfs_read(LID_LAMP_ATTR)
act = "restored" if back == want else "failed: reads %s" % back
except OSError as e:
act = "failed: %s" % e
left.append(Leftover(LID_LAMP_ATTR, got, want, act))
def _kernel_side(self, left): def _kernel_side(self, left):
if hw.sysfs_read("cnc/state") is None: if hw.sysfs_read("cnc/state") is None:
self.log("kernel sysfs not present - kernel-side checks skipped") self.log("kernel sysfs not present - kernel-side checks skipped")
@@ -414,7 +447,8 @@ class Baseline:
for k, v in was.items(): for k, v in was.items():
if body.get(k) == v: if body.get(k) == v:
continue continue
st2, b2 = self.fc_post("/settings", data={k: v}) st2, b2 = (self.fc_post("/settings", params={k: ""}) if v == ""
else self.fc_post("/settings", data={k: v}))
left.append(Leftover("settings." + k, body.get(k), v, left.append(Leftover("settings." + k, body.get(k), v,
"restored" if st2 == 200 else "failed: %s %s" % (st2, b2))) "restored" if st2 == 200 else "failed: %s %s" % (st2, b2)))
@@ -514,8 +548,8 @@ def boot_reference(log, data_dir):
pass pass
up = uptime_s() up = uptime_s()
if up is None or up > BOOT_MAX_AGE_S: if up is None or up > BOOT_MAX_AGE_S:
log("baseline: no fresh-boot reference for this boot (uptime %s s > %d s) - " log("baseline: no fresh-boot reference for this boot (uptime %s s > %d s); "
"the lid lamp resting level is unknown; reboot to take one" % (up, BOOT_MAX_AGE_S)) "power-cycle to take one" % (up, BOOT_MAX_AGE_S))
return None return None
bl = Baseline(log) bl = Baseline(log)
bl.wait_settled() bl.wait_settled()
+1 -3
View File
@@ -422,9 +422,7 @@ class Runner:
record what the previous run left behind. Returns the captured record what the previous run left behind. Returns the captured
preserved state for the post pass.""" preserved state for the post pass."""
bl = _baseline.Baseline(run.log, abort=run.aborted.is_set) bl = _baseline.Baseline(run.log, abort=run.aborted.is_set)
ref = self.boot_ref left = bl.enforce("pre", captured=None)
session = {"sysfs": {a: (ref.get("sysfs") or {}).get(a) for a in _baseline.PRESERVED_SYSFS}} if ref else None
left = bl.enforce("pre", captured=session)
if left: if left:
who = self.last.id if self.last is not None else "an earlier run" who = self.last.id if self.last is not None else "an earlier run"
self.messages.append("leftovers before %s (left by %s): %s" self.messages.append("leftovers before %s (left by %s): %s"
+43 -2
View File
@@ -1,6 +1,7 @@
"""forgectrl.* - the machine-services daemon's API, access control, and panel.""" """forgectrl.* - the machine-services daemon's API, access control, and panel."""
import json import json
import socket import socket
import time
from ..catalog import test from ..catalog import test
from .. import hw from .. import hw
@@ -107,9 +108,11 @@ def auth(ctx):
@test("forgectrl.settings-bounds", title="Settings validation and restore", subsystem="forgectrl", @test("forgectrl.settings-bounds", title="Settings validation and restore", subsystem="forgectrl",
kind="auto", est_min=1, kind="auto", est_min=1,
covers=[("forgectrl", "src/settings.*"), ("forgectrl", "src/main.c")], covers=[("forgectrl", "src/settings.*"), ("forgectrl", "src/main.c"), ("forgectrl", "src/cam.c")],
description="An over-length value and an out-of-range value are refused (400) and leave the " description="An over-length value and an out-of-range value are refused (400) and leave the "
"settings byte-identical; an in-range value is accepted (200).") "settings byte-identical; an in-range value is accepted (200). The lid lamp "
"idles at lid_lamp_idle (unset = 236), an out-of-range level is refused, a new "
"level applies to the lamp at once, and clearing it returns the default.")
def settings_bounds(ctx): def settings_bounds(ctx):
fc = ctx.forgectrl fc = ctx.forgectrl
ev = ctx.evidence ev = ctx.evidence
@@ -158,6 +161,44 @@ def settings_bounds(ctx):
ctx.check(others_before == others_after, "other settings changed by the write") ctx.check(others_before == others_after, "other settings changed by the write")
ctx.check(final.get(key) == val, "%s reads back %r, wrote %r", key, final.get(key), val) ctx.check(final.get(key) == val, "%s reads back %r, wrote %r", key, final.get(key), val)
# the lid lamp's idle level: resting at the setting, bounded, applied live
lamp_was = (before.get("lid_lamp_idle") or "").strip()
want = lamp_was or "236"
got = ctx.sysfs("pic/lid_led")
ev["lid_lamp"] = {"setting": lamp_was, "resting": got}
ctx.log("lid lamp: setting %r, pic/lid_led=%s (expected %s)", lamp_was, got, want)
ctx.check(got == want, "lid lamp rests at %s, lid_lamp_idle is %s", got, want)
for bad in ("256", "-1", "bright"):
st, body = fc.post("/settings", data={"lid_lamp_idle": bad})
ctx.check(st == 400, "lid_lamp_idle=%s -> %s, expected 400", bad, st)
ctx.log("lid_lamp_idle 256 / -1 / bright refused")
try_level = "100" if want != "100" else "120"
st, body = fc.post("/settings", data={"lid_lamp_idle": try_level})
ctx.check(st == 200, "lid_lamp_idle=%s -> %s, expected 200", try_level, st)
applied = None
t0 = time.time()
while time.time() - t0 < 5:
applied = ctx.sysfs("pic/lid_led")
if applied == try_level:
break
ctx.sleep(0.2)
ctx.log("lid_lamp_idle=%s -> pic/lid_led=%s after %.1f s", try_level, applied, time.time() - t0)
# an empty value clears the key: the query-string form carries it
st, body = (fc.post("/settings", params={"lid_lamp_idle": ""}) if not lamp_was
else fc.post("/settings", data={"lid_lamp_idle": lamp_was}))
ctx.check(st == 200, "restoring lid_lamp_idle=%r -> %s", lamp_was, st)
t0 = time.time()
back = None
while time.time() - t0 < 5:
back = ctx.sysfs("pic/lid_led")
if back == want:
break
ctx.sleep(0.2)
ev["lid_lamp"].update({"applied": applied, "restored": back})
ctx.check(applied == try_level, "lamp did not follow lid_lamp_idle=%s (reads %s)", try_level, applied)
ctx.check(back == want, "lamp did not return to %s after the restore (reads %s)", want, back)
ctx.log("lid lamp follows the setting live and returns to %s", want)
@test("forgectrl.panel-serves", title="Control panel and status endpoints", subsystem="forgectrl", @test("forgectrl.panel-serves", title="Control panel and status endpoints", subsystem="forgectrl",
kind="auto", est_min=1, kind="auto", est_min=1,
+71 -2
View File
@@ -5,6 +5,7 @@ Ported from `scripts/bench/pacing_test.py` (protocol-loop pacing) and
and round-trip; the laser stays latched (the tests never touch it); the and round-trip; the laser stays latched (the tests never touch it); the
suite is the only Grbl client while a test runs. suite is the only Grbl client while a test runs.
""" """
import os
import time import time
from ..catalog import test from ..catalog import test
@@ -230,13 +231,23 @@ def jog_roundtrip(ctx):
kind="auto", est_min=1, kind="auto", est_min=1,
covers=[("forgectrl", "src/super.c"), ("forgectrl", "src/liveness.c"), ("kernel-module-glowforge", "**")], covers=[("forgectrl", "src/super.c"), ("forgectrl", "src/liveness.c"), ("kernel-module-glowforge", "**")],
requires=["kernel.latch-locked-idle"], requires=["kernel.latch-locked-idle"],
steps=["Bed clear, lid closed: the probe jogs the head a few mm (+X first)."], steps=["Bed clear, lid closed: the probe jogs the head 15 mm out and back (+X first); "
"forgectrl is restarted once for a fresh probe."],
description="forgectrl's supervisor reports the head-accelerometer liveness probe as " description="forgectrl's supervisor reports the head-accelerometer liveness probe as "
"verified for the running controller (the DRV8825s are not wedged); when the " "verified for the running controller (the DRV8825s are not wedged); when the "
"probe was skipped at spawn, the controller is respawned once so it runs.") "probe was skipped at spawn, the controller is respawned once so it runs. Then "
"the regression: with every axis masked (cnc/motor_lock=15, as a bench tool "
"may leave it) forgectrl is restarted and its fresh probe must still read "
"MOTION OK - the probe unmasks the axes itself - with the head-accel p2p at "
"or above the moving threshold.")
def liveness_probe(ctx): def liveness_probe(ctx):
fc = ctx.forgectrl fc = ctx.forgectrl
ev = ctx.evidence ev = ctx.evidence
_liveness_verdict(ctx, fc, ev)
_liveness_masked_restart(ctx, fc, ev)
def _liveness_verdict(ctx, fc, ev):
st, m = fc.get("/mode") st, m = fc.get("/mode")
ctx.check(st == 200 and isinstance(m, dict), "GET /mode -> %s", st) ctx.check(st == 200 and isinstance(m, dict), "GET /mode -> %s", st)
ev["mode_before"] = m ev["mode_before"] = m
@@ -263,6 +274,64 @@ def liveness_probe(ctx):
ctx.check(m.get("motion") == "verified", "liveness is %r, expected verified", m.get("motion")) ctx.check(m.get("motion") == "verified", "liveness is %r, expected verified", m.get("motion"))
FORGECTRL_LOG = "/data/log/forgefirm/forgectrl/forgectrl.log"
def _log_offset(path):
try:
return os.path.getsize(path)
except OSError:
return 0
def _probe_lines(path, offset):
try:
with open(path, "rb") as f:
f.seek(offset)
data = f.read().decode("utf-8", "replace")
except OSError:
return []
return [ln.strip() for ln in data.splitlines() if "liveness probe:" in ln]
def _liveness_masked_restart(ctx, fc, ev):
"""The regression: a leftover motor_lock must not read as a wedge."""
ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle before the masked restart")
x0 = _kernel_x_mm(ctx)
hw.sysfs_write("cnc/motor_lock", "15")
ctx.log("masked every axis (cnc/motor_lock=15); restarting forgectrl for a fresh probe")
off = _log_offset(FORGECTRL_LOG)
rc, out = hw.initd("forgectrl", "restart")
ctx.check(rc == 0, "forgectrl restart -> rc %s", rc)
m = None
t0 = time.time()
while time.time() - t0 < 150:
ctx.checkpoint()
try:
st, m = fc.get("/mode")
except hw.HwError:
m = None # the daemon is still coming up
if isinstance(m, dict) and ((m.get("controller") == "running" and m.get("motion") == "verified")
or m.get("controller") == "motion-fault"):
break
ctx.sleep(1)
lines = _probe_lines(FORGECTRL_LOG, off)
for ln in lines:
ctx.log(" %s", ln.split(" INFO ", 1)[-1] if " INFO " in ln else ln[-160:])
ev["masked_restart"] = {"mode": m, "probe_lines": lines[-4:], "motor_lock_after": ctx.sysfs("cnc/motor_lock")}
ctx.check(m and m.get("controller") == "running" and m.get("motion") == "verified",
"fresh probe under a leftover mask did not verify motion: %s", m)
ctx.check(lines and "MOTION OK" in lines[0],
"the first probe after the restart was not MOTION OK: %s", lines[:1])
ctx.check(len(lines) == 1, "the probe needed the recovery ladder (%d probes) - a false dead verdict", len(lines))
ctx.check(ctx.sysfs("cnc/motor_lock") == "8", "motor_lock reads %s after the controller start (expected 8)",
ctx.sysfs("cnc/motor_lock"))
ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle after the probe")
x1 = _kernel_x_mm(ctx)
ctx.log("kernel X %s -> %s mm across the probe (out and back)", x0, x1)
ctx.log("PASS: masked restart probed MOTION OK on the first try, mask cleared, controller up")
# ---------------------------------------------------------------- cancel / abort # ---------------------------------------------------------------- cancel / abort
@test("motion.cancel-abort", title="Jog cancel and controlled abort recover cleanly", subsystem="motion", @test("motion.cancel-abort", title="Jog cancel and controlled abort recover cleanly", subsystem="motion",
+9 -14
View File
@@ -105,31 +105,26 @@ class BaselineTests(unittest.TestCase):
self._sync_leds() self._sync_leds()
self.assertEqual(baseline.read_led("button_led_2"), "0") self.assertEqual(baseline.read_led("button_led_2"), "0")
def test_preserved_lamp_and_position(self): def test_preserved_position(self):
b = self.bl() b = self.bl()
self._attr("pic/lid_led", "132")
cap = b.capture() cap = b.capture()
self.assertEqual(cap["sysfs"]["pic/lid_led"], "132")
self.assertEqual(cap["position"], [0, 0, 0]) self.assertEqual(cap["position"], [0, 0, 0])
# the run turned the lamp off and shifted the counters # the run shifted the counters
self._attr("pic/lid_led", "0")
self._pos(1000, 0, 0) self._pos(1000, 0, 0)
left = b.enforce("post", captured=cap) left = b.enforce("post", captured=cap)
items = {x.item: x for x in left} items = {x.item: x for x in left}
self.assertEqual(set(items), {"pic/lid_led", "position"}) self.assertEqual(set(items), {"position"})
self.assertEqual(items["pic/lid_led"].action, "restored")
self.assertEqual(self._read("pic/lid_led"), "132")
# no GRBL controller on the host: the head cannot be jogged back # no GRBL controller on the host: the head cannot be jogged back
self.assertTrue(items["position"].action.startswith("unrestorable"), items["position"].action) self.assertTrue(items["position"].action.startswith("unrestorable"), items["position"].action)
self.assertEqual(items["position"].found, [1000, 0, 0]) self.assertEqual(items["position"].found, [1000, 0, 0])
def test_session_resting_lamp_from_boot_reference(self): def test_lamp_needs_forgectrl(self):
# the pre pass hands the lamp back to the boot level # the lamp's idle level comes from forgectrl's settings: without the
# daemon there is nothing to compare against
self._attr("pic/lid_led", "77") self._attr("pic/lid_led", "77")
session = {"sysfs": {"pic/lid_led": "0"}} left = self.bl().enforce("pre", captured=None)
left = self.bl().enforce("pre", captured=session) self.assertEqual(left, [])
self.assertEqual([(x.item, x.action) for x in left], [("pic/lid_led", "restored")]) self.assertEqual(self._read("pic/lid_led"), "77")
self.assertEqual(self._read("pic/lid_led"), "0")
def test_no_sysfs_means_skip(self): def test_no_sysfs_means_skip(self):
os.environ["GF_SYSFS_ROOT"] = os.path.join(self.tmp, "nope") + os.sep os.environ["GF_SYSFS_ROOT"] = os.path.join(self.tmp, "nope") + os.sep