forgetest: the hand-back reads an engine hold again past the engine's next tick

The cooling engine publishes its state once a tick (1 Hz). A /cool/status
read inside the tick after a run ended still shows the run: while a
diagnostic owns the hardware every tick publishes phase "diag" with the
hold set, and a fail tier's hold stands until the tick that ends its
session. The baseline took one read, and by its rule an arm or a hold is
the run's doing, so a test that finished inside that second failed its
hand-back on a hold the engine's next tick cleared.

Seen on the bench reference twice. cooling.aa-offset-calibrate in campaign
c-20260919215024-c402: the diagnostic reported done at 22:07:14 with its
offset measured (15.7 counts, spread 0.7), and the hand-back at 22:07:15
read "cool=diag/armed=False/hold=True ... -> waited" and failed the run;
the test had passed on five images before, the last one earlier the same
day. cooling.fail-tier-stop in c-20260919202934-3d3a, the same way on the
crash fault's hold (0ceb4ab made that test wait for its own fault; this is
the general case).

The cooling check moves into Baseline._cool_side. An arm or a hold is read
again for up to COOL_PUBLISH_S (2.5 s: two ticks and a margin) before it is
called the run's doing. One the next tick cleared is logged as the engine's
last word on the run and judged on what the engine reads then: idle is
clean, a cooldown phase is waited out as the engine's own post-job work. A
hold a run did leave stands for a job that is never coming back, so it is
still there after the tick and is recorded, stood down and failed exactly
as before; a hold that clears only later is still a leftover ("waited").

