mirror of
https://github.com/openglow-org/forgefirm.git
synced 2026-09-27 16:51:12 -07:00
forgetest: motion tests end on the machine's idle; the Grbl client survives a soft reset
wait_idle returned on a stale Idle before a just-commanded move began, and the tests declared PASS on grblHAL's Idle while the kernel still played the stream depth and the decel tail (the baseline caught state=running after motion.pacing). Every motion test now ends on forgectrl's idle (machine_idle), and wait_idle ignores an Idle inside a short grace unless a non-Idle state was seen. status_report re-sends '?' every 0.5 s until a report arrives: a soft reset (^X) flushes the controller's read buffer and eats a '?' that lands in it - the bench saw motion.cancel-abort error with no report for 5 s after the abort while the controller answered the next '?' at once. motion.deadman: the SIGSTOP drill waited for a running controller and got the killed pid back before the supervisor reaped it (drill 1 already waited for a different pid); and the forgectrl-restart drill expected the busy controller's pid to survive the retake, but a retake under the broker is stop-at-idle, re-probe, start a supervised controller (the old inherited fd cannot be adopted) - the check is now: the move finished unmanaged, supervision came back running and verified. Bench-proven 2026-08-16: kill respawn 1.3 s, hang -> underrun 0.21 s, retake at idle.
This commit is contained in:
@@ -276,10 +276,14 @@ class Grbl:
|
|||||||
self.send_raw(bytes([byte]))
|
self.send_raw(bytes([byte]))
|
||||||
|
|
||||||
def status_report(self):
|
def status_report(self):
|
||||||
"""One '?' report, parsed: {'state': 'Idle', 'MPos': (x,y,z), ...}."""
|
"""One '?' report, parsed: {'state': 'Idle', 'MPos': (x,y,z), ...}.
|
||||||
|
The '?' is re-sent every 0.5 s until a report arrives: a soft
|
||||||
|
reset (^X) flushes the controller's read buffer and eats a '?'
|
||||||
|
that lands in it."""
|
||||||
self.drain()
|
self.drain()
|
||||||
self.send_raw(b"?")
|
self.send_raw(b"?")
|
||||||
deadline = time.time() + self.timeout
|
deadline = time.time() + self.timeout
|
||||||
|
resend = time.time() + 0.5
|
||||||
self.sock.settimeout(0.2)
|
self.sock.settimeout(0.2)
|
||||||
while time.time() < deadline:
|
while time.time() < deadline:
|
||||||
try:
|
try:
|
||||||
@@ -288,6 +292,9 @@ class Grbl:
|
|||||||
self.buf += d
|
self.buf += d
|
||||||
except socket.timeout:
|
except socket.timeout:
|
||||||
pass
|
pass
|
||||||
|
if time.time() >= resend:
|
||||||
|
self.send_raw(b"?")
|
||||||
|
resend = time.time() + 0.5
|
||||||
i = self.buf.find(b"<")
|
i = self.buf.find(b"<")
|
||||||
j = self.buf.find(b">", i + 1) if i >= 0 else -1
|
j = self.buf.find(b">", i + 1) if i >= 0 else -1
|
||||||
if i >= 0 and j > i:
|
if i >= 0 and j > i:
|
||||||
|
|||||||
@@ -48,11 +48,14 @@ def wait_state(ctx, g, prefix, timeout):
|
|||||||
return None
|
return None
|
||||||
|
|
||||||
|
|
||||||
def wait_idle(ctx, g, timeout=30.0, poll=0.05):
|
def wait_idle(ctx, g, timeout=30.0, poll=0.05, grace=0.3):
|
||||||
"""Poll until Idle; returns (peak_feed_mm_min, states_seen, final_report)."""
|
"""Poll until Idle; returns (peak_feed_mm_min, states_seen, final_report).
|
||||||
|
An Idle report inside the first `grace` seconds counts only once a
|
||||||
|
non-Idle state was seen: a move just commanded may not have started."""
|
||||||
peak = 0.0
|
peak = 0.0
|
||||||
states = []
|
states = []
|
||||||
deadline = time.time() + timeout
|
t0 = time.time()
|
||||||
|
deadline = t0 + timeout
|
||||||
st = None
|
st = None
|
||||||
while time.time() < deadline:
|
while time.time() < deadline:
|
||||||
ctx.checkpoint()
|
ctx.checkpoint()
|
||||||
@@ -66,12 +69,20 @@ def wait_idle(ctx, g, timeout=30.0, poll=0.05):
|
|||||||
peak = max(peak, float(str(f).split(",")[0]))
|
peak = max(peak, float(str(f).split(",")[0]))
|
||||||
except ValueError:
|
except ValueError:
|
||||||
pass
|
pass
|
||||||
if state.startswith("Idle"):
|
if state.startswith("Idle") and (time.time() - t0 >= grace or len(states) > 1):
|
||||||
return peak, states, st
|
return peak, states, st
|
||||||
time.sleep(poll)
|
time.sleep(poll)
|
||||||
return peak, states + ["TIMEOUT"], st
|
return peak, states + ["TIMEOUT"], st
|
||||||
|
|
||||||
|
|
||||||
|
def machine_idle(ctx, timeout=15.0):
|
||||||
|
"""The machine itself idle - the kernel has played out the stream
|
||||||
|
depth and the decel tail behind grblHAL's Idle. Every motion test ends
|
||||||
|
on this, so it hands the machine back at rest."""
|
||||||
|
ok = ctx.forgectrl.wait_idle(timeout, abort=ctx.aborted)
|
||||||
|
ctx.check(ok, "the machine did not return to idle within %.0f s of the last move", timeout)
|
||||||
|
|
||||||
|
|
||||||
def clean_slate(ctx, g):
|
def clean_slate(ctx, g):
|
||||||
st = g.status_report()
|
st = g.status_report()
|
||||||
ctx.log("connect: %s", st["state"])
|
ctx.log("connect: %s", st["state"])
|
||||||
@@ -138,6 +149,7 @@ def pacing(ctx):
|
|||||||
g.command("G90")
|
g.command("G90")
|
||||||
final = g.status_report().get("MPos")
|
final = g.status_report().get("MPos")
|
||||||
ev["final_drift_mm"] = round(final[0] - start[0], 3) if final else None
|
ev["final_drift_mm"] = round(final[0] - start[0], 3) if final else None
|
||||||
|
machine_idle(ctx)
|
||||||
|
|
||||||
ctx.check(abs(moved - dist) < 0.05, "hold+resume lost steps: moved %.3f of %.1f mm", moved, dist)
|
ctx.check(abs(moved - dist) < 0.05, "hold+resume lost steps: moved %.3f of %.1f mm", moved, dist)
|
||||||
ctx.check(parked < moving * 0.5 and parked < 8.0,
|
ctx.check(parked < moving * 0.5 and parked < 8.0,
|
||||||
@@ -203,6 +215,7 @@ def jog_roundtrip(ctx):
|
|||||||
drift = max(abs(a - b) for a, b in zip(final[:2], start[:2]))
|
drift = max(abs(a - b) for a, b in zip(final[:2], start[:2]))
|
||||||
ev["drift_mm"] = round(drift, 3)
|
ev["drift_mm"] = round(drift, 3)
|
||||||
ctx.log("final drift %.3f mm (start %s, final %s)", drift, start, final)
|
ctx.log("final drift %.3f mm (start %s, final %s)", drift, start, final)
|
||||||
|
machine_idle(ctx)
|
||||||
ctx.check("Hold" in held["state"], "feed hold did not park (state %s)", held["state"])
|
ctx.check("Hold" in held["state"], "feed hold did not park (state %s)", held["state"])
|
||||||
ctx.check(drift <= 0.05, "position drift %.3f mm", drift)
|
ctx.check(drift <= 0.05, "position drift %.3f mm", drift)
|
||||||
ctx.confirm("Did the gantry move on every jog (X, Y, the fast X, the diagonal, the held move) "
|
ctx.confirm("Did the gantry move on every jog (X, Y, the fast X, the diagonal, the held move) "
|
||||||
@@ -304,6 +317,7 @@ def cancel_abort(ctx):
|
|||||||
ctx.log("returned: drift %.3f mm", drift)
|
ctx.log("returned: drift %.3f mm", drift)
|
||||||
ctx.check(drift <= 0.05, "position drift %.3f mm after cancel/abort/return", drift)
|
ctx.check(drift <= 0.05, "position drift %.3f mm after cancel/abort/return", drift)
|
||||||
g.command("G90")
|
g.command("G90")
|
||||||
|
machine_idle(ctx)
|
||||||
|
|
||||||
|
|
||||||
# ---------------------------------------------------------------- dead-man
|
# ---------------------------------------------------------------- dead-man
|
||||||
@@ -324,6 +338,7 @@ def _return_x(ctx, delta_mm):
|
|||||||
g.command("$X")
|
g.command("$X")
|
||||||
g.command("$J=G91X%.3fF1200" % (-delta_mm))
|
g.command("$J=G91X%.3fF1200" % (-delta_mm))
|
||||||
wait_idle(ctx, g, 30)
|
wait_idle(ctx, g, 30)
|
||||||
|
machine_idle(ctx)
|
||||||
|
|
||||||
|
|
||||||
@test("motion.deadman", title="Dead-man: controller kill, controller hang, forgectrl restart mid-move",
|
@test("motion.deadman", title="Dead-man: controller kill, controller hang, forgectrl restart mid-move",
|
||||||
@@ -348,11 +363,14 @@ def deadman(ctx):
|
|||||||
v = hw.sysfs_int("cnc/interlock_circuit")
|
v = hw.sysfs_int("cnc/interlock_circuit")
|
||||||
return v is not None and bool(v & (1 << 3))
|
return v is not None and bool(v & (1 << 3))
|
||||||
|
|
||||||
def wait_running(timeout=30):
|
def wait_running(timeout=30, not_pid=None):
|
||||||
|
"""A running controller; with not_pid, one other than that pid (a
|
||||||
|
killed controller can still read as running until it is reaped)."""
|
||||||
t0 = time.time()
|
t0 = time.time()
|
||||||
while time.time() - t0 < timeout:
|
while time.time() - t0 < timeout:
|
||||||
st, m = fc.get("/mode")
|
st, m = fc.get("/mode")
|
||||||
if isinstance(m, dict) and m.get("controller") == "running" and m.get("pid"):
|
if (isinstance(m, dict) and m.get("controller") == "running" and m.get("pid")
|
||||||
|
and m.get("pid") != not_pid):
|
||||||
return m
|
return m
|
||||||
ctx.sleep(0.5)
|
ctx.sleep(0.5)
|
||||||
return None
|
return None
|
||||||
@@ -417,7 +435,7 @@ def deadman(ctx):
|
|||||||
_os.kill(pid1, _signal.SIGKILL) # the hung controller cannot recover itself
|
_os.kill(pid1, _signal.SIGKILL) # the hung controller cannot recover itself
|
||||||
ctx.check(kstate == "underrun", "the ring did not drain into a kernel underrun (state %s)", kstate)
|
ctx.check(kstate == "underrun", "the ring did not drain into a kernel underrun (state %s)", kstate)
|
||||||
ctx.check(latch_locked(), "latch unlocked after the underrun")
|
ctx.check(latch_locked(), "latch unlocked after the underrun")
|
||||||
m2 = wait_running(30)
|
m2 = wait_running(30, not_pid=pid1)
|
||||||
ev["sigstop"]["respawn"] = m2
|
ev["sigstop"]["respawn"] = m2
|
||||||
ctx.check(m2 and m2.get("pid") != pid1, "supervisor did not respawn after the hang")
|
ctx.check(m2 and m2.get("pid") != pid1, "supervisor did not respawn after the hang")
|
||||||
ctx.sleep(3)
|
ctx.sleep(3)
|
||||||
@@ -450,10 +468,16 @@ def deadman(ctx):
|
|||||||
ev["restart"]["mode_after"] = m3
|
ev["restart"]["mode_after"] = m3
|
||||||
ctx.log("mode after restart: %s", m3)
|
ctx.log("mode after restart: %s", m3)
|
||||||
ctx.check(m3 and m3.get("controller") == "running", "supervision not retaken after the restart: %s", m3)
|
ctx.check(m3 and m3.get("controller") == "running", "supervision not retaken after the restart: %s", m3)
|
||||||
ctx.check(m3.get("pid") == pid2, "the busy controller was replaced (%s -> %s) instead of retaken",
|
ctx.check(m3.get("motion") == "verified", "motion not verified after the retake: %s", m3)
|
||||||
|
# the retake, by design: the busy controller (unmanaged, its own fd carrying
|
||||||
|
# the dead-man) finished its move; at idle the new supervisor stopped it,
|
||||||
|
# re-probed motion, and started a supervised one under the broker
|
||||||
|
ev["restart"]["replaced_at_idle"] = m3.get("pid") != pid2
|
||||||
|
ctx.log("retake: unmanaged pid %s finished the move; supervised pid %s started at idle",
|
||||||
pid2, m3.get("pid"))
|
pid2, m3.get("pid"))
|
||||||
ctx.check(latch_locked(), "latch unlocked after the restart drill")
|
ctx.check(latch_locked(), "latch unlocked after the restart drill")
|
||||||
x1 = _kernel_x_mm(ctx)
|
x1 = _kernel_x_mm(ctx)
|
||||||
_return_x(ctx, (x1 - x0) if (x0 is not None and x1 is not None) else None)
|
_return_x(ctx, (x1 - x0) if (x0 is not None and x1 is not None) else None)
|
||||||
ctx.log("PASS: kill respawned in %s s, hang -> underrun in %s s, restart retook pid %s",
|
machine_idle(ctx)
|
||||||
respawn_s, halt_s, pid2)
|
ctx.log("PASS: kill respawned in %s s, hang -> underrun in %s s, restart retook supervision (pid %s)",
|
||||||
|
respawn_s, halt_s, m3.get("pid"))
|
||||||
|
|||||||
Reference in New Issue
Block a user