diff --git a/forgetest/forgetest/suite/cooling.py b/forgetest/forgetest/suite/cooling.py index 72c71ac..63bebe9 100644 --- a/forgetest/forgetest/suite/cooling.py +++ b/forgetest/forgetest/suite/cooling.py @@ -10,6 +10,7 @@ legal range trips the gate, the far end of the range turns it off by value, and both are said out loud: the settings reply, /status, the engine's run-start log line), and the airflow gates (a fan under its floor past the spin-up grace is a fault for the rest of the run).""" +import os import time from ..catalog import test @@ -1246,7 +1247,6 @@ LOAD_LINES = 27 # two 30 x 4 mm fills back to back, about 35 LOAD_SHARE_MIN_C = 0.3 # the tube was lit inside the window LOAD_MARGIN_C = 1.0 # the judged rise this far under the limit LOAD_VERDICT_WAIT_S = 120 # the window opens ~15 s into the session and runs 50 s -LOAD_LOG_LINES = "300" _LOAD_LINE_RX = None @@ -1270,9 +1270,19 @@ def _load_fill(): return lines -def _forgectrl_tail(fc): - st, body = fc.get("/logs/tail", params={"name": "forgectrl", "lines": LOAD_LOG_LINES}) - return body.get("text", "") if st == 200 and isinstance(body, dict) else "" +def _log_since(path, offset): + """The text a log gained since byte `offset`. A count of lines in a + tail of fixed length cannot tell a new line from an old one: the new + line comes in at the bottom as an old one leaves at the top. A file now + shorter than the offset was rotated under the test, and all of it is + newer.""" + try: + with open(path, "rb") as f: + if os.fstat(f.fileno()).st_size >= offset: + f.seek(offset) + return f.read().decode("utf-8", "replace") + except OSError: + return "" @test("cooling.flow-under-load", title="The flow check reads true with the tube lit through its window", @@ -1290,6 +1300,7 @@ def _forgectrl_tail(fc): "the tube's share off and read its baseline as a mean.") def flow_under_load(ctx): from .laser import sample, prepare, LiveJob, ARM_CUE, run_and_sample, wait_disarm + from .motion import FORGECTRL_LOG, _log_offset fc = ctx.forgectrl ev = ctx.evidence state, check_s = _gate_state(fc, "cool_flow_check_s") @@ -1297,7 +1308,7 @@ def flow_under_load(ctx): ctx.check(state != "off" and check_s, "the flow check is off (cool_flow_check_s=%s)", check_s) ctx.check(limit, "cool_flow_rise unreadable") ev.update({"check_s": check_s, "limit_c": limit}) - before = _forgectrl_tail(fc).count("heater rise") + off = _log_offset(FORGECTRL_LOG) # the verdict is a line written after this # The fill ends one line length out and (LOAD_LINES - 1) pitches up; # the job brings the head back so the baseline finds it where it began. back = "G0 X%g Y%g" % (-LOAD_WIDTH if LOAD_LINES % 2 else 0.0, -LOAD_PITCH * (LOAD_LINES - 1)) @@ -1332,12 +1343,11 @@ def flow_under_load(ctx): ctx.checkpoint() if hw.sysfs_int("thermal/heater_pwm", 0) > 0: heater_seen = True - text = _forgectrl_tail(fc) - if text.count("heater rise") > before: - m = None - for m in _load_verdict_rx().finditer(text): - pass - line = m.group(0) if m else None + m = None + for m in _load_verdict_rx().finditer(_log_since(FORGECTRL_LOG, off)): + pass + if m: + line = m.group(0) break ctx.sleep(1) ev["heater_seen"] = heater_seen diff --git a/forgetest/tests/test_cooling_suite.py b/forgetest/tests/test_cooling_suite.py index e72671a..e83f7a1 100644 --- a/forgetest/tests/test_cooling_suite.py +++ b/forgetest/tests/test_cooling_suite.py @@ -734,3 +734,51 @@ class FanGateTests(unittest.TestCase): self.run_test() self.assertIn("lacks exhaust", str(cm.exception)) self.assertEqual(self.fc.state["settings"]["cool_tach_exhaust_min_rpm"], "") + + +class FlowVerdictLogTests(unittest.TestCase): + """cooling.flow-under-load finds the engine's verdict in what the log + gained since the job began, not in a count over a tail of fixed length: + there a new verdict line comes in at the bottom as an old one leaves at + the top, the count does not move, and a check that verified reads as + one that never judged.""" + + VERDICT = ("2026-09-19T21:37:46.869674+00:00 forgectrl[2796] INFO cool: coolant flow verified " + "(heater rise 11.5 C, dT 9.5 C; laser 1.6 off 13.1)\n") + OLD = ("2026-09-19T21:17:27.200840+00:00 forgectrl[965] INFO cool: coolant flow verified " + "(heater rise 9.5 C, dT 8.7 C)\n") + + def setUp(self): + self.dir = tempfile.mkdtemp(prefix="flowlog.") + self.addCleanup(shutil.rmtree, self.dir, ignore_errors=True) + self.path = os.path.join(self.dir, "forgectrl.log") + + def write(self, text, mode="w"): + with open(self.path, mode, newline="\n") as f: + f.write(text) + + def test_only_the_text_after_the_offset_comes_back(self): + self.write(self.OLD + "filler\n" * 400) + off = os.path.getsize(self.path) + self.assertEqual(cooling._log_since(self.path, off), "") + self.write(self.VERDICT, mode="a") + text = cooling._log_since(self.path, off) + self.assertEqual(text, self.VERDICT) + m = cooling._load_verdict_rx().search(text) + self.assertEqual(m.group(1), "coolant flow verified") + self.assertEqual((m.group(2), m.group(5)), ("11.5", "1.6")) + + def test_an_old_verdict_before_the_offset_is_not_the_new_one(self): + self.write(self.OLD) + off = os.path.getsize(self.path) + self.write("2026-09-19T21:36:40+00:00 forgectrl[2796] INFO cool: crash watch armed\n", mode="a") + self.assertIsNone(cooling._load_verdict_rx().search(cooling._log_since(self.path, off))) + + def test_a_log_rotated_under_the_test_is_read_whole(self): + self.write(self.OLD + "filler\n" * 400) + off = os.path.getsize(self.path) + self.write(self.VERDICT) # the rotation: a new, shorter file + self.assertEqual(cooling._log_since(self.path, off), self.VERDICT) + + def test_a_missing_log_reads_as_nothing(self): + self.assertEqual(cooling._log_since(os.path.join(self.dir, "none.log"), 0), "")