Просмотр исходного кода

fix(cover): release the DB connection before the FTP thumbnail download (#2572)

GET /printers/{id}/cover took its printer row via Depends(get_db), whose
yield-dependency session stays open for the whole request — including the
3MF cover download (up to 8 remote paths x retries with backoff, minutes
under FTP contention). One pooled connection sat idle-in-transaction the
entire time; on a large farm a wall of dashboards drained the pool. The
route now fetches the printer in a short-lived async_session() and releases
the connection before the download (expire_on_commit=False keeps printer.*
readable). Pinned by a signature-inspection guard that fails if get_db is
ever re-added.

fix(print-start): release the DB connection across plate detection and 3MF download (#2572)

on_print_start held one session from top to bottom of the handler, across
two slow I/O blocks that need no database: the plate-detection camera grab
and, on the new-archive path, the multi-path 3MF FTP download (its own
comments cite worst cases of tens of minutes). The connection sat idle-in-
transaction for both, once per starting print. It now commits at each
boundary — only read SELECTs have run on those paths (every write branch
returns earlier), so the commit persists nothing and simply returns the
connection to the pool for the I/O; the next query re-acquires, and
expire_on_commit=False keeps printer.* readable.

fix(startup): connect to printers concurrently so the API serves within seconds (#2572)

init_printer_connections awaited each printer's connection serially, and
connect_printer ends in a fixed 1s settle wait. The MQTT connect is non-
blocking (connect_async + loop_start), so that 1s x fleet size was pure
serial dead air the FastAPI lifespan blocked on before uvicorn began
serving — ~100s before port 8000 responded on a 93-printer farm. The
connections are now started with asyncio.gather, so the step takes ~1s
regardless of fleet size. return_exceptions=True isolates each result: one
unreachable printer no longer aborts the rest, or startup itself.
maziggy 1 месяц назад
Родитель
Сommit
b8cd1ab22d

+ 3 - 0
CHANGELOG.md

@@ -12,6 +12,9 @@ All notable changes to Bambuddy will be documented in this file.
 - **Queue edit showed the sliced-for model as the scheduler target, and a cross-model queue row could dispatch G-code to an incompatible printer (#2578, reporter @Jostxxl)** — Two bugs with one root. The "Any \<model\>" assignment button labeled itself from the file's slice metadata while the scheduler actually used the row's `target_model`, so an X1C-sliced item targeting H2D read "Any X1C" above "Scheduler will assign to first available idle H2D printer". Worse, the mismatch could be *created* silently: the sliced-for model loads asynchronously, and clicking "Any Model" before it arrived pre-selected the first model alphabetically — on a mixed X1C/P1S/H2D farm that's H2D — after which the model dropdown hid itself, leaving no way to see or fix the wrong target. Nothing downstream checked compatibility, so the scheduler would happily hand X1C G-code to an H2D. Now: the target model is never silently defaulted (the dropdown stays visible in model mode, pre-selected to the sliced-for model when available, and back-fills once the metadata loads); the button reflects the actual target; a warning shows when the target differs from the sliced-for model. Compatibility is enforced end-to-end with an explicit G-code interchange family table (X1/X1C/X1E/P1P/P1S interchange; everything else exact-match — files without slice metadata are never blocked): incompatible models are disabled in the dropdown, queue create/update reject a mismatch with a clear 400 (so API-created rows can't sneak in), and the scheduler holds back pre-existing mismatched rows with an actionable waiting reason instead of dispatching them — fix the target via edit and the job flows again.
 - **Manual jog could drive an axis past its travel limit into a collision (#2579, reporter @R3play210)** — Jog the bed up from Bambuddy and, instead of stopping at the travel limit, it keeps going until the nozzle hits the plate; X/Y overrun too, on every model. Instrumenting the exact bytes sent to an H2D showed Bambuddy issuing a clean, correct move at the limit — `G91` / `G1 Z-1.00 F600` / `G90`, no endstop manipulation — that the printer executed straight past the stop, while the machine's **own touchscreen refuses the identical motion**. **This is a Bambu firmware bug: the firmware does not enforce its soft endstops on G-code received over MQTT** (the path every remote tool, Bambuddy included, must use), and it reports no axis position, so Bambuddy cannot know where the bed is to stop it either. It is not fixable from our side. Two things change here: (1) the jog no longer wraps moves in `M211 S0`/`S1` — the old code disabled the firmware's soft endstops *globally* around every jog, which also broke the **touchscreen's** limits until the printer was power-cycled; it now sends a bare move and never touches `M211`, so the touchscreen stays protected. (2) The jog panel now shows a prominent warning that travel limits are **not** enforced during manual moves because of this firmware bug, so nobody trusts the control to stop at the limit. Client-side travel-limit enforcement (dead-reckoning from a home) is tracked separately as the only real mitigation. If your printer currently overruns even from its touchscreen, power-cycle it once to restore the endstops an older Bambuddy build disabled.
 - **External spool kept its old inventory filament after the type was changed on the printer (#2575, reporter @ajbastien)** — Assigning a new filament to the external spool (e.g. generic ABS in place of generic TPU) left the previous inventory spool assigned, so an ABS spool stayed mapped to TPU. The reconciliation that unlinks a stale external-spool assignment lives in `on_ams_change`, but that callback only fired on changes to the regular AMS units — its change-hash never included the external spool (`vt_tray`/`vir_slot`), and the external-spool data is stored after the AMS handler runs. External-spool identity changes (type, colour, tag, or a reset to empty) now re-trigger the callback so the stale assignment is unlinked; the fill-percentage (`remain`) is deliberately excluded from the fingerprint so a running print doesn't fire it on every push. Follow-up: the auto-unlink now also broadcasts `spool_assignment_changed` for each cleared slot — previously only the manual assign/unassign endpoints did, so an open browser kept rendering the now-unlinked spool on the slot until an unrelated refetch, which read as "the fix didn't work" even though the server state was already correct (reporter confirmed a browser refresh showed the right state all along).
+- **The API didn't start serving for ~100 seconds on a large farm while it connected to printers one at a time (#2572, reporter @Jostxxl)** — On the reporter's 93-printer farm port 8000 didn't respond until roughly 100 seconds after the service started. The cause was in the FastAPI lifespan: `init_printer_connections` looped over every active printer and `await`ed each connection *serially*, and each `connect_printer` ends in a fixed one-second settle wait. The MQTT connect itself is non-blocking — `BambuMQTTClient.connect()` only calls `connect_async()` + `loop_start()`, so the handshake runs on a background thread — which means that one-second wait, times the fleet size, was pure serial dead air that the lifespan blocked on *before* the ASGI server began accepting requests. The connections are now started concurrently with `asyncio.gather`, so the whole step takes about a second regardless of how many printers you run, and the dashboard is reachable almost immediately. Each connection's result is also isolated (`return_exceptions=True`): a single unreachable printer no longer aborts the rest — or, as the old un-guarded serial `await` allowed, the entire startup. The MQTT clients still connect in the background exactly as before; only the startup wait is parallelized.
+- **The print-start handler held a DB connection open across plate detection and the 3MF download (#2572, reporter @Jostxxl)** — After farm-testing the first round of #2572 fixes the reporter still saw `idle in transaction` sessions lasting minutes, and traced one to `on_print_start`: its last statement was `SELECT print_archives…`, immediately followed in the log by the printer's own `on_print_start` → `Trying filenames` → FTP work. The handler opened a single database session at the top and held it to the very end of the function — across two slow I/O blocks that need no database: the optional plate-detection camera capture (a 2.5s chamber-light settle plus an FTP/RTSP grab) and, on the new-archive path, the 3MF FTP download itself (up to five remote paths per candidate filename, each with retry/backoff — the code's own comments cite worst cases of tens of minutes under FTP contention). So one pooled connection sat idle-in-transaction for the whole of both, once per starting print, and print starts cluster on a farm. The connection is now released at both boundaries: reaching either point, only read `SELECT`s have run on that path (every write branch returns earlier), so a commit persists nothing and simply ends the read transaction, returning the connection to the pool for the duration of the I/O; the next query re-acquires a fresh one, and `expire_on_commit=False` keeps the already-loaded `printer.*` columns readable with no lazy load. Behaviour is unchanged. Continues the #2572 effort (camera stream, timelapse scan, finish photo, notification snapshots) to stop holding sessions across slow I/O.
+- **The printer-cover endpoint held a DB connection open across the FTP thumbnail download (#2572, reporter @Jostxxl)** — The reporter's second correlation: a transaction whose last statement was `SELECT printers…`, matched in the log to the cover route (`Cover: resolved plate …` / `Trying to download cover … (trying 4 paths)`), still open more than three and a half minutes later. `GET /printers/{id}/cover` took its printer row via `Depends(get_db)`, and `get_db` is a `yield` dependency — its session stays open for the whole request, including the cover's 3MF download (up to eight remote paths × retries with backoff, minutes under the same single-FTP-socket contention that produces the 425s). The session was used for exactly one `SELECT`; everything after reads already-loaded `printer.*` scalars, `printer_manager`, and FTP/zip — no database. The endpoint now fetches the printer in a short-lived session and releases the connection *before* the download (`expire_on_commit=False` keeps the columns readable), mirroring the camera-stream fix. Pinned by a regression test that fails if a `get_db`-held session is ever re-added to the route.
 - **Queue polling re-parsed every 3MF from scratch on each poll (#2573, reporter @Jostxxl)** — The Queue page polls `GET /api/v1/queue/` every few seconds, and for each item with a `plate_id` the serializer called three separate helpers — `extract_print_time_from_3mf`, `extract_filament_usage_from_3mf`, `extract_bed_type_from_3mf` — each of which independently opened the item's ZIP and re-parsed `Metadata/slice_info.config`. With 22 queued items that is 66 ZIP-open + XML-parse operations per poll, run in the event-loop thread, repeated for *every* connected browser even though the files never changed. The three values now come from a single combined parse (`extract_plate_metadata_from_3mf`) cached by file revision — the key is `(path, plate_id, mtime_ns, size)`, so an unchanged file is parsed at most once and a replaced or edited file transparently re-parses with no manual invalidation. The three legacy helpers still exist (other callers use them) but now delegate to the same cached parse, so usage-tracking and Spoolman paths benefit too; the queue hot path calls the combined helper once per row. The cache is a bounded (512-entry) LRU guarded by a lock so it stays small and is safe from worker threads. Listing an unchanged queue now serializes DB data and does no repeat 3MF parsing. (The reporter's broader farm-scale asks — a WebSocket-delta queue, an initial snapshot endpoint, ETag/304 support, per-row plate-request batching — are a separate queue-page redesign, not part of this fix.)
 - **Progress-milestone and HMS-error notifications held a DB connection across the camera snapshot (#2572, reporter @Jostxxl)** — Both notification paths inside `on_printer_status_change` (the 25/50/75% milestone push and the new-HMS-error push) opened a database session, then captured a camera snapshot for the notification image — an up-to-15s RTSP grab — and sent the notification, all with the session held. So a pooled connection sat idle for the whole grab, per milestone/error, per printer; on a farm those fire constantly. The snapshot needs no database, so it now runs between two short sessions: one to read the printer name, then the grab with no connection held, then a fresh session for the notification send. Behaviour is unchanged; pinned by a test that fails if the snapshot ever runs while a session is open. The AMS-change notification path was left as-is for now (it holds a per-printer lock across its write and needs separate care). Continues the #2572 effort (camera stream, timelapse scan, finish photo).
 - **Finish-photo capture held a DB connection open across the whole camera grab (#2572, reporter @Jostxxl)** — When a print finishes, the background finish-photo task reads a couple of rows (the capture setting, the printer, the archive) and then runs a capture pipeline that can take tens of seconds — timelapse last-frame extraction, waiting up to 20s for the stage-22 producer, an external-camera HTTP grab, or a fresh RTSP shot. It held one database session open across that entire pipeline, so a pooled connection sat `idle in transaction` for the full capture, once per finishing print — and finishes cluster on a farm. It now reads what it needs in a short session, releases the connection, runs the capture with no session held, and re-opens a fresh short session only to append the photo to the archive. Behaviour is unchanged. Continues the #2572 effort (camera stream, timelapse scan) to stop holding sessions across slow I/O.

+ 16 - 3
backend/app/api/routes/printers.py

@@ -8,6 +8,7 @@ from fastapi.responses import Response
 from sqlalchemy import func, select
 from sqlalchemy.ext.asyncio import AsyncSession
 
+from backend.app.core import database
 from backend.app.core.auth import (
     RequireCameraStreamTokenIfAuthEnabled,
     RequirePermissionIfAuthEnabled,
@@ -952,7 +953,6 @@ def clear_cover_cache(printer_id: int) -> None:
 async def get_printer_cover(
     printer_id: int,
     view: str | None = None,
-    db: AsyncSession = Depends(get_db),
     _: None = RequireCameraStreamTokenIfAuthEnabled,
 ):
     """Get the cover image for the current print job.
@@ -961,8 +961,21 @@ async def get_printer_cover(
         view: Optional view type. Use "top" for top-down build plate view (useful for skip objects).
               Default returns angled 3D perspective view.
     """
-    result = await db.execute(select(Printer).where(Printer.id == printer_id))
-    printer = result.scalar_one_or_none()
+    # Fetch the printer in a short-lived session and release the pooled DB
+    # connection BEFORE the FTP download below. Previously this route took its
+    # row via Depends(get_db), whose session stays open for the whole request —
+    # so a 3MF cover download (up to 8 paths × 3 retries with backoff, minutes
+    # under FTP contention) pinned one pooled connection idle-in-transaction the
+    # entire time (issue #2572). db is used only for this one SELECT; everything
+    # after reads already-loaded printer.* scalars (expire_on_commit=False keeps
+    # them readable), printer_manager, and FTP/zip — no lazy loads.
+    #
+    # Reference async_session via the module so the maker is looked up at call
+    # time — keeps it in sync with reinitialize_database() and lets the test
+    # harness's patch of backend.app.core.database.async_session take effect.
+    async with database.async_session() as db:
+        result = await db.execute(select(Printer).where(Printer.id == printer_id))
+        printer = result.scalar_one_or_none()
     if not printer:
         raise HTTPException(404, "Printer not found")
 

+ 20 - 0
backend/app/main.py

@@ -2436,6 +2436,14 @@ async def on_print_start(printer_id: int, data: dict):
         )
         if printer and printer.plate_detection_enabled:
             logger.info("[PLATE CHECK] ENTERING plate detection code for printer %s", printer_id)
+            # Release the pooled DB connection before the plate-detection camera
+            # work (a 2.5s light-settle sleep + FTP/camera capture). Only the
+            # printer SELECT has run so far — nothing to persist — so this commit
+            # is a data-noop that ends the read transaction and returns the
+            # connection to the pool during the I/O (issue #2572). expire_on_commit
+            # =False keeps printer.* readable; on_plate_not_empty (rare) and the
+            # archive lookups below re-acquire a fresh connection on next execute.
+            await db.commit()
             try:
                 from backend.app.services.plate_detection import check_plate_empty
 
@@ -2959,6 +2967,18 @@ async def on_print_start(printer_id: int, data: dict):
 
         logger.info("Trying filenames: %s", possible_names)
 
+        # Release the pooled DB connection before the 3MF FTP download. Reaching
+        # here means none of the expected-/existing-archive write branches ran
+        # (they all return earlier) — only SELECTs have executed on this path, so
+        # this commit persists nothing; it ends the read transaction so the
+        # connection returns to the pool during the download. That download tries
+        # up to five remote paths per candidate filename with retry/backoff and
+        # can run for minutes under FTP contention; holding the session across it
+        # pinned one pooled connection idle-in-transaction (issue #2572). No DB
+        # work runs during the download — the new-archive writes below re-acquire
+        # a fresh connection, and expire_on_commit=False keeps printer.* readable.
+        await db.commit()
+
         # Try to find and download the 3MF file
         temp_path = None
         downloaded_filename = None

+ 30 - 3
backend/app/services/printer_manager.py

@@ -1320,9 +1320,36 @@ printer_manager = PrinterManager()
 
 
 async def init_printer_connections(db: AsyncSession):
-    """Initialize connections to all active printers."""
+    """Initialize connections to all active printers.
+
+    Connections are started concurrently. ``connect_printer()`` is non-blocking
+    apart from a fixed 1-second settle wait — ``BambuMQTTClient.connect()`` only
+    calls ``connect_async()`` + ``loop_start()``, so the handshake happens on a
+    background thread and the coroutine's only real cost is that ``sleep(1)``. A
+    serial loop therefore spent one whole second per printer inside the FastAPI
+    lifespan *before* the ASGI server begins serving: on a large farm that was
+    ~100s of dead air before port 8000 responded (issue #2572, reporter's
+    93-printer farm). Gathering overlaps the settle waits so the whole step takes
+    ~1s regardless of fleet size. Exceptions are isolated per printer with
+    ``return_exceptions=True`` so one unreachable row can't abort the rest — or
+    startup itself, which the old serial loop's un-caught await would have done.
+
+    All columns ``connect_printer`` reads are eagerly loaded by the SELECT above
+    and touched synchronously before its trailing ``await``, so no concurrent
+    lazy-load is triggered on the shared session.
+    """
     result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
     printers = result.scalars().all()
 
-    for printer in printers:
-        await printer_manager.connect_printer(printer)
+    outcomes = await asyncio.gather(
+        *(printer_manager.connect_printer(printer) for printer in printers),
+        return_exceptions=True,
+    )
+    for printer, outcome in zip(printers, outcomes, strict=True):
+        if isinstance(outcome, Exception):
+            logger.warning(
+                "Failed to connect printer %s (%s) at startup: %s",
+                printer.id,
+                printer.name,
+                outcome,
+            )

+ 26 - 0
backend/tests/integration/test_printers_api.py

@@ -571,6 +571,32 @@ class TestPrintersAPI:
     # ========================================================================
 
 
+class TestCoverPoolHygiene:
+    """Regression guard for the /cover DB-connection leak (issue #2572)."""
+
+    def test_cover_does_not_hold_a_get_db_session(self):
+        """The cover endpoint must NOT take a ``Depends(get_db)`` session.
+
+        ``get_db`` is a ``yield`` dependency, so its session stays open for the
+        whole request — including the 3MF cover download (up to 8 remote paths ×
+        retries with backoff, minutes under FTP contention), pinning one pooled
+        DB connection ``idle in transaction`` the entire time. The endpoint
+        fetches the printer in a short-lived ``async with async_session()`` and
+        releases the connection before the FTP work. If someone re-adds a
+        ``Depends(get_db)`` param, this fails.
+        """
+        import inspect
+
+        from backend.app.api.routes.printers import get_db, get_printer_cover
+
+        for name, param in inspect.signature(get_printer_cover).parameters.items():
+            dependency = getattr(param.default, "dependency", None)
+            assert dependency is not get_db, (
+                f"get_printer_cover re-introduced a get_db-held session via parameter {name!r} — "
+                "it would stay open for the entire FTP cover download (issue #2572)"
+            )
+
+
 class TestPrinterDataIntegrity:
     """Tests for printer data integrity."""
 

+ 31 - 0
backend/tests/unit/services/test_printer_manager.py

@@ -1804,6 +1804,37 @@ class TestInitPrinterConnections:
 
             mock_manager.connect_printer.assert_not_called()
 
+    @pytest.mark.asyncio
+    async def test_one_failing_printer_does_not_abort_the_rest(self):
+        """A single unreachable printer must not abort startup or the others (#2572).
+
+        The connections are gathered with return_exceptions=True. The old serial
+        ``await`` loop had no error handling, so the first printer that raised
+        propagated straight out of init_printer_connections and failed the
+        FastAPI lifespan — taking the whole app down over one bad row, and
+        skipping every printer after it. This asserts the isolation: every
+        printer is still attempted and the exception never escapes.
+        """
+        mock_db = AsyncMock()
+        printers = [MagicMock(id=i, name=f"p{i}", is_active=True) for i in range(3)]
+        mock_result = MagicMock()
+        mock_result.scalars.return_value.all.return_value = printers
+        mock_db.execute.return_value = mock_result
+
+        async def connect(printer):
+            if printer.id == 1:
+                raise ConnectionError("printer 1 is unreachable")
+            return True
+
+        with patch("backend.app.services.printer_manager.printer_manager") as mock_manager:
+            mock_manager.connect_printer = AsyncMock(side_effect=connect)
+
+            # Must not raise despite printer 1 failing.
+            await init_printer_connections(mock_db)
+
+            # All three were still attempted (not aborted at the failing one).
+            assert mock_manager.connect_printer.call_count == 3
+
 
 class TestAmsChangeCallback:
     """Tests for AMS change callback functionality."""