vh/forgefirm
1
0
Fork 0
mirror of https://github.com/openglow-org/forgefirm.git synced 2026-09-28 01:01:12 -07:00
Code Issues Packages Projects Releases Wiki Activity

forgetest: cloud tests stay in cloud mode; the page can ignore prerequisites

Browse Source 
The cloud job tests (lid-abort, lid-during-button-wait, hunt-lid-open,
pause-resume) run in cloud mode and leave the machine there: enter_cloud
reuses a live session (pid-scoped from the client's own websocket state
lines) and switches once from GRBL mode, declaring the change to the
baseline; nothing switches back. Each test judges the log from its own
window, the print by its own "print [id]: finished" line, and waits the
service's follow-up moves out (wait_quiet) before it ends. hunt-lid-open
restarts the cloud client through the supervisor's stop/start lever for
a fresh connect. The former switch-back is what failed the last bench run
of hunt-lid-open (409 machine is not idle: the service was still
re-finding the head after the lid closed).

The baseline is mode-aware: in cloud mode the client owns the GRBL
controller's init values, the lid lamp, and the position counters; the
mode itself is preserved unless the run declared the change
(Context.mode_changed); controller_mode is never handed back as a bare
setting (a bare write left the persisted mode out of step with the live
one). The undeclared-change restore now uses the captured state, which
the post pass never saw before.

The acceptance page gets an "Ignore prerequisites" switch (remembered by
the browser): POST /start {ignore_requires} starts a test whose requires
are unmet, and the run records the unmet prerequisites in its evidence
and log; they stay required for the release. The cloud tests' requires
no longer chain through cloud.mode-switch.

