forgetest: the cooling tests judge the log line their own run wrote

Six checks in five cooling tests read forgectrl's log tail once for the
line the engine writes when it acts: the TEC-on line (cooling.tec-drive),
the off gate's line and the run-end temperature line (cooling.gate-off),
the warm-up release and the floor's off line (cooling.floor-and-warm-up),
the critical line's off line (cooling.critical-tier), and the two
put-back lines (cooling.fan-duty-readback). The engine writes to the
device first and logs after, and the line reaches the file through
rsyslog a moment later still: on the bench reference cooling.tec-drive
read thermal/tec_on = 1 and then the tail a few milliseconds before
"TEC on: coolant 26.3 C over 24.5 C, airflow up" landed, and failed. A
tail read also takes a line an earlier run left behind for this run's.

Each check now marks forgectrl's log before the action that makes the
line (the settings write, the M8, the duty written behind the engine's
back) and waits up to 5 s for the line among those written after the
mark. Every line was checked against where cool.c writes it: gates_apply
for an off gate, the run's end for the temperatures, the warm-up release,
fans_verify for a put-back, the TEC policy for the TEC. The helpers
are motion's log offset pair, imported inside each test's function as the
fire-watch tests already do; the tests that poll the tail already
(_tail_wait) are unchanged.

Proof: tests/test_cooling_suite.py's fake engine writes its lines to a
scratch forgectrl log as well as to the fake tail, and a new case puts
an earlier run's off-gate line in the log with the engine writing none
this run: it fails as it must, and against the checks before this it
passes. 25 cooling cases pass; forgetest 500 OK. On the bench reference,
image 20260925183749 with this file mounted: cooling.tec-drive,
cooling.gate-off, cooling.floor-and-warm-up, cooling.critical-tier and
cooling.fan-duty-readback PASS, each baseline clean.

