diff --git a/CHANGELOG.md b/CHANGELOG.md index 1ac50901c..147bc1e05 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,7 @@ All notable changes to Bambuddy will be documented in this file. - **PyJWT CVE-2025-45768 (PYSEC-2025-183 / GHSA-65pc-fj4g-8rjx): permanently ignored in pip-audit** — Advisory is disputed by the PyJWT maintainers, with the advisory description literally noting *"this is disputed by the Supplier because the key length is chosen by the application that uses the library."* `fix_versions=[]` on the advisory confirms no PyJWT patch exists or will exist. Bambuddy is not affected: `backend/app/core/auth.py:184` auto-generates secrets via `secrets.token_urlsafe(64)` (~86 chars of entropy, far above any sane minimum) and the file-loaded path at `:177` rejects secrets shorter than 32 chars. Added a permanent `--ignore-vuln CVE-2025-45768` to `.github/workflows/security.yml` with an inline comment citing the file:line evidence so a future maintainer reviewing the ignore list sees why it's load-bearing. Also dropped the stale `--ignore-vuln CVE-2026-4539` for Pygments — Pygments has since shipped a patched version and the ignore is no longer load-bearing (verified: `pip-audit --ignore-vuln CVE-2025-45768` alone reports clean). ### Fixed +- **A backend restart mid-print no longer duplicates the job in the archive (#1485, reported by @pwostran)** — When the server running Bambuddy restarted during an active print, the running job was duplicated in the archive — and deleting the duplicate didn't help: every subsequent restart while the print was still running spawned a fresh one. Both support bundles confirmed it: `WARNING Found stale 'printing' archive 3 (age: 9:46:23), marking as cancelled and creating new archive` → `Created archive 4`. On reconnect `on_print_start` fires (Bambuddy sees the printer running) and tries to re-attach to the existing archive in `main.py`. The reliable match is by `subtask_id`; the fallback is a name match plus — and this was the bug — a **4-hour staleness heuristic**: a name-matched `printing` archive older than 4h was assumed dead, marked `cancelled`, and a new archive created. Bambu prints routinely run far longer than 4h, so a genuine long print's *live* archive was destroyed and duplicated on every restart. **Two root causes, both fixed.** **(1) Queue/scheduled archives never persisted a restart-stable `subtask_id`.** Bambuddy mints a per-job id (`project_id`/`subtask_id`/`task_id`) inside `start_print` when it sends the `project_file` command, and the printer echoes it back — but often not within the ~10s before `on_print_start` first fires, so the expected-print branch's `if subtask_id and not archive.subtask_id` write got an empty value and the archive was left with no id. A later restart then had nothing to match on and fell through to the fragile name path. Fix: `BambuMQTTClient.start_print` now records the minted id on `last_dispatch_subtask_id`, and `on_print_start` falls back to it when the printer hasn't echoed `subtask_id` yet — so every dispatched archive persists a stable id and a restart resumes it by id, age-independent. **(2) The 4-hour cutoff itself.** Replaced with a progress-aware check: when a name-matched `printing` archive is found on restart, the printer's *current* reported progress decides resume-vs-stale, not wall-clock age. Real progress (or unknown progress — printer offline) always resumes the existing archive. It is only treated as a stale leftover when the printer clearly shows a *different, freshly-started* print — under 1% progress on an archive more than 2h old, a state a real in-progress print is never in. The arbitrary 4h constant is gone. **Net effect**: a restart mid-print resumes the existing archive (`started_at`, energy, timelapse intact) instead of ever cancelling it and creating a duplicate. **Tests**: 2 new in `test_bambu_mqtt.py` (`start_print` records `last_dispatch_subtask_id`, and updates it per submission); new `TestStaleVsResume` in `test_subtask_archive_resume.py` — 6 cases pinning the progress-aware decision (long print mid-run resumes; barely-started long print resumes; ~0% + old archive is stale; ~0% + young archive resumes; unknown progress never cancels; the sub-1%/2h boundary). 472 print-start / MQTT / scheduler / dispatch tests green; backend ruff clean. - **File Manager no longer polls the printer over FTPS every 30 seconds while open (#1480, reported by @OscarsWorldTech)** — The reporter's P1S churned through MQTT disconnect/reconnect cycles and timelapse downloads silently failed. The support bundle showed the real picture: during the churn windows, MQTT (`Connection stale - no message for 60.2s`), FTPS (`_ssl.c:1015: The handshake operation timed out`) and the camera all timed out *together* and recovered together — the P1S's embedded controller saturating, not a network fault (wifi -44 dBm, Docker host networking). A visible contributor on Bambuddy's side: `FileManagerModal.tsx` ran its `getPrinterFiles` query with `refetchInterval: 30000`, so every 30 s while the File Manager modal sat open it opened a *fresh* FTPS connection — full TLS handshake — to re-list the current directory. A printer's file list doesn't change on its own; it only changes on upload / delete (the modal's mutations already `invalidateQueries`) or when a print finishes. The blind 30 s poll was pure load, and on a fragile controller like the P1S it was enough to tip MQTT and FTP into the timeouts above. **Fix**: the `refetchInterval` is removed. The listing still refreshes on modal open, on directory / tab change (the path is in the query key), after every upload / delete, and via the existing manual Refresh button — so nothing stops updating, the printer just isn't hammered. Reduces steady-state FTPS connection load while the modal is open from one handshake every 30 s to zero. 19 FileManagerModal tests green; frontend build clean. - **STL thumbnail generation failures now log a full traceback** — Surfaced by the #1480 support bundle: every STL in the reporter's library failed thumbnail generation with `unsupported operand type(s) for /: 'str' and 'str'`, but `generate_stl_thumbnail`'s `except` handler logged only the bare exception message — no traceback, no line number. The fault could not be reproduced from a clean STL across path shapes (`#` and spaces in the path), `str` vs `Path` arguments, or large meshes that exercise `simplify_quadric_decimation`, so it is data- or environment-specific and the message alone is not enough to locate it. `stl_thumbnail.py` now passes `exc_info=True` on that warning, so the next support bundle carries the traceback and the exact failing line. No behaviour change to thumbnail generation itself. - **Slicer: the Process / Filament dropdowns now filter by printer using the uploaded Slicer Bundles instead of guessing from preset names (#1325, reported by @IndividualGhost1905)** — After the printer-preset pre-selection landed, the reporter found the Process Profile dropdown still showed a flat mix of `@BBL X1C` and `@BBL P2S` presets with the printer set to X1C — P2S presets that should have dropped into the trailing "Other printers" group sat in the main list. **Root cause**: `frontend/src/utils/slicerPrinterMatch.ts` resolved each cloud / standard preset's printer by parsing the `@BBL ` suffix of its name against a hard-coded `KNOWN_MODEL_CODES` allow-list. That list (`X1C, X1E, X1, P1S, P1P, A1M, A1, H2D, H2S`) was missing `P2S` (and `H2C`, `X2D`), so every `@BBL P2S` preset parsed to an empty model-code set, `presetCompatibility` returned `unknown`, and the dropdown keeps `unknown` presets in the main list (only `mismatch` moves to "Other printers"). It was a maintenance trap by construction: every new Bambu model silently broke filtering until someone edited the list. **Fix**: the name-suffix heuristic and both hard-coded model tables (`KNOWN_MODEL_CODES`, `PRINTER_NAME_PATTERNS`) are removed. Compatibility is now read from ground truth — the user's uploaded Slicer Bundles (`.bbscfg`). Each bundle is scoped to one printer and lists the process / filament presets it ships, so "process P works with printer X" holds exactly when some uploaded bundle for printer X contains P. `buildCompatibilityIndex` builds a `presetName → {printer names}` index per slot from `GET /slicer/bundles` (already fetched by the modal), and `presetCompatibility` consults it — still preferring an imported preset's own `compatible_printers` list when present. A newly released Bambu model is covered the moment its bundle is uploaded, with no code change. Presets no bundle covers stay in the main list (`unknown` is never hidden), so a user with no bundle imported sees the un-filtered list rather than a wrong one. `printerPresetCode` / `presetModelCodes` are gone; `SliceModal` passes the bundle-derived index to `PresetDropdown`, `pickProcessDefault`, and `pickFilamentForSlot` in place of the old model code. **Tests**: `slicerPrinterMatch.test.ts` rewritten — 12 tests covering `buildCompatibilityIndex` (per-printer mapping, multi-bundle union, `# ` user-clone-prefix stripping, empty-printer skip) and `presetCompatibility` (imported-tier `compatible_printers` exact match, bundle-driven match / mismatch / unknown, the #1325 P2S-into-X1C repro, no-bundles and no-printer-selected cases). 32 SliceModal tests green; frontend build clean; backend ruff clean. diff --git a/backend/app/main.py b/backend/app/main.py index 53d76d9fa..170354dfc 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -2039,8 +2039,23 @@ async def on_print_start(printer_id: int, data: dict): # Update archive status to printing archive.status = "printing" archive.started_at = datetime.now(timezone.utc) - if subtask_id and not archive.subtask_id: - archive.subtask_id = subtask_id + # Persist a restart-stable id so a later restart resumes this + # archive by subtask_id instead of name-matching + duplicating + # it (#1485). The printer often hasn't echoed subtask_id back + # this soon after dispatch, so fall back to the id Bambuddy + # minted when it sent the print command. Scoped to this + # expected-print branch on purpose: an expected match means + # Bambuddy dispatched this exact print in this process, so the + # client's last-dispatch id genuinely belongs to it — using it + # for an externally-started print could mis-tag the archive. + effective_subtask_id = subtask_id + if not effective_subtask_id: + _client = printer_manager.get_client(printer_id) + _dispatched = getattr(_client, "last_dispatch_subtask_id", None) if _client else None + if _dispatched: + effective_subtask_id = str(_dispatched).strip() or None + if effective_subtask_id and not archive.subtask_id: + archive.subtask_id = effective_subtask_id # #1403 follow-up: VP-queue archives are created with # printer_id=None at queue-add time (we don't know which # printer will run the job yet). When the print actually @@ -2208,18 +2223,31 @@ async def on_print_start(printer_id: int, data: dict): _load_objects_from_archive(existing_archive, printer_id, logger) return - # Name-match only: fall back to the legacy 4h staleness heuristic. + # Name-match only (no subtask_id to anchor on): decide resume vs. + # stale from the printer's *current* progress, not wall-clock age. + # A genuinely long print used to trip a blind 4h cutoff and have its + # live archive cancelled + duplicated on every backend restart + # (#1485). If the printer reports real progress, this name-matched + # 'printing' archive IS that ongoing print — resume it whatever its + # age. Only treat it as a stale leftover when the printer clearly + # shows a different, freshly-started print: near-0% progress on an + # archive far too old to still be at 0%. Unknown progress (printer + # not connected) never cancels — resuming is the safe default. archive_age = datetime.now(timezone.utc) - existing_archive.created_at.replace(tzinfo=timezone.utc) - if archive_age.total_seconds() > 4 * 60 * 60: # 4 hours + live_status = printer_manager.get_status(printer_id) + live_progress = getattr(live_status, "progress", None) if live_status else None + looks_stale = ( + live_progress is not None and live_progress < 1.0 and archive_age.total_seconds() > 2 * 60 * 60 + ) + if looks_stale: logger.warning( - f"Found stale 'printing' archive {existing_archive.id} (age: {archive_age}), " - f"marking as cancelled and creating new archive" + f"Found stale 'printing' archive {existing_archive.id} (age: {archive_age}, " + f"printer progress {live_progress:.0f}%) — marking cancelled and creating new archive" ) existing_archive.status = "cancelled" existing_archive.failure_reason = "Stale - print likely cancelled or failed without status update" await db.commit() # Fall through to create new archive (don't return) - _existing_archive = None # Clear so we don't use stale archive else: logger.info( f"Skipping duplicate - already have printing archive {existing_archive.id} for {check_name}" diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index a81e36e22..8bfe13b04 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -362,6 +362,12 @@ class BambuMQTTClient: self._timelapse_during_print: bool = False # Track if timelapse was active during this print self._last_valid_progress: float = 0.0 # Last non-zero progress (firmware resets on cancel) self._last_valid_layer_num: int = 0 # Last non-zero layer (firmware resets on cancel) + # The subtask_id minted for the most recent start_print() command. The + # printer echoes it back in status, but often not within the first few + # seconds — so on_print_start uses this as the id source when the + # printer hasn't reported it yet, letting queue/scheduled archives + # persist a restart-stable id from the moment they dispatch (#1485). + self.last_dispatch_subtask_id: str | None = None self._is_dual_nozzle: bool = False # Set when device.extruder.info has >= 2 entries self._message_log: deque[MQTTLogEntry] = deque(maxlen=100) self._logging_enabled: bool = False @@ -3358,6 +3364,9 @@ class BambuMQTTClient: # Modulo keeps uniqueness within a ~24-day wrap window; `or 1` guards # the (astronomically unlikely) zero case since task_id=0 is rejected. submission_id = str(int(time.time() * 1000) % 2_147_483_647 or 1) + # Remember it so on_print_start can persist a restart-stable id on + # the archive even before the printer echoes subtask_id back (#1485). + self.last_dispatch_subtask_id = submission_id command = { "print": { diff --git a/backend/tests/unit/services/test_bambu_mqtt.py b/backend/tests/unit/services/test_bambu_mqtt.py index d9082696b..0e2b07507 100644 --- a/backend/tests/unit/services/test_bambu_mqtt.py +++ b/backend/tests/unit/services/test_bambu_mqtt.py @@ -3906,6 +3906,24 @@ class TestStartPrintUniqueIdentityFields: assert int(cmd["task_id"]) > 0 assert len(cmd["task_id"]) <= 64 + def test_last_dispatch_subtask_id_records_the_minted_id(self, mqtt_client): + """#1485: start_print records the minted id on the client so + on_print_start can persist it on the archive before the printer + echoes subtask_id back — letting a later restart resume by id.""" + assert mqtt_client.last_dispatch_subtask_id is None + mqtt_client.start_print("test.3mf") + cmd = self._get_published_command(mqtt_client) + assert mqtt_client.last_dispatch_subtask_id == cmd["subtask_id"] + + def test_last_dispatch_subtask_id_updates_per_submission(self, mqtt_client): + """Each dispatch overwrites the recorded id with the new submission's.""" + mqtt_client.start_print("test.3mf") + first = mqtt_client.last_dispatch_subtask_id + time.sleep(0.002) + mqtt_client.start_print("test.3mf") + assert mqtt_client.last_dispatch_subtask_id != first + assert mqtt_client.last_dispatch_subtask_id == self._get_published_command(mqtt_client)["subtask_id"] + def test_submission_id_fits_signed_int32(self, mqtt_client): """Regression for #1042: P1S firmware clamps oversized task identity fields to signed int32 max (2**31-1 = 2147483647). If we send raw diff --git a/backend/tests/unit/test_subtask_archive_resume.py b/backend/tests/unit/test_subtask_archive_resume.py index 887d5ff73..90f7b8a77 100644 --- a/backend/tests/unit/test_subtask_archive_resume.py +++ b/backend/tests/unit/test_subtask_archive_resume.py @@ -10,7 +10,12 @@ for a print that actually ran 13h08m. The fix stores `subtask_id` (MQTT-provided job identifier) on the archive row. On print-start detection, the handler first tries to match an existing archive by subtask_id regardless of age — same id ⇒ same print ⇒ resume. -Only unmatched prints fall through to the legacy 4h staleness heuristic. +Only unmatched prints fall through to the name-based fallback. + +#1485 follow-up: the name-based fallback no longer cancels on a blind 4h +age cutoff (which duplicated the archive of any genuinely long print on +every restart). It now decides resume-vs-stale from the printer's current +progress — see TestStaleVsResume. """ from datetime import datetime, timedelta, timezone @@ -183,3 +188,48 @@ class TestSubtaskIdResume: ) found = result.scalar_one_or_none() assert found is None + + +def _looks_stale(live_progress: float | None, archive_age_seconds: float) -> bool: + """Mirrors the name-fallback stale decision in main.on_print_start (#1485). + + A name-matched 'printing' archive is treated as a stale leftover ONLY when + the printer clearly shows a different, freshly-started print: near-0% + progress on an archive far too old to still be at 0%. Real progress, or + unknown progress (printer not connected), always resumes — the old blind + 4h age cutoff cancelled the live archive of every long print on restart. + """ + return live_progress is not None and live_progress < 1.0 and archive_age_seconds > 2 * 60 * 60 + + +class TestStaleVsResume: + """The progress-aware replacement for the 4h staleness heuristic (#1485).""" + + def test_long_print_in_progress_resumes_not_stale(self): + """The reporter's case: a ~10h print, backend restarts, printer is + mid-print at 60%. The old 4h cutoff cancelled + duplicated it; it + must now resume regardless of age.""" + assert _looks_stale(60.0, archive_age_seconds=10 * 3600) is False + + def test_barely_started_long_print_resumes(self): + """A genuine print a few percent in is still the same print.""" + assert _looks_stale(3.0, archive_age_seconds=5 * 3600) is False + + def test_fresh_print_with_old_archive_is_stale(self): + """Printer reports a just-started print (~0%) but the matched archive + is hours old — that archive is a dead leftover from a previous run.""" + assert _looks_stale(0.0, archive_age_seconds=9 * 3600) is True + + def test_fresh_print_with_young_archive_resumes(self): + """~0% progress on a young archive is just the same print still + heating / leveling — not stale.""" + assert _looks_stale(0.0, archive_age_seconds=20 * 60) is False + + def test_unknown_progress_never_cancels(self): + """Printer not connected / progress unknown: resuming is the safe + default — never cancel + duplicate when we can't tell.""" + assert _looks_stale(None, archive_age_seconds=10 * 3600) is False + + def test_sub_one_percent_old_archive_is_stale(self): + """The boundary: just under 1% past the 2h mark counts as stale.""" + assert _looks_stale(0.5, archive_age_seconds=3 * 3600) is True