From 5680f5d34b7d58ac5d91f39a5e85adff59b32379 Mon Sep 17 00:00:00 2001 From: maziggy Date: Sat, 16 May 2026 09:05:05 +0200 Subject: [PATCH] fix(scheduler): watchdogs no longer falsely treat FINISH->IDLE as "print landed" (#1370) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both the queue-side _watchdog_print_start and the direct-dispatch _verify_print_response used `status.state != pre_state` to decide whether a project_file command had been accepted. When a printer was in FINISH at dispatch time (un-dismissed post-print prompt from a prior job), the firmware silently rejected the new command; if the user then dismissed the screen prompt, the printer moved FINISH -> IDLE and the watchdog returned early as "command landed" — leaving the queue row stuck at status='printing' indefinitely and the scheduler permanently marking the printer as busy. Narrow the "command landed" check in both verifiers to an allow-list of active-print states (PREPARE / SLICING / RUNNING / PAUSE). Inactive transitions (FINISH -> IDLE, etc.) no longer short-circuit the revert. The subtask_id-advance signal stays in place for H2D's slow FINISH -> PREPARE transition (#1078). Also wrap _watchdog_print_start's revert commit and printer_manager._persist_awaiting_plate_clear in run_with_retry so SQLite single-writer contention can't silently drop these writes. The revert path returns a tristate sentinel so the post-revert MQTT session-recovery logic only runs when we actually reverted (or the commit failed) — not when on_print_complete had already cleared the row, where a forced reconnect could break a healthy concurrent print. --- CHANGELOG.md | 2 + backend/app/services/background_dispatch.py | 22 ++++- backend/app/services/print_scheduler.py | 62 ++++++++++-- backend/app/services/printer_manager.py | 14 +-- .../test_background_dispatch_watchdog.py | 62 ++++++++++++ backend/tests/unit/test_scheduler_watchdog.py | 99 ++++++++++++++++++- 6 files changed, 245 insertions(+), 16 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a0cd34439..b1bec72bc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,8 @@ All notable changes to Bambuddy will be documented in this file. - **Slice modal: pick the build plate (#1337, reported by @digitalskies)** — Slicing a plain STL through the integrated slicer always defaulted to whatever `curr_bed_type` lived in the chosen process preset (typically `Cool Plate`), which the slicer CLI then rejected for high-temp filaments with `Plate 1: Cool Plate does not support filament 1`. The user had no way to switch plates short of cloning the process preset in BambuStudio, which defeats the point of the in-app slicer. The Slice modal now exposes a `Build plate` dropdown with the six canonical BambuStudio / OrcaSlicer plates (Cool Plate, Cool Plate SuperTack, Engineering Plate, High Temp Plate, Textured PEI Plate, Smooth PEI Plate) plus an explicit `Auto (use process preset)` option that preserves the previous behavior. The dropdown sits between Process profile and Filament rows so it stays visible regardless of how many filament slots the picked plate uses (a long filament list would otherwise push it off the modal's `max-h-[85vh]` scroll viewport) and is **always enabled** — including when the user picks a Printer Preset Bundle from the top BundlePicker. When the user picks a specific plate, the new `bed_type` field on `SliceRequest` ([`backend/app/schemas/slicer.py`](backend/app/schemas/slicer.py)) flows through the dispatcher via two paths: (1) **resolved-preset path** — the route helper `_patch_process_bed_type` in [`backend/app/api/routes/library.py`](backend/app/api/routes/library.py) overwrites `curr_bed_type` on the resolved process JSON before forwarding to the sidecar (no preset cloning required); (2) **bundle dispatch path** — `slice_with_bundle` in [`backend/app/services/slicer_api.py`](backend/app/services/slicer_api.py) adds a `bedType` form field to the sidecar multipart so the sidecar can pass `--curr_bed_type` through to the CLI, which lets the override take effect even though Bambuddy can't patch the bundle's process JSON locally (the sidecar materialises it from the stored .bbscfg). Sidecar versions that don't recognise the field silently no-op — the slice still runs, just with the bundle's default plate; the slicer-API fork at maziggy/orca-slicer-api will need the matching change for the bundle path to take full effect. **i18n parity:** 8 new keys (`slice.bedType.{label,auto,coolPlate,coolPlateSuperTack,engineering,highTemp,texturedPEI,smoothPEI}`) added to all 8 locales — full German translation, English fallbacks elsewhere per project convention. **Regression tests:** 4 in [`test_slice_request_bed_type.py`](backend/tests/unit/test_slice_request_bed_type.py) (`bed_type` defaults to None, accepts the six canonical strings, rejects overlong input via the schema's `max_length=64`; `_patch_process_bed_type` overwrites an existing value, adds the field when missing, and returns the input unchanged for malformed JSON or non-dict roots), 4 in [`test_library_slice_api.py`](backend/tests/integration/test_library_slice_api.py) (resolved-preset path: with `bed_type` set, the sidecar receives `"curr_bed_type": "Textured PEI Plate"` in the presetProfile multipart part; without it, `curr_bed_type` stays out of the body entirely. bundle dispatch path: `bedType` form field carries the override through to the sidecar; omitting `bed_type` keeps the form field out of the request so the bundle's own `curr_bed_type` is preserved), 2 in [`SliceModal.test.tsx`](frontend/src/__tests__/components/SliceModal.test.tsx) (dropdown selection puts `bed_type` on the request; leaving it on Auto omits the field). 59 backend slice tests + 34 SliceModal tests pass; build and i18n parity script clean. ### Fixed +- **Queue items no longer get permanently stuck in `printing` status when the printer was in `FINISH` state at dispatch time, and direct-dispatch (Library → Print) no longer reports false success in the same scenario** ([#1370](https://github.com/maziggy/bambuddy/issues/1370), reported by @Martinnygaard) — Symptom: queue page shows `Busy: ` even though the printer is connected, idle, and `awaiting_plate_clear=False`; no new prints will dispatch to it until the user manually deletes or reassigns the queue row. Reproducible by queueing (or directly dispatching) onto a printer that still has the un-dismissed "Print complete" prompt from a prior job. **Root cause** in `_watchdog_print_start` at [`backend/app/services/print_scheduler.py`](backend/app/services/print_scheduler.py) **and the parallel `_verify_print_response` at [`backend/app/services/background_dispatch.py`](backend/app/services/background_dispatch.py)**: the post-dispatch verifiers both treated *any* `gcode_state` transition away from `pre_state` as proof that the printer had accepted the `project_file` command. In the reporter's bundle, item 6 dispatched while printer 3 was in `FINISH` (residual from item 3 earlier that day) — firmware silently rejected the new `project_file` because the previous-print prompt was still up, and ~2 minutes later the user manually dismissed the screen prompt, putting the printer into `IDLE`. The watchdog saw `state != pre_state` and returned early as "command landed", but `FINISH → IDLE` is the user dismissing a prompt, **not** the printer accepting our project_file — so the queue row stayed at `'printing'` indefinitely and the scheduler's busy-printer seed (`SELECT printer_id FROM print_queue WHERE status='printing'` in [`print_scheduler.py:166-171`](backend/app/services/print_scheduler.py)) permanently marked printer 3 as busy. The same broad-transition bug existed in `_verify_print_response`, which would have caused direct-dispatch (Library → Print) onto a FINISH-state printer to report false success — silently failing to print while the UI showed the dispatch as complete. **Fix:** in both verifiers, narrow the "command landed" check to an allow-list of active-print states (`PREPARE` / `SLICING` / `RUNNING` / `PAUSE`) instead of "any state that isn't `pre_state`". Inactive states (`IDLE`, `FINISH`, `FAILED`) no longer short-circuit the early return. The `subtask_id`-advance signal stays as-is in both verifiers — it remains the definitive "command landed" path for H2D firmware that sits at `FINISH` for ~50 s after accepting `project_file` before transitioning to `PREPARE` (#1078 stays green in both). **Resilience hardening alongside the fix:** the watchdog's revert commit and `printer_manager._persist_awaiting_plate_clear` now run through `run_with_retry` ([`backend/app/core/database.py`](backend/app/core/database.py)), so SQLite single-writer `database is locked` contention can't silently drop the queue-row revert or the plate-clear gate flag. The revert path returns a tristate sentinel (`"reverted"` / `"already_moved_on"` / `"revert_failed"`) so the post-revert MQTT session-recovery logic only runs when we actually reverted (or the commit failed) — never when `on_print_complete` had already cleared the row, where a forced reconnect could break a healthy concurrent print on the same printer. (Most other queue/archive writes already went through `run_with_retry`; these two were the holdouts that surfaced as repeated `Failed to persist awaiting_plate_clear` warnings in the reporter's bundle.) **Manual recovery for users on 0.2.4** who already have stuck rows: stop Bambuddy, then `sqlite3 /app/data/bambuddy.db "UPDATE print_queue SET status='cancelled', completed_at=datetime('now') WHERE status='printing';"` and restart. **Regression tests** — new `test_reverts_on_finish_to_idle_user_dismissed_prompt` (queue) and `test_returns_false_on_finish_to_idle_user_dismissed_prompt` (direct-dispatch) reproduce the exact reporter scenario on both code paths; new `test_does_not_revert_on_pickup_via_active_state` (queue) and `test_returns_true_on_each_active_print_state` (direct-dispatch) iterate all four active-print states (PREPARE/SLICING/RUNNING/PAUSE) and pin that each one is correctly treated as a valid "command landed" signal. Existing `test_no_revert_if_item_already_completed` was also hardened — it now uses a real client mock and asserts `force_reconnect_stale_session.assert_not_called()`, so the tristate-sentinel guard around the recovery path is pinned (catches the regression I introduced and then fixed during the audit pass). The pre-existing `test_exits_on_state_change` (uses `RUNNING`) and `test_exits_on_subtask_id_change_even_if_state_still_finish` (the #1078 H2D path) both still pass without modification. All 29 watchdog tests across both files + 411 in the scheduler/queue/dispatch/printer-manager sweep + 3161 in the full backend unit suite + 302 in the targeted integration sweep all pass; ruff clean. + - **Spool removal from AMS no longer requires a manual Reconnect on X1C printers that report `power_on_flag=False` while idle** ([#1365](https://github.com/maziggy/bambuddy/issues/1365), reported by @an3k via @maziggy) — On an X1C running firmware 01.08.02.00, pulling a spool out of an AMS slot left the slot showing as full in Bambuddy until the user clicked "Reconnect"; even re-reading the (now empty) slot's RFID from the printer screen didn't propagate. **Root cause:** the empty-slot detection in [`_handle_ams_data`](backend/app/services/bambu_mqtt.py) at [`bambu_mqtt.py:1721`](backend/app/services/bambu_mqtt.py) gated on `if tray_exist_bits_str and power_on:` — meaning *any* MQTT message with `power_on_flag=False` was skipped wholesale. That guard was added in [`488f6631`](https://github.com/maziggy/bambuddy/commit/488f6631) to fix [#765](https://github.com/maziggy/bambuddy/issues/765), where a printer's final shutdown message (all-zero `tray_exist_bits` + `power_on_flag=False`) was wiping AMS slot data and triggering auto-unlink. But this user's X1C firmware emits `power_on_flag=False` between prints with `tray_exist_bits` still reflecting the real slot inventory — so every spool-removal update was silently discarded and only the manual Reconnect (which sends `pushall`, a full per-tray snapshot independent of the bitfield path) would correct the view. **Fix:** narrow the skip to the exact shutdown pattern — zero bits **AND** `power_on_flag=False`. Non-zero `tray_exist_bits` with `power_on_flag=False` is valid idle-AMS state and the update is now applied. The original #765 regression test (`test_shutdown_message_preserves_ams_data`) uses `tray_exist_bits='0'` and therefore still passes, so the shutdown protection is preserved exactly. **New regression test** `test_idle_printer_with_power_off_and_nonzero_bits_clears_removed_slot` in [`backend/tests/unit/services/test_bambu_mqtt.py`](backend/tests/unit/services/test_bambu_mqtt.py) pins the #1365 behavior: a removal update with non-zero bits and `power_on_flag=False` clears the affected slot, with other slots untouched. All 250 bambu_mqtt tests pass; ruff clean. - **Discord notification provider now accepts legacy `discordapp.com` webhook URLs** ([#1363](https://github.com/maziggy/bambuddy/issues/1363), reported by @mrfoureyed) — Discord's "Copy Webhook URL" button emits `https://discordapp.com/api/webhooks/...` while Bambuddy's validation in [`backend/app/services/notification_service.py`](backend/app/services/notification_service.py) only accepted `https://discord.com/api/webhooks/...`, raising "Invalid Discord webhook URL" on paste. Both hostnames are operational on Discord's side and serve the same webhooks. The validation now accepts either prefix; the check itself is retained (vs. removing it as suggested) because it still catches the common paste-the-wrong-thing-into-the-Discord-field error. **Regression tests** in [`backend/tests/unit/services/test_notification_service.py`](backend/tests/unit/services/test_notification_service.py) — new `TestDiscordProvider` class pins both hostnames accepted, non-Discord hosts rejected, empty URL rejected. diff --git a/backend/app/services/background_dispatch.py b/backend/app/services/background_dispatch.py index 115641ab2..df84935cd 100644 --- a/backend/app/services/background_dispatch.py +++ b/backend/app/services/background_dispatch.py @@ -35,6 +35,16 @@ from backend.app.services.printer_manager import printer_manager logger = logging.getLogger(__name__) +# Bambu firmware states that mean the project_file has actually been accepted +# and the printer is now processing / running / paused mid-print. Used by the +# direct-dispatch verifier (#1370): a transition into one of these states means +# the print landed, anything else (e.g. FINISH -> IDLE after the user dismisses +# a post-print prompt) is NOT a valid "command landed" signal even though the +# state value did change. Mirrors the same constant in print_scheduler.py — +# kept duplicated rather than imported to avoid coupling the two services and +# to keep the value at the point of use. +_ACTIVE_PRINT_STATES: frozenset[str] = frozenset({"PREPARE", "SLICING", "RUNNING", "PAUSE"}) + class DispatchJobCancelled(Exception): """Raised when a dispatch job is cancelled by the user.""" @@ -990,9 +1000,19 @@ class BackgroundDispatchService: # within the remaining timeout and still surface a transition. continue last_status = state - if state.state != pre_state: + if state.state in _ACTIVE_PRINT_STATES: + # Printer is actively processing the job. We do NOT accept + # arbitrary state transitions: a printer going FINISH -> IDLE + # (user dismissed the post-print prompt without accepting our + # project_file) would otherwise look like "command landed" + # and the dispatch job would be marked successful even though + # no print is running (#1370). return True if pre_subtask_id is not None and state.subtask_id is not None and state.subtask_id != pre_subtask_id: + # Printer picked up the job (subtask_id advanced). H2D can + # sit at FINISH for ~50 s after accepting project_file before + # transitioning to PREPARE, but the subtask_id flips to our + # submission_id almost immediately (#1078). return True logger.warning( "Printer %s (%d) did not respond to print command within %.0fs " diff --git a/backend/app/services/print_scheduler.py b/backend/app/services/print_scheduler.py index 296e79e70..9d0cc3f8d 100644 --- a/backend/app/services/print_scheduler.py +++ b/backend/app/services/print_scheduler.py @@ -11,7 +11,7 @@ from sqlalchemy import func, select from sqlalchemy.ext.asyncio import AsyncSession from backend.app.core.config import settings -from backend.app.core.database import async_session +from backend.app.core.database import async_session, run_with_retry from backend.app.models.archive import PrintArchive from backend.app.models.library import LibraryFile from backend.app.models.print_queue import PrintQueueItem @@ -32,6 +32,15 @@ from backend.app.utils.printer_models import normalize_printer_model logger = logging.getLogger(__name__) +# Bambu firmware states that mean the project_file has actually been accepted +# and the printer is now processing / running / paused mid-print. Used by the +# dispatch watchdog (#1370): a transition into one of these states means the +# print landed, anything else (e.g. FINISH -> IDLE after the user dismisses +# a post-print prompt) is NOT a valid "command landed" signal even though the +# state value did change. SLICING is included because some firmwares park +# briefly in SLICING between PREPARE and RUNNING while parsing the g-code. +_ACTIVE_PRINT_STATES: frozenset[str] = frozenset({"PREPARE", "SLICING", "RUNNING", "PAUSE"}) + # Filament type equivalence groups — types within the same group are # interchangeable on the printer side (Bambu Lab firmware treats them as compatible). _FILAMENT_TYPE_GROUPS: list[list[str]] = [ @@ -2029,27 +2038,66 @@ class PrintScheduler: scheduler._release_dispatch_hold(printer_id) return last_status = status - if status.state != pre_state: - # Printer picked up the job (state transition) — release the + if status.state in _ACTIVE_PRINT_STATES: + # Printer is actively processing the job — release the # post-dispatch hold so the next pending item for this printer - # can be evaluated normally. + # can be evaluated normally. We do NOT accept arbitrary state + # transitions: a printer going FINISH -> IDLE (user dismissed + # the post-print prompt without accepting our project_file) + # would otherwise look like "command landed" and leave the + # queue item stuck in 'printing' forever (#1370). scheduler._release_dispatch_hold(printer_id) return if pre_subtask_id is not None and status.subtask_id is not None and status.subtask_id != pre_subtask_id: - # Printer picked up the job (subtask_id advanced) + # Printer picked up the job (subtask_id advanced). H2D can + # sit at FINISH for ~50 s after accepting project_file + # before transitioning to PREPARE, but the subtask_id flips + # to our submission_id almost immediately (#1078). scheduler._release_dispatch_hold(printer_id) return # No transition. Revert the item so the scheduler can retry. # Drop the in-memory hold so the retry isn't blocked by it. scheduler._release_dispatch_hold(printer_id) - async with async_session() as db: + + # Three outcomes from the revert attempt, each routed differently: + # "reverted": row flipped from printing -> pending, run recovery + # "already_moved_on": item.status != 'printing' (completed/cancelled by + # on_print_complete or user). Skip recovery entirely + # — the print clearly landed somewhere even if the + # watchdog didn't see the active-state transition. + # "revert_failed": SQLite contention exhausted retries. Still run + # recovery so the MQTT session gets a fresh client_id + # on the half-broken-session path. + async def _do_revert(db): item = await db.get(PrintQueueItem, queue_item_id) if not item or item.status != "printing": - return # Already moved on (completed/cancelled/etc.) + return "already_moved_on" item.status = "pending" item.started_at = None await db.commit() + return "reverted" + + try: + revert_outcome = await run_with_retry(_do_revert, label=f"watchdog revert item={queue_item_id}") + except Exception as e: + logger.warning( + "Queue item %s: failed to revert to 'pending' (printer %d): %s — " + "scheduler may keep treating this item as in-flight", + queue_item_id, + printer_id, + e, + ) + revert_outcome = "revert_failed" + + if revert_outcome == "already_moved_on": + # Preserves the pre-#1370 early-return: if on_print_complete (or any + # other path) already moved the item past 'printing', don't run the + # MQTT session-recovery logic below — a forced reconnect on a healthy + # session breaks ongoing prints on the same printer. + return + + if revert_outcome == "reverted": logger.warning( "Queue item %s: printer %d did not respond to print command within " "%.0fs (state still %s, subtask_id still %s) — reverted to 'pending' " diff --git a/backend/app/services/printer_manager.py b/backend/app/services/printer_manager.py index 0ec263c15..06d99633e 100644 --- a/backend/app/services/printer_manager.py +++ b/backend/app/services/printer_manager.py @@ -269,14 +269,16 @@ class PrinterManager: ) async def _persist_awaiting_plate_clear(self, printer_id: int, awaiting: bool): - from backend.app.core.database import async_session + from backend.app.core.database import run_with_retry + + async def _do(db): + printer = await db.get(Printer, printer_id) + if printer is not None: + printer.awaiting_plate_clear = awaiting + await db.commit() try: - async with async_session() as db: - printer = await db.get(Printer, printer_id) - if printer is not None: - printer.awaiting_plate_clear = awaiting - await db.commit() + await run_with_retry(_do, label=f"persist awaiting_plate_clear printer={printer_id}") except Exception as e: logger.warning("Failed to persist awaiting_plate_clear for printer %d: %s", printer_id, e) diff --git a/backend/tests/unit/services/test_background_dispatch_watchdog.py b/backend/tests/unit/services/test_background_dispatch_watchdog.py index 3ecc23767..f800e25f5 100644 --- a/backend/tests/unit/services/test_background_dispatch_watchdog.py +++ b/backend/tests/unit/services/test_background_dispatch_watchdog.py @@ -99,6 +99,68 @@ class TestReturnsFalseOnTimeout: assert result is False client.force_reconnect_stale_session.assert_called_once() + @pytest.mark.asyncio + async def test_returns_false_on_finish_to_idle_user_dismissed_prompt(self): + """Regression for #1370 in the direct-dispatch path: when pre_state is + FINISH and the printer transitions to IDLE during the verifier window, + that's the user dismissing a post-print prompt — NOT acceptance of our + project_file. The original ``state != pre_state`` check incorrectly + returned True on this transition, so the dispatch job was marked + successful even though no print was running. Must now report failure + so the caller raises RuntimeError and the user sees the actual error. + """ + get_status = MagicMock(return_value=_status("IDLE", "OLD_SUBTASK")) + client = MagicMock() + get_client = MagicMock(return_value=client) + + with ( + patch( + "backend.app.services.background_dispatch.printer_manager.get_status", + get_status, + ), + patch( + "backend.app.services.background_dispatch.printer_manager.get_client", + get_client, + ), + ): + result = await BackgroundDispatchService._verify_print_response( + printer_id=42, + printer_name="P1S", + pre_state="FINISH", + pre_subtask_id="OLD_SUBTASK", + timeout=0.2, + poll_interval=0.05, + ) + + assert result is False, ( + "FINISH -> IDLE is the user dismissing a screen prompt, not the " + "printer accepting project_file — verifier must report failure (#1370)" + ) + + @pytest.mark.asyncio + async def test_returns_true_on_each_active_print_state(self): + """Counterpart to the #1370 fix: transitions into the active-print + state set ARE valid "command landed" signals. PREPARE / SLICING / + RUNNING / PAUSE all return True. + """ + for active_state in ("PREPARE", "SLICING", "RUNNING", "PAUSE"): + get_status = MagicMock(return_value=_status(active_state, "OLD_SUBTASK")) + with patch( + "backend.app.services.background_dispatch.printer_manager.get_status", + get_status, + ): + result = await BackgroundDispatchService._verify_print_response( + printer_id=42, + printer_name="P1S", + pre_state="IDLE", + pre_subtask_id="OLD_SUBTASK", + timeout=0.2, + poll_interval=0.05, + ) + assert result is True, ( + f"transition IDLE -> {active_state} must be treated as a valid 'command landed' signal" + ) + @pytest.mark.asyncio async def test_returns_false_when_pre_subtask_id_none_and_state_unchanged(self): """Backward-compat: callers without a captured pre_subtask_id (e.g. the diff --git a/backend/tests/unit/test_scheduler_watchdog.py b/backend/tests/unit/test_scheduler_watchdog.py index aac226a42..deea7cc0d 100644 --- a/backend/tests/unit/test_scheduler_watchdog.py +++ b/backend/tests/unit/test_scheduler_watchdog.py @@ -118,6 +118,7 @@ class TestWatchdogRevertsWhenStuck: patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1, @@ -135,6 +136,87 @@ class TestWatchdogRevertsWhenStuck: client.force_reconnect_stale_session.assert_called_once() + @pytest.mark.asyncio + async def test_reverts_on_finish_to_idle_user_dismissed_prompt(self, db_session): + """Regression for #1370: when pre_state is FINISH and the printer + transitions to IDLE during the watchdog window, that's the user + dismissing a post-print prompt — NOT acceptance of our project_file. + + The bundle in #1370 showed exactly this: queue item dispatched while + printer was in FINISH (residual from a previous print), command sent + but silently rejected by firmware, then the user manually cleared + the screen prompt so the printer moved to IDLE. The original + ``state != pre_state`` check returned early on this transition and + the queue row was left stuck in 'printing' indefinitely, blocking + all future dispatches to that printer. + + The watchdog now only treats transitions into the active-print + state set (PREPARE / SLICING / RUNNING / PAUSE) as a valid "command + landed" signal. + """ + get_status = MagicMock(return_value=_status("IDLE", "OLD_SUBTASK")) + client = MagicMock() + get_client = MagicMock(return_value=client) + + with ( + patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), + patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), + patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), + ): + await PrintScheduler._watchdog_print_start( + queue_item_id=1, + printer_id=42, + pre_state="FINISH", + pre_subtask_id="OLD_SUBTASK", + timeout=0.2, + poll_interval=0.05, + ) + + async with db_session() as db: + item = await db.get(PrintQueueItem, 1) + assert item.status == "pending", ( + "FINISH -> IDLE is the user dismissing a screen prompt, not " + "the printer accepting project_file — item must be reverted " + "to 'pending' so the scheduler can retry (#1370)" + ) + assert item.started_at is None + + @pytest.mark.asyncio + async def test_does_not_revert_on_pickup_via_active_state(self, db_session): + """Counterpart to the #1370 fix: transitions into the active-print + state set ARE a valid "command landed" signal. PREPARE / SLICING / + RUNNING / PAUSE all keep the item in 'printing'. + """ + for active_state in ("PREPARE", "SLICING", "RUNNING", "PAUSE"): + async with db_session() as db: + item = await db.get(PrintQueueItem, 1) + item.status = "printing" + item.started_at = None + await db.commit() + + get_status = MagicMock(return_value=_status(active_state, "OLD_SUBTASK")) + with ( + patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), + patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), + ): + await PrintScheduler._watchdog_print_start( + queue_item_id=1, + printer_id=42, + pre_state="IDLE", + pre_subtask_id="OLD_SUBTASK", + timeout=0.2, + poll_interval=0.05, + ) + + async with db_session() as db: + item = await db.get(PrintQueueItem, 1) + assert item.status == "printing", ( + f"transition IDLE -> {active_state} must be treated as a " + f"valid 'command landed' signal — watchdog must not revert" + ) + @pytest.mark.asyncio async def test_default_timeout_is_90_seconds(self): """The default timeout must cover slow H2D FINISH→PREPARE transitions @@ -163,6 +245,7 @@ class TestWatchdogFallbackBehaviour: patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1, @@ -190,6 +273,7 @@ class TestWatchdogFallbackBehaviour: patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1, @@ -231,7 +315,12 @@ class TestWatchdogFallbackBehaviour: async def test_no_revert_if_item_already_completed(self, db_session): """If the print completed between watchdog arm-time and timeout (item is no longer "printing"), the watchdog must not clobber whatever status it - ended up in — #967 race guard.""" + ended up in — #967 race guard. Additionally it must NOT run the MQTT + session-recovery path (forced reconnect): when on_print_complete has + already moved the row, the print clearly landed on the printer and a + forced reconnect on a healthy session would break ongoing prints on + the same printer. + """ # Move item on to "completed" before the watchdog fires. async with db_session() as db: item = await db.get(PrintQueueItem, 1) @@ -239,12 +328,14 @@ class TestWatchdogFallbackBehaviour: await db.commit() get_status = MagicMock(return_value=_status("FINISH", "OLD_SUBTASK")) - get_client = MagicMock(return_value=None) + client = MagicMock() # NOT None — must verify reconnect isn't called + get_client = MagicMock(return_value=client) with ( patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1, @@ -259,6 +350,8 @@ class TestWatchdogFallbackBehaviour: item = await db.get(PrintQueueItem, 1) assert item.status == "completed" # untouched + client.force_reconnect_stale_session.assert_not_called() + class TestGcodeFileDiscriminator: """#1150 vs #887/#936: skip the forced reconnect when gcode_file changed @@ -278,6 +371,7 @@ class TestGcodeFileDiscriminator: patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1, @@ -308,6 +402,7 @@ class TestGcodeFileDiscriminator: patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), patch("backend.app.services.print_scheduler.printer_manager.get_client", get_client), patch("backend.app.services.print_scheduler.async_session", db_session), + patch("backend.app.core.database.async_session", db_session), ): await PrintScheduler._watchdog_print_start( queue_item_id=1,