From d7093c7fe4878a569dbd544b67c23aa82e48076d Mon Sep 17 00:00:00 2001 From: maziggy Date: Sat, 18 Jul 2026 16:41:15 +0200 Subject: [PATCH] fix(dispatch): don't send start-print to a busy printer; scheduler defers (#2598) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit start_print() published project_file guarding only on connection state, so a re-dispatch onto a printer that had already started — e.g. a watchdog revert (#2555) after the printer sat in FINISH past accepting the job — collided with the live print. The firmware answers 0500_4004 ("Device is busy and cannot start a new task"), which on an A1 mini cancels the running job. Defense-in-depth at the paths that can reach a busy printer: - bambu_mqtt: refuse to publish project_file when gcode_state is PREPARE/SLICING/RUNNING/PAUSE and return without sending. This is the one publish choke point every dispatch path funnels through (queue scheduler, manual start, webhook, Virtual-Printer forward). IDLE/FINISH/FAILED still start. - print_scheduler: re-check the live printer state right before the FTP upload and defer a busy printer (leave the item pending for a later tick) instead of uploading and dispatching. If the printer goes busy in the upload window and the start is refused, revert the item to pending rather than marking it failed — a busy printer is a deferral, not a failure. A transport-level MQTT QoS-1 replay on reconnect would bypass the client guard, but the dispatch/watchdog reconnect path already hard-resets the client with a fresh session, so it has no inflight project_file to replay. --- CHANGELOG.md | 1 + backend/app/services/bambu_mqtt.py | 32 ++++ backend/app/services/print_scheduler.py | 45 +++++ .../test_start_print_busy_guard_2598.py | 60 +++++++ .../unit/test_scheduler_busy_defer_2598.py | 159 ++++++++++++++++++ 5 files changed, 297 insertions(+) create mode 100644 backend/tests/unit/services/test_start_print_busy_guard_2598.py create mode 100644 backend/tests/unit/test_scheduler_busy_defer_2598.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 9e2c5f8f3..be198a94a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,7 @@ All notable changes to Bambuddy will be documented in this file. - **Orca Cloud profile sync now connects by approving a code instead of the copy-paste sign-in** — Connecting Bambuddy to Orca Cloud used to mean opening an OAuth sign-in in a new tab, watching it redirect to a `localhost` URL that fails to load, then copying that dead URL out of the address bar and pasting it back into Bambuddy. That dance existed only because Orca's auth backend (Supabase) accepts no redirect target other than `localhost`, and the deliberately-broken redirect page confused nearly everyone who reached it. OrcaSlicer has since shipped a first-class external-app pairing API (the OAuth 2.0 Device Authorization Grant, RFC 8628), so the flow is now: click **Connect**, approve a short code on your Orca Cloud settings page, and Bambuddy pairs itself — no redirect, no paste, no client secret, and it behaves identically from a LAN IP, `localhost`, or behind a reverse proxy. Bambuddy requests **read-only** access (it only lists and views your Orca Cloud profiles), keeps the pairing alive with the API's rotating refresh tokens (validated end-to-end against Orca's staging and production servers), and stores nothing beyond the issued token pair. The profile list and detail views are unchanged, so nothing downstream of the connect step looks different. The old paste-based sign-in and the email/password fallback are removed. Points at production Orca Cloud by default; `ORCA_CLOUD_API_BASE` overrides the endpoint for testing. ### Fixed +- **A start-print dispatched to an already-busy printer could cancel the running job (#2598, reporter @khaosdoctor)** — On an A1 mini across a night of prints, jobs were cancelled with no apparent cause; debug logs showed Bambuddy sending `project_file` twice ~3 minutes apart with no completion between, and the printer answering `0500_4004` ("Device is busy and cannot start a new task") — which on that model cancels the RUNNING print. **Root cause.** `start_print()` in the MQTT client guarded only on connection state (`self._client and self.state.connected`) — it published `project_file` with no check on the printer's `gcode_state`. The scheduler *does* gate dispatch on an idle check, but that check treats `FINISH` as idle, and a printer can keep reporting `FINISH` for tens of seconds *after* it accepted a `project_file`; combined with a dispatch watchdog that reverts a queue item and releases its dispatch hold when it doesn't observe the active-state transition in time (#2555), a re-selected item could reach the FTP upload while the printer had actually started, so the start command landed on a live print. **Fix (defense-in-depth).** (a) `start_print()` now refuses to publish `project_file` when the printer is in an active state (`PREPARE` / `SLICING` / `RUNNING` / `PAUSE`) and returns without sending — a single guard at the one publish choke point that every dispatch path (queue, manual, webhook, Virtual-Printer forward) funnels through. `IDLE` / `FINISH` / `FAILED` remain valid start targets. (b) The scheduler re-checks the live printer state right before the FTP upload and *defers* a busy printer (leaves the item pending for a later tick) instead of uploading and dispatching — no wasted transfer, no collision. (c) If the printer goes busy during the upload window and the start command is refused, the scheduler reverts the item to pending (a deferral) rather than marking it failed — a busy printer is not a failure. Covered by tests for the client-level guard (refused while busy, published while idle, guard precedes the connection check) and the scheduler deferring both before the upload and after a busy-refused start. Note: a transport-level MQTT QoS-1 replay on reconnect would bypass the client guard, but the dispatch/watchdog reconnect path already hard-resets the client with a fresh session so it has no inflight `project_file` to replay. - **Three more idle-in-transaction / thundering-herd paths surfaced by continued farm testing (#2572, reporter @Jostxxl)** — On `origin/dev` with 93 printers and multiple concurrent UI clients the reporter timestamp-correlated the surviving pool pressure to three remaining paths, none of them auth-related. **(a) The scheduler held its per-item session across preheat and the FTP upload.** `_dispatch_selected` opens one `async_session` per queue item and hands it to `_start_print`, which reads the printer/archive rows up front and then runs the preheat/heat-soak wait and the FTP delete+upload — all on the transaction opened by those first `SELECT`s. One correlated session's last statement was a `settings` `SELECT` at the exact moment the log showed "Starting queue item" → preheat → "FTP upload started" for a 96 MB 3MF; the transaction stayed open for the whole transfer. (This refines the earlier note that the scheduler paths were "already bounded" — the per-item session itself was the hold.) `_start_print` now commits right before the FTP delete/upload, and `_preheat_and_soak` commits after its read phase and before the up-to-15-minute soak wait (both loops touch only `printer_manager` state and `asyncio.sleep`, no DB). `expire_on_commit=False` keeps the loaded rows readable; the status writes afterward (upload-failure path and the pending→printing CAS) transparently open a fresh transaction. **(b) `/cloud/filament-info` held its request session across sequential Bambu Cloud round-trips and single-flighted nothing.** The route took its session via `Depends(get_db)` (held for the whole request), read the stored token, then looped over the uncached ids issuing one external `get_setting_detail` HTTP call each — so the session sat idle-in-transaction across N cloud calls, and because the printer overview mounts one filament-info request per printer card, several browsers hit the same uncached preset at once and each issued its own cloud call. The route now releases the transaction (`rollback`) right after the token read and before the cloud loop (Phase 3's local-preset read reopens a fresh one), and concurrent misses for the same id single-flight through one shared cloud call. **(c) `/printers/{id}/cover` had no in-flight coalescing.** The connection was already released before the download, but simultaneous clients could all miss the cache and each run the full multi-path FTP lookup + 3MF extraction (one observed transfer pulled an 81 MB 3MF while real print uploads were in flight). Identical concurrent cover requests now coalesce: the first becomes the leader and the rest await it, then serve from the positive/negative cache it filled. Also adds `pool_use_lifo` (PostgreSQL default on, `DB_POOL_USE_LIFO` override, shown in `/system/db-pool`) so a bursty farm keeps a small hot connection set busy and lets excess overflow connections age out via `pool_recycle` instead of churning the whole pool. Covered by tests: the scheduler releasing its connection before both the FTP upload and the soak wait, the filament-info single-flight (concurrent misses share one cloud call, cache-hit skips cloud, a failed fetch leaves no stuck in-flight entry), and concurrent cover requests downloading once. - **An "Any [model]" queue job dispatched from a Virtual Printer printed to the empty external spool and aborted at layer 0 (#2595, diagnosed by @Sawtaytoes, PR #2596)** — On a farm of identical X1Cs with different filaments loaded per AMS, the intended flow — VP in Queue mode, auto-dispatch, target **Any X1C**, force-colour-match picks the printer that has the right spool — sent the job to the correctly-matched printer and then failed: the printer ignored the AMS, pulled the empty external spool, and aborted with "not enough filament", even though the mapped slot was loaded (the same print via a specific printer, or straight from the slicer, worked). **Root cause.** A slicer talking to a Virtual Printer only ever sees the VP's external spool — a VP advertises no AMS — so the slicer sends `use_ams=false`, and VP intake stamps that onto the queue item. But an "Any [model]" item is colour-matched to a real printer *at dispatch*, resolving a real AMS slot in `ams_mapping`; the scheduler still forwarded the stale `use_ams=false`. The print-command builder only ever forced `use_ams` **off** (the all-external case) and never back **on**, so `use_ams=false` shipped alongside `ams_mapping=[]` → external spool → abort. **Fix.** For single-nozzle printers the resolved mapping is now authoritative: a real AMS tray (0-253) forces `use_ams=true`; an explicit external selection (254/255) still forces it false; an unresolved `-1` mapping does neither (preserving the #2589 contract — it should have been recomputed upstream, and must not be silently promoted to AMS or downgraded to external). Dual-nozzle printers are untouched, where `use_ams` encodes nozzle routing rather than an on/off flag. Because the correction lives at the single command-builder choke point, it fixes the VP, queue, and manual paths alike. Covered by tests for the VP `false`+real-tray promotion, padded mappings, all-external staying off, unresolved `-1` staying put, the original all-external downgrade, and the dual-nozzle bypass. - **Reconnecting or restarting inflated Stats → Total Print Time by hundreds of hours on large farms (#2592, reporter @Jostxxl)** — On the reporter's farm a restart pushed Total Print Time from ~1,500h to 3,215h. When a printer reconnects, the connected edge runs `reconcile_stale_active_prints`, which closes out every archive still stuck in `status="printing"` (missed completions, disconnects, restarts) by synthesising an aborted `on_print_complete`. That wrote a `PrintLogEntry` whose duration was `completed_at - started_at` — but for a reconciled archive the real end time is unknown: the print stopped somewhere during the disconnect, and `completed_at` is only the reconnect moment. So each stale archive banked its entire multi-day gap as print time (one row was 51.9h), and a printer with several stale archives contributed hundreds of fabricated hours at once. Worse, the Stats total *recomputed* `completed_at - started_at` whenever the stored duration was falsy, so storing NULL wouldn't have helped. Reconciled completions now log an explicit `duration_seconds = 0` (honest "no measured runtime") and the two Stats time paths trust a stored 0 instead of recomputing from the stale timestamps — legacy rows that never recorded a duration still fall back as before. Reconciled aborts also get a truthful `failure_reason` ("Stale - reconciled after reconnect, end time unknown") instead of being mislabelled "User cancelled". Genuine long prints are untouched: nothing is capped, a still-running >24h print is never treated as stale, and a real >24h run keeps its full measured duration. Re-running reconciliation is already idempotent (the archive flips to `aborted`, so it isn't re-selected). Existing inflated rows from before this fix are not auto-corrected — they're indistinguishable from real cancellations in the database, and a blanket cap would clobber genuine long prints; the reporter repaired his own rows by hand. Covered by tests for the multi-day reconcile, multiple stale archives per printer, a retained >24h print, and the Stats total ignoring reconciled time while still counting real runtime. diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 639b5d0a5..35b18662a 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -32,6 +32,14 @@ logger = logging.getLogger(__name__) # "n3s/" – AMS HT (H2D Pro and similar; IDs typically start at 128) _AMS_MODULE_PREFIXES = ("ams/", "n3f/", "n3s/") +# gcode_state values that mean the printer is not idle and must not be handed a +# new start-print (#2598). The firmware rejects a project_file while busy with +# 0500_4004 "Device is busy and cannot start a new task", and on some models +# (A1 mini reported) that error cancels the RUNNING job. IDLE / FINISH / FAILED +# are valid start targets and are deliberately excluded. Mirrors +# printer_manager.ACTIVE_PRINT_STATES and print_scheduler._ACTIVE_PRINT_STATES. +_ACTIVE_PRINT_STATES = frozenset({"PREPARE", "SLICING", "RUNNING", "PAUSE"}) + def parse_ams_filament_backup_from_cfg(cfg_raw: object) -> bool | None: """Extract AMS Filament Backup state from a Bambu push_status ``print.cfg`` value. @@ -3851,7 +3859,31 @@ class BambuMQTTClient: firmware honours the user's slicer pick instead of falling back to "last matching nozzle" auto-pick. Silently ignored on single-nozzle printers. + + Returns True when the start command was published, False otherwise + (not connected, or the printer is already busy — see the run-state + guard below). """ + # Never dispatch project_file to a printer that is not idle (#2598). + # This is the single publish choke point for every dispatch path — the + # queue scheduler, a manual start, a webhook, and a Virtual-Printer + # forwarded job all funnel through here — so one guard covers them all. + # The firmware rejects a start while busy with 0500_4004 ("Device is + # busy and cannot start a new task"), and on an A1 mini that error + # cancels the RUNNING job (#2598). IDLE / FINISH / FAILED are valid + # start targets; only the active-print states are refused. (A + # transport-level QoS-1 replay on reconnect would bypass this guard, + # but the dispatch/watchdog reconnect path hard-resets the client with a + # fresh client_id, so paho has no inflight project_file to replay there.) + if self.state.state in _ACTIVE_PRINT_STATES: + logger.warning( + "[%s] start_print refused: printer busy (gcode_state=%s) — not publishing project_file for %s", + self.serial_number, + self.state.state, + filename, + ) + return False + if self._client and self.state.connected: # Bambu print command format — matches Bambu Studio's format. # The calibration/leveling fields (timelapse, bed_leveling, diff --git a/backend/app/services/print_scheduler.py b/backend/app/services/print_scheduler.py index c9b0ed495..95fbc54da 100644 --- a/backend/app/services/print_scheduler.py +++ b/backend/app/services/print_scheduler.py @@ -2868,6 +2868,28 @@ class PrintScheduler: ) return + # Busy-printer guard (#2598). check_queue gates dispatch on + # _is_printer_idle(), but that treats FINISH as idle and a printer can + # keep reporting FINISH for tens of seconds *after* it accepted a + # project_file (see the watchdog's phase-B note). A watchdog revert + # (#2555) also releases the dispatch hold, so a re-selected item can + # reach here while its printer has actually started printing. Uploading + # and dispatching then collides with the live job — the firmware answers + # 0500_4004 and, on an A1 mini, cancels the running print. Re-check the + # live state right before the expensive FTP upload: if the printer is + # busy, leave the item pending and let a later tick dispatch it once the + # printer is genuinely idle. No wasted upload, no collision. + pre_dispatch_state = getattr(printer_manager.get_status(item.printer_id), "state", None) + if pre_dispatch_state in _ACTIVE_PRINT_STATES: + logger.info( + "Queue item %s: printer %s is busy (state=%s) — deferring dispatch, " + "leaving item pending for a later tick (#2598)", + item.id, + item.printer_id, + pre_dispatch_state, + ) + return + # Determine source: archive or library file archive = None library_file = None @@ -3447,6 +3469,29 @@ class PrintScheduler: except Exception: pass # Best-effort — don't fail the error handler + # Busy-refusal is a deferral, not a failure (#2598). The printer's + # state can flip from idle to active in the window between the + # pre-dispatch check above and this publish (the FTP upload takes + # seconds); start_print() then refuses to send project_file to the + # now-busy printer and returns False. Failing the item here would be + # wrong — the printer is fine, it is simply busy — so revert to + # pending and let a later tick dispatch it once the printer is idle, + # exactly like the pre-dispatch guard. Only a start_print() False on + # an idle/unknown printer is a genuine command failure. + post_dispatch_state = getattr(printer_manager.get_status(item.printer_id), "state", None) + if post_dispatch_state in _ACTIVE_PRINT_STATES: + logger.info( + "Queue item %s: printer %s became busy (state=%s) before the start " + "command was sent — deferring, reverting item to pending (#2598)", + item.id, + item.printer_id, + post_dispatch_state, + ) + item.status = "pending" + item.started_at = None + await db.commit() + return + # Print command failed - revert status item.status = "failed" item.error_message = "Failed to send print command to printer" diff --git a/backend/tests/unit/services/test_start_print_busy_guard_2598.py b/backend/tests/unit/services/test_start_print_busy_guard_2598.py new file mode 100644 index 000000000..c26f562a8 --- /dev/null +++ b/backend/tests/unit/services/test_start_print_busy_guard_2598.py @@ -0,0 +1,60 @@ +"""start_print() must not publish project_file to a busy printer (#2598). + +The firmware rejects a start command while the printer is not idle with +0500_4004 ("Device is busy and cannot start a new task"), and on an A1 mini +that error cancels the RUNNING job. Because every dispatch path (queue +scheduler, manual start, webhook, Virtual-Printer forward) funnels through +BambuMQTTClient.start_print, a run-state guard here covers them all. + +IDLE / FINISH / FAILED are valid start targets; only PREPARE / SLICING / +RUNNING / PAUSE are refused. +""" + +import json +from unittest.mock import MagicMock + +import pytest + +from backend.app.services.bambu_mqtt import BambuMQTTClient + + +def _connected_client() -> BambuMQTTClient: + client = BambuMQTTClient(ip_address="127.0.0.1", serial_number="TEST123", access_code="12345678") + client._client = MagicMock() + client.state.connected = True + return client + + +@pytest.mark.parametrize("busy_state", ["RUNNING", "PREPARE", "PAUSE", "SLICING"]) +def test_start_print_refused_when_printer_busy(busy_state): + client = _connected_client() + client.state.state = busy_state + + result = client.start_print("job.3mf") + + assert result is False, f"start_print should refuse while {busy_state}" + client._client.publish.assert_not_called() + + +@pytest.mark.parametrize("idle_state", ["IDLE", "FINISH", "FAILED"]) +def test_start_print_publishes_when_printer_idle(idle_state): + client = _connected_client() + client.state.state = idle_state + + result = client.start_print("job.3mf") + + assert result is True, f"start_print should proceed while {idle_state}" + client._client.publish.assert_called_once() + topic, payload = client._client.publish.call_args.args[:2] + assert json.loads(payload)["print"]["command"] == "project_file" + + +def test_busy_guard_takes_precedence_over_disconnected(): + """A busy printer is refused even if the connection flag is stale/false — + the guard runs before the connection check, so no publish is attempted.""" + client = _connected_client() + client.state.connected = False + client.state.state = "RUNNING" + + assert client.start_print("job.3mf") is False + client._client.publish.assert_not_called() diff --git a/backend/tests/unit/test_scheduler_busy_defer_2598.py b/backend/tests/unit/test_scheduler_busy_defer_2598.py new file mode 100644 index 000000000..baea5f38b --- /dev/null +++ b/backend/tests/unit/test_scheduler_busy_defer_2598.py @@ -0,0 +1,159 @@ +"""The scheduler defers (never fails) a dispatch that hits a busy printer (#2598). + +check_queue gates dispatch on _is_printer_idle(), but that treats FINISH as +idle and a printer can keep reporting FINISH for tens of seconds after it +accepted a project_file; a watchdog revert (#2555) also releases the dispatch +hold. So a re-selected item can reach _start_print while its printer has +actually started printing. Two guards keep that from cancelling the live job: + +* pre-dispatch — before the FTP upload, a busy printer defers (item stays + pending), so there is no wasted upload and no start command; +* post-dispatch — if the printer goes busy in the upload window and + start_print() returns False, the item is reverted to pending (deferred), not + marked failed. +""" + +from contextlib import ExitStack +from pathlib import Path +from types import SimpleNamespace +from unittest.mock import AsyncMock, MagicMock, patch + +import pytest +from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine + +import backend.app.models # noqa: F401 - populate Base.metadata +import backend.app.services.print_scheduler as scheduler_module +from backend.app.core.database import Base +from backend.app.models.archive import PrintArchive +from backend.app.models.print_queue import PrintQueueItem +from backend.app.models.printer import Printer +from backend.app.services.print_scheduler import PrintScheduler + + +@pytest.fixture +async def dispatch_case(tmp_path): + engine = create_async_engine("sqlite+aiosqlite:///:memory:", echo=False) + async with engine.begin() as conn: + await conn.run_sync(Base.metadata.create_all) + session_maker = async_sessionmaker(engine, expire_on_commit=False) + + base_dir = tmp_path / "case" + base_dir.mkdir() + archive_rel = Path("archives") / "job.3mf" + archive_abs = base_dir / archive_rel + archive_abs.parent.mkdir(parents=True, exist_ok=True) + archive_abs.write_bytes(b"archive payload") + + async with session_maker() as db: + printer = Printer( + name="Printer", + serial_number="SERIAL", + ip_address="127.0.0.1", + access_code="access-code", + model="A1MINI", + ) + db.add(printer) + await db.flush() + archive = PrintArchive( + printer_id=printer.id, + filename="job.3mf", + file_path=str(archive_rel), + file_size=archive_abs.stat().st_size, + status="completed", + ) + db.add(archive) + await db.flush() + item = PrintQueueItem(printer_id=printer.id, archive_id=archive.id, status="pending") + db.add(item) + await db.commit() + ids = SimpleNamespace(printer_id=printer.id, archive_id=archive.id, item_id=item.id) + + try: + yield SimpleNamespace(session_maker=session_maker, base_dir=base_dir, ids=ids) + finally: + await engine.dispose() + + +def _base_patches(scheduler, ctx, upload_mock, start_print_mock, get_status): + return [ + patch.object(scheduler_module.settings, "base_dir", ctx.base_dir), + patch("backend.app.services.print_scheduler.printer_manager.is_connected", MagicMock(return_value=True)), + patch("backend.app.services.print_scheduler.printer_manager.get_status", get_status), + patch("backend.app.services.print_scheduler.printer_manager.start_print", start_print_mock), + patch("backend.app.services.print_scheduler.printer_manager.set_awaiting_plate_clear", MagicMock()), + patch( + "backend.app.services.print_scheduler.get_ftp_retry_settings", + AsyncMock(return_value=(False, 0, 0, 1.0)), + ), + patch("backend.app.services.print_scheduler.delete_file_async", AsyncMock(return_value=True)), + patch("backend.app.services.print_scheduler.upload_file_async", upload_mock), + patch("backend.app.services.print_scheduler.cache_3mf_download", MagicMock()), + patch("backend.app.services.print_scheduler.spawn_background_task", MagicMock()), + patch.object(scheduler, "_propagate_owner_to_printer_manager", AsyncMock()), + patch.object(scheduler, "_power_off_if_needed", AsyncMock()), + patch.object(scheduler, "_preheat_and_soak", AsyncMock()), + ] + + +async def _final_item(ctx): + async with ctx.session_maker() as db: + return await db.get(PrintQueueItem, ctx.ids.item_id) + + +@pytest.mark.asyncio +async def test_pre_dispatch_busy_defers_without_upload(dispatch_case): + """Printer already RUNNING when _start_print begins → defer, no upload/start.""" + scheduler = PrintScheduler() + upload = AsyncMock(return_value=True) + start_print = MagicMock(return_value=True) + get_status = MagicMock(return_value=SimpleNamespace(state="RUNNING", subtask_id=None, gcode_file=None)) + + async with dispatch_case.session_maker() as db: + item = await db.get(PrintQueueItem, dispatch_case.ids.item_id) + with ExitStack() as stack: + for p in _base_patches(scheduler, dispatch_case, upload, start_print, get_status): + stack.enter_context(p) + await scheduler._start_print(db, item) + + upload.assert_not_awaited() + start_print.assert_not_called() + final = await _final_item(dispatch_case) + assert final.status == "pending", "a busy printer must defer the item, not consume it" + + +@pytest.mark.asyncio +async def test_post_dispatch_busy_reverts_to_pending_not_failed(dispatch_case): + """Printer goes busy in the upload window; start_print returns False → defer.""" + scheduler = PrintScheduler() + upload = AsyncMock(return_value=True) + + holder = {"state": "IDLE"} + + class _Status: + subtask_id = None + gcode_file = None + + @property + def state(self): + return holder["state"] + + def _start_print(*args, **kwargs): + # The printer became busy between the pre-dispatch check and the publish. + holder["state"] = "RUNNING" + return False # start_print() refused: busy + + start_print = MagicMock(side_effect=_start_print) + get_status = MagicMock(return_value=_Status()) + + async with dispatch_case.session_maker() as db: + item = await db.get(PrintQueueItem, dispatch_case.ids.item_id) + with ExitStack() as stack: + for p in _base_patches(scheduler, dispatch_case, upload, start_print, get_status): + stack.enter_context(p) + await scheduler._start_print(db, item) + + upload.assert_awaited_once() # it proceeded past the (idle) pre-dispatch check + start_print.assert_called_once() + final = await _final_item(dispatch_case) + assert final.status == "pending", "a busy-refused start must defer, not fail the item" + assert final.started_at is None