Proven: tests/test_baseline.py CoolPublishTests - a diagnostic's hold the
next tick clears, a fail tier's hold clearing into the smoke phase, a hold
that outlives the tick (recorded, machine stood down), a hold that clears
only later (recorded as waited), an idle engine and a silent daemon; the
baseline, queue, operator, mode, responsiveness and server host tests
pass under Linux. baseline.py is not a suite module, so no test's
fingerprint moves with it.
This commit is contained in:
ScottW514
2026-09-19 18:16:04 -04:00
parent dc7170d0d1
commit f306c9983f
2 changed files with 128 additions and 28 deletions
+53 -28
View File
@@ -138,6 +138,7 @@ BOOT_MAX_AGE_S = 600 # a boot reference is taken only this soon a
SETTLE_S = 150 # the supervisor's probe + rail-off ladder
CAM_IDLE_S = 20 # camera engine idle stop is 10 s
COOL_IDLE_S = 120 # cooldown after motion
COOL_PUBLISH_S = 2.5 # the engine publishes once a tick (1 Hz): two ticks and a margin
IDLE_S = 30 # cnc/state back to idle after a job
GRBL_PORT_S = 30 # the Grbl port after the supervisor reports grblHAL running
@@ -613,36 +614,60 @@ class Baseline:
except OSError as e:
act = "failed: %s" % e
left.append(Leftover("laser_locked", False, True, act))
# cooling engine idle, unarmed
self._cool_side(left)
def _cool_side(self, left):
"""The cooling engine idle, unarmed, holding nothing."""
st, c = self.fc_get("/cool/status")
if st == 200 and isinstance(c, dict):
if c.get("phase") != "idle" or c.get("armed") or c.get("hold"):
if st != 200 or not isinstance(c, dict):
return
if c.get("phase") == "idle" and not c.get("armed") and not c.get("hold"):
return
found = "%s/armed=%s/hold=%s" % (c.get("phase"), c.get("armed"), c.get("hold"))
idle = lambda: (lambda x: x.get("phase") == "idle" and not x.get("armed") # noqa: E731
and not x.get("hold"))(self.fc_get("/cool/status")[1] or {})
# The engine publishes once a tick (1 Hz). A read inside the tick
# after a run ended still shows the run: a diagnostic's hold until
# the engine has the hardware back, a fail tier's hold until the
# session ends with the controller. What the engine's next tick
# clears was never left behind, so an arm or a hold is read again
# past that tick before it is called the run's doing. One that a
# run did leave stands for a job that is never coming back, and it
# is still there.
if c.get("armed") or c.get("hold"):
free = lambda: (lambda x: bool(x) and not x.get("armed") # noqa: E731
and not x.get("hold"))(self.fc_get("/cool/status")[1] or {})
if self._wait("cool publish", free, COOL_PUBLISH_S) is not None:
st, c2 = self.fc_get("/cool/status")
c = c2 if st == 200 and isinstance(c2, dict) else {}
self.log("cool: %s was the engine's last word on the run; its next tick reads "
"%s/armed=%s/hold=%s" % (found, c.get("phase"), c.get("armed"), c.get("hold")))
if c.get("phase") == "idle":
return
found = "%s/armed=%s/hold=%s" % (c.get("phase"), c.get("armed"), c.get("hold"))
idle = lambda: (lambda x: x.get("phase") == "idle" and not x.get("armed") # noqa: E731
and not x.get("hold"))(self.fc_get("/cool/status")[1] or {})
# Armed, or holding, is the run's doing. A phase alone is
# not: the engine clears smoke at run duty after an armed
# session and cools down after a hot one, both timed and
# both ending on their own. Waiting for that is right;
# calling it a leftover is not, because nothing was left -
# the machine was still finishing.
dirt = bool(c.get("armed") or c.get("hold"))
w = self._wait("cool idle", idle, COOL_IDLE_S)
if w is not None and not dirt:
self.log("cool: %s ended on its own after %.0f s; the engine's own post-job "
"work, not a leftover" % (found, w))
else:
# The engine holds for a job. A run that ended without
# ending its job leaves one alive, and no amount of
# waiting ends it: stand the machine down and let the
# supervisor bring the controller back clean.
act = "waited"
if w is None:
self.stand_down("the cooling engine is still %s" % found)
w = self._wait("cool idle", idle, COOL_IDLE_S)
act = "restored (stood the machine down)"
left.append(Leftover("cool", found, "idle/unarmed/no hold",
act if w is not None else "failed: still %s" % found))
# Armed, or holding, is the run's doing. A phase alone is
# not: the engine clears smoke at run duty after an armed
# session and cools down after a hot one, both timed and
# both ending on their own. Waiting for that is right;
# calling it a leftover is not, because nothing was left -
# the machine was still finishing.
dirt = bool(c.get("armed") or c.get("hold"))
w = self._wait("cool idle", idle, COOL_IDLE_S)
if w is not None and not dirt:
self.log("cool: %s ended on its own after %.0f s; the engine's own post-job "
"work, not a leftover" % (found, w))
return
# The engine holds for a job. A run that ended without
# ending its job leaves one alive, and no amount of
# waiting ends it: stand the machine down and let the
# supervisor bring the controller back clean.
act = "waited"
if w is None:
self.stand_down("the cooling engine is still %s" % found)
w = self._wait("cool idle", idle, COOL_IDLE_S)
act = "restored (stood the machine down)"
left.append(Leftover("cool", found, "idle/unarmed/no hold",
act 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).
+75
View File
@@ -437,6 +437,81 @@ class TransientNotLeftoverTests(BaselineTests):
self.assertEqual(items[0].found, "1014")
class CoolPublishTests(unittest.TestCase):
"""The cooling engine publishes once a tick. A status read inside the
tick after a run ended is the engine's last word on the run, not the
machine as the run left it. Found on the bench reference: a diagnostic
that finished clean (cooling.aa-offset-calibrate) and a fail tier that
did its work (cooling.fail-tier-stop) both failed their hand-back on a
hold the engine's next tick cleared."""
IDLE = {"phase": "idle", "armed": False, "hold": False}
def setUp(self):
self.lines = []
def bl(self, statuses):
"""A baseline whose /cool/status answers play in order (the last
one repeats) and whose waits count reads, not seconds: three for
the engine's next tick, as the real wait makes, and enough for the
cooldown to let a slow script run out."""
b = baseline.Baseline(self.lines.append)
seq = list(statuses)
b.fc_get = lambda path: (200, dict(seq.pop(0) if len(seq) > 1 else seq[0]))
def wait(what, pred, timeout):
for i in range(3 if what == "cool publish" else 50):
if pred():
return float(i)
return None
b._wait = wait
b.stood_down = []
b.stand_down = b.stood_down.append
return b
def test_a_diagnostic_hold_the_next_tick_clears_is_not_a_leftover(self):
left = []
b = self.bl([{"phase": "diag", "armed": False, "hold": True}, self.IDLE])
b._cool_side(left)
self.assertEqual(left, [])
self.assertTrue(any("last word on the run" in ln for ln in self.lines), self.lines)
def test_a_fail_tier_hold_clears_into_the_engines_own_post_job_phase(self):
left = []
b = self.bl([{"phase": "run", "armed": False, "hold": True},
{"phase": "smoke", "armed": False, "hold": False},
{"phase": "smoke", "armed": False, "hold": False}, self.IDLE])
b._cool_side(left)
self.assertEqual(left, [])
self.assertTrue(any("not a leftover" in ln for ln in self.lines), self.lines)
def test_a_hold_that_outlives_the_tick_is_the_runs_doing(self):
left = []
b = self.bl([{"phase": "run", "armed": True, "hold": True}])
b._cool_side(left)
self.assertEqual([x.item for x in left], ["cool"])
self.assertEqual(left[0].found, "run/armed=True/hold=True")
self.assertTrue(left[0].action.startswith("failed: still"), left[0].action)
self.assertEqual(len(b.stood_down), 1)
def test_a_hold_that_clears_only_later_is_still_recorded(self):
left = []
held = {"phase": "run", "armed": False, "hold": True}
b = self.bl([held] * 10 + [self.IDLE])
b._cool_side(left)
self.assertEqual([x.item for x in left], ["cool"])
self.assertEqual(left[0].action, "waited")
self.assertEqual(b.stood_down, [])
def test_an_idle_engine_and_a_silent_daemon_leave_nothing(self):
left = []
self.bl([self.IDLE])._cool_side(left)
b = baseline.Baseline(self.lines.append)
b.fc_get = lambda path: (None, None)
b._cool_side(left)
self.assertEqual(left, [])
class CloudOwnedSysfsTests(unittest.TestCase):
"""In cloud mode the cloud client configures the machine from the
pulse header it is playing, the lens included: z_mode comes from