Acceptance: the five tests are the change; their fingerprints move and
no other test's does.
This commit is contained in:
ScottW514
2026-09-25 15:57:08 -04:00
parent 8570c0141e
commit d2307a899e
2 changed files with 86 additions and 14 deletions
+43 -6
View File
@@ -26,7 +26,28 @@ import unittest
import helpers
from forgetest.runner import Context, Failed, Run
from forgetest.suite import cooling
from forgetest.suite import cooling, motion
class EngineLog:
"""The engine's log lines, as the tests read them: appended to a scratch
forgectrl log (a check reads the lines written after its mark) and to the
fake /logs/tail."""
def log_setup(self):
self.logdir = tempfile.mkdtemp(prefix="forgetest-cool-")
self.saved_log = motion.FORGECTRL_LOG
motion.FORGECTRL_LOG = os.path.join(self.logdir, "forgectrl.log")
open(motion.FORGECTRL_LOG, "w").close()
def log_teardown(self):
motion.FORGECTRL_LOG = self.saved_log
shutil.rmtree(self.logdir, ignore_errors=True)
def emit(self, text):
self.fc.state.setdefault("logs_tail", {"text": ""})["text"] += text
with open(motion.FORGECTRL_LOG, "a", encoding="utf-8") as f:
f.write(text)
class FakeGrbl:
@@ -256,7 +277,7 @@ if __name__ == "__main__":
unittest.main()
class GateOffTests(unittest.TestCase):
class GateOffTests(EngineLog, unittest.TestCase):
"""cooling.gate-off against a scripted engine: the fake forgectrl
re-reads the ceiling at every M8 (as the engine reloads its tunables
at run start), trips OVERTEMP when the coolant is over it, skips the
@@ -267,6 +288,7 @@ class GateOffTests(unittest.TestCase):
def setUp(self):
self.fc = helpers.FakeForgectrl().start()
self.log_setup()
self.grbl = FakeGrbl()
self.saved = (cooling.VERDICT_WAIT_S, cooling.SESSION_END_WAIT_S)
cooling.VERDICT_WAIT_S = 3
@@ -292,6 +314,7 @@ class GateOffTests(unittest.TestCase):
cooling.VERDICT_WAIT_S, cooling.SESSION_END_WAIT_S = self.saved
self.grbl.close()
self.fc.stop()
self.log_teardown()
# -- the scripted machine --------------------------------------------------
def ceiling(self):
@@ -327,7 +350,7 @@ class GateOffTests(unittest.TestCase):
time.sleep(0.3)
cool["phase"] = "smoke"
if self.temps_line:
self.fc.state["logs_tail"]["text"] += (
self.emit(
"Aug 22 12:00:30 forgectrl: cool: temps this job: chassis 29.0..29.4 C, "
"soc 42.8..47.1 C, supply raw 587..592\n")
time.sleep(0.2)
@@ -341,7 +364,7 @@ class GateOffTests(unittest.TestCase):
v = self.ceiling()
off = v >= self.TOP
if off and self.log_line:
self.fc.state["logs_tail"]["text"] += (
self.emit(
"Aug 21 12:00:00 forgectrl: cool: gate coolant_max OFF: cool_temp_max = 60 "
"(the high end of 5 to 60; recommended 25 to 38, default 33)\n")
gates_off = ["coolant_max"] if off and self.report_off else []
@@ -418,6 +441,18 @@ class GateOffTests(unittest.TestCase):
self.assertIn("run-start log line", str(cm.exception))
self.assertEqual(self.fc.state["settings"]["cool_temp_max"], "")
def test_an_earlier_runs_line_is_not_this_runs(self):
# The off gate's line from a run before this one is in the log, and
# the engine writes none this time: the line judged is one written
# after the test's own mark, so the old one does not pass for it.
self.emit("Aug 21 11:00:00 forgectrl: cool: gate coolant_max OFF: cool_temp_max = 60 "
"(the high end of 5 to 60; recommended 25 to 38, default 33)\n")
self.log_line = False
with self.assertRaises(Failed) as cm:
self.run_test()
self.assertIn("run-start log line", str(cm.exception))
self.assertEqual(self.fc.state["settings"]["cool_temp_max"], "")
def test_a_missing_run_end_temperature_line_fails(self):
self.temps_line = False
with self.assertRaises(Failed) as cm:
@@ -433,7 +468,7 @@ class GateOffTests(unittest.TestCase):
self.assertEqual(self.fc.state["settings"]["cool_temp_max"], "30")
class CriticalTierTests(unittest.TestCase):
class CriticalTierTests(EngineLog, unittest.TestCase):
"""cooling.critical-tier against a scripted engine: two tiers on the
coolant, the fail tier winning over the pause tier in a run session
and ending with it, the critical line off at its top, and the settings
@@ -448,6 +483,7 @@ class CriticalTierTests(unittest.TestCase):
def setUp(self):
self.fc = helpers.FakeForgectrl().start()
self.log_setup()
self.grbl = FakeGrbl()
self.saved = (cooling.VERDICT_WAIT_S, cooling.SESSION_END_WAIT_S)
cooling.VERDICT_WAIT_S = 3
@@ -471,6 +507,7 @@ class CriticalTierTests(unittest.TestCase):
cooling.VERDICT_WAIT_S, cooling.SESSION_END_WAIT_S = self.saved
self.grbl.close()
self.fc.stop()
self.log_teardown()
def setting(self, key):
v = self.fc.state["settings"].get(key) or ""
@@ -523,7 +560,7 @@ class CriticalTierTests(unittest.TestCase):
crit_off = tcrit >= self.ROWS["cool_temp_critical_c"][3]
off = ["coolant_critical"] if crit_off else []
if crit_off:
self.fc.state["logs_tail"]["text"] += (
self.emit(
"Aug 22 12:00:00 forgectrl: cool: gate coolant_critical OFF: cool_temp_critical_c = 70 "
"(the high end of 6 to 70; recommended 36 to 45, default 38)\n")
if self.faults and not crit_off and self.UP >= tcrit: