From 0ca7618c850371c0120264c77dc75ae600b4e3ca Mon Sep 17 00:00:00 2001 From: viewit Date: Sun, 26 Jul 2026 23:29:32 +0200 Subject: [PATCH] fix(moonraker): metadata state-leak + terminal-state reset gaps (Issue #102) Three related gaps found via careful moonraker-obico observation: 1. _build_file_metadata() read layer_height/total_layers/estimated_time from live self._state before falling back to the queried file's own GCodeStore row - so querying metadata for any file other than the currently/last tracked job leaked that job's values into the response. Live state is now only used when the query targets that same tracked file; any other filename relies solely on its own stored row. 2. curr_layer/total_layers were never reset at print end in either _on_print or _on_info - only explicitly overwritten if a later payload happened to carry those keys, otherwise stuck indefinitely. Additionally, a successful "finished" print only ever cleared file_ready (Issue #29's fix), while stoped/canceled reset every other per-job field (progress, filename, duration, ...) - finished now gets the same full reset. Found and fixed a knock-on bug this surfaced: the unconditional `self._state["filename"] = d.get(...)` right after the reset block would immediately undo the filename reset, since the printer's own finished/stoped/canceled payload still carries the just-ended job's filename - now only applied outside terminal states. 3. The printer's own "progress" during pre-print phases (auto_leveling/ preheating/checking/updated/init) was forwarded as-is to virtual_sdcard.progress/display_status.progress, causing a non-monotonic jump-then-reset once real printing began. These phases no longer update the tracked progress value. Reported by @fmontagna, who correctly identified all three as genuine gaps rather than intentional behavior. --- NIGHTLY_CHANGELOG.md | 3 + kobrax_moonraker_bridge.py | 49 ++++-- tests/test_metadata_and_print_state_reset.py | 151 +++++++++++++++++++ 3 files changed, 190 insertions(+), 13 deletions(-) create mode 100644 tests/test_metadata_and_print_state_reset.py diff --git a/NIGHTLY_CHANGELOG.md b/NIGHTLY_CHANGELOG.md index 12b7a39..9bebc9d 100644 --- a/NIGHTLY_CHANGELOG.md +++ b/NIGHTLY_CHANGELOG.md @@ -7,3 +7,6 @@ - Fix: **the camera stream could hang forever after a printer reboot** — the printer rotates its stream token on reboot, but the running ffmpeg processes kept reading from the stale, now-silent connection and never noticed. The bridge now detects the URL change and automatically restarts the camera pipeline, ffmpeg itself now times out on a stalled read as a second line of defense, and `/api/camera/stream` now returns a proper 503 instead of hanging if no frame arrives within 5s (Issue #99, thanks @fmontagna for the excellent root-cause analysis and reproduction) - Fix: shrinking the Progress dashboard tile below its default height clipped the lower content (time grid, filename, buttons) out of view instead of scaling with it; dashboard tiles in general could show a scrollbar even when there was nothing to scroll. Both fixed (Issue #97, thanks @Blaim) - Feat: custom ACE-RFID filament tags (e.g. written via the "ACE RFID" app for third-party spools) are now matched automatically against your imported OrcaSlicer profiles. Anycubic's ACE RFID system concatenates vendor + material + a truncated serial into one type string (e.g. "GEEETECH PLA Bas") for custom tags — the bridge now recognizes the vendor prefix and resolves it to your already-imported profile instead of falling back to a generic default, so no manual per-slot reassignment is needed anymore (Issue #101, thanks @Blaim) +- Fix: `server/files/metadata` could leak the currently/last tracked print job's layer count and estimated time into a query for a *different* file, since those values were read from live state before falling back to the queried file's own stored metadata. Now only the currently-tracked file's own query uses live state — any other filename relies solely on its own record (Issue #102, thanks @fmontagna) +- Fix: `curr_layer`/`total_layers` (and, after a successful print, every other per-job field — progress, filename, duration, etc.) were never reset when a print finished normally, only on stop/cancel — they stayed at the last job's values until the next print happened to overwrite them (Issue #102, thanks @fmontagna) +- Fix: the printer's own progress value during pre-print phases (auto-leveling/preheating/bed-checking) was passed straight through to `virtual_sdcard.progress`/`display_status.progress`, causing it to jump non-monotonically once real printing started and progress reset. Pre-print progress is no longer forwarded (Issue #102, thanks @fmontagna) diff --git a/kobrax_moonraker_bridge.py b/kobrax_moonraker_bridge.py index 0f2d081..5dc5dfd 100644 --- a/kobrax_moonraker_bridge.py +++ b/kobrax_moonraker_bridge.py @@ -1394,12 +1394,12 @@ class KobraXBridge: self._spoolman_notify_end() self._current_job_id = "" - # Hide the upload banner after the print finishes (Issue #29): the - # printer reports "finished" after a successful print - file_ready used to be - # cleared only on stoped/canceled, which brought the banner back. - if kobra_state == "finished": - self._state["file_ready"] = "" - if kobra_state in ("stoped", "canceled"): + # Terminal states (successful finish AND stop/cancel) must leave the + # same clean end state - a "finished" print used to only clear + # file_ready (Issue #29), leaving progress/filename/duration/layer + # fields stuck at the last job's values until the *next* print + # happened to overwrite them (Issue #102). + if kobra_state in ("finished", "stoped", "canceled"): self._state["progress"] = 0.0 self._state["filename"] = "" self._state["file_ready"] = "" @@ -1409,9 +1409,20 @@ class KobraXBridge: self._state["layer_height"] = 0.0 self._state["first_layer_height"] = 0.0 self._state["supplies_usage"] = 0 + self._state["curr_layer"] = 0 + self._state["total_layers"] = 0 self._thumbnail_b64 = "" - self._state["filename"] = d.get("filename", self._state["filename"]) - if "progress" in d: + else: + # Only adopt the payload's filename outside terminal states - the + # printer often still reports the just-finished job's filename in + # the same "finished"/"stoped"/"canceled" message that triggered + # the reset above, which would otherwise immediately undo it. + self._state["filename"] = d.get("filename", self._state["filename"]) + # Pre-print phases (leveling/preheating/checking) report their own + # "progress" - passing it through would make display_status.progress/ + # virtual_sdcard.progress jump non-monotonically once real printing + # starts and the value resets (Issue #102). + if "progress" in d and kobra_state not in ("preheating", "auto_leveling", "checking", "updated", "init"): self._state["progress"] = float(d["progress"]) / 100.0 if "print_time" in d: self._state["print_duration"] = int(d["print_time"]) * 60 @@ -1447,8 +1458,13 @@ class KobraXBridge: self._state["kobra_state"] = kobra_state # Hide the upload banner after the print ends (Issue #29) - the state also # arrives via info/report (project.state) depending on the printer, not only print/report. + # Layer fields must reset here too (Issue #102) - info/report is the + # only source for curr_layer/total_layers on some printers, and they + # otherwise stay stuck at the last job's values indefinitely. if kobra_state in ("finished", "stoped", "canceled"): self._state["file_ready"] = "" + self._state["curr_layer"] = 0 + self._state["total_layers"] = 0 # Camera auto-start here as well (OrcaSlicer often reports the start via info/report). # The _camera_autostarted guard prevents a double start with _on_print. if kobra_state == "printing": @@ -1467,7 +1483,8 @@ class KobraXBridge: if project: if "filename" in project: self._state["filename"] = project["filename"] - if "progress" in project: + # Same non-monotonic-progress guard as _on_print (Issue #102). + if "progress" in project and kobra_state not in ("preheating", "auto_leveling", "checking", "updated", "init"): self._state["progress"] = float(project["progress"]) / 100.0 if "print_time" in project: self._state["print_duration"] = int(project["print_time"]) * 60 @@ -3405,10 +3422,16 @@ class KobraXBridge: `modified` are non-nullable in GCodeFile; `print_start_time` and the Slicer-Felder optional.""" s = self._state - layer_h = float(s.get("layer_height") or 0.0) - first_h = float(s.get("first_layer_height") or 0.0) - total_layers = int(s.get("total_layers") or 0) - est_time = int(s.get("slicer_time") or 0) + # Live _state values are only relevant for the currently/last tracked + # job's own file - using them as a starting point for a DIFFERENT + # filename leaked the tracked job's layer count/time into unrelated + # metadata queries (Issue #102). For any other filename, rely solely + # on that file's own GCodeStore row. + is_tracked_file = bool(filename) and filename == s.get("filename") + layer_h = float(s.get("layer_height") or 0.0) if is_tracked_file else 0.0 + first_h = float(s.get("first_layer_height") or 0.0) if is_tracked_file else 0.0 + total_layers = int(s.get("total_layers") or 0) if is_tracked_file else 0 + est_time = int(s.get("slicer_time") or 0) if is_tracked_file else 0 size_bytes = 0 try: gf = self._store.get_file_by_name(filename) or {} diff --git a/tests/test_metadata_and_print_state_reset.py b/tests/test_metadata_and_print_state_reset.py new file mode 100644 index 0000000..7a9b70d --- /dev/null +++ b/tests/test_metadata_and_print_state_reset.py @@ -0,0 +1,151 @@ +"""server/files/metadata state-leak + terminal-state reset gaps (Issue #102). + +Reported by @fmontagna via moonraker-obico: +1. Querying metadata for a file OTHER than the currently/last tracked job + leaked that job's live layer count / estimated time into the response, + because _build_file_metadata() read from self._state first and only fell + back to the file's own GCodeStore row when the state value was falsy. +2. curr_layer/total_layers (and, for a successful "finished" print, every + other per-job field) were never reset at print end - they stayed at the + last job's values until the next print happened to overwrite them. +3. The printer reports its own "progress" during pre-print phases + (preheating/auto_leveling/checking/...), which used to pass straight + through to display_status.progress/virtual_sdcard.progress and then jump + non-monotonically once real printing started and progress reset. +""" +import argparse +import tempfile +from unittest.mock import MagicMock + +from kobrax_moonraker_bridge import KobraXBridge + + +def _bridge(): + c = MagicMock(); c.callbacks = {}; c.connected = False + args = argparse.Namespace( + printer_ip="", mqtt_port=9883, username="", password="", + mode_id="20030", device_id="", host="127.0.0.1", port=7125, + data_dir=tempfile.mkdtemp(prefix="kxmeta-"), + ) + return KobraXBridge(c, args=args) + + +def _insert_store_row(b, filename, layer_count=None, est_time=None, size_bytes=0): + with b._store._lock: + b._store._conn.execute( + "INSERT OR REPLACE INTO gcode_files (id, filename, path, size_bytes, uploaded_at, layer_count, est_print_time_sec) " + "VALUES (?,?,?,?,?,?,?)", + (filename, filename, "/tmp/" + filename, size_bytes, "2026-01-01T00:00:00Z", layer_count, est_time), + ) + b._store._conn.commit() + + +# --- Fix 1: metadata state-leak ------------------------------------------- + +def test_metadata_for_untracked_file_does_not_leak_running_job_state(): + b = _bridge() + # A job is "running": live state has its own layer/time values. + b._state["filename"] = "running.gcode" + b._state["total_layers"] = 999 + b._state["slicer_time"] = 12345 + b._state["layer_height"] = 0.3 + + # Querying a DIFFERENT, unrelated file must use ITS OWN store row, not + # the running job's live state. + _insert_store_row(b, "other.gcode", layer_count=42, est_time=600, size_bytes=1000) + meta = b._build_file_metadata("other.gcode") + assert meta["layer_count"] == 42 + assert meta["estimated_time"] == 600 + assert meta["size"] == 1000 + + +def test_metadata_for_tracked_file_still_uses_live_state(): + """The currently-tracked file's OWN metadata query should still prefer + live state (fresher than what was known at upload time).""" + b = _bridge() + b._state["filename"] = "running.gcode" + b._state["total_layers"] = 55 + b._state["slicer_time"] = 999 + _insert_store_row(b, "running.gcode", layer_count=1, est_time=1) + meta = b._build_file_metadata("running.gcode") + assert meta["layer_count"] == 55 + assert meta["estimated_time"] == 999 + + +def test_metadata_for_nonexistent_file_falls_back_cleanly(): + b = _bridge() + b._state["filename"] = "running.gcode" + b._state["total_layers"] = 999 + meta = b._build_file_metadata("DOES_NOT_EXIST.gcode") + assert meta["layer_count"] is None + assert meta["size"] == 1 # documented fallback, unrelated to this fix + + +# --- Fix 2: terminal-state reset ------------------------------------------- + +def _print_payload(state, **extra): + """print/report envelope: `state` is top-level, everything else is under + `data` (see _on_print: kobra_state = payload.get("state", "")). """ + d = {"filename": "job.gcode"} + d.update(extra) + return {"state": state, "data": d} + + +def test_finished_resets_layer_fields_like_stoped_canceled(): + b = _bridge() + b._state["curr_layer"] = 10 + b._state["total_layers"] = 20 + b._state["progress"] = 0.5 + b._state["filename"] = "job.gcode" + b._on_print(_print_payload("finished")) + assert b._state["curr_layer"] == 0 + assert b._state["total_layers"] == 0 + assert b._state["progress"] == 0.0 + assert b._state["filename"] == "" + + +def test_canceled_resets_layer_fields(): + b = _bridge() + b._state["curr_layer"] = 7 + b._state["total_layers"] = 20 + b._on_print(_print_payload("canceled")) + assert b._state["curr_layer"] == 0 + assert b._state["total_layers"] == 0 + + +def test_on_info_resets_layer_fields_on_terminal_state(): + b = _bridge() + b._state["curr_layer"] = 7 + b._state["total_layers"] = 20 + b._on_info({"data": {"project": {"state": "finished"}}}) + assert b._state["curr_layer"] == 0 + assert b._state["total_layers"] == 0 + + +# --- Fix 3: progress clamping during pre-print phases ---------------------- + +def test_progress_not_updated_during_auto_leveling(): + b = _bridge() + b._state["progress"] = 0.0 + b._on_print(_print_payload("auto_leveling", progress=87)) + assert b._state["progress"] == 0.0 + + +def test_progress_not_updated_during_preheating(): + b = _bridge() + b._state["progress"] = 0.0 + b._on_print(_print_payload("preheating", progress=42)) + assert b._state["progress"] == 0.0 + + +def test_progress_updates_normally_once_printing(): + b = _bridge() + b._on_print(_print_payload("printing", progress=33)) + assert b._state["progress"] == 0.33 + + +def test_on_info_progress_clamped_during_checking(): + b = _bridge() + b._state["progress"] = 0.0 + b._on_info({"data": {"project": {"state": "checking", "progress": 55}}}) + assert b._state["progress"] == 0.0