Proof: tests/test_cloud_suite.py replays the four tests on the bench's
own gfcloud excerpts (fixtures/) and the run loop's emitted pause/resume
lines under the real runner Context against a fake forgectrl; baseline
mode tests and the server override test; the whole suite (98) and the
coverage lint pass. Catalog consequence: cloud.* fingerprints move with
the module; the catalog hash moves with the requires.
This commit is contained in:
ScottW514
2026-08-17 06:42:48 -04:00
parent e908db7f3a
commit 86ce0419e5
15 changed files with 1408 additions and 209 deletions
Download Patch File Download Diff File Expand all files Collapse all files
forgetest/forgetest/baseline.py
+49 -7
View File
@@ -16,6 +16,17 @@ restores it after (on every exit path), so a test cannot hand the next one
The lid lamp is fixed too, at forgectrl's `lid_lamp_idle` setting (unset =
236): the daemon asserts it at start and at every controller spawn.
The controller mode in force decides what the baseline owns. In GRBL mode
everything above applies. In cloud mode the cloud client owns what it
configures for itself - the GRBL controller's init values (it writes its
own from each pulse header), the lid lamp (its lid-image level), and the
position counters (re-zeroed at every service action, so not a preserved
value) - and the baseline checks the rest: the safety readbacks, the
latch, the ring, the module defaults, the diagnostics tools, the cooling
engine. The mode itself is preserved: a run hands back the mode it
found, unless it declared a deliberate change (Context.mode_changed) -
the cloud tests enter cloud mode once and stay there.
Everything found off-baseline is a "leftover": logged, kept in the run's
evidence, and surfaced on the page. The pre-run pass attributes leftovers
to the previous run; the post-run pass attributes them to the run itself.
@@ -53,6 +64,20 @@ FIXED_SYSFS = [
("thermal/tec_on", "0"),
]
# The subset the GRBL controller writes at its start: checked and restored
# in GRBL mode only. The cloud client sets its own values for these from
# every pulse header (step_freq 10 kHz, the run currents) and hands the
# hold currents back at idle; forcing the GRBL values under it would be
# the baseline configuring another controller's machine.
GRBL_CONTROLLER_SYSFS = ("cnc/motor_lock", "cnc/x_mode", "cnc/y_mode", "cnc/x_decay", "cnc/y_decay",
"cnc/step_freq", "pic/x_step_current", "pic/y_step_current")
# Settings the baseline never hands back as bare settings: controller_mode
# is the persisted mirror of the live mode (the mode item restores it
# through POST /mode, which keeps the two in step; a bare settings write
# would leave the runtime in one mode and the boot in the other).
UNPRESERVED_SETTINGS = ("controller_mode",)
# Read-only readbacks with their idle values (no direct restore: the state
# comes right through forgectrl - see restore_forgectrl - or is fatal).
IDLE_READBACKS = [
@@ -149,6 +174,7 @@ class Baseline:
self.abort = abort or (lambda: False)
self.captured = None
self.forgectrl = None
self.mode = None # the controller mode in force (per enforce)
def log(self, msg):
self._log("baseline: " + msg)
@@ -228,7 +254,8 @@ class Baseline:
cap["sysfs"][attr] = hw.sysfs_read(attr)
st, body = self.fc_get("/settings")
if st == 200 and isinstance(body, dict):
cap["settings"] = {k: v for k, v in body.items() if isinstance(v, str)}
cap["settings"] = {k: v for k, v in body.items()
if isinstance(v, str) and k not in UNPRESERVED_SETTINGS}
st, body = self.fc_get("/mode")
if st == 200 and isinstance(body, dict):
cap["mode"] = body.get("mode")
@@ -241,7 +268,8 @@ class Baseline:
phase is 'pre' or 'post' (log wording only). captured is the
preserved state to hand back (post) - None compares nothing."""
left = []
self._forgectrl_side(left)
self.mode = None
self._forgectrl_side(left, captured)
self._kernel_side(left)
self._lamp_side(left)
self._preserved(left, captured)
@@ -259,11 +287,15 @@ class Baseline:
time.sleep(1.0)
return None
def _forgectrl_side(self, left):
def cloud_mode(self):
return self.mode == "cloud"
def _forgectrl_side(self, left, captured=None):
st, mode = self.fc_get("/mode")
if st != 200 or not isinstance(mode, dict):
self.log("forgectrl not answering - service-side checks skipped")
return
self.mode = mode.get("mode")
# a diagnostic left running seizes the thermal hardware: abort it
st, d = self.fc_get("/diag/status")
if st == 200 and isinstance(d, dict) and d.get("running"):
@@ -278,11 +310,14 @@ class Baseline:
CAM_IDLE_S)
if w is None:
left.append(Leftover("cam.running", True, False, "failed: still running"))
# supervisor: the captured mode, controller running, motion verified
want = (self.captured or {}).get("mode") or mode.get("mode") or "grbl"
# supervisor: the mode the run found (or declared), controller
# running, motion verified. A mode the run changed without
# declaring it is handed back through the switch.
want = (captured or {}).get("mode") or mode.get("mode") or "grbl"
if mode.get("mode") != want:
st, body = self.fc_post("/mode", data={"controller": want})
mode = self.wait_settled() or mode
self.mode = mode.get("mode")
left.append(Leftover("mode", mode.get("mode"), want,
"restored" if mode.get("mode") == want else "failed: %s %s" % (st, body)))
if mode.get("controller") == "motion-fault":
@@ -336,7 +371,10 @@ class Baseline:
"waited" 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)."""
"""The lid lamp at forgectrl's idle level (the lid_lamp_idle setting).
In cloud mode the cloud client owns the lamp (its lid-image level)."""
if self.cloud_mode():
return
st, body = self.fc_get("/settings")
if st != 200 or not isinstance(body, dict):
return
@@ -373,6 +411,8 @@ class Baseline:
left.append(Leftover("pulse ring", "%d unplayed bytes" % residue, "0 (nothing queued)",
"unrestorable: the next run would replay them first"))
for attr, want in FIXED_SYSFS:
if self.cloud_mode() and attr in GRBL_CONTROLLER_SYSFS:
continue
got = hw.sysfs_read(attr)
if got is None or got == want:
continue
@@ -461,9 +501,11 @@ class Baseline:
except OSError as e:
act = "failed: %s" % e
left.append(Leftover(attr, now, was, act))
# In cloud mode the counters are the cloud client's: every service
# action re-zeroes them at its start, so they preserve nothing.
was = captured.get("position")
now = read_position()
if was is not None and now is not None and now != was:
if was is not None and now is not None and now != was and not self.cloud_mode():
left.append(Leftover("position", now, was, self._return_head(was, now)))
was = captured.get("settings")
if was:
forgetest/forgetest/page.py
+16 -2
View File
@@ -63,6 +63,10 @@ pre#log{background:#1d1e26;color:#d7dae0;font-family:ui-monospace,Consolas,monos
.err{color:var(--red);font-size:13px;margin:6px 0}
.note{background:#fdf3e3;border:1px solid #eccb90;border-radius:6px;padding:8px 12px;margin:8px 0;font-size:13px}
.ack{display:block;margin:8px 0;font-size:12.5px}
.switch{display:flex;align-items:center;gap:8px;margin:10px 0 0;font-size:13px}
.switch input{width:16px;height:16px;margin:0}
.switch .on{color:var(--warn);font-weight:600}
.req.over{color:var(--dim)}
.grp{margin-top:6px}
.tool .argrow{display:flex;gap:8px;flex-wrap:wrap;margin:6px 0}
.tool .argrow label{font-size:12px;color:var(--dim)}
@@ -89,7 +93,10 @@ pre#log{background:#1d1e26;color:#d7dae0;font-family:ui-monospace,Consolas,monos
<button class='danger' onclick='doInvalidate()'>Invalidate all results</button>
</div>
<div id='actmsg'></div>
<p class='hint'>A release is authorized when a campaign is open on this image and every catalog test is satisfied - by a PASS in the campaign, or (never for the core) by an earlier PASS whose domain fingerprint is unchanged. A FAIL ends the campaign. Invalidate-all forces a full campaign; give the reason.</p>
<label class='switch'><input type='checkbox' id='ignreq' onchange='setIgnoreReq(this.checked)'>
<span>Ignore prerequisites - Start any test on its own, whatever its <i>requires</i> list says</span>
<span id='ignreqon'></span></label>
<p class='hint'>A release is authorized when a campaign is open on this image and every catalog test is satisfied - by a PASS in the campaign, or (never for the core) by an earlier PASS whose domain fingerprint is unchanged. A FAIL ends the campaign. Invalidate-all forces a full campaign; give the reason. A test's <i>requires</i> list only orders the runs: with the switch above on, any test starts alone and its record notes which prerequisites were unmet - the release still needs every test satisfied.</p>
</div>
<div id='groups'></div>
</div>
@@ -114,7 +121,10 @@ pre#log{background:#1d1e26;color:#d7dae0;font-family:ui-monospace,Consolas,monos
var TOKEN='__TOKEN__';
var state=null, catalog=null, catalogHash=null, bench=null, tab='acceptance', openDetails={};
var lastRunKey=null;
var ignoreReq=false;try{ignoreReq=window.localStorage.getItem('forgetest.ignoreReq')==='1'}catch(e){}
function $(id){return document.getElementById(id)}
function setIgnoreReq(on){ignoreReq=!!on;try{window.localStorage.setItem('forgetest.ignoreReq',ignoreReq?'1':'0')}catch(e){}
$('ignreq').checked=ignoreReq;$('ignreqon').innerHTML=ignoreReq?"<span class='on'>ON - prerequisites are not enforced</span>":'';if(state&&catalog)renderGroups()}
function esc(s){return String(s==null?'':s).replace(/[&<>"']/g,function(c){return {'&':'&amp;','<':'&lt;','>':'&gt;','"':'&quot;',"'":'&#39;'}[c]})}
function api(method,path,body,cb){var x=new XMLHttpRequest();x.open(method,path,true);x.setRequestHeader('X-ForgeFIRM-Token',TOKEN);
if(body!==undefined&&body!==null){x.setRequestHeader('Content-Type','application/json')}
@@ -151,8 +161,10 @@ function renderGroups(){var groups={},order=[];catalog.forEach(function(t){if(!g
if(s.required&&s.status!=='running')st+="<br><span class='req'>required: "+esc(s.reason)+"</span>";
var last=s.last?(esc(s.last.result)+' '+esc(fmtTs(s.last.ts))):'-';
if(s.status==='inherited'&&s.origin)last+="<br><span class='tid'>from "+esc(s.origin.campaign)+" on "+esc(s.origin.image)+"</span>";
var canStart=!busy&&s.requires_met!==false;var why=busy?'a run is in progress':(!s.requires_met?('needs: '+(s.missing_requires||[]).join(', ')):'');
var unmet=s.requires_met===false;var canStart=!busy&&(!unmet||ignoreReq);
var why=busy?'a run is in progress':(unmet?((ignoreReq?'prerequisites overridden - needs: ':'needs: ')+(s.missing_requires||[]).join(', ')):'');
var startBtn="<button class='pri' "+(canStart?'':'disabled')+" title='"+esc(why)+"' onclick='startTest(\""+esc(t.id)+"\")'>Start</button>";
if(unmet)startBtn+="<div class='req"+(ignoreReq?' over':'')+"'>"+(ignoreReq?'unmet: ':'needs: ')+esc((s.missing_requires||[]).join(', '))+"</div>";
var det="<div class='details"+(openDetails[t.id]?' on':'')+"' id='det-"+esc(t.id)+"'>"+esc(t.description||'')+
(t.steps&&t.steps.length?"<br><b>Operator steps:</b><ol>"+t.steps.map(function(x){return '<li>'+esc(x)+'</li>'}).join('')+"</ol>":'')+
"<b>Requires:</b> "+esc((t.requires||[]).join(', ')||'-')+"<br><b>Covers:</b> "+esc((t.covers||[]).map(function(c){return c[0]+':'+c[1]}).join(', ')||'-')+
@@ -179,6 +191,7 @@ function renderRun(){var r=state.running||state.last_run;var key=r?(r.kind+':'+r
var benchNeedsRefresh=false;
function findTest(id){for(var i=0;i<catalog.length;i++)if(catalog[i].id===id)return catalog[i];return null}
function startTest(id){var t=findTest(id);var body={test:id};
if(ignoreReq)body.ignore_requires=true;
if(t&&t.kind==='live'){if(!confirmLive())return;body.ack_live=true}
api('POST','/start',body,function(s,d){setMsg('actmsg',d.message||d.error,s!==200)})}
function confirmLive(){return window.confirm('LIVE LASER TEST.\n\nConfirm before starting:\n - eye protection on, everyone in the room\n - fire watch present, extinguisher at hand\n - exhaust running, lid closed, scrap in place\n - you will press the physical button to arm when prompted\n\nStart the test?')}
@@ -208,6 +221,7 @@ function startTool(id){var t=null;bench.tools.forEach(function(x){if(x.id===id)t
(t.args||[]).forEach(function(a){var e=$('arg-'+id+'-'+a.name);if(e)args[a.name]=e.value});
var body={tool:id,args:args};if(t.safety==='live'){if(!confirmLive())return;body.ack_live=true}
api('POST','/bench/start',body,function(s,d){setMsg('benchmsg',d.message||d.error,s!==200);if(s===200)benchNeedsRefresh=true})}
setIgnoreReq(ignoreReq);
poll();
</script></body></html>
"""
forgetest/forgetest/runner.py
+22 -3
View File
@@ -203,6 +203,16 @@ class Context:
self.log("position counters re-zeroed at the starting position; the baseline "
"expects (0,0,0) at the end")
def mode_changed(self, mode):
"""Declare a deliberate controller-mode change for the operator:
the run leaves the machine in `mode` and the baseline keeps it
there instead of switching back to the mode the run found (the
cloud tests enter cloud mode once and stay)."""
cap = self.run.baseline_captured
if cap is not None and cap.get("mode") != mode:
self.log("controller mode changed to %s for the operator; the baseline keeps it", mode)
cap["mode"] = mode
class Takeover:
"""Hardware takeover: the controller is stopped through the supervisor,
@@ -391,7 +401,12 @@ class Runner:
return art
# -- starting -----------------------------------------------------------
def start_test(self, test_id, ack_live=False):
def start_test(self, test_id, ack_live=False, ignore_requires=False):
"""Start a test. `requires` gates the start unless the operator
set ignore_requires: the test then runs alone, and the run's
evidence records which prerequisites were unmet (the release gate
needs every test satisfied anyway, so nothing is hidden - the
record just says the order was the operator's)."""
t = _catalog.get(test_id, self.registry)
if t is None:
return False, "unknown test"
@@ -400,8 +415,9 @@ class Runner:
return False, "a run is in progress"
state, _ = self.state()
ts = state["tests"][t.id]
if not ts["requires_met"]:
return False, "prerequisites not satisfied: %s" % ", ".join(ts["missing_requires"])
missing = list(ts["missing_requires"])
if missing and not ignore_requires:
return False, "prerequisites not satisfied: %s" % ", ".join(missing)
if t.kind == "live" and not ack_live:
return False, "live test: acknowledge eye protection, fire watch, and exhaust first"
campaign = self._open_campaign_if_needed(state)
@@ -409,6 +425,9 @@ class Runner:
self.last = self.current
self.current = run
run.log("start %s (%s, %s) in campaign %s" % (t.id, t.kind, t.hardware, campaign["id"]))
if missing:
run.log("prerequisites overridden by the operator - not satisfied: %s" % ", ".join(missing))
run.evidence["prerequisites"] = {"overridden": True, "missing": missing, "ts": now_ts()}
if t.kind == "live":
run.evidence["operator"] = {"ack_live": True, "ts": now_ts()}
th = threading.Thread(target=self._exec_test, args=(t, run, campaign), daemon=True,
forgetest/forgetest/server.py
+3 -2
View File
@@ -15,7 +15,7 @@ Routes
GET /result?test&ts one full result record (log, evidence)
GET /log the raw JSONL
GET /export/acceptance.json | .md the last export
POST /start {test, ack_live} start an acceptance test
POST /start {test, ack_live, ignore_requires} start an acceptance test
POST /bench/start {tool, args, ack_live}
POST /answer {prompt_id, value}
POST /abort
@@ -219,7 +219,8 @@ class Handler(BaseHTTPRequestHandler):
return
try:
if path == "/start":
ok, msg = r.start_test(str(body.get("test", "")), ack_live=bool(body.get("ack_live")))
ok, msg = r.start_test(str(body.get("test", "")), ack_live=bool(body.get("ack_live")),
ignore_requires=bool(body.get("ignore_requires")))
self._send(200 if ok else 409, {"ok": ok, "message": msg})
elif path == "/bench/start":
args = body.get("args") or {}
forgetest/forgetest/suite/cloud.py
+319 -191
View File
@@ -1,5 +1,7 @@
"""cloud.* - the controller mode switch and the optional Glowforge web-service
mode (gfcloud daemon, gfhome homing runner)."""
mode (gfcloud daemon, gfhome homing runner). The mode-switch test makes the
grbl -> cloud -> grbl round trip; the job-behavior tests run in cloud mode
and leave the machine there (see enter_cloud)."""
import json
import os
import socket
@@ -198,7 +200,7 @@ def mode_switch(ctx):
@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"],
covers=_CLOUD_COVERS + [("grblhal-glowforge", "src/**")], requires=[],
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.",
"The machine ends homed, the head parked at the home corner (the position "
@@ -249,6 +251,24 @@ def gfhome_homing(ctx):
# ---- lid / button behavior of a cloud job (the factory's) ------------------
#
# These tests run IN cloud mode and stay there: enter_cloud() reuses a live
# cloud session when the machine is already in cloud mode (the operator
# switched once, on the panel or through an earlier test) and switches -
# once, declaring the change to the baseline - only when it finds GRBL
# mode. Nothing switches back; the operator does, when done. Each test
# judges the gfcloud log from its own window (the offset enter_cloud
# returns) and waits for the service's deferred moves (the re-hunt after a
# lid close, the hunt after a print) to finish before it ends, so the next
# run - or the operator - gets a quiet machine.
WS_MARKS = ("RX-EVENT: ready", "RX-EVENT: closed", "RECONNECTING", "CLOSING")
ACTIVITY_MARKS = ("start motion", "start return home", "starting run", "starting z homing cycle")
LOG_TAIL_BYTES = 4 << 20
QUIET_S = 8 # the re-hunt's motions are ~4 s apart (a lid image between them)
QUIET_TIMEOUT_S = 180
HUNT_TIMEOUT_S = 180
def log_lines_since(path, offset):
"""New gfcloud log lines since offset (each 'ISO-time gfcloud[pid] LEVEL where message')."""
@@ -260,6 +280,12 @@ def log_lines_since(path, offset):
return []
def log_tail(path, max_bytes=LOG_TAIL_BYTES):
"""The last max_bytes of the log, as lines (the first may be partial)."""
size = log_size(path)
return log_lines_since(path, max(0, size - max_bytes))
def line_time(line):
"""Seconds (float) from the log line's ISO timestamp, or None."""
try:
@@ -296,47 +322,150 @@ def wait_log(ctx, offset, needles, timeout, poll=0.5):
return found
def enter_cloud(ctx):
"""Switch to the cloud controller and wait for its service session.
Returns (log offset at the switch, lid lamp level before)."""
fc = ctx.forgectrl
st, m0 = fc.get("/mode")
ctx.check(st == 200 and isinstance(m0, dict) and m0.get("mode") == "grbl",
"start this test in grbl mode (now %s)", m0)
lamp0 = hw.sysfs_read("pic/lid_led")
offset = log_size(GFCLOUD_LOG)
st, body = fc.post("/mode", data={"controller": "cloud"})
ctx.check(st == 200, "mode switch to cloud refused: %s %s", st, body)
m = wait_mode(ctx, fc, "cloud", timeout=90)
ctx.check(m and m.get("mode") == "cloud" and m.get("controller") == "running",
"cloud controller did not come up: %s", m)
def action_finish_index(lines, action):
"""Index of the first '<action> [id]: finished with event ...' line, or None."""
return next((i for i, ln in enumerate(lines)
if (action + " [") in ln and "finished with event" in ln), None)
def wait_action_finished(ctx, offset, action, timeout, poll=0.5):
"""The action's own terminal line ('<action> [id]: finished with event
":completed"' / '":cancelled"'), or None within timeout."""
t0 = time.time()
while time.time() - t0 < timeout:
ctx.checkpoint()
lines = log_lines_since(GFCLOUD_LOG, offset)
i = action_finish_index(lines, action)
if i is not None:
return lines[i]
time.sleep(poll)
return None
def message(line):
"""The message part of a log line (after 'ISO-time gfcloud[pid]')."""
return line.split(" ", 2)[-1] if line else None
def session_live(pid):
"""(live, detail): the running cloud client (gfcloud[pid]) has a live
service session when its last websocket state line is 'ready' - a
later 'closed'/'RECONNECTING'/'CLOSING' means it is not connected
now. Without any line for that pid the newest lines of the log stand
in (the client may log under a wrapper's pid)."""
tag = "gfcloud[%s]" % pid if pid else None
last_pid = last_any = None
for ln in log_tail(GFCLOUD_LOG):
for m in WS_MARKS:
if m in ln:
last_any = m
if tag and tag in ln:
last_pid = m
last = last_pid if last_pid is not None else last_any
where = "pid %s" % pid if last_pid is not None else "newest lines"
return last == "RX-EVENT: ready", "%s: last websocket state %s" % (where, last)
def wait_quiet(ctx, offset, quiet_s=None, timeout=None):
"""The service's moves are over: the machine idle and no new service
activity in the log (a motion, a park, a run, a lens homing) for
quiet_s (default QUIET_S; timeout QUIET_TIMEOUT_S). False on timeout."""
quiet_s = QUIET_S if quiet_s is None else quiet_s
timeout = QUIET_TIMEOUT_S if timeout is None else timeout
fc = ctx.forgectrl
t0 = time.time()
n_seen = -1
last_change = t0
while time.time() - t0 < timeout:
ctx.checkpoint()
lines = log_lines_since(GFCLOUD_LOG, offset)
n = sum(1 for ln in lines if any(m in ln for m in ACTIVITY_MARKS))
if n != n_seen:
n_seen = n
last_change = time.time()
if fc.status().get("state") == "idle" and time.time() - last_change >= quiet_s:
return True
time.sleep(0.5)
return False
def wait_session(ctx, offset, timeout=120):
session = []
while time.time() - t0 < 120:
t0 = time.time()
while time.time() - t0 < timeout:
ctx.checkpoint()
session = session_lines(GFCLOUD_LOG, offset)
if session_established(session):
break
return session
time.sleep(2)
ctx.check(session_established(session), "the cloud client never established its service session")
ctx.log("cloud session established")
return offset, lamp0
return session
def leave_cloud(ctx, lamp0):
"""Back to grbl; the head returns to where the run found it."""
def fresh_cloud_connect(ctx):
"""A NEW cloud client with a fresh service session (its connect-time
hunt follows): in cloud mode the controller is restarted through the
supervisor's stop/start lever; in GRBL mode the mode is switched (and
the change declared - the machine stays in cloud mode). Returns the log
offset from before the connect, so the caller sees the whole session."""
fc = ctx.forgectrl
st, body = fc.post("/mode", data={"controller": "grbl"})
ctx.check(st == 200, "mode switch back to grbl refused: %s %s", st, body)
m = wait_mode(ctx, fc, "grbl", timeout=120)
ctx.check(m and m.get("mode") == "grbl" and m.get("controller") == "running",
"grbl controller did not come back: %s", m)
ctx.sleep(3)
ctx.counters_rezeroed()
return_head(ctx)
lamp1 = hw.sysfs_read("pic/lid_led")
if lamp0 is not None and lamp1 != lamp0:
hw.sysfs_write("pic/lid_led", lamp0)
st, m = fc.get("/mode")
ctx.check(st == 200 and isinstance(m, dict), "GET /mode -> %s", st)
offset = log_size(GFCLOUD_LOG)
if m.get("mode") == "cloud":
ctx.log("cloud mode: restarting the cloud client for a fresh connect (was pid %s)", m.get("pid"))
st, body = fc.post("/controller/stop")
ctx.check(st == 200, "controller stop refused: %s %s", st, body)
m = wait_mode(ctx, fc, "cloud", want_controller="standby", timeout=30)
ctx.check(m and m.get("controller") == "standby", "the cloud client did not stop: %s", m)
st, body = fc.post("/controller/start")
ctx.check(st == 200, "controller start refused: %s %s", st, body)
else:
ctx.log("%s mode: switching to cloud", m.get("mode"))
st, body = fc.post("/mode", data={"controller": "cloud"})
ctx.check(st == 200, "mode switch to cloud refused: %s %s", st, body)
m = wait_mode(ctx, fc, "cloud", timeout=90)
ctx.check(m and m.get("mode") == "cloud" and m.get("controller") == "running",
"cloud controller did not come up: %s", m)
ctx.mode_changed("cloud")
session = wait_session(ctx, offset)
ctx.check(session_established(session),
"the cloud client never established its service session (no credentials, no "
"network, or the service refused)")
ctx.log("cloud session established (pid %s)", m.get("pid"))
return offset
def enter_cloud(ctx):
"""Cloud mode with a live service session and a quiet machine. An
existing cloud session is reused; from GRBL mode the switch is made
once (its connect-time hunt is waited out) and the machine stays in
cloud mode. Returns the log offset where the test's own window begins."""
fc = ctx.forgectrl
st, m = fc.get("/mode")
ctx.check(st == 200 and isinstance(m, dict), "GET /mode -> %s", st)
if m.get("mode") == "cloud" and m.get("controller") == "running":
live, detail = session_live(m.get("pid"))
ctx.check(live, "cloud mode is up (pid %s) but the client has no live service session (%s) - "
"check credentials and network, or restart the controller", m.get("pid"), detail)
ctx.log("cloud mode already up (pid %s), service session live - reusing it", m.get("pid"))
offset = log_size(GFCLOUD_LOG)
else:
offset = fresh_cloud_connect(ctx)
hunt = wait_action_finished(ctx, offset, "hunt", HUNT_TIMEOUT_S)
ctx.check(hunt, "the service sent no connect-time hunt (or it never finished) within %d s",
HUNT_TIMEOUT_S)
ctx.log("connect-time hunt: %s", message(hunt))
ctx.check(wait_quiet(ctx, offset), "the cloud client was still running service moves after %d s",
QUIET_TIMEOUT_S)
return log_size(GFCLOUD_LOG)
def settle_cloud(ctx, offset):
"""End of a cloud test: the service's follow-up moves (a hunt after a
print, the re-hunt after a lid close) done and the machine idle."""
ctx.check(wait_quiet(ctx, offset), "the service was still moving the head %d s after the test",
QUIET_TIMEOUT_S)
ctx.log("cloud mode stays up; the machine is quiet")
def wait_print_running(ctx, offset, timeout):
@@ -367,13 +496,14 @@ APP_PRINT_CUE = ("In the Glowforge app: scrap on the bed, lid closed, a SMALL en
CANCELLED = 'finished with event ":cancelled"'
COMPLETED = 'finished with event ":completed"'
CLOUD_STEP = ("Cloud credentials configured; the machine in cloud mode (the test switches once from "
"GRBL mode and stays in cloud mode; switch back on the panel when done).")
@test("cloud.lid-abort", title="Lid open during a cloud print: stop, park with the lid open, cancelled",
subsystem="cloud", kind="live", est_min=8,
covers=_CLOUD_COVERS, requires=["cloud.mode-switch", "laser.emission-witness"],
steps=["Cloud credentials configured; the app open in a browser; scrap on the bed and a small "
"engrave/score job ready.",
covers=_CLOUD_COVERS, requires=["laser.emission-witness"],
steps=[CLOUD_STEP, "The app open in a browser; scrap on the bed and a small engrave/score job ready.",
"Print from the app and press the button when it lights; open the lid a few seconds "
"into the run."],
description="A cloud print aborted by the lid behaves as the factory's does: the edge "
@@ -382,161 +512,158 @@ COMPLETED = 'finished with event ":completed"'
"closes, and the job ends ':cancelled'.")
def lid_abort(ctx):
ev = ctx.evidence
offset, lamp0 = enter_cloud(ctx)
try:
ctx.instruct(APP_PRINT_CUE)
got = wait_print_running(ctx, offset, 300)
ctx.check(got, "the print never reached its run within 300 s (not started, or the button not pressed)")
ctx.instruct("The head is moving. Open the lid NOW, then click Done. Leave it open until the head "
"has returned to the corner.")
needles = ["lid opened", "lid opened mid-run; stopping motion", "start return home",
"return home complete", CANCELLED]
got = wait_log(ctx, offset, needles, 90)
ev["log"] = {k: (v.split(" ", 2)[-1] if v else None) for k, v in got.items()}
for k, v in got.items():
ctx.log(" %s: %s", k, "seen" if v else "MISSING")
ctx.check(got["lid opened mid-run; stopping motion"], "the lid open did not stop the run")
# The lid edge that stopped the run is the LAST "lid opened" edge line
# before the stop line (an earlier open, e.g. to place the scrap, is
# not the one).
lines = log_lines_since(GFCLOUD_LOG, offset)
stop_i = next((i for i, ln in enumerate(lines) if "lid opened mid-run; stopping motion" in ln), None)
edge_line = None
if stop_i is not None:
edge_line = next((ln for ln in reversed(lines[:stop_i])
if "_switch_event lid opened" in ln or ln.rstrip().endswith(" lid opened")), None)
t_edge = line_time(edge_line) if edge_line else None
t_stop = line_time(lines[stop_i]) if stop_i is not None else None
if t_edge is not None and t_stop is not None:
ev["edge_to_stop_ms"] = round((t_stop - t_edge) * 1000, 1)
ctx.log("lid edge -> stop: %s ms", ev["edge_to_stop_ms"])
ctx.check(ev["edge_to_stop_ms"] < 60, "stop was not edge-driven (%s ms after the lid edge)",
ev["edge_to_stop_ms"])
ctx.check(got["start return home"] and got["return home complete"],
"the park did not run to completion with the lid open")
# the machine, not the client: the job started at counters (0,0,0)
# (cloud clears them at every job start), so a completed park reads
# back there - stale ring bytes replayed ahead of the park would not
ctx.check(ctx.forgectrl.wait_idle(15, abort=ctx.aborted), "machine not idle after the park")
kpos = read_position()
ev["kernel_counters_after_park"] = kpos
ctx.log("kernel counters after the park: %s", kpos)
ctx.check(kpos is not None and abs(kpos[0]) <= 3 and abs(kpos[1]) <= 3,
"the head did not come back to the job start (kernel counters %s)", kpos)
ctx.check(got[CANCELLED], "the print did not end ':cancelled'")
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after"] = cs.get("armed") if isinstance(cs, dict) else None
ev["latch_locked"] = latch_locked()
ctx.check(not ev["armed_after"], "armed window still open after the abort")
ctx.check(ev["latch_locked"], "kernel latch not locked after the abort")
ctx.confirm("Did the head stop as soon as the lid opened and go straight home with the lid "
"still open, and does the app show the print as cancelled?")
ctx.instruct("Close the lid, then click Done.")
ctx.sleep(3)
finally:
leave_cloud(ctx, lamp0)
offset = enter_cloud(ctx)
ctx.instruct(APP_PRINT_CUE)
got = wait_print_running(ctx, offset, 300)
ctx.check(got, "the print never reached its run within 300 s (not started, or the button not pressed)")
ctx.instruct("The head is moving. Open the lid NOW, then click Done. Leave it open until the head "
"has returned to the corner.")
needles = ["lid opened", "lid opened mid-run; stopping motion", "start return home",
"return home complete"]
got = wait_log(ctx, offset, needles, 90)
fin = wait_action_finished(ctx, offset, "print", 60)
got["print finished"] = fin
ev["log"] = {k: message(v) for k, v in got.items()}
for k, v in got.items():
ctx.log(" %s: %s", k, "seen" if v else "MISSING")
ctx.check(got["lid opened mid-run; stopping motion"], "the lid open did not stop the run")
# The lid edge that stopped the run is the LAST "lid opened" edge line
# before the stop line (an earlier open, e.g. to place the scrap, is
# not the one).
lines = log_lines_since(GFCLOUD_LOG, offset)
stop_i = next((i for i, ln in enumerate(lines) if "lid opened mid-run; stopping motion" in ln), None)
edge_line = None
if stop_i is not None:
edge_line = next((ln for ln in reversed(lines[:stop_i])
if "_switch_event lid opened" in ln or ln.rstrip().endswith(" lid opened")), None)
t_edge = line_time(edge_line) if edge_line else None
t_stop = line_time(lines[stop_i]) if stop_i is not None else None
if t_edge is not None and t_stop is not None:
ev["edge_to_stop_ms"] = round((t_stop - t_edge) * 1000, 1)
ctx.log("lid edge -> stop: %s ms", ev["edge_to_stop_ms"])
ctx.check(ev["edge_to_stop_ms"] < 60, "stop was not edge-driven (%s ms after the lid edge)",
ev["edge_to_stop_ms"])
ctx.check(got["start return home"] and got["return home complete"],
"the park did not run to completion with the lid open")
# the machine, not the client: the job started at counters (0,0,0)
# (cloud clears them at every job start), so a completed park reads
# back there - stale ring bytes replayed ahead of the park would not
ctx.check(ctx.forgectrl.wait_idle(15, abort=ctx.aborted), "machine not idle after the park")
kpos = read_position()
ev["kernel_counters_after_park"] = kpos
ctx.log("kernel counters after the park: %s", kpos)
ctx.check(kpos is not None and abs(kpos[0]) <= 3 and abs(kpos[1]) <= 3,
"the head did not come back to the job start (kernel counters %s)", kpos)
ctx.check(fin and CANCELLED in fin, "the print did not end ':cancelled': %s",
message(fin) or "no finish line")
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after"] = cs.get("armed") if isinstance(cs, dict) else None
ev["latch_locked"] = latch_locked()
ctx.check(not ev["armed_after"], "armed window still open after the abort")
ctx.check(ev["latch_locked"], "kernel latch not locked after the abort")
ctx.confirm("Did the head stop as soon as the lid opened and go straight home with the lid "
"still open, and does the app show the print as cancelled?")
ctx.instruct("Close the lid, then click Done.")
settle_cloud(ctx, offset)
ctx.log("PASS: lid open -> stop in %s ms, park completed with the lid open, ':cancelled'",
ev.get("edge_to_stop_ms"))
@test("cloud.lid-during-button-wait", title="Lid open at the cloud button prompt cancels the print",
subsystem="cloud", kind="operator", est_min=6,
covers=_CLOUD_COVERS, requires=["cloud.mode-switch"],
steps=["Cloud credentials configured; the app open; any small job ready (nothing will fire).",
covers=_CLOUD_COVERS, requires=[],
steps=[CLOUD_STEP, "The app open; any small job ready (nothing will fire).",
"Print from the app; when the button lights white, do NOT press it - open the lid."],
description="A cloud print waiting for the button is cancelled by the lid: the wait ends "
"with the lid named as the reason, the laser latch relocks, the armed window "
"closes, no run starts, and the job ends ':cancelled'.")
def lid_during_button_wait(ctx):
ev = ctx.evidence
offset, lamp0 = enter_cloud(ctx)
try:
ctx.instruct("In the Glowforge app: lid closed, a small job set up. Click Done here, then press "
"Print in the app. When the button lights white, do NOT press it.")
got = wait_log(ctx, offset, ["waiting for button"], 300)
ctx.check(got["waiting for button"], "the print never reached the button wait")
ctx.instruct("The button is lit. Open the lid now (do not press the button), then click Done.")
needles = ["button wait lid opened - relocking the laser", CANCELLED]
got = wait_log(ctx, offset, needles, 60)
ev["log"] = {k: bool(v) for k, v in got.items()}
ctx.check(got["button wait lid opened - relocking the laser"], "the lid did not end the button wait")
ctx.check(got[CANCELLED], "the print did not end ':cancelled'")
# No run may start between the button wait and the cancel: the print
# itself, or a park (the head never moved, there is nothing to park).
# The connect-time hunt and the service's moves BEFORE the print are
# legitimate runs and are outside this window.
lines = log_lines_since(GFCLOUD_LOG, offset)
wait_i = next((i for i, ln in enumerate(lines) if "waiting for button" in ln), None)
end_i = next((i for i, ln in enumerate(lines) if wait_i is not None and i > wait_i and CANCELLED in ln),
len(lines))
ran = ([ln for ln in lines[wait_i:end_i] if "starting run" in ln]
if wait_i is not None else [])
ev["runs_started_after_wait"] = len(ran)
ctx.check(not ran, "a run started after the lid-open cancel (%d)", len(ran))
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after"] = cs.get("armed") if isinstance(cs, dict) else None
ev["latch_locked"] = latch_locked()
ctx.check(not ev["armed_after"], "armed window still open after the cancel")
ctx.check(ev["latch_locked"], "kernel latch not locked after the cancel")
ctx.confirm("Did the button go dark when the lid opened, with no motion, and does the app show "
"the print as cancelled?")
ctx.instruct("Close the lid, then click Done.")
ctx.sleep(3)
finally:
leave_cloud(ctx, lamp0)
offset = enter_cloud(ctx)
ctx.instruct("In the Glowforge app: lid closed, a small job set up. Click Done here, then press "
"Print in the app. When the button lights white, do NOT press it.")
got = wait_log(ctx, offset, ["waiting for button"], 300)
ctx.check(got["waiting for button"], "the print never reached the button wait")
ctx.instruct("The button is lit. Open the lid now (do not press the button), then click Done.")
relock = "button wait lid opened - relocking the laser"
got = wait_log(ctx, offset, [relock], 60)
fin = wait_action_finished(ctx, offset, "print", 60)
ev["log"] = {relock: bool(got[relock]), "print finished": message(fin)}
ctx.check(got[relock], "the lid did not end the button wait")
ctx.check(fin and CANCELLED in fin, "the print did not end ':cancelled': %s",
message(fin) or "no finish line")
# No run may start between the button wait and the cancel: the print
# itself, or a park (the head never moved, there is nothing to park).
# The service's moves BEFORE the print are legitimate runs and are
# outside this window.
lines = log_lines_since(GFCLOUD_LOG, offset)
wait_i = next((i for i, ln in enumerate(lines) if "waiting for button" in ln), None)
end_i = action_finish_index(lines, "print")
if end_i is None or wait_i is None or end_i < wait_i:
end_i = len(lines)
ran = ([ln for ln in lines[wait_i:end_i] if "starting run" in ln]
if wait_i is not None else [])
ev["runs_started_after_wait"] = len(ran)
ctx.check(not ran, "a run started after the lid-open cancel (%d)", len(ran))
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after"] = cs.get("armed") if isinstance(cs, dict) else None
ev["latch_locked"] = latch_locked()
ctx.check(not ev["armed_after"], "armed window still open after the cancel")
ctx.check(ev["latch_locked"], "kernel latch not locked after the cancel")
ctx.confirm("Did the button go dark when the lid opened, with no motion, and does the app show "
"the print as cancelled?")
ctx.instruct("Close the lid, then click Done.")
settle_cloud(ctx, offset)
ctx.log("PASS: lid open at the button prompt cancelled the print; latch locked, armed=false")
@test("cloud.hunt-lid-open", title="A cloud hunt runs with the lid open",
subsystem="cloud", kind="operator", est_min=5,
covers=_CLOUD_COVERS, requires=["cloud.mode-switch"],
steps=["Cloud credentials configured; bed clear.",
"Open the lid BEFORE the test switches to cloud mode and leave it open through the "
"connect-time hunt."],
covers=_CLOUD_COVERS + [("forgectrl", "src/super.c")], requires=[],
steps=[CLOUD_STEP, "Bed clear.",
"Open the lid when asked and leave it open through the connect-time hunt of the fresh "
"cloud client the test starts (in cloud mode the client is restarted; from GRBL mode "
"the switch is made)."],
description="The service's connect-time hunt (lens homing plus its XY hunt) is not gated by "
"the lid: it runs and reports ':completed' with the lid open, as the factory's does.")
"the lid: it runs and reports ':completed' with the lid open, as the factory's does. "
"The service's moves after the lid closes again are waited out.")
def hunt_lid_open(ctx):
ev = ctx.evidence
ctx.instruct("Open the lid and leave it open, then click Done.")
sw = (ctx.forgectrl.status().get("switches") or {})
ev["lid_before"] = sw.get("lid")
ctx.check(not sw.get("lid"), "the lid reads closed (%s)", sw)
offset, lamp0 = enter_cloud(ctx)
try:
# The hunt's own terminal line ("hunt [id]: finished with event ..."):
# it must be :completed, and no lid refusal may precede it. Service
# motions AFTER the hunt are rightly refused with the lid open and
# are outside this window.
hunt_line = None
t0 = time.time()
while time.time() - t0 < 180 and hunt_line is None:
ctx.checkpoint()
lines = log_lines_since(GFCLOUD_LOG, offset)
hunt_i = next((i for i, ln in enumerate(lines) if "hunt [" in ln and "finished with event" in ln), None)
if hunt_i is not None:
hunt_line = lines[hunt_i]
break
time.sleep(0.5)
ev["hunt_line"] = hunt_line.split(" ", 2)[-1] if hunt_line else None
ctx.check(hunt_line, "the service sent no hunt (or it never finished) within 180 s of the session")
refused = [ln for ln in lines[:hunt_i] if "unsafe to move" in ln]
ev["refusals_before_hunt_end"] = len(refused)
ctx.check(not refused, "the hunt was refused for the lid (%d 'unsafe to move')", len(refused))
ctx.check(COMPLETED in hunt_line, "the hunt did not complete: %s", ev["hunt_line"])
ctx.confirm("Did the lens home (Z motion) with the lid open, with no error in the app?")
ctx.instruct("Close the lid, then click Done.")
ctx.sleep(3)
finally:
leave_cloud(ctx, lamp0)
ctx.log("PASS: the connect-time hunt ran and completed with the lid open")
offset = fresh_cloud_connect(ctx)
# The hunt's own terminal line ("hunt [id]: finished with event ..."):
# it must be :completed, and no lid refusal may precede it. Service
# motions AFTER the hunt are rightly refused with the lid open and
# are outside this window.
hunt_line = wait_action_finished(ctx, offset, "hunt", HUNT_TIMEOUT_S)
ev["hunt_line"] = message(hunt_line)
ctx.check(hunt_line, "the service sent no hunt (or it never finished) within %d s of the session",
HUNT_TIMEOUT_S)
lines = log_lines_since(GFCLOUD_LOG, offset)
hunt_i = action_finish_index(lines, "hunt")
refused = [ln for ln in lines[:hunt_i] if "unsafe to move" in ln]
ev["refusals_before_hunt_end"] = len(refused)
ctx.check(not refused, "the hunt was refused for the lid (%d 'unsafe to move')", len(refused))
ctx.check(COMPLETED in hunt_line, "the hunt did not complete: %s", ev["hunt_line"])
ctx.log("hunt with the lid open: %s", ev["hunt_line"])
ctx.confirm("Did the lens home (Z motion) with the lid open, with no error in the app?")
ctx.instruct("Close the lid, then click Done. (The service now re-finds the head: several "
"moves with lid images between them - the test waits them out.)")
settle_cloud(ctx, offset)
lines = log_lines_since(GFCLOUD_LOG, offset)
ev["motions_after_lid_close"] = sum(1 for ln in lines if "motion [" in ln and COMPLETED in ln)
ctx.log("PASS: the connect-time hunt ran and completed with the lid open; %d service motion(s) "
"completed after the lid closed", ev["motions_after_lid_close"])
@test("cloud.pause-resume", title="Button pauses and resumes a cloud print (factory backtrack + lead)",
subsystem="cloud", kind="live", est_min=8,
covers=_CLOUD_COVERS + [("forgectrl", "src/main.c")],
requires=["cloud.mode-switch", "laser.emission-witness"],
steps=["Cloud credentials configured; the app open; scrap on the bed and a small engrave/score "
"job (about 60 s) ready.",
requires=["laser.emission-witness"],
steps=[CLOUD_STEP, "The app open; scrap on the bed and a small engrave/score job (about 60 s) ready.",
"Print from the app and press the button when it lights; a few seconds into the run "
"press it again (pause), wait ~3 s, press again (resume); let the job finish."],
description="Pressing the button during a cloud print pauses it the factory way - controlled "
@@ -545,32 +672,33 @@ def hunt_lid_open(ctx):
"latch stays unlocked and the armed window open through the pause.")
def pause_resume(ctx):
ev = ctx.evidence
offset, lamp0 = enter_cloud(ctx)
try:
ctx.instruct(APP_PRINT_CUE)
got = wait_print_running(ctx, offset, 300)
ctx.check(got, "the print never reached its run within 300 s (not started, or the button not pressed)")
ctx.instruct("The head is moving. Press the button once NOW (pause), watch the head stop and back up "
"a few millimeters, wait about 3 seconds, press it again (resume), then click Done.")
got = wait_log(ctx, offset, ["button pressed mid-run; pausing", "paused at",
"button pressed while paused; resuming"], 90)
ev["log"] = {k: bool(v) for k, v in got.items()}
ctx.check(got["button pressed mid-run; pausing"], "the press did not pause the run")
ctx.check(got["paused at"], "the pause did not settle (no 'paused at')")
ctx.check(got["button pressed while paused; resuming"], "the second press did not resume")
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after_resume"] = cs.get("armed") if isinstance(cs, dict) else None
ctx.log("armed after the resume: %s", ev["armed_after_resume"])
got = wait_log(ctx, offset, ["return home complete", COMPLETED], 300)
ev["log_end"] = {k: bool(v) for k, v in got.items()}
ctx.check(got[COMPLETED], "the print did not complete after the resume")
ctx.check(got["return home complete"], "the post-print park did not complete")
relocked = [ln for ln in log_lines_since(GFCLOUD_LOG, offset)
if "relocking the laser" in ln or CANCELLED in ln]
ev["relock_or_cancel_lines"] = len(relocked)
ctx.check(not relocked, "the pause relocked or cancelled the job (%s)", relocked[:2])
ctx.confirm("Did the head stop and back up a few millimeters (laser off) on the first press, "
"resume on the second, and did the job finish and the app show it complete?")
finally:
leave_cloud(ctx, lamp0)
offset = enter_cloud(ctx)
ctx.instruct(APP_PRINT_CUE)
got = wait_print_running(ctx, offset, 300)
ctx.check(got, "the print never reached its run within 300 s (not started, or the button not pressed)")
ctx.instruct("The head is moving. Press the button once NOW (pause), watch the head stop and back up "
"a few millimeters, wait about 3 seconds, press it again (resume), then click Done.")
got = wait_log(ctx, offset, ["button pressed mid-run; pausing", "paused at",
"button pressed while paused; resuming"], 90)
ev["log"] = {k: bool(v) for k, v in got.items()}
ctx.check(got["button pressed mid-run; pausing"], "the press did not pause the run")
ctx.check(got["paused at"], "the pause did not settle (no 'paused at')")
ctx.check(got["button pressed while paused; resuming"], "the second press did not resume")
st, cs = ctx.forgectrl.get("/cool/status")
ev["armed_after_resume"] = cs.get("armed") if isinstance(cs, dict) else None
ctx.log("armed after the resume: %s", ev["armed_after_resume"])
fin = wait_action_finished(ctx, offset, "print", 300)
got = wait_log(ctx, offset, ["return home complete"], 5)
ev["log_end"] = {"return home complete": bool(got["return home complete"]),
"print finished": message(fin)}
ctx.check(fin, "the print did not finish within 300 s of the resume")
ctx.check(COMPLETED in fin, "the print did not complete after the resume: %s", message(fin))
ctx.check(got["return home complete"], "the post-print park did not complete")
relocked = [ln for ln in log_lines_since(GFCLOUD_LOG, offset)
if "relocking the laser" in ln or ("print [" in ln and CANCELLED in ln)]
ev["relock_or_cancel_lines"] = len(relocked)
ctx.check(not relocked, "the pause relocked or cancelled the job (%s)", relocked[:2])
ctx.confirm("Did the head stop and back up a few millimeters (laser off) on the first press, "
"resume on the second, and did the job finish and the app show it complete?")
settle_cloud(ctx, offset)
ctx.log("PASS: button pause/resume mid-print, job completed and parked")
forgetest/tests/fixtures/gfcloud-buttonwait.log
Vendored
+41
View File
@@ -0,0 +1,41 @@
2026-08-17T09:44:00.417337+00:00 gfcloud[1927] INFO cnc:set_step_freq 28160
2026-08-17T09:44:00.418627+00:00 gfcloud[1927] INFO cnc:set_x_decay 1
2026-08-17T09:44:00.419858+00:00 gfcloud[1927] INFO cnc:set_x_mode 8
2026-08-17T09:44:00.421083+00:00 gfcloud[1927] INFO cnc:set_x_current 135
2026-08-17T09:44:00.422535+00:00 gfcloud[1927] INFO cnc:set_y_decay 1
2026-08-17T09:44:00.423794+00:00 gfcloud[1927] INFO cnc:set_y_mode 8
2026-08-17T09:44:00.425014+00:00 gfcloud[1927] INFO cnc:set_y_current 22
2026-08-17T09:44:00.432591+00:00 gfcloud[1927] INFO machine:_run_loop starting run
2026-08-17T09:44:00.434005+00:00 gfcloud[1927] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:44:00.438277+00:00 gfcloud[1927] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:44:01.785230+00:00 gfcloud[1927] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:44:01.797728+00:00 gfcloud[1927] INFO machine:_run_loop finished run
2026-08-17T09:44:01.800661+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:01.808504+00:00 gfcloud[1927] INFO machine:_motion_locked end positions (actual/expected): X (-10313/-10313), Y (-649/-649), Z (0/0)
2026-08-17T09:44:01.809326+00:00 gfcloud[1927] INFO machine:_motion_locked motion bytes actual:34952, expected: 34952
2026-08-17T09:44:01.810066+00:00 gfcloud[1927] INFO machine:_motion_locked start idle
2026-08-17T09:44:01.811352+00:00 gfcloud[1927] INFO cnc:set_x_current 33
2026-08-17T09:44:01.812874+00:00 gfcloud[1927] INFO cnc:set_y_current 5
2026-08-17T09:44:01.820631+00:00 gfcloud[1927] INFO machine:_motion_locked end positions (-10313, -649, 0)
2026-08-17T09:44:01.822062+00:00 gfcloud[1927] INFO machine:_motion end motion
2026-08-17T09:44:01.822829+00:00 gfcloud[1927] INFO basemachine:_finish_action motion [1576550614]: finished with event ":completed"
2026-08-17T09:44:01.824200+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:07.993647+00:00 gfcloud[1927] INFO gfuiservice:run service action request: print (ready)
2026-08-17T09:44:07.998655+00:00 gfcloud[1927] INFO machine:_motion start motion
2026-08-17T09:44:07.999643+00:00 gfcloud[1927] INFO gfuiservice:run print (ready) service action print
2026-08-17T09:44:14.199666+00:00 gfcloud[1927] INFO cnc:laser_latch 0
2026-08-17T09:44:14.208291+00:00 gfcloud[1927] INFO machine:_button_wait waiting for button
2026-08-17T09:44:21.270846+00:00 gfcloud[1927] INFO machine:_switch_event lid opened
2026-08-17T09:44:21.275703+00:00 gfcloud[1927] WARNING machine:_button_wait button wait lid opened - relocking the laser
2026-08-17T09:44:21.278615+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:21.288305+00:00 gfcloud[1927] INFO machine:_return_home start return home
2026-08-17T09:44:21.291373+00:00 gfcloud[1927] INFO machine:_return_home return home: already at the job start
2026-08-17T09:44:21.292501+00:00 gfcloud[1927] INFO machine:_motion_locked start cool down
2026-08-17T09:44:21.305578+00:00 gfcloud[1927] INFO machine:_motion_locked start idle
2026-08-17T09:44:21.307322+00:00 gfcloud[1927] INFO cnc:set_x_current 33
2026-08-17T09:44:21.309185+00:00 gfcloud[1927] INFO cnc:set_y_current 5
2026-08-17T09:44:21.316340+00:00 gfcloud[1927] INFO machine:_motion_locked end positions (0, 0, 0)
2026-08-17T09:44:21.318139+00:00 gfcloud[1927] INFO machine:_motion end motion
2026-08-17T09:44:21.318860+00:00 gfcloud[1927] INFO basemachine:_finish_action print [1576550621]: finished with event ":cancelled"
2026-08-17T09:44:21.320214+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:34.058320+00:00 gfcloud[1927] INFO machine:_switch_event lid closed
forgetest/tests/fixtures/gfcloud-huntlid.log
Vendored
+207
View File
@@ -0,0 +1,207 @@
2026-08-17T09:44:35.789556+00:00 gfcloud[1927] INFO websocket:img_upload START
2026-08-17T09:44:36.105516+00:00 gfcloud[1927] INFO websocket:img_upload COMPLETE
2026-08-17T09:44:36.109421+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:38.461442+00:00 gfcloud[1927] INFO gfcloud:_shutdown shutdown requested
2026-08-17T09:44:38.910494+00:00 gfcloud[1927] INFO machine:_shutdown shutting down
2026-08-17T09:44:38.913049+00:00 gfcloud[1927] INFO cnc:laser_latch 1
2026-08-17T09:44:38.950354+00:00 gfcloud[1927] INFO machine:_shutdown joining switch thread
2026-08-17T09:44:38.956909+00:00 gfcloud[1927] INFO machine:_shutdown shut down complete
2026-08-17T09:44:38.986287+00:00 gfcloud[1927] INFO websocket:_on_close RX-EVENT: closed (None, None)
2026-08-17T09:44:38.989003+00:00 gfcloud[1927] INFO websocket:run CLOSING
2026-08-17T09:44:38.992724+00:00 gfcloud[1927] INFO gfcloud:main gfcloud exit
2026-08-17T09:45:08.449553+00:00 gfcloud[2278] INFO gfuiservice:__init__ INITIALIZED
2026-08-17T09:45:08.451929+00:00 gfcloud[2278] INFO authentication:authenticate_machine START
2026-08-17T09:45:08.965893+00:00 gfcloud[2278] INFO authentication:authenticate_machine SUCCESS
2026-08-17T09:45:08.967947+00:00 gfcloud[2278] INFO websocket:ws_connect CONNECTING
2026-08-17T09:45:09.421918+00:00 gfcloud[2278] INFO _logging:info Websocket connected
2026-08-17T09:45:09.424224+00:00 gfcloud[2278] INFO websocket:_on_open RX-EVENT: ready
2026-08-17T09:45:09.973615+00:00 gfcloud[2278] INFO websocket:ws_connect ESTABLISHED
2026-08-17T09:45:09.994287+00:00 gfcloud[2278] INFO cnc:set_ignored_faults 0
2026-08-17T09:45:09.996281+00:00 gfcloud[2278] INFO cnc:set_step_freq 10000
2026-08-17T09:45:09.998803+00:00 gfcloud[2278] INFO cnc:set_x_mode Microstep.M_8
2026-08-17T09:45:09.999688+00:00 gfcloud[2278] INFO cnc:set_y_mode Microstep.M_8
2026-08-17T09:45:10.000483+00:00 gfcloud[2278] INFO cnc:set_x_decay 1
2026-08-17T09:45:10.001229+00:00 gfcloud[2278] INFO cnc:set_y_decay 1
2026-08-17T09:45:10.002000+00:00 gfcloud[2278] INFO cnc:set_x_current 33
2026-08-17T09:45:10.007267+00:00 gfcloud[2278] INFO cnc:set_y_current 33
2026-08-17T09:45:10.008695+00:00 gfcloud[2278] INFO z_axis:reset resetting z
2026-08-17T09:45:10.009124+00:00 gfcloud[2278] INFO z_axis:configure configuring z_enable: False, current: ZCur.LOW, mode: Microstep.HALF
2026-08-17T09:45:10.021592+00:00 gfcloud[2278] INFO gfuiservice:run service action request: settings (ready)
2026-08-17T09:45:10.024928+00:00 gfcloud[2278] INFO settings:send_report START
2026-08-17T09:45:10.039856+00:00 gfcloud[2278] INFO settings:send_report COMPLETE
2026-08-17T09:45:10.040650+00:00 gfcloud[2278] INFO gfuiservice:run settings (ready) service action dispatched
2026-08-17T09:45:10.591813+00:00 gfcloud[2278] INFO gfuiservice:run service action request: hunt (ready)
2026-08-17T09:45:10.596213+00:00 gfcloud[2278] INFO z_axis:home starting z homing cycle
2026-08-17T09:45:10.599109+00:00 gfcloud[2278] INFO gfuiservice:run hunt (ready) service action hunt
2026-08-17T09:45:10.600433+00:00 gfcloud[2278] INFO z_axis:configure configuring z_enable: True, current: ZCur.HIGH, mode: Microstep.FULL
2026-08-17T09:45:10.607559+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:11.160422+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:11.161195+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:11.714663+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:11.717907+00:00 gfcloud[2278] INFO z_axis:home pass: 1
2026-08-17T09:45:11.719134+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:12.272747+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:12.274301+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:12.829585+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:12.831305+00:00 gfcloud[2278] INFO z_axis:home pass: 2
2026-08-17T09:45:12.832786+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:13.385567+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:13.397106+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:13.947958+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:13.949754+00:00 gfcloud[2278] INFO z_axis:home pass: 3
2026-08-17T09:45:13.951244+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:14.504840+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:14.506743+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:15.060854+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:15.062536+00:00 gfcloud[2278] INFO z_axis:home pass: 4
2026-08-17T09:45:15.063941+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:15.617907+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:15.619505+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:16.175270+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:16.177421+00:00 gfcloud[2278] INFO z_axis:home pass: 5
2026-08-17T09:45:16.179808+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:45:16.733698+00:00 gfcloud[2278] INFO z_axis:_step_until took -3 z_steps
2026-08-17T09:45:16.735355+00:00 gfcloud[2278] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:45:17.289377+00:00 gfcloud[2278] INFO z_axis:_step_until took 3 z_steps
2026-08-17T09:45:17.291109+00:00 gfcloud[2278] INFO z_axis:configure configuring z_enable: None, current: ZCur.LOW, mode: Microstep.HALF
2026-08-17T09:45:17.296301+00:00 gfcloud[2278] INFO z_axis:home homing cycle complete: [0, 0, 0, 0, 0]
2026-08-17T09:45:17.298209+00:00 gfcloud[2278] INFO machine:_motion start motion
2026-08-17T09:45:17.968494+00:00 gfcloud[2278] INFO cnc:set_step_freq 10000
2026-08-17T09:45:17.969759+00:00 gfcloud[2278] INFO cnc:set_x_decay 1
2026-08-17T09:45:17.970993+00:00 gfcloud[2278] INFO cnc:set_x_mode 8
2026-08-17T09:45:17.972200+00:00 gfcloud[2278] INFO cnc:set_x_current 135
2026-08-17T09:45:17.973616+00:00 gfcloud[2278] INFO cnc:set_y_decay 1
2026-08-17T09:45:17.974870+00:00 gfcloud[2278] INFO cnc:set_y_mode 8
2026-08-17T09:45:17.976077+00:00 gfcloud[2278] INFO cnc:set_y_current 22
2026-08-17T09:45:17.983820+00:00 gfcloud[2278] INFO machine:_run_loop starting run
2026-08-17T09:45:17.985159+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:17.989360+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:45:19.630807+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:19.636283+00:00 gfcloud[2278] INFO machine:_run_loop finished run
2026-08-17T09:45:19.637979+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:19.651159+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (actual/expected): X (0/0), Y (0/0), Z (-4/-4)
2026-08-17T09:45:19.652103+00:00 gfcloud[2278] INFO machine:_motion_locked motion bytes actual:15874, expected: 15874
2026-08-17T09:45:19.652852+00:00 gfcloud[2278] INFO machine:_motion_locked start idle
2026-08-17T09:45:19.653964+00:00 gfcloud[2278] INFO cnc:set_x_current 33
2026-08-17T09:45:19.655305+00:00 gfcloud[2278] INFO cnc:set_y_current 5
2026-08-17T09:45:19.664032+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (0, 0, -4)
2026-08-17T09:45:19.664853+00:00 gfcloud[2278] INFO machine:_motion end motion
2026-08-17T09:45:19.665575+00:00 gfcloud[2278] INFO basemachine:_finish_action hunt [1576550660]: finished with event ":completed"
2026-08-17T09:45:19.667114+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:20.027338+00:00 gfcloud[2278] INFO gfuiservice:run service action request: lid_image (ready)
2026-08-17T09:45:20.030024+00:00 gfcloud[2278] INFO ffmachine:_lid_image capturing Lid Image via forgectrl
2026-08-17T09:45:20.040337+00:00 gfcloud[2278] INFO gfuiservice:run lid_image (ready) service action dispatched
2026-08-17T09:45:21.195560+00:00 gfcloud[2278] INFO ffmachine:_lid_image uploading Lid Image
2026-08-17T09:45:21.196529+00:00 gfcloud[2278] INFO websocket:img_upload START
2026-08-17T09:45:21.721382+00:00 gfcloud[2278] INFO websocket:img_upload COMPLETE
2026-08-17T09:45:21.725394+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:23.732857+00:00 gfcloud[2278] INFO gfuiservice:run service action request: motion (ready)
2026-08-17T09:45:23.736044+00:00 gfcloud[2278] INFO machine:_motion start motion
2026-08-17T09:45:23.737995+00:00 gfcloud[2278] INFO gfuiservice:run motion (ready) service action motion
2026-08-17T09:45:23.738941+00:00 gfcloud[2278] INFO machine:_safe_to_move lid opened, unsafe to move
2026-08-17T09:45:23.739814+00:00 gfcloud[2278] INFO machine:_motion end motion
2026-08-17T09:45:23.740605+00:00 gfcloud[2278] INFO basemachine:_finish_action motion [1576550667]: finished with event ":cancelled"
2026-08-17T09:45:23.742169+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:42.629674+00:00 gfcloud[2278] INFO machine:_switch_event lid closed
2026-08-17T09:45:42.920194+00:00 gfcloud[2278] INFO gfuiservice:run service action request: lid_image (ready)
2026-08-17T09:45:42.924152+00:00 gfcloud[2278] INFO ffmachine:_lid_image capturing Lid Image via forgectrl
2026-08-17T09:45:42.927934+00:00 gfcloud[2278] INFO gfuiservice:run lid_image (ready) service action dispatched
2026-08-17T09:45:43.989152+00:00 gfcloud[2278] INFO ffmachine:_lid_image uploading Lid Image
2026-08-17T09:45:43.990022+00:00 gfcloud[2278] INFO websocket:img_upload START
2026-08-17T09:45:44.312060+00:00 gfcloud[2278] INFO websocket:img_upload COMPLETE
2026-08-17T09:45:44.315952+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:46.652633+00:00 gfcloud[2278] INFO gfuiservice:run service action request: motion (ready)
2026-08-17T09:45:46.654950+00:00 gfcloud[2278] INFO machine:_motion start motion
2026-08-17T09:45:46.657522+00:00 gfcloud[2278] INFO gfuiservice:run motion (ready) service action motion
2026-08-17T09:45:48.089456+00:00 gfcloud[2278] INFO cnc:set_step_freq 10000
2026-08-17T09:45:48.090706+00:00 gfcloud[2278] INFO cnc:set_x_decay 1
2026-08-17T09:45:48.091970+00:00 gfcloud[2278] INFO cnc:set_x_mode 8
2026-08-17T09:45:48.093155+00:00 gfcloud[2278] INFO cnc:set_x_current 135
2026-08-17T09:45:48.094587+00:00 gfcloud[2278] INFO cnc:set_y_decay 1
2026-08-17T09:45:48.095866+00:00 gfcloud[2278] INFO cnc:set_y_mode 8
2026-08-17T09:45:48.097182+00:00 gfcloud[2278] INFO cnc:set_y_current 22
2026-08-17T09:45:48.104758+00:00 gfcloud[2278] INFO machine:_run_loop starting run
2026-08-17T09:45:48.106128+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:48.110477+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:45:50.393091+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:50.398748+00:00 gfcloud[2278] INFO machine:_run_loop finished run
2026-08-17T09:45:50.399629+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:50.423949+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (actual/expected): X (12939/12939), Y (7402/7402), Z (0/0)
2026-08-17T09:45:50.425534+00:00 gfcloud[2278] INFO machine:_motion_locked motion bytes actual:22740, expected: 22740
2026-08-17T09:45:50.426258+00:00 gfcloud[2278] INFO machine:_motion_locked start idle
2026-08-17T09:45:50.427835+00:00 gfcloud[2278] INFO cnc:set_x_current 33
2026-08-17T09:45:50.429387+00:00 gfcloud[2278] INFO cnc:set_y_current 5
2026-08-17T09:45:50.437659+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (12939, 7402, 0)
2026-08-17T09:45:50.438474+00:00 gfcloud[2278] INFO machine:_motion end motion
2026-08-17T09:45:50.439167+00:00 gfcloud[2278] INFO basemachine:_finish_action motion [1576550679]: finished with event ":completed"
2026-08-17T09:45:50.440481+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:50.770056+00:00 gfcloud[2278] INFO gfuiservice:run service action request: lid_image (ready)
2026-08-17T09:45:50.772800+00:00 gfcloud[2278] INFO ffmachine:_lid_image capturing Lid Image via forgectrl
2026-08-17T09:45:50.782017+00:00 gfcloud[2278] INFO gfuiservice:run lid_image (ready) service action dispatched
2026-08-17T09:45:51.427848+00:00 gfcloud[2278] INFO ffmachine:_lid_image uploading Lid Image
2026-08-17T09:45:51.428456+00:00 gfcloud[2278] INFO websocket:img_upload START
2026-08-17T09:45:51.757479+00:00 gfcloud[2278] INFO websocket:img_upload COMPLETE
2026-08-17T09:45:51.760692+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:54.222123+00:00 gfcloud[2278] INFO gfuiservice:run service action request: motion (ready)
2026-08-17T09:45:54.224786+00:00 gfcloud[2278] INFO machine:_motion start motion
2026-08-17T09:45:54.226855+00:00 gfcloud[2278] INFO gfuiservice:run motion (ready) service action motion
2026-08-17T09:45:54.557705+00:00 gfcloud[2278] INFO cnc:set_step_freq 10000
2026-08-17T09:45:54.562210+00:00 gfcloud[2278] INFO cnc:set_x_decay 1
2026-08-17T09:45:54.571212+00:00 gfcloud[2278] INFO cnc:set_x_mode 8
2026-08-17T09:45:54.573373+00:00 gfcloud[2278] INFO cnc:set_x_current 135
2026-08-17T09:45:54.596668+00:00 gfcloud[2278] INFO cnc:set_y_decay 1
2026-08-17T09:45:54.597612+00:00 gfcloud[2278] INFO cnc:set_y_mode 8
2026-08-17T09:45:54.598479+00:00 gfcloud[2278] INFO cnc:set_y_current 22
2026-08-17T09:45:54.622488+00:00 gfcloud[2278] INFO machine:_run_loop starting run
2026-08-17T09:45:54.624223+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:54.629307+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:45:54.835600+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:45:54.838848+00:00 gfcloud[2278] INFO machine:_run_loop finished run
2026-08-17T09:45:54.839726+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:54.849011+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (actual/expected): X (159/159), Y (5/5), Z (0/0)
2026-08-17T09:45:54.849946+00:00 gfcloud[2278] INFO machine:_motion_locked motion bytes actual:1222, expected: 1222
2026-08-17T09:45:54.850790+00:00 gfcloud[2278] INFO machine:_motion_locked start idle
2026-08-17T09:45:54.852317+00:00 gfcloud[2278] INFO cnc:set_x_current 33
2026-08-17T09:45:54.854073+00:00 gfcloud[2278] INFO cnc:set_y_current 5
2026-08-17T09:45:54.880450+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (159, 5, 0)
2026-08-17T09:45:54.881925+00:00 gfcloud[2278] INFO machine:_motion end motion
2026-08-17T09:45:54.882641+00:00 gfcloud[2278] INFO basemachine:_finish_action motion [1576550683]: finished with event ":completed"
2026-08-17T09:45:54.884500+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:55.137070+00:00 gfcloud[2278] INFO gfuiservice:run service action request: lid_image (ready)
2026-08-17T09:45:55.139449+00:00 gfcloud[2278] INFO ffmachine:_lid_image capturing Lid Image via forgectrl
2026-08-17T09:45:55.142346+00:00 gfcloud[2278] INFO gfuiservice:run lid_image (ready) service action dispatched
2026-08-17T09:45:55.809276+00:00 gfcloud[2278] INFO ffmachine:_lid_image uploading Lid Image
2026-08-17T09:45:55.810155+00:00 gfcloud[2278] INFO websocket:img_upload START
2026-08-17T09:45:56.158888+00:00 gfcloud[2278] INFO websocket:img_upload COMPLETE
2026-08-17T09:45:56.162644+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:45:58.467590+00:00 gfcloud[2278] INFO gfuiservice:run service action request: motion (ready)
2026-08-17T09:45:58.469426+00:00 gfcloud[2278] INFO machine:_motion start motion
2026-08-17T09:45:58.471091+00:00 gfcloud[2278] INFO gfuiservice:run motion (ready) service action motion
2026-08-17T09:46:00.721960+00:00 gfcloud[2278] INFO cnc:set_step_freq 28160
2026-08-17T09:46:00.725688+00:00 gfcloud[2278] INFO cnc:set_x_decay 1
2026-08-17T09:46:00.727477+00:00 gfcloud[2278] INFO cnc:set_x_mode 8
2026-08-17T09:46:00.728738+00:00 gfcloud[2278] INFO cnc:set_x_current 135
2026-08-17T09:46:00.730198+00:00 gfcloud[2278] INFO cnc:set_y_decay 1
2026-08-17T09:46:00.731506+00:00 gfcloud[2278] INFO cnc:set_y_mode 8
2026-08-17T09:46:00.732735+00:00 gfcloud[2278] INFO cnc:set_y_current 22
2026-08-17T09:46:00.740459+00:00 gfcloud[2278] INFO machine:_run_loop starting run
2026-08-17T09:46:00.741865+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:46:00.745983+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:46:02.491897+00:00 gfcloud[2278] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:46:02.494137+00:00 gfcloud[2278] INFO machine:_run_loop finished run
2026-08-17T09:46:02.495155+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:46:02.530565+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (actual/expected): X (-13096/-13096), Y (-7400/-7400), Z (0/0)
2026-08-17T09:46:02.531413+00:00 gfcloud[2278] INFO machine:_motion_locked motion bytes actual:47243, expected: 47243
2026-08-17T09:46:02.538168+00:00 gfcloud[2278] INFO machine:_motion_locked start idle
2026-08-17T09:46:02.539603+00:00 gfcloud[2278] INFO cnc:set_x_current 33
2026-08-17T09:46:02.541147+00:00 gfcloud[2278] INFO cnc:set_y_current 5
2026-08-17T09:46:02.549578+00:00 gfcloud[2278] INFO machine:_motion_locked end positions (-13096, -7400, 0)
2026-08-17T09:46:02.550385+00:00 gfcloud[2278] INFO machine:_motion end motion
2026-08-17T09:46:02.551153+00:00 gfcloud[2278] INFO basemachine:_finish_action motion [1576550685]: finished with event ":completed"
2026-08-17T09:46:02.552496+00:00 gfcloud[2278] INFO cnc:laser_latch 1
2026-08-17T09:46:03.007623+00:00 gfcloud[2278] INFO gfuiservice:run service action request: lid_image (ready)
2026-08-17T09:46:03.009488+00:00 gfcloud[2278] INFO ffmachine:_lid_image capturing Lid Image via forgectrl
2026-08-17T09:46:03.037155+00:00 gfcloud[2278] INFO gfuiservice:run lid_image (ready) service action dispatched
2026-08-17T09:46:03.758520+00:00 gfcloud[2278] INFO ffmachine:_lid_image uploading Lid Image
2026-08-17T09:46:03.760049+00:00 gfcloud[2278] INFO websocket:img_upload START
2026-08-17T09:46:04.128126+00:00 gfcloud[2278] INFO websocket:img_upload COMPLETE
forgetest/tests/fixtures/gfcloud-lidabort.log
Vendored
+72
View File
@@ -0,0 +1,72 @@
2026-08-17T09:42:09.781500+00:00 gfcloud[1522] INFO gfuiservice:run motion (ready) service action motion
2026-08-17T09:42:11.281337+00:00 gfcloud[1522] INFO cnc:set_step_freq 28160
2026-08-17T09:42:11.282627+00:00 gfcloud[1522] INFO cnc:set_x_decay 1
2026-08-17T09:42:11.283850+00:00 gfcloud[1522] INFO cnc:set_x_mode 8
2026-08-17T09:42:11.285121+00:00 gfcloud[1522] INFO cnc:set_x_current 135
2026-08-17T09:42:11.286711+00:00 gfcloud[1522] INFO cnc:set_y_decay 1
2026-08-17T09:42:11.287977+00:00 gfcloud[1522] INFO cnc:set_y_mode 8
2026-08-17T09:42:11.289235+00:00 gfcloud[1522] INFO cnc:set_y_current 22
2026-08-17T09:42:11.297425+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:42:11.299141+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:11.303264+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:42:12.560917+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:12.572022+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:42:12.572811+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:42:12.580801+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (actual/expected): X (-10313/-10313), Y (-649/-649), Z (0/0)
2026-08-17T09:42:12.581620+00:00 gfcloud[1522] INFO machine:_motion_locked motion bytes actual:34952, expected: 34952
2026-08-17T09:42:12.582366+00:00 gfcloud[1522] INFO machine:_motion_locked start idle
2026-08-17T09:42:12.583540+00:00 gfcloud[1522] INFO cnc:set_x_current 33
2026-08-17T09:42:12.584928+00:00 gfcloud[1522] INFO cnc:set_y_current 5
2026-08-17T09:42:12.593681+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (-10313, -649, 0)
2026-08-17T09:42:12.604394+00:00 gfcloud[1522] INFO machine:_motion end motion
2026-08-17T09:42:12.604757+00:00 gfcloud[1522] INFO basemachine:_finish_action motion [1576550503]: finished with event ":completed"
2026-08-17T09:42:12.605824+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:42:15.672518+00:00 gfcloud[1522] INFO gfuiservice:run service action request: print (ready)
2026-08-17T09:42:15.676330+00:00 gfcloud[1522] INFO machine:_motion start motion
2026-08-17T09:42:15.680419+00:00 gfcloud[1522] INFO gfuiservice:run print (ready) service action print
2026-08-17T09:42:21.975587+00:00 gfcloud[1522] INFO cnc:laser_latch 0
2026-08-17T09:42:22.001354+00:00 gfcloud[1522] INFO machine:_button_wait waiting for button
2026-08-17T09:42:24.774117+00:00 gfcloud[1522] INFO machine:_switch_event button pushed
2026-08-17T09:42:24.778509+00:00 gfcloud[1522] INFO cnc:set_step_freq 10000
2026-08-17T09:42:24.781114+00:00 gfcloud[1522] INFO cnc:set_x_decay 1
2026-08-17T09:42:24.783654+00:00 gfcloud[1522] INFO cnc:set_x_mode 8
2026-08-17T09:42:24.786180+00:00 gfcloud[1522] INFO cnc:set_x_current 135
2026-08-17T09:42:24.789088+00:00 gfcloud[1522] INFO cnc:set_y_decay 1
2026-08-17T09:42:24.791559+00:00 gfcloud[1522] INFO cnc:set_y_mode 8
2026-08-17T09:42:24.794380+00:00 gfcloud[1522] INFO cnc:set_y_current 22
2026-08-17T09:42:24.815263+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:42:24.816687+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:24.820823+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:42:25.049489+00:00 gfcloud[1522] INFO machine:_switch_event button released
2026-08-17T09:42:30.832527+00:00 gfcloud[1522] INFO machine:_switch_event lid opened
2026-08-17T09:42:30.838627+00:00 gfcloud[1522] WARNING machine:_run_loop lid opened mid-run; stopping motion
2026-08-17T09:42:30.941553+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:30.947477+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:42:30.949099+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:42:30.964916+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (actual/expected): X (8454/7573), Y (684/684), Z (3/3)
2026-08-17T09:42:30.965704+00:00 gfcloud[1522] INFO machine:_motion_locked motion bytes actual:60649, expected: 238043
2026-08-17T09:42:30.972180+00:00 gfcloud[1522] INFO machine:_return_home start return home
2026-08-17T09:42:31.847247+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:42:31.848617+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:31.852977+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:42:36.970521+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:36.976059+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:42:36.977738+00:00 gfcloud[1522] INFO machine:_return_home return home complete
2026-08-17T09:42:36.979696+00:00 gfcloud[1522] INFO machine:_motion_locked start cool down
2026-08-17T09:42:36.998973+00:00 gfcloud[1522] INFO machine:_motion_locked start idle
2026-08-17T09:42:37.000314+00:00 gfcloud[1522] INFO cnc:set_x_current 33
2026-08-17T09:42:37.001774+00:00 gfcloud[1522] INFO cnc:set_y_current 5
2026-08-17T09:42:37.010089+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (0, 0, 3)
2026-08-17T09:42:37.010885+00:00 gfcloud[1522] INFO machine:_motion end motion
2026-08-17T09:42:37.011563+00:00 gfcloud[1522] INFO basemachine:_finish_action print [1576550507]: finished with event ":cancelled"
2026-08-17T09:42:37.013071+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:42:37.449180+00:00 gfcloud[1522] INFO gfuiservice:run service action request: hunt (ready)
2026-08-17T09:42:37.451286+00:00 gfcloud[1522] INFO z_axis:home starting z homing cycle
2026-08-17T09:42:37.452782+00:00 gfcloud[1522] INFO gfuiservice:run hunt (ready) service action hunt
2026-08-17T09:42:37.453691+00:00 gfcloud[1522] INFO z_axis:configure configuring z_enable: True, current: ZCur.HIGH, mode: Microstep.FULL
2026-08-17T09:42:37.458283+00:00 gfcloud[1522] INFO z_axis:_step_until starting z_step until at_home: False
2026-08-17T09:42:37.827610+00:00 gfcloud[1522] INFO z_axis:_step_until took -2 z_steps
2026-08-17T09:42:37.829278+00:00 gfcloud[1522] INFO z_axis:_step_until starting z_step until at_home: True
2026-08-17T09:42:38.200493+00:00 gfcloud[1522] INFO z_axis:_step_until took 2 z_steps
2026-08-17T09:42:38.202234+00:00 gfcloud[1522] INFO z_axis:home pass: 1
2026-08-17T09:42:38.203788+00:00 gfcloud[1522] INFO z_axis:_step_until starting z_step until at_home: False
forgetest/tests/fixtures/gfcloud-pause.log
Vendored
+53
View File
@@ -0,0 +1,53 @@
2026-08-17T09:42:15.672518+00:00 gfcloud[1522] INFO gfuiservice:run service action request: print (ready)
2026-08-17T09:42:15.676330+00:00 gfcloud[1522] INFO machine:_motion start motion
2026-08-17T09:42:15.680419+00:00 gfcloud[1522] INFO gfuiservice:run print (ready) service action print
2026-08-17T09:42:21.975587+00:00 gfcloud[1522] INFO cnc:laser_latch 0
2026-08-17T09:42:22.001354+00:00 gfcloud[1522] INFO machine:_button_wait waiting for button
2026-08-17T09:42:24.774117+00:00 gfcloud[1522] INFO machine:_switch_event button pushed
2026-08-17T09:42:24.778509+00:00 gfcloud[1522] INFO cnc:set_step_freq 10000
2026-08-17T09:42:24.781114+00:00 gfcloud[1522] INFO cnc:set_x_decay 1
2026-08-17T09:42:24.783654+00:00 gfcloud[1522] INFO cnc:set_x_mode 8
2026-08-17T09:42:24.786180+00:00 gfcloud[1522] INFO cnc:set_x_current 135
2026-08-17T09:42:24.789088+00:00 gfcloud[1522] INFO cnc:set_y_decay 1
2026-08-17T09:42:24.791559+00:00 gfcloud[1522] INFO cnc:set_y_mode 8
2026-08-17T09:42:24.794380+00:00 gfcloud[1522] INFO cnc:set_y_current 22
2026-08-17T09:42:24.815263+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:42:24.816687+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:24.820823+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:42:25.049489+00:00 gfcloud[1522] INFO machine:_switch_event button released
2026-08-17T09:42:31.104201+00:00 gfcloud[1522] INFO machine:_switch_event button pushed
2026-08-17T09:42:31.106877+00:00 gfcloud[1522] INFO machine:_run_loop button pressed mid-run; pausing
2026-08-17T09:42:31.288114+00:00 gfcloud[1522] INFO machine:_switch_event button released
2026-08-17T09:42:31.612040+00:00 gfcloud[1522] INFO machine:_run_loop paused at Position(x=AxisPosition(steps=1210, mm=22.68, inch=0.89), y=AxisPosition(steps=402, mm=7.54, inch=0.30), z=AxisPosition(steps=3, mm=0.0, inch=0.0), bytes=PulsPosition(total=238043, processed=61200))
2026-08-17T09:42:34.702311+00:00 gfcloud[1522] INFO machine:_switch_event button pushed
2026-08-17T09:42:34.704560+00:00 gfcloud[1522] INFO machine:_run_loop button pressed while paused; resuming (laser lead 1950 ticks)
2026-08-17T09:42:34.901002+00:00 gfcloud[1522] INFO machine:_switch_event button released
2026-08-17T09:42:58.130807+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:58.136283+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:42:58.137979+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:42:58.151159+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (actual/expected): X (7573/7573), Y (684/684), Z (3/3)
2026-08-17T09:42:58.152103+00:00 gfcloud[1522] INFO machine:_motion_locked motion bytes actual:238043, expected: 238043
2026-08-17T09:42:58.160180+00:00 gfcloud[1522] INFO machine:_return_home start return home
2026-08-17T09:42:59.047247+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:42:59.048617+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:42:59.052977+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.RUNNING
2026-08-17T09:43:04.170521+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:43:04.176059+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:43:04.177738+00:00 gfcloud[1522] INFO machine:_return_home return home complete
2026-08-17T09:43:04.179696+00:00 gfcloud[1522] INFO machine:_motion_locked start cool down
2026-08-17T09:43:04.198973+00:00 gfcloud[1522] INFO machine:_motion_locked start idle
2026-08-17T09:43:04.200314+00:00 gfcloud[1522] INFO cnc:set_x_current 33
2026-08-17T09:43:04.201774+00:00 gfcloud[1522] INFO cnc:set_y_current 5
2026-08-17T09:43:04.210089+00:00 gfcloud[1522] INFO machine:_motion_locked end positions (0, 0, 3)
2026-08-17T09:43:04.210885+00:00 gfcloud[1522] INFO machine:_motion end motion
2026-08-17T09:43:04.211563+00:00 gfcloud[1522] INFO basemachine:_finish_action print [1576550507]: finished with event ":completed"
2026-08-17T09:43:04.213071+00:00 gfcloud[1522] INFO cnc:laser_latch 1
2026-08-17T09:43:04.649180+00:00 gfcloud[1522] INFO gfuiservice:run service action request: hunt (ready)
2026-08-17T09:43:04.651286+00:00 gfcloud[1522] INFO z_axis:home starting z homing cycle
2026-08-17T09:43:04.652782+00:00 gfcloud[1522] INFO gfuiservice:run hunt (ready) service action hunt
2026-08-17T09:43:11.298209+00:00 gfcloud[1522] INFO machine:_motion start motion
2026-08-17T09:43:11.983820+00:00 gfcloud[1522] INFO machine:_run_loop starting run
2026-08-17T09:43:13.630807+00:00 gfcloud[1522] INFO machine:_run_loop current state: MachineState.IDLE
2026-08-17T09:43:13.636283+00:00 gfcloud[1522] INFO machine:_run_loop finished run
2026-08-17T09:43:13.664853+00:00 gfcloud[1522] INFO machine:_motion end motion
2026-08-17T09:43:13.665575+00:00 gfcloud[1522] INFO basemachine:_finish_action hunt [1576550560]: finished with event ":completed"
forgetest/tests/helpers.py
+86
View File
@@ -76,3 +76,89 @@ def make_test(id, covers, always=False, requires=(), kind="auto", fn=None, subsy
def registry(*tests):
return {t.id: t for t in tests}
# ------------------------------------------------------- fake forgectrl
class FakeForgectrl:
"""A stand-in for the machine-services daemon on localhost: canned
JSON for the endpoints the suite reads, a mutable `state` the test
scripts, every POST recorded, and an optional `on_post(path, form)`
hook returning (status, body) to script the daemon's reactions.
Point the suite at it with FORGECTRL_URL (see start/stop)."""
def __init__(self):
import http.server
import json as _json
import threading as _threading
import urllib.parse as _up
self.state = {
"mode": {"mode": "grbl", "controller": "running", "pid": 100, "motion": "verified"},
"status": {"state": "idle", "homed": False, "diag": False, "laser_locked": True,
"pos": {"x": 0.0, "y": 0.0, "z": 0.0},
"switches": {"lid": True, "button": False, "interlock_ok": True,
"head": True, "hv_enable": False}},
"cool": {"phase": "idle", "armed": False, "hold": False},
"cam": {"running": False, "clients": 0},
"diag": {"running": False},
"settings": {"controller_mode": "grbl", "lid_lamp_idle": ""},
}
self.posts = []
self.on_post = None
fake = self
class H(http.server.BaseHTTPRequestHandler):
def log_message(self, *a):
pass
def _send(self, st, body):
data = _json.dumps(body).encode()
self.send_response(st)
self.send_header("Content-Type", "application/json")
self.send_header("Content-Length", str(len(data)))
self.end_headers()
self.wfile.write(data)
def do_GET(self):
path = self.path.split("?", 1)[0]
key = {"/mode": "mode", "/status": "status", "/cool/status": "cool", "/cam/status": "cam",
"/diag/status": "diag", "/settings": "settings"}.get(path)
if key is None:
return self._send(404, {"error": "no " + path})
self._send(200, fake.state[key])
def do_POST(self):
path, _, query = self.path.partition("?")
n = int(self.headers.get("Content-Length") or 0)
raw = self.rfile.read(n).decode() if n else ""
form = dict(_up.parse_qsl(raw)) if raw else dict(_up.parse_qsl(query))
fake.posts.append((path, form))
if fake.on_post:
r = fake.on_post(path, form)
if r is not None:
return self._send(*r)
if path == "/mode" and form.get("controller"):
fake.state["mode"] = dict(fake.state["mode"], mode=form["controller"], controller="running",
pid=fake.state["mode"].get("pid", 0) + 1)
fake.state["settings"]["controller_mode"] = form["controller"]
elif path == "/settings":
fake.state["settings"].update(form)
self._send(200, {"ok": True})
self._srv = http.server.ThreadingHTTPServer(("127.0.0.1", 0), H)
self._srv.daemon_threads = True
self._srv.block_on_close = False # never wait on a lingering connection
self.url = "http://127.0.0.1:%d" % self._srv.server_address[1]
self._th = _threading.Thread(target=self._srv.serve_forever, daemon=True)
def start(self):
self._th.start()
os.environ["FORGECTRL_URL"] = self.url
os.environ["FORGECTRL_TOKEN_FILE"] = os.devnull
return self
def stop(self):
self._srv.shutdown()
self._srv.server_close()
os.environ.pop("FORGECTRL_URL", None)
os.environ.pop("FORGECTRL_TOKEN_FILE", None)
forgetest/tests/test_baseline.py
+92
View File
@@ -266,3 +266,95 @@ class BaselineTests(unittest.TestCase):
if __name__ == "__main__":
unittest.main()
class BaselineModeTests(BaselineTests):
"""The baseline against a fake forgectrl: what the mode in force
owns. Reuses the fake sysfs tree of BaselineTests; only the new
tests run here (the inherited ones are skipped)."""
def setUp(self):
super().setUp()
import helpers
self.fc = helpers.FakeForgectrl().start()
baseline.Baseline._unreachable_until = 0.0
def tearDown(self):
self.fc.stop()
super().tearDown()
def run(self, result=None):
# only this class's own tests, not the base class's
if self._testMethodName not in BaselineModeTests.__dict__:
return
return super().run(result)
def cloud(self):
self.fc.state["mode"] = {"mode": "cloud", "controller": "running", "pid": 7, "motion": "verified"}
self.fc.state["settings"]["controller_mode"] = "cloud"
def test_grbl_mode_restores_the_controller_values_and_the_lamp(self):
self._attr("cnc/step_freq", "10000")
self._attr("pic/lid_led", "77")
left = self.bl().enforce("pre", captured=None)
self.assertEqual(sorted(x.item for x in left), ["cnc/step_freq", "pic/lid_led"])
self.assertEqual(self._read("cnc/step_freq"), "28160")
self.assertEqual(self._read("pic/lid_led"), "236")
def test_cloud_mode_leaves_the_clients_config_lamp_and_counters(self):
self.cloud()
self._attr("cnc/step_freq", "10000") # the cloud client's tick
self._attr("pic/x_step_current", "135")
self._attr("pic/lid_led", "77") # its lid-image level
b = self.bl()
cap = b.capture()
self.assertEqual(cap["mode"], "cloud")
self.assertNotIn("controller_mode", cap["settings"])
self._pos(-13096, -7400, 0) # the service re-zeroed and moved
self._attr("cnc/streaming", "1") # NOT the client's: still restored
left = b.enforce("post", captured=cap)
self.assertEqual([x.item for x in left], ["cnc/streaming"])
self.assertEqual(self._read("cnc/step_freq"), "10000")
self.assertEqual(self._read("pic/x_step_current"), "135")
self.assertEqual(self._read("pic/lid_led"), "77")
self.assertEqual(self._read("cnc/streaming"), "0")
self.assertEqual(self.fc.posts, []) # no mode switch, no settings write
def test_cloud_mode_still_relocks_the_latch(self):
self.cloud()
self._attr("cnc/interlock_circuit", "37") # bit 3 clear: unlocked
left = self.bl().enforce("post", captured=None)
self.assertEqual([x.item for x in left], ["laser_latch"])
self.assertEqual(self._read("cnc/laser_latch"), "1")
def test_undeclared_mode_change_is_handed_back_through_the_switch(self):
b = self.bl()
cap = b.capture() # found in grbl
self.assertEqual(cap["mode"], "grbl")
self.cloud() # the run left it in cloud, silently
left = b.enforce("post", captured=cap)
items = {x.item: x for x in left}
self.assertIn("mode", items)
self.assertEqual(items["mode"].action, "restored")
self.assertEqual(self.fc.posts, [("/mode", {"controller": "grbl"})])
self.assertEqual(self.fc.state["mode"]["mode"], "grbl")
def test_declared_mode_change_is_kept(self):
b = self.bl()
cap = b.capture()
self.cloud()
cap["mode"] = "cloud" # Context.mode_changed("cloud")
left = b.enforce("post", captured=cap)
self.assertNotIn("mode", [x.item for x in left])
self.assertEqual(self.fc.posts, [])
self.assertEqual(self.fc.state["mode"]["mode"], "cloud")
def test_controller_mode_setting_is_never_written_back_bare(self):
b = self.bl()
cap = b.capture()
self.assertNotIn("controller_mode", cap["settings"])
self.fc.state["settings"]["controller_mode"] = "cloud" # a switch persisted it
self.fc.state["mode"]["mode"] = "cloud"
cap["mode"] = "cloud"
b.enforce("post", captured=cap)
self.assertEqual([p for p, _ in self.fc.posts if p == "/settings"], [])
forgetest/tests/test_cloud_suite.py
+385
View File
@@ -0,0 +1,385 @@
"""The cloud.* job-behavior tests against a fake forgectrl and a replayed
gfcloud log: the real test functions run under the real runner Context,
the operator prompts answered by a script that also drives the replay
(open the lid -> the machine's lid reads open; close it -> the service's
re-hunt lines land). The log lines are the machine's own: bench excerpts
(the lid-abort, button-wait, and lid-open-hunt runs) and, for the pause,
the run loop's lines as its host test emits them on the print skeleton
of the lid-abort excerpt.
What is proven here: the tests find the right lines in real log noise,
reuse an existing cloud session and never switch back, restart the client
for a fresh hunt, judge the print's own finish line (not another action's),
wait the service's deferred moves out, and fail for the right reasons."""
import os
import shutil
import struct
import tempfile
import threading
import time
import unittest
import helpers
from forgetest.runner import Context, Failed, Run
from forgetest.suite import cloud
HERE = os.path.dirname(os.path.abspath(__file__))
FIX = os.path.join(HERE, "fixtures")
def fixture(name):
with open(os.path.join(FIX, "gfcloud-%s.log" % name), "rb") as f:
return f.read().decode().splitlines()
def cut(lines, marker, count=1):
"""(before, after) at the count-th line containing marker (the line
itself opens `after`)."""
n = 0
for i, ln in enumerate(lines):
if marker in ln:
n += 1
if n == count:
return lines[:i], lines[i:]
raise KeyError(marker)
class Script:
"""Answers every prompt with its first option; a hook per prompt
substring drives the fake machine and the log replay."""
def __init__(self, run, hooks=None):
self.run = run
self.hooks = hooks or {}
self.asked = []
self.th = threading.Thread(target=self._loop, daemon=True)
self.stop = False
def start(self):
self.th.start()
return self
def _loop(self):
seen = None
while not self.stop:
p = self.run.prompt
if p and p["id"] != seen:
seen = p["id"]
self.asked.append(p["question"])
for key, fn in self.hooks.items():
if key in p["question"]:
fn()
self.run.answer(p["id"], p["options"][0])
time.sleep(0.02)
class CloudSuiteTests(unittest.TestCase):
def setUp(self):
self.tmp = tempfile.mkdtemp(prefix="forgetest-cloud-")
self.log = os.path.join(self.tmp, "gfcloud.log")
open(self.log, "wb").close()
self.sysfs = os.path.join(self.tmp, "sysfs") + os.sep
os.makedirs(self.sysfs + "cnc")
self._attr("cnc/interlock_circuit", "45") # latch locked (bit 3)
self._pos(0, 0, 3)
os.environ["GF_SYSFS_ROOT"] = self.sysfs
self.fc = helpers.FakeForgectrl().start()
self.saved = (cloud.GFCLOUD_LOG, cloud.QUIET_S, cloud.QUIET_TIMEOUT_S, cloud.HUNT_TIMEOUT_S)
cloud.GFCLOUD_LOG = self.log
cloud.QUIET_S = 0.4
cloud.QUIET_TIMEOUT_S = 3
cloud.HUNT_TIMEOUT_S = 8
self.script = None
def tearDown(self):
if self.script:
self.script.stop = True
self.fc.stop()
cloud.GFCLOUD_LOG, cloud.QUIET_S, cloud.QUIET_TIMEOUT_S, cloud.HUNT_TIMEOUT_S = self.saved
os.environ.pop("GF_SYSFS_ROOT", None)
shutil.rmtree(self.tmp, ignore_errors=True)
# -- fakes -----------------------------------------------------------
def _attr(self, attr, val):
with open(self.sysfs + attr, "w") as f:
f.write(val)
def _pos(self, x, y, z):
with open(self.sysfs + "cnc/position", "wb") as f:
f.write(struct.pack("<3i2I", x, y, z, 0, 0))
def append(self, lines, delay=0.0):
def go():
if delay:
time.sleep(delay)
with open(self.log, "ab") as f:
f.write(("\n".join(lines) + "\n").encode())
if delay:
threading.Thread(target=go, daemon=True).start()
else:
go()
def in_cloud(self, pid=2278):
self.fc.state["mode"] = {"mode": "cloud", "controller": "running", "pid": pid, "motion": "verified"}
self.fc.state["settings"]["controller_mode"] = "cloud"
def lid(self, closed):
self.fc.state["status"]["switches"]["lid"] = bool(closed)
def run_test(self, fn, hooks=None, test_id="cloud.x"):
run = Run("test", test_id, test_id)
run.baseline_captured = {"mode": self.fc.state["mode"]["mode"], "position": [0, 0, 0]}
ctx = Context(run, None, helpers.make_test(test_id, []))
self.script = Script(run, hooks).start()
try:
fn(ctx)
finally:
self.script.stop = True
return run
def assertFails(self, fn, needle, hooks=None):
with self.assertRaises(Failed) as cm:
self.run_test(fn, hooks)
self.assertIn(needle, str(cm.exception))
return cm.exception
# -- session detection -------------------------------------------------
def test_session_live_is_per_client(self):
lines = fixture("huntlid")
# the old client (1927) closed and left; the new one (2278) is ready
self.append(lines)
self.assertTrue(cloud.session_live(2278)[0])
self.assertFalse(cloud.session_live(1927)[0])
# an unknown pid falls back to the newest lines (ready)
self.assertTrue(cloud.session_live(9999)[0])
# a drop after the ready line: not live until it is ready again
self.append(["2026-08-17T10:00:00.000000+00:00 gfcloud[2278] INFO websocket:_on_close RX-EVENT: closed (1006, )",
"2026-08-17T10:00:00.100000+00:00 gfcloud[2278] INFO websocket:run RECONNECTING"])
live, detail = cloud.session_live(2278)
self.assertFalse(live)
self.assertIn("RECONNECTING", detail)
self.append(["2026-08-17T10:00:06.000000+00:00 gfcloud[2278] INFO websocket:_on_open RX-EVENT: ready"])
self.assertTrue(cloud.session_live(2278)[0])
def test_enter_cloud_reuses_a_live_session_and_never_switches(self):
self.in_cloud()
self.append(fixture("huntlid"))
run = self.run_test(lambda ctx: cloud.enter_cloud(ctx))
self.assertTrue(any("reusing it" in l for l in run.lines), run.lines)
self.assertEqual(self.fc.posts, [])
self.assertEqual(run.baseline_captured["mode"], "cloud")
def test_enter_cloud_refuses_a_dead_session(self):
self.in_cloud(pid=1927) # the client that shut down in the excerpt
self.append(fixture("huntlid"))
self.assertFails(cloud.enter_cloud, "no live service session")
def test_enter_cloud_switches_once_from_grbl_and_declares_it(self):
lines = fixture("huntlid")
pre, post = cut(lines, "gfuiservice:__init__ INITIALIZED")
self.append(pre)
def on_post(path, form):
if path == "/mode":
self.append(post, delay=0.2) # the new client's session + hunt + moves
return None
self.fc.on_post = on_post
run = self.run_test(lambda ctx: cloud.enter_cloud(ctx))
self.assertEqual([p for p, _ in self.fc.posts], ["/mode"])
self.assertEqual(self.fc.state["mode"]["mode"], "cloud")
self.assertEqual(run.baseline_captured["mode"], "cloud") # declared: the baseline keeps it
self.assertTrue(any("connect-time hunt" in l and ":completed" in l for l in run.lines), run.lines)
def test_enter_cloud_waits_for_the_service_to_stop_moving(self):
self.in_cloud()
self.append(fixture("huntlid"))
# a motion in flight (never idle within the timeout) fails, and says so
self.fc.state["status"]["state"] = "running"
self.assertFails(cloud.enter_cloud, "still running service moves")
# -- the hunt with the lid open ------------------------------------------
def test_hunt_lid_open_restarts_the_client_in_cloud_mode(self):
self.in_cloud(pid=1927)
lines = fixture("huntlid")
pre, post = cut(lines, "gfuiservice:__init__ INITIALIZED")
hunt_part, close_part = cut(post, "_switch_event lid closed")
self.append(pre)
def on_post(path, form):
if path == "/controller/stop":
self.fc.state["mode"] = dict(self.fc.state["mode"], controller="standby", pid=0)
elif path == "/controller/start":
self.fc.state["mode"] = dict(self.fc.state["mode"], controller="running", pid=2278)
self.append(hunt_part, delay=0.2)
return None
self.fc.on_post = on_post
def lid_closed():
self.lid(True)
self.append(close_part, delay=0.2)
run = self.run_test(cloud.hunt_lid_open,
hooks={"Open the lid": lambda: self.lid(False), "Close the lid": lid_closed},
test_id="cloud.hunt-lid-open")
self.assertEqual([p for p, _ in self.fc.posts], ["/controller/stop", "/controller/start"])
ev = run.evidence
self.assertIn(":completed", ev["hunt_line"])
self.assertEqual(ev["refusals_before_hunt_end"], 0)
self.assertEqual(ev["motions_after_lid_close"], 3)
self.assertEqual(self.fc.state["mode"]["mode"], "cloud") # still cloud
self.assertTrue(any("PASS:" in l for l in run.lines))
# the prompts, in order: open, confirm lens, close
self.assertEqual(len(self.script.asked), 3)
def test_hunt_lid_open_from_grbl_switches_and_stays(self):
lines = fixture("huntlid")
pre, post = cut(lines, "gfuiservice:__init__ INITIALIZED")
hunt_part, close_part = cut(post, "_switch_event lid closed")
self.append(pre)
def on_post(path, form):
if path == "/mode":
self.append(hunt_part, delay=0.2)
return None
self.fc.on_post = on_post
run = self.run_test(cloud.hunt_lid_open,
hooks={"Open the lid": lambda: self.lid(False),
"Close the lid": lambda: (self.lid(True), self.append(close_part, delay=0.2))})
self.assertEqual([p for p, _ in self.fc.posts], ["/mode"])
self.assertEqual(self.fc.state["mode"]["mode"], "cloud")
self.assertEqual(run.baseline_captured["mode"], "cloud")
self.assertIn(":completed", run.evidence["hunt_line"])
def test_hunt_lid_open_needs_the_lid_open(self):
self.in_cloud()
self.append(fixture("huntlid"))
self.assertFails(cloud.hunt_lid_open, "lid reads closed")
def test_hunt_refused_for_the_lid_fails(self):
self.in_cloud(pid=1927)
lines = fixture("huntlid")
pre, post = cut(lines, "gfuiservice:__init__ INITIALIZED")
# a refusal ahead of the hunt's end (the lid gating the hunt would look like this)
i = next(i for i, l in enumerate(post) if "z_axis:home starting z homing cycle" in l)
post = post[:i] + ["2026-08-17T09:45:10.595000+00:00 gfcloud[2278] INFO machine:_safe_to_move lid opened, unsafe to move"] + post[i:]
self.append(pre)
def on_post(path, form):
if path == "/controller/stop":
self.fc.state["mode"] = dict(self.fc.state["mode"], controller="standby", pid=0)
elif path == "/controller/start":
self.fc.state["mode"] = dict(self.fc.state["mode"], controller="running", pid=2278)
self.append(post, delay=0.1)
return None
self.fc.on_post = on_post
self.assertFails(cloud.hunt_lid_open, "refused for the lid", hooks={"Open the lid": lambda: self.lid(False)})
# -- pause / resume ---------------------------------------------------------
def replay_print(self, name, at_run, at_end, tail_delay=0.3):
"""Split a print excerpt into: up to the run's RUNNING line
(lands when the operator says Print is done), the block landing at
the mid-run prompt, and the rest."""
lines = fixture(name)
pre, rest = cut(lines, "waiting for button")
run_pre, rest = cut(rest, "current state: MachineState.RUNNING") # the PRINT's run
pre, rest = pre + run_pre + [rest[0]], rest[1:]
mid, tail = cut(rest, at_end)
return {"Click Done here": lambda: self.append(pre, delay=0.1),
at_run: lambda: (self.append(mid, delay=0.05), self.append(tail, delay=tail_delay))}
def test_pause_resume_passes_on_the_machines_lines(self):
self.in_cloud(pid=1522)
self.append(["2026-08-17T09:41:00.000000+00:00 gfcloud[1522] INFO authentication:authenticate_machine SUCCESS",
"2026-08-17T09:41:00.500000+00:00 gfcloud[1522] INFO websocket:_on_open RX-EVENT: ready",
"2026-08-17T09:41:00.900000+00:00 gfcloud[1522] INFO websocket:ws_connect ESTABLISHED"])
hooks = self.replay_print("pause", "Press the button once NOW", "current state: MachineState.IDLE")
self.fc.state["cool"]["armed"] = True
run = self.run_test(cloud.pause_resume, hooks=hooks, test_id="cloud.pause-resume")
ev = run.evidence
self.assertEqual(ev["log"], {"button pressed mid-run; pausing": True, "paused at": True,
"button pressed while paused; resuming": True})
self.assertTrue(ev["armed_after_resume"])
self.assertIn(":completed", ev["log_end"]["print finished"])
self.assertTrue(ev["log_end"]["return home complete"])
self.assertEqual(ev["relock_or_cancel_lines"], 0)
self.assertEqual(self.fc.posts, [])
self.assertTrue(any("PASS: button pause/resume" in l for l in run.lines))
# the post-print hunt was waited out
self.assertTrue(any("machine is quiet" in l for l in run.lines))
def test_pause_resume_fails_when_the_print_is_cancelled_instead(self):
self.in_cloud(pid=1522)
self.append(["2026-08-17T09:41:00.500000+00:00 gfcloud[1522] INFO websocket:_on_open RX-EVENT: ready"])
lines = fixture("pause")
lines = [l.replace('print [1576550507]: finished with event ":completed"',
'print [1576550507]: finished with event ":cancelled"') for l in lines]
pre, rest = cut(lines, "current state: MachineState.RUNNING")
pre, rest = pre + [rest[0]], rest[1:]
hooks = {"Click Done here": lambda: self.append(pre, delay=0.1),
"Press the button once NOW": lambda: self.append(rest, delay=0.05)}
self.assertFails(cloud.pause_resume, "did not complete after the resume", hooks=hooks)
def test_pause_resume_fails_without_the_pause_line(self):
self.in_cloud(pid=1522)
self.append(["2026-08-17T09:41:00.500000+00:00 gfcloud[1522] INFO websocket:_on_open RX-EVENT: ready"])
lines = [l for l in fixture("pause") if "button pressed mid-run" not in l]
pre, rest = cut(lines, "current state: MachineState.RUNNING")
pre, rest = pre + [rest[0]], rest[1:]
# the wait for the pause lines is 90 s: shorten it through the module's poll by
# ending the log early - the finish line arrives, but the pause never does
saved = cloud.wait_log
def fast_wait_log(ctx, offset, needles, timeout, poll=0.5):
return saved(ctx, offset, needles, min(timeout, 1.5), poll=0.1)
cloud.wait_log = fast_wait_log
try:
hooks = {"Click Done here": lambda: self.append(pre, delay=0.1),
"Press the button once NOW": lambda: self.append(rest, delay=0.05)}
self.assertFails(cloud.pause_resume, "did not pause the run", hooks=hooks)
finally:
cloud.wait_log = saved
# -- the two lid tests, on their bench excerpts --------------------------------
def test_lid_abort_on_the_bench_excerpt(self):
self.in_cloud(pid=1522)
self.append(["2026-08-17T09:41:00.500000+00:00 gfcloud[1522] INFO websocket:_on_open RX-EVENT: ready"])
hooks = self.replay_print("lidabort", "Open the lid NOW", "start cool down")
run = self.run_test(cloud.lid_abort, hooks=hooks, test_id="cloud.lid-abort")
ev = run.evidence
self.assertLess(ev["edge_to_stop_ms"], 60)
self.assertIn(":cancelled", ev["log"]["print finished"])
self.assertEqual(ev["kernel_counters_after_park"], [0, 0, 3])
self.assertTrue(ev["latch_locked"])
self.assertFalse(ev["armed_after"])
self.assertEqual(self.fc.posts, [])
self.assertTrue(any("PASS: lid open" in l for l in run.lines))
def test_lid_during_button_wait_on_the_bench_excerpt(self):
self.in_cloud(pid=1927)
self.append(["2026-08-17T09:41:00.500000+00:00 gfcloud[1927] INFO websocket:_on_open RX-EVENT: ready"])
lines = fixture("buttonwait")
pre, rest = cut(lines, "waiting for button")
pre, rest = pre + [rest[0]], rest[1:]
hooks = {"Click Done here": lambda: self.append(pre, delay=0.1),
"Open the lid now": lambda: self.append(rest, delay=0.05)}
run = self.run_test(cloud.lid_during_button_wait, hooks=hooks, test_id="cloud.lid-during-button-wait")
ev = run.evidence
self.assertEqual(ev["runs_started_after_wait"], 0)
self.assertIn(":cancelled", ev["log"]["print finished"])
self.assertTrue(ev["latch_locked"])
self.assertEqual(self.fc.posts, [])
self.assertTrue(any("PASS: lid open at the button prompt" in l for l in run.lines))
def test_print_finish_is_the_prints_not_another_actions(self):
# a motion that completes before the print must not satisfy the print's finish
lines = fixture("lidabort")
i = cloud.action_finish_index(lines, "print")
j = cloud.action_finish_index(lines, "motion")
self.assertIsNotNone(i)
self.assertIsNotNone(j)
self.assertLess(j, i)
self.assertIn(":cancelled", lines[i])
self.assertIn(":completed", lines[j])
if __name__ == "__main__":
unittest.main()
forgetest/tests/test_server.py
+12
View File
@@ -181,6 +181,18 @@ class ServerTests(unittest.TestCase):
st, d = self.call("POST", "/start", {"test": "fake.needs"})
self.assertEqual(st, 409)
self.assertIn("prerequisites", d["message"])
# the operator's override: the test runs alone and the record says so
st, d = self.call("POST", "/start", {"test": "fake.needs", "ignore_requires": True})
self.assertEqual(st, 200)
state = self.wait_idle()
self.assertEqual(state["tests"]["fake.needs"]["status"], "pass")
st, rec = self.call("GET", "/result?test=fake.needs")
self.assertEqual(rec["evidence"]["prerequisites"]["missing"], ["fake.prompt"])
self.assertTrue(rec["evidence"]["prerequisites"]["overridden"])
self.assertTrue(any("prerequisites overridden" in l for l in rec["log"]))
# its prerequisite is still required for the release
self.assertFalse(state["tests"]["fake.prompt"]["satisfied"])
self.assertFalse(state["authorized"])
st, d = self.call("POST", "/start", {"test": "fake.live"})
self.assertEqual(st, 409)
self.assertIn("live", d["message"])