diff --git a/forgetest/forgetest/baseline.py b/forgetest/forgetest/baseline.py index 1f6b315..75f5201 100644 --- a/forgetest/forgetest/baseline.py +++ b/forgetest/forgetest/baseline.py @@ -71,6 +71,9 @@ CAM_IDLE_S = 20 # camera engine idle stop is 10 s COOL_IDLE_S = 120 # cooldown after motion IDLE_S = 30 # cnc/state back to idle after a job +XY_STEPS_PER_MM = 53.333 # boards/glowforge.h (x8 microstepping) +RETURN_MAX_MM = 100.0 # a displaced head is jogged back at most this far + def leds_root(): r = os.environ.get("GF_LEDS_ROOT") or "/sys/class/leds/" @@ -339,6 +342,53 @@ class Baseline: act = "failed: %s" % e left.append(Leftover("leds/" + name, got, "0", act)) + def _return_head(self, was, now): + """Jog the head back along its own path by the kernel-measured X/Y + delta (Z is never touched), through the GRBL controller. Bounded: + beyond RETURN_MAX_MM per axis, or without a running GRBL + controller, the counters are reported and left.""" + dx = (now[0] - was[0]) / XY_STEPS_PER_MM + dy = (now[1] - was[1]) / XY_STEPS_PER_MM + if abs(dx) < 0.02 and abs(dy) < 0.02: + return "unrestorable (Z only)" if now[2] != was[2] else "restored" + if abs(dx) > RETURN_MAX_MM or abs(dy) > RETURN_MAX_MM: + return "unrestorable: %.1f/%.1f mm exceeds %.0f mm" % (dx, dy, RETURN_MAX_MM) + # a controller may be inside a respawn backoff (seconds): wait for it + mode = None + deadline = time.time() + 30 + while time.time() < deadline: + st, mode = self.fc_get("/mode") + if (st == 200 and isinstance(mode, dict) and mode.get("mode") == "grbl" + and mode.get("controller") == "running"): + break + if st is None: + break + time.sleep(1.0) + if not (isinstance(mode, dict) and mode.get("mode") == "grbl" + and mode.get("controller") == "running"): + return "unrestorable: no running GRBL controller" + try: + with hw.Grbl() as g: + rep = g.status_report() + if rep["state"].startswith("Alarm"): + g.command("$X") + g.command("$J=G91X%.3fY%.3fF1200" % (-dx, -dy)) + deadline = time.time() + 60 + while time.time() < deadline: + rep = g.status_report() + if rep["state"].startswith("Idle") and time.time() > deadline - 59.5: + break + time.sleep(0.2) + g.command("G90") + except (hw.HwError, OSError) as e: + return "failed: %s" % e + self.fc().wait_idle(15) + back = read_position() + if back is not None and abs(back[0] - was[0]) <= 2 and abs(back[1] - was[1]) <= 2: + self.log("head jogged back %.3f/%.3f mm to its start" % (-dx, -dy)) + return "restored (jogged back %.1f/%.1f mm)" % (-dx, -dy) + return "failed: counters read %s after the return jog" % back + def _preserved(self, left, captured): if not captured: return @@ -356,7 +406,7 @@ class Baseline: was = captured.get("position") now = read_position() if was is not None and now is not None and now != was: - left.append(Leftover("position", now, was, "unrestorable")) + left.append(Leftover("position", now, was, self._return_head(was, now))) was = captured.get("settings") if was: st, body = self.fc_get("/settings") diff --git a/forgetest/forgetest/runner.py b/forgetest/forgetest/runner.py index aeab5b4..adf4883 100644 --- a/forgetest/forgetest/runner.py +++ b/forgetest/forgetest/runner.py @@ -52,6 +52,7 @@ class Run: self.prompt = None # {"id","question","options"} self.answers = [] self.evidence = {} + self.baseline_captured = None # preserved state the post pass hands back self.aborted = threading.Event() self.finished = None # {"result","message","duration_s"} self.proc = None @@ -191,6 +192,17 @@ class Context: def takeover(self): return Takeover(self.run.log, self.test.id) + def counters_rezeroed(self): + """Tell the baseline the kernel position counters were re-zeroed + at the head's starting position during this run (cloud mode's + connect clears them): counters at (0,0,0) afterward mean the head + is back where the run found it.""" + cap = self.run.baseline_captured + if cap and cap.get("position") is not None: + cap["position"] = [0, 0, 0] + self.log("position counters re-zeroed at the starting position; the baseline " + "expects (0,0,0) at the end") + class Takeover: """Hardware takeover: the controller is stopped through the supervisor, @@ -418,11 +430,12 @@ class Runner: self.messages.append("leftovers before %s (left by %s): %s" % (run.id, who, "; ".join(str(x) for x in left))) run.evidence["baseline"] = {"pre": [x.as_dict() for x in left]} - return bl.capture() + run.baseline_captured = bl.capture() + return run.baseline_captured def _baseline_post(self, run, captured): bl = _baseline.Baseline(run.log) - left = bl.enforce("post", captured=captured) + left = bl.enforce("post", captured=run.baseline_captured or captured) run.evidence.setdefault("baseline", {})["post"] = [x.as_dict() for x in left] if left: self.messages.append("leftovers after %s: %s" % (run.id, "; ".join(str(x) for x in left))) diff --git a/forgetest/forgetest/suite/cloud.py b/forgetest/forgetest/suite/cloud.py index b349035..59ef08a 100644 --- a/forgetest/forgetest/suite/cloud.py +++ b/forgetest/forgetest/suite/cloud.py @@ -12,6 +12,64 @@ _CLOUD_COVERS = [("forgefirm-app", "**"), ("python3-gfhardware", "**"), ("python ("forgectrl", "src/super.c"), ("forgectrl", "src/main.c")] GF_LATEST = "/data/forgefirm/gf-latest.json" +GFCLOUD_LOG = "/data/log/forgefirm/gfcloud/gfcloud.log" +SESSION_MARKS = ("authenticate_machine SUCCESS", "ws_connect ESTABLISHED") +RETURN_MAX_MM = 600.0 # the head comes back from the home corner across the bed + + +def log_size(path): + try: + return os.path.getsize(path) + except OSError: + return 0 + + +def session_lines(path, offset): + """New gfcloud log lines since offset that carry a session mark.""" + try: + with open(path, "rb") as f: + f.seek(offset) + data = f.read().decode("utf-8", "replace") + except OSError: + return [] + return [ln.strip()[:160] for ln in data.splitlines() if any(m in ln for m in SESSION_MARKS)] + + +def session_established(lines): + return all(any(m in ln for ln in lines) for m in SESSION_MARKS) + + +def return_head(ctx, feed=2400): + """Jog the head back to where the run found it: cloud mode re-zeroed the + kernel counters at the starting position, so the counters now read the + displacement (the home corner). Ends on the machine idle.""" + fc = ctx.forgectrl + pos = fc.status().get("pos") or {} + x, y = float(pos.get("x", 0.0)), float(pos.get("y", 0.0)) + ctx.log("head displacement since the switch: X %.3f Y %.3f mm", x, y) + ctx.check(abs(x) <= RETURN_MAX_MM and abs(y) <= RETURN_MAX_MM, + "displacement %.1f/%.1f mm exceeds %.0f mm - not jogging back", x, y, RETURN_MAX_MM) + if abs(x) < 0.05 and abs(y) < 0.05: + return + with ctx.grbl() as g: + st = g.status_report()["state"] + if st.startswith("Alarm"): + g.command("$X") + r = g.command("$J=G91X%.3fY%.3fF%d" % (-x, -y, feed)) + ctx.check(not any(k.startswith("error") for k in r), "return jog refused: %s", r) + t0 = time.time() + while time.time() - t0 < 120: + ctx.checkpoint() + st = g.status_report()["state"] + if st.startswith("Idle") and time.time() - t0 > 0.5: + break + time.sleep(0.2) + g.command("G90") + ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle after the return jog") + pos = fc.status().get("pos") or {} + ctx.log("head returned: counters X %.3f Y %.3f mm", float(pos.get("x", 0)), float(pos.get("y", 0))) + ctx.check(abs(float(pos.get("x", 0))) < 0.1 and abs(float(pos.get("y", 0))) < 0.1, + "head not back at the start after the return jog: %s", pos) def wait_mode(ctx, fc, want_mode, want_controller="running", timeout=90): @@ -43,12 +101,14 @@ def grbl_port_open(timeout=5): @test("cloud.mode-switch", title="Controller mode switch grbl -> cloud -> grbl", subsystem="cloud", kind="auto", est_min=4, covers=_CLOUD_COVERS, requires=["forgectrl.auth", "motion.pacing"], - steps=["Bed clear (the supervisor's liveness probe may jog the head a few mm on a " - "controller spawn). Cloud credentials configured; the machine on the network."], + steps=["Bed clear: the cloud client homes the head to the corner on connect (the factory " + "hunt) and the test jogs it back to where it started afterward. Cloud credentials " + "configured; the machine on the network."], description="POST /mode switches to the cloud controller: gfcloud comes up under " - "supervision and records its connect-time service probe (/status gfsvc); the " - "camera service survives the switch; switching back brings grblHAL up with the " - "Grbl port open and Idle.") + "supervision, authenticates and establishes its service session (its own log " + "lines are the evidence; the connect-time firmware probe is recorded when " + "configured); the camera service survives the switch; switching back brings " + "grblHAL up with the Grbl port open and Idle, and the head returns to its start.") def mode_switch(ctx): fc = ctx.forgectrl ev = ctx.evidence @@ -64,6 +124,8 @@ def mode_switch(ctx): probe_before = os.stat(GF_LATEST).st_mtime except OSError: pass + log_offset = log_size(GFCLOUD_LOG) + lamp0 = hw.sysfs_read("pic/lid_led") st, body = fc.post("/mode", data={"controller": "cloud"}) ctx.log("POST /mode controller=cloud -> %s %s", st, body) @@ -73,22 +135,28 @@ def mode_switch(ctx): ctx.log("mode after switch: %s", m) ctx.check(m and m.get("mode") == "cloud" and m.get("controller") == "running", "cloud controller did not come up: %s", m) - # the connect-time service probe is the evidence of a live cloud session + # the client's own session lines are the evidence of a live cloud session t0 = time.time() + session = [] probe = None while time.time() - t0 < 120: ctx.checkpoint() - try: - mt = os.stat(GF_LATEST).st_mtime - if probe_before is None or mt > probe_before: - with open(GF_LATEST) as f: - probe = json.load(f) - break - except (OSError, ValueError): - pass + session = session_lines(GFCLOUD_LOG, log_offset) + if session_established(session): + break time.sleep(2) + ev["session"] = session + for ln in session: + ctx.log(" gfcloud: %s", ln.split(" ", 1)[-1] if " " in ln else ln) + try: + mt = os.stat(GF_LATEST).st_mtime + if probe_before is None or mt > probe_before: + with open(GF_LATEST) as f: + probe = json.load(f) + except (OSError, ValueError): + pass ev["gf_probe"] = probe - ctx.log("cloud service probe: %s", probe) + ctx.log("cloud session established: %s; firmware probe: %s", session_established(session), probe) st, cam1 = fc.get("/cam/status") ev["cam_during_cloud"] = cam1 ctx.check(st == 200 and isinstance(cam1, dict), "camera status lost during cloud mode (%s)", st) @@ -109,18 +177,31 @@ def mode_switch(ctx): ev["grbl_state"] = st ctx.log("grbl state after: %s", st) ctx.check(st.startswith("Idle") or st.startswith("Alarm"), "grbl reports %s", st) - ctx.check(probe is not None, "the cloud controller never recorded a service probe " - "(no credentials, no network, or the service refused) - cloud mode not proven") + ctx.check(session_established(session), + "the cloud client never established its service session (no credentials, no " + "network, or the service refused) - cloud mode not proven") st, cam2 = fc.get("/cam/status") ev["cam_after"] = cam2 ctx.check(st == 200, "camera status lost after the switch back") + # cloud mode's connect cleared the kernel counters at the starting position + # and its hunt homed the head: bring it back + ctx.counters_rezeroed() + return_head(ctx) + # cloud mode sets its own lid-lamp level (LLvl) and leaves it: hand back the level found + lamp1 = hw.sysfs_read("pic/lid_led") + ev["lid_lamp"] = {"before": lamp0, "after_cloud": lamp1} + if lamp0 is not None and lamp1 != lamp0: + hw.sysfs_write("pic/lid_led", lamp0) + ctx.log("lid lamp: cloud mode left %s, restored %s", lamp1, lamp0) @test("cloud.gfhome-homing", title="Glowforge web-service homing ($H with homing_mode=gfcloud)", subsystem="cloud", kind="operator", est_min=5, covers=_CLOUD_COVERS + [("grblhal-glowforge", "src/**")], requires=["cloud.mode-switch"], steps=["homing_mode = gfcloud and cloud credentials configured; bed clear, lid closed.", - "Watch the gantry: the service drives it to the corner with camera corrections."], + "Watch the gantry: the service drives it to the corner with camera corrections.", + "The machine ends homed, the head parked at the home corner (the position " + "counters are re-anchored there)."], description="In grbl mode, $H runs gfhome: the web-service homing session with the " "head-accelerometer motion witness. The controller returns to Idle with " "homed:true within the session timeout, and the operator confirms the head " @@ -161,3 +242,6 @@ def gfhome_homing(ctx): ctx.log("homing: homed=%s after %.1f s (kernel %s, grbl %s)", homed, ev["homing_s"], state, gs) ctx.check(homed, "homing did not complete (grbl %s)", gs) ctx.confirm("Did the head travel to the home corner under camera corrections and stop there?") + # homed: the counters are re-anchored at the corner, where the head stays + ctx.counters_rezeroed() + ctx.check(fc.wait_idle(15, abort=ctx.aborted), "machine not idle after homing") diff --git a/forgetest/tests/test_baseline.py b/forgetest/tests/test_baseline.py index 7c81a9d..c21984c 100644 --- a/forgetest/tests/test_baseline.py +++ b/forgetest/tests/test_baseline.py @@ -119,7 +119,8 @@ class BaselineTests(unittest.TestCase): self.assertEqual(set(items), {"pic/lid_led", "position"}) self.assertEqual(items["pic/lid_led"].action, "restored") self.assertEqual(self._read("pic/lid_led"), "132") - self.assertEqual(items["position"].action, "unrestorable") + # no GRBL controller on the host: the head cannot be jogged back + self.assertTrue(items["position"].action.startswith("unrestorable"), items["position"].action) self.assertEqual(items["position"].found, [1000, 0, 0]) def test_session_resting_lamp_from_boot_reference(self):