diff --git a/docs/BRINGUP.md b/docs/BRINGUP.md index 8592a53..23a06a6 100644 --- a/docs/BRINGUP.md +++ b/docs/BRINGUP.md @@ -938,6 +938,84 @@ Open items only. Anything closed is in `CAMPAIGN-LOG.md`. log EV_SW head-bit edges plus `head/beam_detect_digital|_analog` while firing. +16. **Step timing under CPU contention.** The board runs one core, and of + grblHAL's four threads only the shipper is `SCHED_FIFO`. The producer — + the thread that emulates the stepper timer and stamps every step onto the + virtual time grid — is `SCHED_OTHER` at nice 5, the same class and nice as + forgectrl's MHD connection threads, so a camera stream viewer (~35 % of the + core on its own) competes with step generation on equal terms. When the + producer's virtual clock falls behind wall clock by more than the ring + depth (200 ms), `gf_stream_pulse` clamps late events forward and the + backlog ships one step per machine tick: 28 160 steps/s against the 1 778 + that 2000 mm/min asks for, a ~16× velocity burst the motors cannot follow. + `cnc/underruns` stays 0 through all of it, because the ring never goes + dry — the stream is continuous and only its timing is wrong, which is + exactly what the present counters cannot see. Owed: put the producer on + `SCHED_FIFO` just below the shipper; gate or throttle the camera stream + while a job runs (forgectrl already holds the run state, so this shares the + bench slot with the HTTP surface caps in item 8); and report the clamp + count per run instead of only cumulatively at process exit. The per-run + `LOG_DEBUG` line is the instrument — a clean 2000 mm/min run with no camera + consumer reports `max behind 1.5 ms, clamped 0`. +17. **Laser power model and the missing duty floor.** grblHAL maps S onto the + analog PWM duty (`$30`/`$31` → `$35`/`$36`, written raw into PWMSAR against + the 127-count period), and ForgeFIRM overrides only `$32`, so a shipped + machine has `$35` = 0: duty runs linearly to zero with S and nothing stops + it falling below the tube's striking threshold. Under M4 the core scales S + by velocity, so every corner, every reversal, and every segment shorter + than the accelerate-in-and-out distance (~1.6 mm at 2000 mm/min with the + default 700 mm/s²) is commanded below the striking point and does not burn + at all. + + The factory does not use duty as a power control. All five firing jobs in + the captured pulse files pin the power byte at 127 (one also uses 102) and + modulate dose entirely by dithering the FIRE bit at the 10 kHz tick, at + 6.5–18.8 % density. Two consequences: the captures cannot supply a `$35` + default, because nothing in them runs anywhere near the threshold; and the + duty → optical-power transfer function of this HV supply is unmeasured, + because nothing has ever depended on it. + + Owed, in order: run `live_fire_drills.py pthresh` on scrap with `$35` = 0 + to find the striking threshold, set `DEFAULT_SPINDLE_PWM_MIN_VALUE` (a + percent) in `grblHAL-glowforge/src/boards/glowforge.h` from it — the + marking rung's percent is the value — and record the number here. Then the + design question behind it: whether to follow the factory and modulate dose + by FIRE-bit density at a fixed high duty rather than by analog duty. That + is what the per-tick FIRE bit exists for, it cannot fall below the striking + threshold by construction, and it is the only power model this tube and + supply are known to work well with. + + What that model means for image engraving, since it decides the design as + much as cutting does. LightBurn has two image paths. Its 1-bit modes + (Dither, Stucki, Jarvis, Halftone, Ordered) dither in the image domain and + emit only `Smax` or 0, so density is solid whenever a dot is on. Grayscale + mode emits a level per pixel, and that is the path the present duty model + breaks worst: dark pixels map below the striking threshold and mark + nothing, so shadows do not fade, they drop out. FIRE-bit density fixes that + by construction — a low level becomes sparse full-power pulses, every one + of which marks. Three consequences to design around: + - **Tonal resolution is set by ticks per pixel**, `rate × pixel_mm ÷ + speed_mm_s`: 56 ticks at 254 DPI and 3000 mm/min, 14 at 508 DPI and + 6000 mm/min. Fine, fast rasters have few pulse slots per pixel and lose + levels. The factory works at 10 kHz with ~20 ticks per pixel at 254 DPI, + so this envelope is livable, not comfortable. + - **The dither accumulator must carry across pixels**, so a level too fine + to express inside one pixel still averages over a run of them — that + spatial averaging is what recovers the levels the arithmetic above + loses. It follows that the accumulator resets only on fire-off, run + boundaries, disarm and abort, never per pixel. + - **A 1-bit image run below full layer power stacks two dithers**, and a + plain integer carry repeats on a short period, so it can beat against + LightBurn's own pattern as moiré. Perturbing the accumulator removes the + short period; the workflow answer is that 1-bit modes belong at 100 % + power with darkness set by speed, where density is solid and no second + dither exists. + + Rasters also gain from the model directly: a level change costs a power + byte in the stream today, and the feeder contract forbids back-to-back + power bytes, while under FIRE dithering the duty is a constant sent once + per run and a per-pixel level change costs no stream byte at all. + **Deliberately not gated:** an armed GRBL job after an underrun cuts at the stale origin unless homing is required (GRBL mode permits unhomed cutting; the underrun itself alarms and unlinks the anchor). Not in the acceptance catalog diff --git a/forgetest/forgetest/suite/motion.py b/forgetest/forgetest/suite/motion.py index 0230a9a..78cbb6a 100644 --- a/forgetest/forgetest/suite/motion.py +++ b/forgetest/forgetest/suite/motion.py @@ -317,14 +317,18 @@ def _log_offset(path): return 0 -def _probe_lines(path, offset): +def _log_lines(path, offset, needle): try: with open(path, "rb") as f: f.seek(offset) data = f.read().decode("utf-8", "replace") except OSError: return [] - return [ln.strip() for ln in data.splitlines() if "liveness probe:" in ln] + return [ln.strip() for ln in data.splitlines() if needle in ln] + + +def _probe_lines(path, offset): + return _log_lines(path, offset, "liveness probe:") def _liveness_masked_restart(ctx, fc, ev): @@ -952,3 +956,97 @@ def lid_policy_hold(ctx): ctx.check(ev["lid_policy_restored"] == was, "lid_policy was not restored to %r", was) ctx.log("PASS: lid_policy=hold parked the job in Door and the cycle start finished it (%.3f mm)", ev["moved_mm"]) + + +GRBLHAL_LOG = "/data/log/forgefirm/grblhal/grblhal.log" +SCHED_FIFO = 1 + + +def _thread_sched(pid): + """(tid, policy, rt_priority) for every thread of pid. Those are fields + 41 and 40 of /proc//stat; comm can hold spaces and parentheses, so + the fields are indexed from the last ')' - rest[0] is field 3.""" + out = [] + for tid in sorted(os.listdir("/proc/%d/task" % pid)): + try: + with open("/proc/%d/task/%s/stat" % (pid, tid)) as f: + s = f.read() + except OSError: + continue + rest = s[s.rindex(")") + 1:].split() + if len(rest) >= 39: + out.append((tid, int(rest[38]), int(rest[37]))) + return out + + +@test("motion.step-timing-under-load", + title="Step timing holds while userspace competes for the core", + subsystem="motion", kind="auto", est_min=2, + covers=_MOTION_COVERS, requires=["kernel.latch-locked-idle", "motion.jog-roundtrip"], + steps=["Bed clear, lid closed; the head needs >= 40 mm of free +X travel."], + description="The board has one core, so the thread that stamps steps onto the pulse grid " + "has to outrank ordinary userspace: when its virtual clock slips behind wall " + "clock past the queue depth, late events clamp forward and the backlog ships " + "one step per machine tick - a burst no motor follows, while cnc/underruns " + "stays 0 because the ring never runs dry. Asserts the producer and the shipper " + "both hold SCHED_FIFO, then drives 2000 mm/min round trips against a deliberate " + "nice-5 CPU hog and requires the controller to report no clamped events.") +def step_timing_under_load(ctx): + import subprocess + + ev = ctx.evidence + pid = controller_pid() + + threads = _thread_sched(pid) + rt = sorted(prio for _tid, pol, prio in threads if pol == SCHED_FIFO) + ev["threads"] = len(threads) + ev["rt_priorities"] = rt + ctx.log("controller threads: %d, SCHED_FIFO priorities: %s", len(threads), rt) + ctx.check(len(rt) >= 2, + "expected the stream producer and the shipper on SCHED_FIFO, found %d of %d " + "threads at real time (%s): step timing is exposed to ordinary userspace", + len(rt), len(threads), rt) + + off = _log_offset(GRBLHAL_LOG) + load = None + try: + # One SCHED_OTHER hog at the same nice as forgectrl's HTTP threads: + # the realistic competitor, and the one the fix must outrank. + load = subprocess.Popen(["nice", "-n", "5", "sh", "-c", "while :; do :; done"], + stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL) + ctx.log("CPU hog started (pid %d, nice 5)", load.pid) + with ctx.grbl() as g: + clean_slate(ctx, g) + ctrl0 = cpu_ticks(pid) + t0 = time.time() + legs = 0 + for _i in range(10): + ctx.checkpoint() + for jog in ("$J=G91X40F2000", "$J=G91X-40F2000"): + r = g.command(jog) + ctx.check(not any(x.startswith("error") for x in r), + "jog refused under load: %s", r) + _peak, states, _ = wait_idle(ctx, g, 30) + ctx.check("TIMEOUT" not in states, "a leg did not return to Idle under load") + legs += 1 + elapsed = time.time() - t0 + hz = os.sysconf("SC_CLK_TCK") + ev["legs"] = legs + ev["motion_s"] = round(elapsed, 1) + ev["controller_cpu_pct"] = round(100.0 * (cpu_ticks(pid) - ctrl0) / (hz * elapsed), 1) + ctx.log("%d legs in %.1f s, controller CPU %.1f %%", + legs, elapsed, ev["controller_cpu_pct"]) + machine_idle(ctx) + finally: + if load is not None: + load.kill() + load.wait() + ctx.log("CPU hog stopped") + + clamped = _log_lines(GRBLHAL_LOG, off, "late events clamped") + ev["clamp_lines"] = clamped + ctx.check(not clamped, + "step generation was starved while userspace competed for the core: %s", + "; ".join(clamped)) + ctx.log("PASS: %d legs at 2000 mm/min against a nice-5 CPU hog, no clamped events", + ev["legs"]) diff --git a/meta-forgefirm/recipes-forgefirm/grblhal-glowforge/grblhal-glowforge-pin.inc b/meta-forgefirm/recipes-forgefirm/grblhal-glowforge/grblhal-glowforge-pin.inc index ab76239..65c398c 100644 --- a/meta-forgefirm/recipes-forgefirm/grblhal-glowforge/grblhal-glowforge-pin.inc +++ b/meta-forgefirm/recipes-forgefirm/grblhal-glowforge/grblhal-glowforge-pin.inc @@ -2,5 +2,5 @@ # changes; keep only SRCREV and PV here - the image manifest leaves # *-pin.inc out of the layer content hash because the component entry # already identifies the pinned source (forgefirm-image-manifest.bbclass). -SRCREV = "0c192659f8c1c9ecf36a824c08bdcecd5085666a" +SRCREV = "026c169c6ee028907a0235d4e3bbf5cf9d91e2a8" PV = "0.1.0" diff --git a/scripts/bench/README.md b/scripts/bench/README.md index ab3aa5c..4f7b1db 100644 --- a/scripts/bench/README.md +++ b/scripts/bench/README.md @@ -32,7 +32,7 @@ page's takeover does that; from a host, stop them first. | `gate_a_kernel_drills.py` | Kernel laser-safety drills (run on the board with forgectrl stopped so the pulse device is free): `K1` controlled-stop deceleration floor, `K2` resume waypoint honors the locked latch, `K3` a mid-ramp latch unlock never re-arms the FIRE drive. Software witnesses (`cnc/state`, `laser_enable`, `laser_on`, `laser_on_sampled`, interlock bit 3) plus the PSU-connector LASER_ON scope point; K3 refuses to run if HV reports good. | | `laser_stream_test.py` | Host-side laser pulse-stream emission harness: runs the native null-sink controller with `GFSINK_DUMP`, drives small laser jobs over TCP, and checks the dumped bytes against the kernel feeder contract (leading power byte, no back-to-back power bytes, FIRE only inside cutting moves, every stream ends FIRE-clear, no FIRE on a stepless gap, no FIRE leak across cycle churn). Runs in the grblHAL repo's CI. | | `laser_lifecycle_test.py` | Host-side operator-armed-window lifecycle harness (null-sink controller): arm once per job with M5/M3 persistence, the M2 close, sender-change re-consent, the disarm grace counting down in Hold, and arm refusal under a blocking cooling verdict. Runs in the grblHAL repo's CI. | -| `live_fire_drills.py` | **LIVE LASER** drills, on the board (the bench page) or from a LAN host (`GF_HOST`): `live_fire_drills.py [S] [F]` - `witness` (emission witness, lid-IR peaks vs the ambient baseline, HV current, job-based disarm on M2), `hold` (disarm grace in Hold), `faultpos` (armed job refuses a stale origin after an underrun), `ircut` (lid-IR characterization cut at S/F), `expstop` (armed kill on the expected-stop path; needs the panel token - `GF_TOKEN`, or the board's token file) and `ctrlstart` (the separate controller restart after it). Every drill waits for the operator's physical arm press; eye protection, fire watch, extinguisher, and exhaust are mandatory. | +| `live_fire_drills.py` | **LIVE LASER** drills, on the board (the bench page) or from a LAN host (`GF_HOST`): `live_fire_drills.py [S] [F]` - `witness` (emission witness, lid-IR peaks vs the ambient baseline, HV current, job-based disarm on M2), `hold` (disarm grace in Hold), `faultpos` (armed job refuses a stale origin after an underrun), `ircut` (lid-IR characterization cut at S/F), `pthresh` (laser power-threshold ladder: 13 constant-power rungs from 2 % to 30 % of full on scrap; the lowest rung that marks is the tube's striking threshold and reads directly as the `$35` value - requires `$35` = 0 for the run), `expstop` (armed kill on the expected-stop path; needs the panel token - `GF_TOKEN`, or the board's token file) and `ctrlstart` (the separate controller restart after it). Every drill waits for the operator's physical arm press; eye protection, fire watch, extinguisher, and exhaust are mandatory. | | `pacing_test.py` | Protocol-loop pacing check (runs on the board, dry motion): idle and parked-in-Hold states are coarse-paced, active motion is tight-paced, and a feed-hold/resume mid-move preserves position with no feeder starve. | | `gfbench.py` | Not a tool: the helper the board/host tools share - `HOST`/`LOCAL` from `GF_HOST`, `board(cmd)` (local `sh -c` or ssh), the factory coolant conversion `degc()`, `data_path()` (`FORGETEST_BENCH_DATA` or next to the tool), forgectrl's HTTP API with the panel token, `setting(key)` (from forgectrl, or from `/data/forgefirm.conf` on the board while forgectrl is stopped). | | `fan_test.py` | Fan/coolant bench (board or host; controller running): snapshots fan PWMs/tachs/temps, drives M8 → cut fans, M9 → cooldown → idle, verifying via tach readbacks. | diff --git a/scripts/bench/live_fire_drills.py b/scripts/bench/live_fire_drills.py index 11dc1d4..02e6237 100644 --- a/scripts/bench/live_fire_drills.py +++ b/scripts/bench/live_fire_drills.py @@ -7,7 +7,7 @@ watch, an extinguisher, and the exhaust running. Every drill waits for the operator to press the physical arm button before the machine fires; nothing here defeats that gate. -Usage: live_fire_drills.py [S] [F] (S, F used by ircut) +Usage: live_fire_drills.py [S] [F] (S, F used by ircut, pthresh) Drills (pass a name): witness Phase 5 A-1/A-2/A-5: a short vector mark at S400. Samples @@ -33,6 +33,15 @@ Drills (pass a name): >= 3 times on representative material; the highest peak delta sizes cool_fire_ir_delta. ircut [S] [F] e.g. ircut 1000 300 + pthresh Laser power-threshold ladder: one line per power level on + scrap, climbing from 2 % to 30 % of full, at constant power + (M3) so nothing scales the duty with velocity. The lowest + rung that leaves a mark is the tube's striking threshold, + and because $35 is a percent of full duty and the rungs are + percents of $30 with $31 = 0, that rung's percent IS the + $35 value. Requires $35 = 0 for the run: a floor already in + place lifts every rung and hides the threshold. + pthresh [Smax] [F] e.g. pthresh 1000 300 expstop Armed kill on the EXPECTED-stop path: start a mark job, then mid-burn POST /controller/stop (the supervisor stops the controller: SIGTERM, reap, exit safing). PASS: emission @@ -414,6 +423,71 @@ def drill_ircut(g): return samples +# Power ladder for `pthresh`, in percent of full duty. The spacing is fine +# at the bottom because that is where the tube stops striking. +PTHRESH_PCT = (2, 3, 4, 5, 6, 8, 10, 12, 14, 16, 20, 25, 30) +PTHRESH_LEN = 25.0 # mm of burn per rung +PTHRESH_PITCH = 3.0 # mm between rungs + + +def drill_pthresh(g): + smax = int(sys.argv[2]) if len(sys.argv) > 2 else 1000 + feed = int(sys.argv[3]) if len(sys.argv) > 3 else 300 + levels = [(p, max(1, int(round(smax * p / 100.0)))) for p in PTHRESH_PCT] + print('=== laser power threshold ladder: %d rungs, F%d, %g mm each ===' + % (len(levels), feed, PTHRESH_LEN)) + print('constant power (M3): the commanded duty is the tested duty.') + print('PRECONDITION: $35 must be 0 for this run. A floor already in') + print('place lifts every rung and the threshold cannot be read.') + print('rungs (drawn in order, alternating direction, +Y between):') + for i, (pct, s) in enumerate(levels): + print(' %2d: %2d%% -> S%d' % (i + 1, pct, s)) + print('connect: %s' % prepare(g)) + base = sample_forgectrl() + print('pre-fire: %s' % base) + arm_cue() + print('>>> This ladder reaches %d%% of full power - use scrap you are' + % PTHRESH_PCT[-1]) + print('>>> willing to cut through.\n') + job = ['G91', 'G21', 'M3'] + for i, (_pct, s) in enumerate(levels): + job.append('S%d' % s) + job.append('G1 X%g F%d' % (PTHRESH_LEN if i % 2 == 0 else -PTHRESH_LEN, + feed)) + job.append('G0 Y%g' % PTHRESH_PITCH) + job += ['M5', 'G90', 'M2'] + samples = run_and_sample(g, job, overall_timeout=600) + hv_vals = [s['hv'] for s in samples if s['hv'] is not None] + emis = [s['emission'] for s in samples if s['emission'] is not None] + print('\n--- results ---') + print('samples: %d emission peak=%s' % (len(samples), + max(emis) if emis else '-')) + print('hv_current range: %s..%s' % (min(hv_vals) if hv_vals else '-', + max(hv_vals) if hv_vals else '-')) + if samples: + t0 = samples[0]['t'] + print('hv_current trace (t s : raw) - the discharge current is the') + print('electrical witness of striking; it lifts off baseline at the') + print('same rung the material starts marking:') + line = [] + for s in samples: + if s['hv'] is None: + continue + line.append('%5.1f:%s' % (s['t'] - t0, s['hv'])) + if len(line) == 8: + print(' ' + ' '.join(line)) + line = [] + if line: + print(' ' + ' '.join(line)) + print('\nRead the material: count rungs from the FIRST one drawn. The') + print('lowest rung that leaves any mark is the striking threshold; set') + print('$35 to that rung\'s percent (round up to the next rung for') + print('margin). Note the emission counter proves the safety chain') + print('asserted LASER_ON, not that the tube lased - only the mark and') + print('the discharge current say that.') + return samples + + def post_ctrl(action): # http.client preserves the header-name case exactly as given. import http.client @@ -499,6 +573,7 @@ def main(): drill = sys.argv[1] if len(sys.argv) > 1 else '' drills = {'witness': drill_witness, 'hold': drill_hold, 'faultpos': drill_faultpos, 'ircut': drill_ircut, + 'pthresh': drill_pthresh, 'expstop': drill_expstop, 'ctrlstart': drill_ctrlstart} if drill not in drills: print(__doc__)