From be7e85344c1ed06618cf78676c95d3d191567007 Mon Sep 17 00:00:00 2001 From: maziggy Date: Sat, 13 Jun 2026 13:28:58 +0200 Subject: [PATCH] fix(finish-photo): drive capture from stg_cur=22, drop dispatch force-on (#1721) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit capture_finish_photo (default-on) was forcing the timelapse MQTT field to true on every print, even when the user explicitly unchecked Timelapse in the slicer send dialog. On profiles with Timelapse Type = Smooth, that flipped the printer's timelapse_record_flag and un-gated the per-layer M622 J1 wipe blocks the slicer had baked in — toolhead parked off the part every layer, on prints the user opted out of recording. Root cause: #1397 implemented the finish-photo feature as a side channel of "force the printer into timelapse-recording mode at dispatch" so the last-frame extractor had a video to pull from. That conflated recording a timelapse with snapping a finish photo, and the per-layer side effects were decided at slice time by the user's timelapse_type, which Bambuddy has no visibility into post-slice. Fix: replace the force-on with a clean MQTT-state-driven trigger. bambu_mqtt.py fires a new on_finish_photo_moment callback when stg_cur transitions INTO 22 ("Filament unloading") while _was_running AND end-of-print gate matches (progress >= 99 OR layer_num >= total_layers OR remaining_time <= 0). The gate disambiguates from mid-print color swaps (which also transit stage 22 but at progress < 99). FINISH-state fallback in the same handler fires the callback at the existing transition if stage 22 never arrived (cancel, external-spool-only, HMS halt, firmware variants). main.py registers on_finish_photo_moment as a top-level handler. It pre-captures one camera frame at the trigger edge (external cam → buffered RTSP → fresh RTSP via capture_camera_frame_bytes) and caches the JPEG bytes in _stage22_finish_frames[printer_id]. _background_finish_photo consumes the cached bytes before its existing live-grab chain, so the saved photo has the better framing (toolhead parked, before bed drop) without restructuring the archive-resolution / fallback / notification wiring. When a timelapse IS actively recording (user explicitly opted in), pre-capture is skipped — _capture_finish_photo_from_timelapse still extracts the last frame, which is still the best framing and now has no force-on side effects because the user wanted the video. Removed: resolve_effective_timelapse, _resolve_effective_timelapse wrapper, both background_dispatch call sites, the print_scheduler call site, the archive.bambuddy_forced_timelapse write, _cleanup_forced_timelapse (~75 lines including the FTP-DELE walk across /timelapse, /timelapse/video, /record, /recording) and its call site. All paths now read bool(item.timelapse) / bool(job.options.get("timelapse", False)) directly. The archive.bambuddy_forced_timelapse DB column stays defined (default False) for back-compat with existing rows — no consumer reads it anymore. --- CHANGELOG.md | 1 + backend/app/main.py | 258 +++++++++------- backend/app/services/background_dispatch.py | 52 +--- backend/app/services/bambu_mqtt.py | 76 ++++- backend/app/services/print_scheduler.py | 22 +- backend/app/services/printer_manager.py | 19 ++ .../unit/services/test_background_dispatch.py | 10 +- .../test_background_dispatch_watchdog.py | 16 - .../services/test_dispatch_force_timelapse.py | 156 ---------- .../unit/test_cleanup_forced_timelapse.py | 291 ------------------ .../test_scheduler_force_timelapse_wiring.py | 71 ----- 11 files changed, 260 insertions(+), 712 deletions(-) delete mode 100644 backend/tests/unit/services/test_dispatch_force_timelapse.py delete mode 100644 backend/tests/unit/test_cleanup_forced_timelapse.py delete mode 100644 backend/tests/unit/test_scheduler_force_timelapse_wiring.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 9d81aa39f..8c8533aad 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes to Bambuddy will be documented in this file. ## [0.2.5b1] - Unreleased ### Fixed +- **Finish-photo force-on removed; user's explicit timelapse=off in the slicer send dialog is now respected (#1721, reported by @agrisci)** — On H2D 01.x firmware, `capture_finish_photo` (default-on global setting) was forcing every print's `timelapse` MQTT field to `enable` regardless of whether the user had unchecked the Timelapse box in OrcaSlicer's send dialog. That bit flips the printer's runtime `timelapse_record_flag`, which un-gates the slicer-baked `M1002 judge_flag timelapse_record_flag` / `M622 J1` / `G1 X-48.2 F3000` / `M971 S11 C11 O0` wipe blocks emitted by **Smooth**-mode timelapse profiles — so the toolhead parked off the part and snapped a frame every single layer, on prints the user explicitly opted out of recording. The reporter's gcode export confirmed the macro block was baked in (28 occurrences across the file) and the printer's MQTT log showed `Sending print command: {"print": { … "timelapse": true, … }}` even though the slicer-side checkbox was unchecked. Live-stop confirmed: turning the global `capture_finish_photo` setting off in Bambuddy made the per-layer parking stop immediately. **Root cause:** the #1397 "finish photo from timelapse" feature used "force the printer into timelapse-recording mode at dispatch" as the side-channel to get a well-framed end-of-print shot (toolhead parked, before bed drop, extracted from the recorded video's last frame). That mechanism conflated two semantically different things — recording a timelapse video vs. snapping a finish photo — and the per-layer side effects of the recording mode were decided at slice time by the user's `timelapse_type` profile setting, which Bambuddy has no visibility into post-slice. Traditional-mode gcode has no per-layer wipe block (no parking, no defects) — so the bug was invisible to anyone whose slicer profile defaults to Traditional. Smooth-mode gcode (the reporter's case) bakes the wipe block and gates it on `timelapse_record_flag`, so flipping the runtime flag fired the macro every layer. **Fix:** replaced the force-on mechanism entirely with a clean MQTT-state-driven trigger. `bambu_mqtt.py::_handle_push_status` now fires a new `on_finish_photo_moment` callback when `stg_cur` transitions INTO **22** ("Filament unloading") while `_was_running == True` AND the end-of-print gate matches (`progress >= 99` OR `layer_num >= total_layers` OR `remaining_time <= 0`) — that's the same framing window #1397 was after (toolhead parked, bed not yet dropped, AMS pulling filament back) but reached via a clean state signal instead of by exploiting the per-layer macros. The end-of-print gate is what disambiguates from mid-print filament swaps in multi-color prints, which ALSO transit through stage 22 (M620 unload → 22, M621 load → 24) but always at progress < 99 / layer < total / remaining > 0. A FINISH-state fallback in the same handler fires the same callback at the existing FINISH-state transition if stage 22 never arrived — covers cancel-mid-print (state goes RUNNING → IDLE / FAILED without 22), external-spool-only prints where some firmwares skip the unload phase, HMS halts before unload, and any firmware variant we don't see stage 22 on. Net behavior: every print that gets a finish photo today still gets one; the lucky majority get the better-framed pre-bed-drop shot too. `main.py::on_finish_photo_moment` is a new top-level handler that pre-captures one camera frame at the trigger edge — external camera (snapshot URL → MJPEG fallback), buffered live RTSP frame from `_active_streams` / `_active_chamber_streams`, or a fresh RTSP grab via `capture_camera_frame_bytes` — and caches the JPEG bytes in a module-level `_stage22_finish_frames: dict[int, bytes]` keyed by printer_id. `_background_finish_photo` (inside `on_print_complete`) consumes the cached bytes via `_stage22_finish_frames.pop(printer_id, None)` before falling through to its existing live-grab chain, so the saved photo has the better framing without the existing complex archive-resolution / fallback / notification wiring needing to move. When a timelapse IS actively recording (user explicitly opted in this time), the pre-capture is skipped — `_capture_finish_photo_from_timelapse` still extracts the last frame from the recorded video, which is still the highest-quality option and now has no force-on side effects because the user actually wanted the video. **What was removed:** `resolve_effective_timelapse` in `background_dispatch.py` (the shared force-on resolver), `BackgroundDispatchService._resolve_effective_timelapse` wrapper, both call sites in `background_dispatch.py` (`_run_reprint_archive` + library-file print path), the `resolve_effective_timelapse` call in `print_scheduler.py::_dispatch_item`, the `archive.bambuddy_forced_timelapse` write in the resolver, the `if archive.bambuddy_forced_timelapse: await _cleanup_forced_timelapse(...)` branch in `_background_finish_photo`, and the entire `_cleanup_forced_timelapse` function (~75 lines including the FTP-DELE walk across `/timelapse` / `/timelapse/video` / `/record` / `/recording`). All call sites now read `bool(item.timelapse)` / `bool(job.options.get("timelapse", False))` directly — the literal user choice flows straight through to `start_print(timelapse=…)`. The `archive.bambuddy_forced_timelapse` DB column stays defined (default `False`) for back-compat with existing rows that may have it set to `True` from before — no consumer reads it anymore, and dropping a column on the user-data table risks breaking restore-from-backup flows we don't need to break. **New callback wiring:** added `on_finish_photo_moment` parameter to `BambuMQTT.__init__`, new `_finish_photo_captured` one-shot flag (reset on each new print at the same site as `_completion_triggered`), new `PrinterManager._on_finish_photo_moment` field + `set_finish_photo_moment_callback` setter, new `on_finish_photo_moment` inner wrapper in `_setup_callbacks`, threaded through to the `BambuMQTTClient` constructor call. `main.py::on_print_start` clears any leftover `_stage22_finish_frames` entry from a prior print so a never-consumed cache (e.g. capture succeeded but on_print_complete bailed before reaching it) can't bleed into the new print's photo. **Tests removed:** `test_cleanup_forced_timelapse.py` (~290 lines, 7 test cases pinning the FTP-DELE walk and `bambuddy_forced_timelapse` flag handling), `test_scheduler_force_timelapse_wiring.py` (the source-pattern check that pinned `print_scheduler.py` imports `resolve_effective_timelapse`), `test_dispatch_force_timelapse.py` (5 test cases pinning the `_resolve_effective_timelapse` wrapper's interaction with `capture_finish_photo` + archive flag). The behaviour these tests verified is intentionally gone. **Tests updated:** `test_background_dispatch_watchdog.py` dropped two `patch.object(BackgroundDispatchService, "_resolve_effective_timelapse", ...)` blocks that stubbed the now-removed method; `test_background_dispatch.py::test_dispatch_options_pass_through_pattern` comment updated to explain why `timelapse` stays excluded from the bare-pattern needle check (the wrap in `bool(...)` is intentional to coerce non-bool option payloads, not a force-on remnant). **Verification:** ruff clean; full backend suite 5961/5961 green with `-n 30`; ESLint clean; `npm run build` clean; vitest 2118/2118 green; i18n parity 5107 leaves × 11 locales green (no new keys). No migration. **What this does NOT change:** users who explicitly enable the Timelapse checkbox in the slicer send dialog still get the timelapse video AND the timelapse-extracted finish photo (highest-quality framing, no per-layer parking because that was never the issue — it's the user's intentional choice). Users who explicitly disable the Timelapse checkbox now get no per-layer parking AND still get a finish photo (pre-captured at the stage-22 edge for the same pre-bed-drop framing). - **Configure AMS Slot: filament profiles for other printer models now filtered out (#1623, reported by @shaddowlink)** — Three independent gaps in the same picker, each surfaced by a different round of reporter screenshots. **(1) Local "Custom" imported profiles** were unconditionally listed regardless of the slot's printer; a user with PETG / PLA profiles imported from OrcaSlicer / BambuStudio for A1 mini, H2D, and P1S saw all three lined up when configuring an AMS slot on any one of those printers. **(2) Cloud presets using the `@Bambu Lab ` suffix form** (user-renamed Bambu Cloud presets and most Orca Cloud profiles) slipped through the existing filter, which only matched the `@BBL ` form Bambu's system presets use. **(3) Cloud presets with the printer model in the BODY of the name** (the literal failure shape the reporter screenshotted on H2D: `"X1C eSUN PETG-Basic Filament"` with no `@` suffix at all) — the existing extractor returned null for these and the filter no-op'd. **Fix:** `ConfigureAmsSlotModal.tsx` now (a) queries the backend's Bambu printer-model registry (`/slicer/printer-models`, same fetch SliceModal uses), (b) for local presets — reverse-looks-up the slot's short model code to a long printer-preset fragment, pairs it with the slot's nozzle diameter to synthesise the full slicer preset name ("Bambu Lab P1S 0.4 nozzle"), and passes that into `presetCompatibility(...)` from `utils/slicerPrinterMatch.ts` against each local preset's parsed `compatible_printers` JSON; (c) for cloud / Orca Cloud presets — `extractPresetModel(name, registry)` is now multi-strategy: first the `@BBL ` form (existing), then the `@Bambu Lab ` form with case-insensitive reverse-lookup against the registry (so "A1 mini" vs "A1 Mini" capitalisation drift doesn't hide A1 Mini profiles, preserving the #1649 alias-aware match), then a body-text scan against every known model token (long-name fragments and short codes from the registry, long-first sort so "A1 Mini" / "X1 Carbon" / "H2D Pro" aren't eaten by their shorter siblings, word-boundary regex so "PA1" doesn't match "A1" and "X1Box" doesn't match "X1"). Presets where no strategy resolves still pass through — free-form names with no recognisable model token stay visible (can't filter what we can't classify). **Fail-open posture preserved:** `match` and `unknown` verdicts keep showing for local presets (back-compat for hand-edited imports without `compatible_printers`); the currently-configured preset (`slotInfo.savedPresetId`) bypasses the filter so the active selection always remains visible; built-in filaments stay unfiltered (generic fallback); when the registry hasn't loaded yet OR `printerModel` is empty, every filter no-ops. **No backend / schema / i18n changes.** Frontend ESLint clean; `npm run build` clean; vitest `ConfigureAmsSlotModal` 24/24 green. - **Virtual Printer: empty AMS slots forwarded as phantom loaded filaments to BambuStudio Sync (#1726, reported with full code-level analysis by @needo37)** — On any VP bound to a target printer (Proxy mode, or Queue mode with a specific target), the slicer-facing AMS state was the printer's raw push_status — the empty-slot cleanup that `bambu_mqtt.py::_handle_ams_data` applies to Bambuddy's own internal state was NEVER run on the bridge cache. Concrete case: real printer has 3 filaments loaded (AMS-A slots 2/3/4), AMS-A slot 1 and all of AMS-B empty; Bambuddy's AMS card renders the empty slots correctly as Empty (control — internal state path is fine), but BambuStudio after Sync paints 7 populated/green-checked filament slots — the 3 real ones plus 4 phantoms whose color/material is stale RFID/calibration data from before those slots went empty. The diagnostic signature is the mismatch between the AMS card (correct) and the slicer view (wrong) for the same payload. Archive mode and Queue-by-model are NOT affected — no target printer → no bridge → the slicer gets the synthetic stub at `mqtt_server.py:927` with no real AMS data. **Root cause:** two code paths consume the same printer AMS payload. Internal (`bambu_mqtt.py::_handle_ams_data` lines 1802-1858) parses `tray_exist_bits`, promotes empty slots to `state=9`, and wipes the stale `tray_type`/`tray_color`/`tray_info_idx`/`tag_uid`/`tray_uuid`/`remain` fields. VP bridge (`mqtt_bridge.py::_on_printer_raw` lines 551-656) deep-merges AMS structurally via `_merge_ams_dict` and copies `tray_exist_bits` through as an opaque top-level scalar — but never applies the bit→clear-empty-slot logic. The cached state ships to the slicer untouched. **Fix:** factored the bit-clear logic out of `_handle_ams_data` into a shared module-level helper `bambu_mqtt.py::apply_tray_exist_bits(units, tray_exist_bits_str, *, power_on_flag, log_label)` and call it from both paths. The internal call site is replaced with a single helper invocation; the bridge calls it on the merged AMS dict after `_merge_ams_dict` runs, before the 1 Hz cached-as-base push picks the cache up. Shared shutdown guard preserved on both sides: all-zero bits + `power_on_flag=False` is the printer-off pattern (#765) and skips cleanup — a non-zero bits + power-off combo is valid idle-printer state (#1365 — X1C between prints) and still applies. AMS-HT units (`id >= 128`) skipped on both sides (separate addressing scheme). **Tests:** new `TestApplyTrayExistBitsHelper` class in `test_bambu_mqtt.py` (10 cases pinning the helper contract directly — missing/unparseable bits → no-op, shutdown guard, nonzero+power-off X1C case, int-9 state, AMS-HT skip, string id handling, multi-AMS global bit math, state-promote-even-without-stale-data). 3 new bridge regression tests in `test_vp_mqtt_bridge.py::TestPushStatusCache`: `test_tray_exist_bits_clears_empty_slots_in_slicer_cache` reproduces the #1726 wire shape (slot 0 carries stale `tray_type`/`tray_color`/`tray_info_idx`/`tag_uid`/`tray_uuid`/`remain` + `tray_exist_bits="e"` → slot 0 must clear, slots 1-3 preserved), `test_tray_exist_bits_shutdown_guard_preserves_cache` pins the printer-off path won't propagate phantom empties on every reconnect, `test_tray_exist_bits_skips_ams_ht_units` pins the HT addressing skip. Existing internal-state tests for the bit-clear logic (`test_tray_exist_bits_clears_empty_slots`, `test_tray_exist_bits_promotes_empty_slot_to_state_9`, `test_tray_exist_bits_does_not_change_state_on_loaded_slots`, …) continue to pass against the refactored internal path — same contract, same behavior, different implementation seam. One pre-existing bridge fixture (`test_partial_ams_unit_update_preserves_other_units`) had an inconsistent `tray_exist_bits="3"` for two AMS units (bit 0 set, bit 4 unset, but both unit 0 and unit 1 had slot 0 populated as loaded). The fix exposed the inconsistency — corrected to `"11"` (bits 0 + 4) to match what the real printer would send. Full backend suite 5955/5955 green; ruff clean; i18n parity 5107 leaves × 11 locales green (no new keys). Frontend untouched. **Verification on a live system (per @needo37's analysis):** set `BAMBUDDY_VP_DUMP_WIRE=1`, restart, Sync the slicer, inspect `/vp_wire/_out.json`. For any tray whose bit in `tray_exist_bits` is 0, `tray_type`/`tray_color` should now be empty. - **Windows: `/api/local-backup/status` 500 on `ZoneInfoNotFoundError: 'No time zone found with key UTC'` (from a user's log on the Windows installer)** — Reported via a Windows traceback against the new local-backup status endpoint. The stdlib `zoneinfo` module reads the system IANA tz database on Linux/macOS, but Windows has none — and the embedded Python in our Windows installer doesn't carry the `tzdata` PyPI package either, so even `ZoneInfo("UTC")` raises `ZoneInfoNotFoundError`. `_local_zone()` in `services/local_backup.py` only caught that exception for the `TZ`-env branch; the empty-`TZ` fallback and the unrecognised-`TZ` fallback both unconditionally called `ZoneInfo("UTC")` and re-raised, bubbling out of the FastAPI handler as a 500. **Fix (two parts):** (1) `_local_zone()` is now resilient — return type widened from `ZoneInfo` to `tzinfo`, the `UTC` fallback is wrapped in its own try, and the last-resort fallback returns the stdlib `datetime.timezone.utc` (which needs no IANA DB and satisfies every `astimezone` / `str()` call site downstream — `str(timezone.utc) == "UTC"` matches the previous response shape). Restores function on existing Windows installs without re-bundling. (2) `requirements.txt` now pins `tzdata>=2024.1; sys_platform == "win32"` so the next Windows installer build ships the IANA DB and any non-UTC `TZ` value (e.g. `Europe/Berlin`) resolves correctly — the stdlib fallback can only ever give UTC. Linux/macOS unaffected: the platform marker keeps them on the system tz DB they already have. **Tests:** new `test_zoneinfo_completely_unavailable_falls_back_to_stdlib_utc` in `test_local_backup.py` monkeypatches `ZoneInfo` to always raise `ZoneInfoNotFoundError` and pins that `_local_zone()` returns `datetime.timezone.utc` rather than propagating. 31/31 local_backup tests green; ruff clean. diff --git a/backend/app/main.py b/backend/app/main.py index 928f44ed1..9236ab30f 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -333,6 +333,16 @@ logging.info("Bambuddy starting - debug=%s, log_level=%s", app_settings.debug, l # Track active prints: {(printer_id, filename): archive_id} _active_prints: dict[tuple[int, str], int] = {} +# #1721: stage-22 pre-captured finish photo bytes per printer. on_finish_photo_moment +# fires when stg_cur enters 22 ("Filament unloading") at end-of-print — toolhead +# parked, bed not yet dropped — and grabs a single camera frame into this cache. +# `_background_finish_photo` (inside on_print_complete) consumes the cached bytes +# instead of running its own grab-now chain when present, so the finish photo +# captures the better-framed pre-bed-drop moment without us having to force +# timelapse on at dispatch (the #1397 mechanism that caused #1721's per-layer +# nozzle parking on slicer profiles with Timelapse Type = Smooth). +_stage22_finish_frames: dict[int, bytes] = {} + # Per-printer "connected" edge tracker. Used by `on_printer_status_change` # to fire `reconcile_stale_active_prints` exactly once per (re)connection # (#1542 follow-up — power-cycle ghost prints). The value is True after @@ -1946,6 +1956,10 @@ async def on_print_start(printer_id: int, data: dict): # Clear any stale user-stopped flag from previous print cycles _user_stopped_printers.discard(printer_id) + # #1721: drop any leftover pre-captured finish frame from a prior print + # so a never-consumed cache entry can't bleed into the new print's photo. + _stage22_finish_frames.pop(printer_id, None) + # Cancel any active bed cooldown waiter for this printer if _bed_cool_waiters.pop(printer_id, None): logger.info("[BED-COOL] Cancelled bed cooldown waiter for printer %s (new print started)", printer_id) @@ -3321,101 +3335,6 @@ async def _capture_finish_photo_from_timelapse( await asyncio.sleep(poll_interval) -async def _cleanup_forced_timelapse(archive_id: int, printer_id: int) -> None: - """Delete the timelapse Bambuddy forced on for #1397's finish-photo path. - - Called from the finish-photo background task after the extractor has had - its turn (regardless of whether extraction succeeded — the user never - asked for a video and we shouldn't leave one behind even if ffmpeg - failed). Cleanup is best-effort and never raises: a printer that's - offline at cleanup time means a single orphaned file on the SD card, - not a broken Bambuddy flow. - - Cleans both: - - the locally-attached file (clears archive.timelapse_path) - - the printer-side file via FTP DELE - """ - from backend.app.models.archive import PrintArchive - from backend.app.models.printer import Printer - from backend.app.services.bambu_ftp import delete_file_async - - logger = logging.getLogger(__name__) - - local_relpath: str | None = None - printer = None - - async with async_session() as db: - archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) - archive = archive_result.scalar_one_or_none() - if not archive or not archive.bambuddy_forced_timelapse: - return - - local_relpath = archive.timelapse_path - if local_relpath: - local_abspath = app_settings.base_dir / local_relpath - try: - if local_abspath.exists(): - local_abspath.unlink() - logger.info( - "[FORCED-TIMELAPSE] Deleted local timelapse %s for archive %s", - local_relpath, - archive_id, - ) - except OSError as e: - logger.warning("[FORCED-TIMELAPSE] Could not delete local timelapse %s: %s", local_relpath, e) - archive.timelapse_path = None - await db.commit() - - printer_result = await db.execute(select(Printer).where(Printer.id == printer_id)) - printer = printer_result.scalar_one_or_none() - - if printer is None or not local_relpath: - return - - # _scan_for_timelapse_with_retries used the original filename when it - # attached, so the basename of timelapse_path matches the printer-side - # filename. Try the directories the scanner walks (#1397). - from backend.app.services.bambu_ftp import DeleteResult - - filename = Path(local_relpath).name - any_real_failure = False - for remote_dir in ("/timelapse", "/timelapse/video", "/record", "/recording"): - remote_path = f"{remote_dir}/{filename}" - try: - result = await delete_file_async( - printer.ip_address, - printer.access_code, - remote_path, - printer_model=printer.model, - ) - except Exception as e: - logger.debug("[FORCED-TIMELAPSE] FTP delete attempt failed for %s: %s", remote_path, e) - continue - if result == DeleteResult.DELETED: - logger.info("[FORCED-TIMELAPSE] Deleted printer-side timelapse %s", remote_path) - return - if result == DeleteResult.FAILED: - any_real_failure = True - - # All four dirs returned NOT_FOUND with no actual failures: the printer - # never wrote a file under any expected path (or already swept). That's - # the normal post-print state on most models — debug, not warning. - if any_real_failure: - logger.warning( - "[FORCED-TIMELAPSE] Could not delete printer-side timelapse %s for archive %s " - "(network/auth/transient error)", - filename, - archive_id, - ) - else: - logger.debug( - "[FORCED-TIMELAPSE] No printer-side timelapse to delete for %s (archive %s) — " - "every candidate dir returned 550", - filename, - archive_id, - ) - - async def on_print_running_observed(printer_id: int, data: dict): """Restart-recovery: capture a fresh timelapse baseline for a print that started before Bambuddy came up. @@ -3609,6 +3528,117 @@ async def reconcile_stale_active_prints(printer_id: int) -> int: return reconciled +async def on_finish_photo_moment(printer_id: int, data: dict): + """Pre-capture a finish photo when the printer enters stage 22 / FINISH (#1721). + + Fires either at the stage-22 ("Filament unloading") edge — toolhead + parked, bed not yet dropped, optimal framing — or as a FINISH-state + fallback for prints that skip stage 22 (cancel, external-spool-only, + HMS halt, firmware variants). Grabs one frame via the same + external-camera / RTSP path the post-completion fallback uses, stores + the JPEG bytes in ``_stage22_finish_frames[printer_id]``, and lets + ``_background_finish_photo`` consume the cached bytes when it runs. + + Replaces the #1397 "force timelapse on at dispatch" mechanism, which + caused per-layer nozzle parking on slicer profiles with Timelapse Type + set to Smooth (#1721). No force-on now means the user's explicit + timelapse=off in the slicer send dialog is respected. + """ + logger = logging.getLogger(__name__) + trigger = data.get("trigger", "unknown") + timelapse_was_active = bool(data.get("timelapse_was_active")) + logger.info( + "[FINISH-PHOTO-MOMENT] printer=%s trigger=%s timelapse_active=%s", + printer_id, + trigger, + timelapse_was_active, + ) + + # If a timelapse is actively recording, skip the pre-capture — the + # post-completion path will extract the last frame from the recorded + # video, which still provides the best framing (toolhead parked, + # before bed drop) without the per-layer parking side effects. + if timelapse_was_active: + logger.info( + "[FINISH-PHOTO-MOMENT] timelapse active for printer %s — skipping pre-capture (last-frame extraction will run post-completion)", + printer_id, + ) + return + + try: + async with async_session() as db: + from backend.app.api.routes.settings import get_setting + from backend.app.models.printer import Printer + + capture_setting = await get_setting(db, "capture_finish_photo") + if capture_setting is not None and capture_setting.lower() != "true": + logger.info("[FINISH-PHOTO-MOMENT] capture_finish_photo disabled — skipping pre-capture") + return + + result = await db.execute(select(Printer).where(Printer.id == printer_id)) + printer = result.scalar_one_or_none() + if printer is None: + logger.warning( + "[FINISH-PHOTO-MOMENT] printer %s not found in DB", + printer_id, + ) + return + + frame_bytes: bytes | None = None + + if printer.external_camera_enabled and printer.external_camera_url: + from backend.app.services.external_camera import capture_frame + + frame_bytes = await capture_frame( + printer.external_camera_url, + printer.external_camera_type or "mjpeg", + snapshot_url=printer.external_camera_snapshot_url, + ) + if frame_bytes: + logger.info( + "[FINISH-PHOTO-MOMENT] captured external-camera frame (%d bytes)", + len(frame_bytes), + ) + else: + from backend.app.api.routes.camera import get_buffered_frame + + buffered = get_buffered_frame(printer_id) + if buffered: + frame_bytes = buffered + logger.info( + "[FINISH-PHOTO-MOMENT] used buffered RTSP frame (%d bytes)", + len(frame_bytes), + ) + else: + from backend.app.services.camera import capture_camera_frame_bytes + + frame_bytes = await capture_camera_frame_bytes( + ip_address=printer.ip_address, + access_code=printer.access_code, + model=printer.model, + timeout=15, + ) + if frame_bytes: + logger.info( + "[FINISH-PHOTO-MOMENT] captured RTSP frame (%d bytes)", + len(frame_bytes), + ) + + if frame_bytes: + _stage22_finish_frames[printer_id] = frame_bytes + else: + logger.warning( + "[FINISH-PHOTO-MOMENT] no frame captured for printer %s — post-completion fallback will retry", + printer_id, + ) + except Exception as e: + logger.warning( + "[FINISH-PHOTO-MOMENT] pre-capture failed for printer %s: %s", + printer_id, + e, + ) + + async def on_print_complete(printer_id: int, data: dict): """Handle print completion - update the archive status.""" import time @@ -4452,7 +4482,11 @@ async def on_print_complete(printer_id: int, data: dict): # recording — it captures the moment after the toolhead parks # but before the bed drops, which the live-camera grab below # would miss (#1397). Skipped for external cameras (those have - # their own framing and don't see a Bambu timelapse). + # their own framing and don't see a Bambu timelapse). Only + # runs when the USER explicitly enabled timelapse for this + # print — #1721 removed Bambuddy's force-on at dispatch + # because it caused per-layer nozzle parking on Smooth-mode + # slicer profiles. prefer_timelapse_source = bool(data.get("timelapse_was_active")) and not ( printer.external_camera_enabled and printer.external_camera_url ) @@ -4463,6 +4497,27 @@ async def on_print_complete(printer_id: int, data: dict): archive_dir=archive_dir, ) + # #1721: replacement framing path — on_finish_photo_moment + # pre-captured a frame at the stage-22 / FINISH edge (toolhead + # parked, bed not yet dropped) and cached the JPEG bytes in + # _stage22_finish_frames. Consume them now so the saved photo + # has the better framing instead of the post-bed-drop angle + # the live-camera fallback below would give. + if not photo_filename: + cached_frame = _stage22_finish_frames.pop(printer_id, None) + if cached_frame: + photos_dir = archive_dir / "photos" + photos_dir.mkdir(parents=True, exist_ok=True) + timestamp = datetime.now().strftime("%Y%m%d_%H%M%S") + photo_filename = f"finish_{timestamp}_{uuid.uuid4().hex[:8]}.jpg" + photo_path = photos_dir / photo_filename + await asyncio.to_thread(photo_path.write_bytes, cached_frame) + logger.info( + "[PHOTO-BG] Saved stage-22 pre-captured frame: %s (%d bytes)", + photo_filename, + len(cached_frame), + ) + # Fallback chain: external camera → buffered live frame → # fresh RTSP capture. Only runs if the timelapse path above # didn't already produce a photo. @@ -4522,16 +4577,6 @@ async def on_print_complete(printer_id: int, data: dict): await db.commit() logger.info("[PHOTO-BG] Saved: %s", photo_filename) - # When Bambuddy forced timelapse on for this print, delete - # the timelapse afterward (#1397). The user didn't ask for - # a video to keep — only the finish photo. Runs even when - # photo extraction failed, so we don't leave debris. - if archive.bambuddy_forced_timelapse: - await _cleanup_forced_timelapse( - archive_id=archive_id, - printer_id=printer_id, - ) - if photo_filename: return photo_filename return None @@ -5456,6 +5501,7 @@ async def lifespan(app: FastAPI): printer_manager.set_print_start_callback(on_print_start) printer_manager.set_print_complete_callback(on_print_complete) printer_manager.set_print_running_observed_callback(on_print_running_observed) + printer_manager.set_finish_photo_moment_callback(on_finish_photo_moment) printer_manager.set_ams_change_callback(on_ams_change) # Rehydrate persisted awaiting-plate-clear gate (#961) so prompts survive restarts diff --git a/backend/app/services/background_dispatch.py b/backend/app/services/background_dispatch.py index b9685827d..582a5106b 100644 --- a/backend/app/services/background_dispatch.py +++ b/backend/app/services/background_dispatch.py @@ -493,17 +493,6 @@ class BackgroundDispatchService: if self._is_cancel_requested(job.id): raise DispatchJobCancelled(f"Dispatch job {job.id} cancelled") - async def _resolve_effective_timelapse(self, db, archive, job: PrintDispatchJob) -> bool: - """Dispatch-flow wrapper around the shared resolver (#1397). - - Returns the effective value to pass to ``start_print(timelapse=...)``. - """ - return await resolve_effective_timelapse( - db, - archive, - user_wanted_timelapse=bool(job.options.get("timelapse", False)), - ) - def _build_state_payload_unlocked(self, recent_event: dict[str, Any] | None = None) -> dict[str, Any]: processing = len(self._active_jobs) dispatched = len(self._queued_jobs) @@ -685,7 +674,7 @@ class BackgroundDispatchService: self._raise_if_cancel_requested(job) - effective_timelapse = await self._resolve_effective_timelapse(db, archive, job) + effective_timelapse = bool(job.options.get("timelapse", False)) await self._set_active_message(job, f"Starting print on {printer_name}...") started = printer_manager.start_print( @@ -892,7 +881,7 @@ class BackgroundDispatchService: self._raise_if_cancel_requested(job) - effective_timelapse = await self._resolve_effective_timelapse(db, archive, job) + effective_timelapse = bool(job.options.get("timelapse", False)) await self._set_active_message(job, f"Starting print on {printer_name}...") started = printer_manager.start_print( @@ -1108,41 +1097,4 @@ class BackgroundDispatchService: return lower.endswith(".gcode") or lower.endswith(".gcode.3mf") -async def resolve_effective_timelapse(db, archive, user_wanted_timelapse: bool) -> bool: - """Resolve whether this print should record a timelapse (#1397). - - Shared by both the on-demand dispatch path (``background_dispatch.py``, - used by Print Now / Reprint flows) and the queued-dispatch path - (``print_scheduler.py``, used by the print queue). Both must apply the - same override semantics or the queue path's prints would slip through - without a finish photo. - - Bambuddy forces timelapse recording on when: - - the global ``capture_finish_photo`` setting is enabled, AND - - the user did NOT opt in to a timelapse for this specific print - - The forced bit is recorded on the archive so the post-extraction - cleanup path can delete the timelapse afterward (the user didn't - ask for a video to keep, only the framed finish photo, #1397). - """ - from backend.app.api.routes.settings import get_setting - - if user_wanted_timelapse: - return True - - # User didn't ask — check the master capture-finish-photo toggle. - capture_setting = await get_setting(db, "capture_finish_photo") - capture_enabled = capture_setting is None or capture_setting.lower() == "true" - if not capture_enabled: - return False - - archive.bambuddy_forced_timelapse = True - await db.commit() - logging.getLogger(__name__).info( - "[FORCED-TIMELAPSE] Forcing timelapse on for archive %s (capture_finish_photo enabled, user did not opt in)", - archive.id, - ) - return True - - background_dispatch = BackgroundDispatchService() diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index bb8b7b296..cee63308d 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -436,6 +436,7 @@ class BambuMQTTClient: on_bed_temp_update: Callable[[float], None] | None = None, on_drying_complete: Callable[[int], None] | None = None, on_print_running_observed: Callable[[dict], None] | None = None, + on_finish_photo_moment: Callable[[dict], None] | None = None, ): self.ip_address = ip_address self.serial_number = serial_number @@ -459,6 +460,17 @@ class BambuMQTTClient: # the same shape as on_print_start (filename / subtask_name / # remaining_time / raw_data / ams_mapping). self.on_print_running_observed = on_print_running_observed + # #1721: fired the moment the printer enters the end-of-print + # "Filament unloading" phase (stg_cur=22 while progress>=99 or + # we've hit the last layer / remaining_time<=0). This is the + # framing #1397 was after — toolhead parked, bed not yet + # dropped — but reached via a clean state signal instead of + # the per-layer M622 J1 macros which caused per-layer nozzle + # parks on slicer profiles with Timelapse Type = Smooth. + # A FINISH-state fallback below fires this same callback if + # stage 22 never arrives (cancel mid-print, external-spool- + # only prints, HMS halt before unload, firmware variants). + self.on_finish_photo_moment = on_finish_photo_moment # Per-AMS previous dry_time, used to detect the falling edge above. # Seeded lazily as we observe each AMS unit. self._previous_dry_times: dict[int, int] = {} @@ -471,6 +483,10 @@ class BambuMQTTClient: self._was_running: bool = False # Track if we've seen RUNNING state for current print self._completion_triggered: bool = False # Prevent duplicate completion triggers self._timelapse_during_print: bool = False # Track if timelapse was active during this print + # #1721: one-shot guard so the end-of-print stage-22 detector + # and the FINISH-state fallback don't both fire on the same + # print. Reset to False on every print start. + self._finish_photo_captured: bool = False 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 @@ -2107,12 +2123,46 @@ class BambuMQTTClient: # Calibration stage tracking if "stg_cur" in data: new_stg = data["stg_cur"] + prev_stg = self.state.stg_cur # Always log ANY stg_cur change for debugging filament operations - if new_stg != self.state.stg_cur: + if new_stg != prev_stg: logger.debug( - f"[{self.serial_number}] stg_cur changed: {self.state.stg_cur} -> {new_stg} ({get_stage_name(new_stg)})" + f"[{self.serial_number}] stg_cur changed: {prev_stg} -> {new_stg} ({get_stage_name(new_stg)})" ) self.state.stg_cur = new_stg + # #1721 end-of-print finish photo trigger. + # Stage 22 = "Filament unloading" fires at end-of-print AND + # during mid-print color swaps. The end-of-print gate + # (progress>=99 / layer>=total / remaining<=0) disambiguates + # — those signals only line up at the real end. Edge-only + # (prev != 22) so the trigger fires once per stage entry. + if ( + new_stg == 22 + and prev_stg != 22 + and self._was_running + and not self._finish_photo_captured + and self.on_finish_photo_moment + ): + progress = self.state.progress or 0.0 + layer_num = self.state.layer_num or 0 + total_layers = self.state.total_layers or 0 + remaining = self.state.remaining_time or 0 + is_end_of_print = progress >= 99 or (total_layers > 0 and layer_num >= total_layers) or remaining <= 0 + if is_end_of_print: + self._finish_photo_captured = True + logger.info( + f"[{self.serial_number}] FINISH PHOTO MOMENT (stage-22) — " + f"progress={progress}, layer={layer_num}/{total_layers}, " + f"remaining={remaining}min, timelapse_active={self._timelapse_during_print}" + ) + self.on_finish_photo_moment( + { + "trigger": "stage_22", + "filename": self._previous_gcode_file or self.state.gcode_file, + "subtask_name": self.state.subtask_name, + "timelapse_was_active": self._timelapse_during_print, + } + ) if "stg" in data: self.state.stg = data["stg"] if isinstance(data["stg"], list) else [] @@ -3024,6 +3074,8 @@ class BambuMQTTClient: # Reset completion tracking for new print self._was_running = True self._completion_triggered = False + # #1721: rearm the end-of-print finish-photo trigger for the new print + self._finish_photo_captured = False # Reset last valid progress/layer for usage tracking self._last_valid_progress = 0.0 self._last_valid_layer_num = 0 @@ -3135,6 +3187,26 @@ class BambuMQTTClient: f"timelapse_during_print: {self._timelapse_during_print}" ) timelapse_was_active = self._timelapse_during_print + # #1721 fallback: if the stage-22 trigger never fired (cancel, + # external-spool-only, HMS halt, or firmware variant that skips + # the unload phase) fire the finish-photo moment now. Bed has + # already dropped, framing is worse, but we still capture. + # Only on successful completion — aborted/failed prints don't + # produce a meaningful finish photo. + if status == "completed" and not self._finish_photo_captured and self.on_finish_photo_moment: + self._finish_photo_captured = True + logger.info( + f"[{self.serial_number}] FINISH PHOTO MOMENT (FINISH fallback) — " + f"stage-22 never fired; capturing at FINISH-state transition" + ) + self.on_finish_photo_moment( + { + "trigger": "finish_state", + "filename": self._previous_gcode_file or current_file, + "subtask_name": self.state.subtask_name, + "timelapse_was_active": timelapse_was_active, + } + ) self._completion_triggered = True self._was_running = False self._timelapse_during_print = False # Reset for next print diff --git a/backend/app/services/print_scheduler.py b/backend/app/services/print_scheduler.py index f3c0eba6c..8449f6db1 100644 --- a/backend/app/services/print_scheduler.py +++ b/backend/app/services/print_scheduler.py @@ -2187,21 +2187,13 @@ class PrintScheduler: pre_subtask_id = getattr(pre_status, "subtask_id", None) if pre_status else None pre_gcode_file = getattr(pre_status, "gcode_file", None) if pre_status else None - # #1397: force timelapse on when capture_finish_photo is enabled so - # the finish-photo extractor has something to pull from. Same override - # semantics as background_dispatch.py — both queue paths must apply - # the same rule or queued prints slip through without a finish photo. - # When archive_print failed (library_file path, line 1968 except), we - # have no archive to mark — fall back to the literal user choice; the - # downstream finish-photo path can't run without an archive anyway. - if archive is not None: - from backend.app.services.background_dispatch import resolve_effective_timelapse - - effective_timelapse = await resolve_effective_timelapse( - db, archive, user_wanted_timelapse=bool(item.timelapse) - ) - else: - effective_timelapse = bool(item.timelapse) + # #1721: respect the user's explicit timelapse choice. The #1397 + # force-on at dispatch was removed because it caused per-layer nozzle + # parking on slicer profiles with Timelapse Type = Smooth. Finish-photo + # capture is now driven by the stg_cur=22 transition in bambu_mqtt.py + # ("Filament unloading", toolhead parked, bed not yet dropped) with a + # FINISH-state fallback — no need to force a video. + effective_timelapse = bool(item.timelapse) # Start the print with AMS mapping, plate_id and print options started = printer_manager.start_print( diff --git a/backend/app/services/printer_manager.py b/backend/app/services/printer_manager.py index 2f09bcc59..0aa76850f 100644 --- a/backend/app/services/printer_manager.py +++ b/backend/app/services/printer_manager.py @@ -173,6 +173,7 @@ class PrinterManager: self._on_print_start: Callable[[int, dict], None] | None = None self._on_print_complete: Callable[[int, dict], None] | None = None self._on_print_running_observed: Callable[[int, dict], None] | None = None + self._on_finish_photo_moment: Callable[[int, dict], None] | None = None self._on_status_change: Callable[[int, PrinterState], None] | None = None self._on_ams_change: Callable[[int, list], None] | None = None self._on_layer_change: Callable[[int, int], None] | None = None @@ -322,6 +323,19 @@ class PrinterManager: hook to recover.""" self._on_print_running_observed = callback + def set_finish_photo_moment_callback(self, callback: Callable[[int, dict], None]): + """Set callback for the #1721 finish-photo moment. + + Fires on the stage-22 (\"Filament unloading\") edge at end-of-print + — the framing window where the toolhead is parked but the bed + hasn't dropped yet. Falls back to firing at the FINISH-state + transition for prints that skip stage 22 (cancel, external-spool- + only, HMS halt, firmware variants). Payload includes the + ``trigger`` key (``\"stage_22\"`` or ``\"finish_state\"``) and + ``timelapse_was_active`` so the photo path can choose between + live-camera capture and timelapse last-frame extraction.""" + self._on_finish_photo_moment = callback + def set_status_change_callback(self, callback: Callable[[int, PrinterState], None]): """Set callback for status change events.""" self._on_status_change = callback @@ -389,6 +403,10 @@ class PrinterManager: if self._on_print_running_observed: self._schedule_async(self._on_print_running_observed(printer_id, data)) + def on_finish_photo_moment(data: dict): + if self._on_finish_photo_moment: + self._schedule_async(self._on_finish_photo_moment(printer_id, data)) + def on_ams_change(ams_data: list): if self._on_ams_change: self._schedule_async(self._on_ams_change(printer_id, ams_data)) @@ -418,6 +436,7 @@ class PrinterManager: on_bed_temp_update=on_bed_temp_update, on_drying_complete=on_drying_complete, on_print_running_observed=on_print_running_observed, + on_finish_photo_moment=on_finish_photo_moment, ) client.connect() diff --git a/backend/tests/unit/services/test_background_dispatch.py b/backend/tests/unit/services/test_background_dispatch.py index 663126507..e87f9bee7 100644 --- a/backend/tests/unit/services/test_background_dispatch.py +++ b/backend/tests/unit/services/test_background_dispatch.py @@ -231,11 +231,11 @@ def test_dispatch_option_defaults_align_with_request_schema_defaults(): from backend.app.schemas.library import FilePrintRequest from backend.app.services import background_dispatch as bd - # `timelapse` deliberately excluded — the dispatcher now resolves it via - # ``_resolve_effective_timelapse`` so the value passed to ``start_print`` - # depends on the ``capture_finish_photo`` setting + ``bambuddy_forced_timelapse`` - # column (#1397). The original literal `job.options.get("timelapse", False)` - # pattern no longer appears. + # `timelapse` deliberately excluded — the dispatcher wraps it in + # ``bool(...)`` (``effective_timelapse = bool(job.options.get("timelapse", + # False))``) so the bare-pattern needle in the loop below would miss it. + # The wrap exists to coerce None / non-bool option payloads to a bool + # boundary the printer firmware accepts (#1721 follow-up). fields = ("bed_levelling", "flow_cali", "vibration_cali", "layer_inspect", "use_ams") reprint_defaults = {f: getattr(ReprintRequest(), f) for f in fields} libprint_defaults = {f: getattr(FilePrintRequest(), f) for f in fields} diff --git a/backend/tests/unit/services/test_background_dispatch_watchdog.py b/backend/tests/unit/services/test_background_dispatch_watchdog.py index 4bd366a93..f800e25f5 100644 --- a/backend/tests/unit/services/test_background_dispatch_watchdog.py +++ b/backend/tests/unit/services/test_background_dispatch_watchdog.py @@ -606,14 +606,6 @@ class TestReprintArchiveDispatchWiring: new_callable=AsyncMock, ), patch("backend.app.main.register_expected_print"), - # #1397: _resolve_effective_timelapse touches DB + setting layer - # that this watchdog-focused test isn't equipped to mock. Stub - # the whole helper so the dispatch flow proceeds unaffected. - patch.object( - BackgroundDispatchService, - "_resolve_effective_timelapse", - new=AsyncMock(return_value=False), - ), pytest.raises(RuntimeError, match="did not acknowledge print command"), ): await service._run_reprint_archive(job) @@ -682,14 +674,6 @@ class TestReprintArchiveDispatchWiring: new_callable=AsyncMock, ), patch("backend.app.main.register_expected_print"), - # #1397: _resolve_effective_timelapse touches DB + setting layer - # that this watchdog-focused test isn't equipped to mock. Stub - # the whole helper so the dispatch flow proceeds unaffected. - patch.object( - BackgroundDispatchService, - "_resolve_effective_timelapse", - new=AsyncMock(return_value=False), - ), ): await service._run_reprint_archive(job) # must not raise diff --git a/backend/tests/unit/services/test_dispatch_force_timelapse.py b/backend/tests/unit/services/test_dispatch_force_timelapse.py deleted file mode 100644 index b43abf0cc..000000000 --- a/backend/tests/unit/services/test_dispatch_force_timelapse.py +++ /dev/null @@ -1,156 +0,0 @@ -"""Tests for _resolve_effective_timelapse (#1397). - -Bambuddy forces timelapse recording on at dispatch time when the -capture_finish_photo setting is enabled and the user did not opt in -to timelapse for the specific print. The forced bit is recorded on -the archive so the post-extraction cleanup path can delete the file. - -These tests exercise the four decision shapes the helper has to handle: - - 1. capture_finish_photo OFF → no override regardless of user choice - 2. capture_finish_photo ON, user chose timelapse → no override (the - user's choice already covers the photo path) - 3. capture_finish_photo ON, user chose NO timelapse → override to ON, - mark archive.bambuddy_forced_timelapse=True - 4. capture_finish_photo unset (None / missing) → defaults to ON, so - the same override applies as case 3 -""" - -from types import SimpleNamespace -from unittest.mock import AsyncMock, patch - -import pytest - -from backend.app.services.background_dispatch import ( - BackgroundDispatchService, - PrintDispatchJob, -) - - -def _make_job(timelapse: bool | None) -> PrintDispatchJob: - """Mint a job with the smallest valid shape — the only field - _resolve_effective_timelapse reads from job is `options`.""" - return PrintDispatchJob( - id=1, - kind="print_library_file", - source_id=42, - source_name="test.gcode.3mf", - printer_id=10, - printer_name="Printer A", - options={"timelapse": timelapse} if timelapse is not None else {}, - ) - - -def _make_archive() -> SimpleNamespace: - """Stand-in archive object; the helper only touches .id and - .bambuddy_forced_timelapse.""" - return SimpleNamespace(id=99, bambuddy_forced_timelapse=False) - - -def _make_db() -> AsyncMock: - """Fake db with a no-op .commit().""" - db = AsyncMock() - return db - - -@pytest.mark.asyncio -async def test_capture_finish_photo_off_means_no_override(): - """Master toggle off → user's timelapse=False stays False, no flag set.""" - service = BackgroundDispatchService() - archive = _make_archive() - db = _make_db() - job = _make_job(timelapse=False) - - with patch( - "backend.app.api.routes.settings.get_setting", - new=AsyncMock(return_value="false"), - ): - effective = await service._resolve_effective_timelapse(db, archive, job) - - assert effective is False - assert archive.bambuddy_forced_timelapse is False - db.commit.assert_not_awaited() - - -@pytest.mark.asyncio -async def test_user_opted_in_passes_through_unchanged(): - """User asked for a timelapse → no override needed (their normal flow - already records one). bambuddy_forced_timelapse stays False so cleanup - leaves the file alone.""" - service = BackgroundDispatchService() - archive = _make_archive() - db = _make_db() - job = _make_job(timelapse=True) - - # get_setting shouldn't even be consulted — but if it is, no override - # should still fire. - with patch( - "backend.app.api.routes.settings.get_setting", - new=AsyncMock(return_value="true"), - ): - effective = await service._resolve_effective_timelapse(db, archive, job) - - assert effective is True - assert archive.bambuddy_forced_timelapse is False - db.commit.assert_not_awaited() - - -@pytest.mark.asyncio -async def test_capture_on_user_off_forces_timelapse_and_marks_flag(): - """The whole point of the fix: capture_finish_photo=on + user-timelapse=off - flips the MQTT command to timelapse=True and marks the archive for - post-extraction cleanup.""" - service = BackgroundDispatchService() - archive = _make_archive() - db = _make_db() - job = _make_job(timelapse=False) - - with patch( - "backend.app.api.routes.settings.get_setting", - new=AsyncMock(return_value="true"), - ): - effective = await service._resolve_effective_timelapse(db, archive, job) - - assert effective is True - assert archive.bambuddy_forced_timelapse is True - db.commit.assert_awaited_once() - - -@pytest.mark.asyncio -async def test_capture_finish_photo_unset_defaults_to_enabled(): - """Setting absent from DB → default is True (per the Field default in the - schema), so the override fires just like when explicitly enabled.""" - service = BackgroundDispatchService() - archive = _make_archive() - db = _make_db() - job = _make_job(timelapse=False) - - with patch( - "backend.app.api.routes.settings.get_setting", - new=AsyncMock(return_value=None), - ): - effective = await service._resolve_effective_timelapse(db, archive, job) - - assert effective is True - assert archive.bambuddy_forced_timelapse is True - db.commit.assert_awaited_once() - - -@pytest.mark.asyncio -async def test_user_missing_timelapse_treated_as_false(): - """Some queue paths pass options without a timelapse key. Treat absent - as False (matches existing job.options.get('timelapse', False) default - that the caller previously used).""" - service = BackgroundDispatchService() - archive = _make_archive() - db = _make_db() - job = _make_job(timelapse=None) # falls through to {} - - with patch( - "backend.app.api.routes.settings.get_setting", - new=AsyncMock(return_value="true"), - ): - effective = await service._resolve_effective_timelapse(db, archive, job) - - assert effective is True - assert archive.bambuddy_forced_timelapse is True diff --git a/backend/tests/unit/test_cleanup_forced_timelapse.py b/backend/tests/unit/test_cleanup_forced_timelapse.py deleted file mode 100644 index a6d0fa95c..000000000 --- a/backend/tests/unit/test_cleanup_forced_timelapse.py +++ /dev/null @@ -1,291 +0,0 @@ -"""Tests for _cleanup_forced_timelapse (#1397). - -When Bambuddy forced timelapse on for the finish-photo path, this helper -runs after the extractor (success OR failure — we never leave debris). -It deletes: - - the locally-attached file (clears archive.timelapse_path) - - the printer-side file via FTP DELE, walking the four scanner dirs - -These tests pin the four branches: - - 1. archive doesn't exist → no-op - 2. archive exists but bambuddy_forced_timelapse=False → no-op (user wanted - the timelapse) - 3. archive exists, forced=True, local file present → delete local + DB - update + FTP DELE on the first directory that succeeds - 4. archive exists, forced=True, but FTP DELE fails on every dir → local - side still cleaned up; warn log emitted (best-effort) -""" - -from pathlib import Path -from types import SimpleNamespace -from unittest.mock import AsyncMock, patch - -import pytest - -from backend.app import main as main_module -from backend.app.main import _cleanup_forced_timelapse -from backend.app.services.bambu_ftp import DeleteResult - - -def _fake_session_factory(rows: dict): - """Return an async_session() replacement that yields the given rows. - - `rows` is a mapping of model -> object that the test wants returned - from `db.execute(select(...)).scalar_one_or_none()`. The select - target is detected by walking the column descriptions — for these - tests we just look at the model class name. - """ - from contextlib import asynccontextmanager - - @asynccontextmanager - async def fake_session(): - async def execute(stmt): - # The select(...) statement carries the target entity in - # `stmt.column_descriptions[0]["entity"]`. Match by class name. - target_name = stmt.column_descriptions[0]["entity"].__name__ - row = rows.get(target_name) - return SimpleNamespace(scalar_one_or_none=lambda: row) - - commits: list[None] = [] - - async def commit(): - commits.append(None) - - yield SimpleNamespace(execute=execute, commit=commit, _commits=commits) - - return fake_session - - -@pytest.fixture(autouse=True) -def patch_app_settings(monkeypatch, tmp_path): - """Point base_dir at a tmp_path so the helper can resolve relative - timelapse paths against a real fs we control.""" - monkeypatch.setattr(main_module.app_settings, "base_dir", tmp_path) - return tmp_path - - -@pytest.mark.asyncio -async def test_no_archive_is_noop(monkeypatch): - """Archive deleted between print start and cleanup? Don't crash.""" - monkeypatch.setattr(main_module, "async_session", _fake_session_factory({"PrintArchive": None, "Printer": None})) - delete_mock = AsyncMock() - with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - delete_mock.assert_not_awaited() - - -@pytest.mark.asyncio -async def test_not_forced_is_noop(monkeypatch, tmp_path): - """User wanted a timelapse → don't delete anything.""" - archive = SimpleNamespace( - bambuddy_forced_timelapse=False, - timelapse_path="archive/1/timelapse.mp4", - ) - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": None}), - ) - - # Lay down a real file so we'd detect a stray delete. - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - delete_mock = AsyncMock(return_value=DeleteResult.DELETED) - with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - delete_mock.assert_not_awaited() - assert video_path.exists() - # archive.timelapse_path is untouched — we still have the user's video - # tracked correctly. - assert archive.timelapse_path == "archive/1/timelapse.mp4" - - -@pytest.mark.asyncio -async def test_forced_deletes_local_and_remote(monkeypatch, tmp_path): - """Happy path: forced=True → local file unlinked, DB row cleared, FTP - DELE called against /timelapse/ (the first dir to succeed).""" - archive = SimpleNamespace( - bambuddy_forced_timelapse=True, - timelapse_path="archive/1/myprint.mp4", - ) - printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="O1C") - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": printer}), - ) - - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - # FTP DELE succeeds on the first directory we try. - delete_mock = AsyncMock(return_value=DeleteResult.DELETED) - with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - # Local side: file gone, DB cleared. - assert not video_path.exists() - assert archive.timelapse_path is None - # Remote side: DELE'd against /timelapse/myprint.mp4 — that's the - # first dir the cleanup tries. - delete_mock.assert_awaited() - call = delete_mock.await_args - assert call.args[0] == "10.0.0.5" - assert call.args[1] == "12345678" - assert call.args[2] == "/timelapse/myprint.mp4" - - -@pytest.mark.asyncio -async def test_forced_walks_alternate_dirs_when_first_fails(monkeypatch, tmp_path): - """If /timelapse/ DELE returns False (file not there), try the other - scanner dirs in order.""" - archive = SimpleNamespace( - bambuddy_forced_timelapse=True, - timelapse_path="archive/1/myprint.mp4", - ) - printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="O1C") - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": printer}), - ) - - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - # First two dirs report NOT_FOUND (file not there), third succeeds. - # Cleanup should stop after the third — and crucially must NOT WARN - # because no real network/auth failure happened (#1721). - delete_mock = AsyncMock(side_effect=[DeleteResult.NOT_FOUND, DeleteResult.NOT_FOUND, DeleteResult.DELETED]) - with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - assert delete_mock.await_count == 3 - paths_tried = [call.args[2] for call in delete_mock.await_args_list] - assert paths_tried == [ - "/timelapse/myprint.mp4", - "/timelapse/video/myprint.mp4", - "/record/myprint.mp4", - ] - - -@pytest.mark.asyncio -async def test_forced_local_cleanup_runs_even_if_ftp_unreachable(monkeypatch, tmp_path): - """FTP completely failing must not block local cleanup — the user's - archive UI should reflect that the timelapse is gone immediately, - even if the printer-side file lingers.""" - archive = SimpleNamespace( - bambuddy_forced_timelapse=True, - timelapse_path="archive/1/myprint.mp4", - ) - printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="O1C") - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": printer}), - ) - - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - # Every FTP attempt throws. - delete_mock = AsyncMock(side_effect=OSError("connection refused")) - with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - # Local side cleaned up even though all FTP attempts threw. - assert not video_path.exists() - assert archive.timelapse_path is None - # All four dirs were attempted before giving up. - assert delete_mock.await_count == 4 - - -@pytest.mark.asyncio -async def test_forced_no_warning_when_every_dir_returns_not_found(monkeypatch, tmp_path, caplog): - """#1721: when every candidate dir returns 550 (file not there) the - helper used to emit "Could not delete printer-side timelapse ... - (file may already be gone)" at WARNING. That message landed in support - bundles for healthy printers whose firmware swept the SD card itself. - With DeleteResult.NOT_FOUND signalling, no real failure happened → - must be DEBUG, not WARNING. - """ - import logging - - archive = SimpleNamespace( - bambuddy_forced_timelapse=True, - timelapse_path="archive/1/myprint.mp4", - ) - printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="N2S") - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": printer}), - ) - - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - delete_mock = AsyncMock(return_value=DeleteResult.NOT_FOUND) - with ( - caplog.at_level(logging.DEBUG, logger="backend.app.main"), - patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock), - ): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - assert delete_mock.await_count == 4 - warnings = [r for r in caplog.records if r.levelno >= logging.WARNING and "[FORCED-TIMELAPSE]" in r.message] - assert warnings == [], f"unexpected WARNING(s): {[w.message for w in warnings]}" - debugs = [ - r for r in caplog.records if r.levelno == logging.DEBUG and "No printer-side timelapse to delete" in r.message - ] - assert len(debugs) == 1, "expected the 'nothing to delete' debug summary" - - -@pytest.mark.asyncio -async def test_forced_warns_when_any_dir_returns_failed(monkeypatch, tmp_path, caplog): - """Counterpart to the above: a real network/auth/transient FAILED on any - dir keeps the WARNING — that's the signal the maintainer actually wants - to see. - """ - import logging - - archive = SimpleNamespace( - bambuddy_forced_timelapse=True, - timelapse_path="archive/1/myprint.mp4", - ) - printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="O1C") - monkeypatch.setattr( - main_module, - "async_session", - _fake_session_factory({"PrintArchive": archive, "Printer": printer}), - ) - - video_path = tmp_path / archive.timelapse_path - video_path.parent.mkdir(parents=True, exist_ok=True) - video_path.write_bytes(b"x" * 100) - - delete_mock = AsyncMock( - side_effect=[ - DeleteResult.NOT_FOUND, - DeleteResult.FAILED, - DeleteResult.NOT_FOUND, - DeleteResult.NOT_FOUND, - ] - ) - with ( - caplog.at_level(logging.WARNING, logger="backend.app.main"), - patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock), - ): - await _cleanup_forced_timelapse(archive_id=99, printer_id=10) - - warnings = [r for r in caplog.records if r.levelno >= logging.WARNING and "[FORCED-TIMELAPSE]" in r.message] - assert len(warnings) == 1 - assert "network/auth/transient" in warnings[0].message diff --git a/backend/tests/unit/test_scheduler_force_timelapse_wiring.py b/backend/tests/unit/test_scheduler_force_timelapse_wiring.py deleted file mode 100644 index 9ee599ebc..000000000 --- a/backend/tests/unit/test_scheduler_force_timelapse_wiring.py +++ /dev/null @@ -1,71 +0,0 @@ -"""Regression test for the print-queue path of the #1397 force-timelapse fix. - -The first round of #1397 only wired the override into ``background_dispatch.py``, -which covers Print Now / Reprint Now flows. The print *queue* uses a separate -scheduler at ``print_scheduler.py:_start_print`` that calls -``printer_manager.start_print`` directly — and the first attempt skipped that -call site, so queued prints' timelapse setting passed through unchanged and -the finish-photo path had nothing to draw from. Field-test caught this when -Martin queued two prints (H2D + X1C); neither got a forced timelapse and -``archive.bambuddy_forced_timelapse`` stayed False on both. - -This test pins the wiring at the source level: the helper is imported AND -its return value is what ``start_print(timelapse=...)`` receives. We can't -exercise the full ``_start_print`` method without standing up a real DB + -printer_manager + ams_assignment fixture stack, but the structural assert -is enough to catch regression at the dispatch hook. -""" - -import ast -from pathlib import Path - -SCHEDULER_PATH = Path(__file__).resolve().parent.parent.parent / "app" / "services" / "print_scheduler.py" - - -def _find_call_to_start_print(tree: ast.AST) -> ast.Call: - """Walk the AST and return the printer_manager.start_print(...) Call node - inside _start_print. Should be exactly one.""" - for node in ast.walk(tree): - if not isinstance(node, ast.Call): - continue - func = node.func - if not isinstance(func, ast.Attribute): - continue - if func.attr != "start_print": - continue - value = func.value - if not isinstance(value, ast.Name) or value.id != "printer_manager": - continue - return node - raise AssertionError("Could not find printer_manager.start_print(...) call in print_scheduler.py") - - -def test_start_print_timelapse_kwarg_uses_resolved_value(): - """``timelapse=`` kwarg passed to start_print must reference - ``effective_timelapse`` (the resolved value) — not ``item.timelapse`` - (the user's raw choice). If a refactor drops the resolver call and - restores ``item.timelapse``, this test fails.""" - source = SCHEDULER_PATH.read_text() - tree = ast.parse(source) - - call = _find_call_to_start_print(tree) - timelapse_kw = next((kw for kw in call.keywords if kw.arg == "timelapse"), None) - assert timelapse_kw is not None, "start_print(timelapse=...) kwarg is missing" - - # The value must be the resolved variable, not item.timelapse. - value = timelapse_kw.value - assert isinstance(value, ast.Name) and value.id == "effective_timelapse", ( - f"timelapse= must be the resolver's return value (effective_timelapse), " - f"got {ast.dump(value)}. The queue path must apply the same #1397 " - f"override as background_dispatch.py — otherwise queued prints' " - f"finish-photo extractor has nothing to pull from." - ) - - -def test_scheduler_imports_resolve_effective_timelapse(): - """The import must exist somewhere in print_scheduler.py — guards against - a future refactor removing it and falling back to item.timelapse.""" - source = SCHEDULER_PATH.read_text() - assert "from backend.app.services.background_dispatch import resolve_effective_timelapse" in source, ( - "print_scheduler.py must import resolve_effective_timelapse from background_dispatch" - )