From a5176349ddfffd6d560ce14ee84b350009be4255 Mon Sep 17 00:00:00 2001 From: maziggy Date: Thu, 16 Jul 2026 09:20:12 +0200 Subject: [PATCH] fix(notifications): capture the snapshot outside the DB session (#2572) The progress-milestone and HMS-error notification paths in on_printer_status_change held a session across the ~15s camera snapshot taken for the notification image, pinning a pooled connection per milestone/error per printer. The snapshot needs no DB: read the printer in a short session, release it, grab the snapshot with none held, then open a fresh session for the notification send (and lift the db-free MQTT publish out too). Pinned by a test that fails if the snapshot runs while a session is open. --- CHANGELOG.md | 1 + backend/app/main.py | 93 ++++++++++--------- .../unit/test_printer_offline_notification.py | 78 ++++++++++++++++ 3 files changed, 130 insertions(+), 42 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 36267c96d..33ad56797 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes to Bambuddy will be documented in this file. ## [1.2.5b2] - Unreleased ### Fixed +- **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. - **Timelapse scan held a DB connection open across every FTP round-trip (#2572, reporter @Jostxxl)** — After a print completes, `_scan_for_timelapse_with_retries` polls the printer's FTP server for the new timelapse file (up to 4 retry attempts, plus a name-match fallback). Each attempt opened one database session and held it across the FTP directory listing *and* the multi-MB video download — so a pooled connection sat `idle in transaction` for the whole transfer, once per attempt, per completed print. When several prints finish together on a farm that adds up. The scan now reads the archive + printer in a short session, releases the connection, does the FTP list/download with no session held, and re-opens a fresh short session only to attach the downloaded file. Behaviour is unchanged; the existing scan tests already exercise the read→download→attach path. Continues the #2572 effort (after the camera-stream fix) to stop holding sessions across slow I/O; the scheduler paths were reviewed and found already bounded (single loop + capped concurrent uploads, with an explicit pre-dispatch commit) so they were left as-is. - **Live camera stream held a database connection open for its entire duration (#2572, reporter @Jostxxl)** — The `/camera/stream` MJPEG endpoint took its printer row via `Depends(get_db)`, but `get_db` is a `yield` dependency: its session isn't released until the response body finishes streaming, which for a live stream is however long the browser tab stays open — minutes to hours. On a large farm every open camera tile therefore pinned one pooled DB connection `idle in transaction`, so a wall of dashboards could drain the pool on its own (a top contributor to the exhaustion in #2572). The endpoint now fetches the printer in a short-lived session and releases the connection *before* it starts streaming (`expire_on_commit=False` keeps the already-loaded columns readable). Pinned by a regression test that fails if a `get_db`-held session is ever re-added to the route. Part of the broader effort to stop holding sessions across slow MQTT/FTP/camera/3MF work. diff --git a/backend/app/main.py b/backend/app/main.py index 46c8f1113..6f7d9c246 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -1236,21 +1236,25 @@ async def on_printer_status_change(printer_id: int, state: PrinterState): if current_milestone > last_milestone: _last_progress_milestone[printer_id] = current_milestone try: - async with async_session() as db: - from backend.app.models.printer import Printer + from backend.app.models.printer import Printer + # Read the printer in a short session and release the connection + # BEFORE the ~15s camera snapshot below — holding it across the grab + # pinned a pooled connection per milestone, per printer (issue #2572). + async with async_session() as db: result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() - printer_name = printer.name if printer else f"Printer {printer_id}" - filename = state.subtask_name or state.gcode_file or "Unknown" - # remaining_time is in minutes, convert to seconds for notification - remaining_time_seconds = state.remaining_time * 60 if state.remaining_time else None - # Capture camera snapshot for notification image attachment - image_data = await _capture_snapshot_for_notification( - printer_id, printer, logging.getLogger(__name__) - ) + printer_name = printer.name if printer else f"Printer {printer_id}" + filename = state.subtask_name or state.gcode_file or "Unknown" + # remaining_time is in minutes, convert to seconds for notification + remaining_time_seconds = state.remaining_time * 60 if state.remaining_time else None + # Capture camera snapshot for notification image attachment (no DB held). + image_data = await _capture_snapshot_for_notification(printer_id, printer, logging.getLogger(__name__)) + + # Notification send needs a session (provider/template lookups). + async with async_session() as db: await notification_service.on_print_progress( printer_id, printer_name, @@ -1293,30 +1297,35 @@ async def on_printer_status_change(printer_id: int, state: PrinterState): new_errors = [e for e in current_hms_errors if f"{e.attr:08x}" in new_error_codes and e.severity >= 2] try: - async with async_session() as db: - from backend.app.models.printer import Printer + from backend.app.models.printer import Printer + # Read the printer in a short session and release the connection + # BEFORE the ~15s camera snapshot below (issue #2572). + async with async_session() as db: result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() - printer_name = printer.name if printer else f"Printer {printer_id}" - # Format error details for notification - # Module 0x07 = AMS/Filament, 0x05 = Nozzle, 0x0C = Motion Controller, etc. - module_names = { - 0x03: "Print/Task", - 0x05: "Nozzle/Extruder", - 0x07: "AMS/Filament", - 0x0C: "Motion Controller", - 0x12: "Chamber", - } + printer_name = printer.name if printer else f"Printer {printer_id}" - from backend.app.services.hms_errors import get_error_description + # Format error details for notification + # Module 0x07 = AMS/Filament, 0x05 = Nozzle, 0x0C = Motion Controller, etc. + module_names = { + 0x03: "Print/Task", + 0x05: "Nozzle/Extruder", + 0x07: "AMS/Filament", + 0x0C: "Motion Controller", + 0x12: "Chamber", + } - # Capture camera snapshot once for all error notifications - error_image_data = await _capture_snapshot_for_notification( - printer_id, printer, logging.getLogger(__name__) - ) + from backend.app.services.hms_errors import get_error_description + # Capture camera snapshot once for all error notifications (no DB held). + error_image_data = await _capture_snapshot_for_notification( + printer_id, printer, logging.getLogger(__name__) + ) + + # Notification sends need a session (provider/template lookups). + async with async_session() as db: sent_count = 0 for error in new_errors: module_name = module_names.get(error.module, f"Module 0x{error.module:02X}") @@ -1345,21 +1354,21 @@ async def on_printer_status_change(printer_id: int, state: PrinterState): f"[HMS] Sent notification for {sent_count} error(s) on printer {printer_id}" ) - # Also publish to MQTT relay - printer_info = printer_manager.get_printer(printer_id) - if printer_info: - errors_data = [ - { - "code": e.code, - "attr": e.attr, - "module": e.module, - "severity": e.severity, - } - for e in new_errors - ] - await mqtt_relay.on_printer_error( - printer_id, printer_info.name, printer_info.serial_number, errors_data - ) + # Also publish to MQTT relay (no DB). + printer_info = printer_manager.get_printer(printer_id) + if printer_info: + errors_data = [ + { + "code": e.code, + "attr": e.attr, + "module": e.module, + "severity": e.severity, + } + for e in new_errors + ] + await mqtt_relay.on_printer_error( + printer_id, printer_info.name, printer_info.serial_number, errors_data + ) except Exception as e: logging.getLogger(__name__).warning(f"HMS error notification failed: {e}") diff --git a/backend/tests/unit/test_printer_offline_notification.py b/backend/tests/unit/test_printer_offline_notification.py index 2936c08c1..f650b4337 100644 --- a/backend/tests/unit/test_printer_offline_notification.py +++ b/backend/tests/unit/test_printer_offline_notification.py @@ -256,3 +256,81 @@ class TestOfflineEdgeDetection: assert first_task is second_task if first_task is not None: first_task.cancel() + + +class TestProgressMilestoneSessionHygiene: + """The progress-milestone notification path must capture the camera + snapshot WITHOUT holding a DB session (issue #2572): a ~15s RTSP grab + across an open session pinned a pooled connection per milestone, per + printer. The read (printer name) and the send (provider lookups) each get + their own short session; the snapshot happens in between with none held.""" + + @staticmethod + def _printing_state(progress: int): + st = _state(connected=True, state="RUNNING") + st.progress = progress + st.remaining_time = 30 + st.gcode_file = "benchy.gcode" + return st + + @pytest.mark.asyncio + async def test_milestone_captures_snapshot_outside_session_and_notifies(self): + main_module._last_progress_milestone.clear() + + printer = SimpleNamespace(id=1, name="Workshop") + db = AsyncMock() + db.execute = AsyncMock(return_value=MagicMock(scalar_one_or_none=MagicMock(return_value=printer))) + + # Stateful session that tracks how many sessions are currently open. + open_sessions = {"count": 0} + + class _SessionCM: + async def __aenter__(self): + open_sessions["count"] += 1 + return db + + async def __aexit__(self, *exc): + open_sessions["count"] -= 1 + return False + + snap_calls = [] + + async def _snap(printer_id, prn, _logger): + # The whole point of the fix (#2572): the ~15s camera grab must NOT + # run while a DB session is held. On the old code the snapshot sat + # inside the milestone session, so this would be 1. + assert open_sessions["count"] == 0, "camera snapshot ran while a DB session was held" + snap_calls.append((printer_id, prn)) + return b"jpeg-bytes" + + ws_mgr = MagicMock() + ws_mgr.send_printer_status = AsyncMock() + relay = MagicMock() + relay.on_printer_status = AsyncMock() + pm = MagicMock() + pm.get_printer.return_value = None + pm.get_model.return_value = "" + + with ( + patch("backend.app.main.ws_manager", ws_mgr), + patch("backend.app.main.mqtt_relay", relay), + patch("backend.app.main.printer_manager", pm), + patch("backend.app.main.spawn_background_task"), + patch("backend.app.main.printer_state_to_dict", return_value={}), + patch("backend.app.main.async_session", side_effect=lambda: _SessionCM()), + patch("backend.app.main._capture_snapshot_for_notification", new=_snap), + patch("backend.app.main.notification_service") as mock_notif, + ): + mock_notif.on_print_progress = AsyncMock() + + await main_module.on_printer_status_change(1, self._printing_state(25)) + + # Snapshot ran (with the detached printer) and outside any session. + assert snap_calls == [(1, printer)] + # The notification fired carrying that image (send legitimately holds a session). + mock_notif.on_print_progress.assert_awaited_once() + assert mock_notif.on_print_progress.await_args.kwargs["image_data"] == b"jpeg-bytes" + # Every session opened was also closed — none leaked past the handler. + assert open_sessions["count"] == 0 + + main_module._last_progress_milestone.clear()