From a95a3c52eea91bb6622121b52b7900b02f89b954 Mon Sep 17 00:00:00 2001 From: maziggy Date: Fri, 17 Apr 2026 09:29:46 +0200 Subject: [PATCH] fix(mqtt): detect zombie sessions via ams_filament_setting response tracking (#887) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit After hours idle the MQTT connection can degrade so telemetry still flows but published commands never reach the printer. The existing dev-mode probe only ran on first connect; this adds tracking for user-initiated ams_filament_setting commands — two consecutive unanswered commands (10 s timeout each) trigger force_reconnect. --- CHANGELOG.md | 1 + backend/app/services/bambu_mqtt.py | 31 ++++ .../tests/unit/services/test_bambu_mqtt.py | 168 ++++++++++++++++++ 3 files changed, 200 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 164119b05..59fd09ac7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -29,6 +29,7 @@ All notable changes to Bambuddy will be documented in this file. - **Bambu Lab X2D Support** ([#988](https://github.com/maziggy/bambuddy/issues/988)) — Added X2D to the Add Printer and Edit Printer model dropdowns (both were missing the new model, so manual printer setup had no X2D option — auto-discovery via SSDP was unaffected). The newly released X2D (dual-nozzle, enclosed, hardened steel rod gantry, AMS 2 Pro compatible) identifies itself as internal model code `N6` via SSDP/MQTT, and serials begin with `20P9`. Because neither the code nor the prefix existed in any of Bambuddy's model tables, multiple paths silently fell back to wrong defaults: the camera service routed to the chamber-image protocol on port 6000 (which the X2D doesn't speak) instead of RTSP on port 322 — the reporter saw `Chamber image: data is not a valid JPEG` spam and no stream; the K-profile edit/delete path conditioned its in-place `cali_idx` write on the H2D serial prefix `094` and would therefore have treated X2D as a single-nozzle printer even though its dual-extruder layout matches H2D; the firmware-update check logged `Unknown printer model: N6`; and the virtual-printer model registry had no way to emulate X2D. Added the `N6 → X2D` mapping across every registry (`PRINTER_MODEL_ID_MAP`, `PRINTER_MODEL_MAP`, `ETHERNET_MODELS`, `STEEL_ROD_MODELS`, `CHAMBER_TEMP_SUPPORTED_MODELS`, firmware-check API keys and wiki path, virtual-printer SSDP product names and serial prefix, DB migration `vp_model_fixes`), extended `supports_rtsp()` to match `X2` display names and the `N6` internal code (camera now goes to port 322), expanded the dual-nozzle serial prefix check in `kprofiles.py` and the K-profile delete command in `bambu_mqtt.py` to also accept `20P9` so the H2D-style `cali_idx` in-place edit path runs on X2D, added X2D to the `is_h2d` model-family gate that selects the integer-format `timelapse`/`bed_leveling`/`flow_cali`/`vibration_cali`/`layer_inspect` fields in the MQTT print command, and added X2D to the frontend's door-badge and airduct-mode whitelists, `mapModelCode` lookups on both the Printers page and Spoolbuddy AMS page, and the MaintenancePage wiki-URL resolver (X2D inherits P2S's steel-rod lubrication, belt-tension, nozzle cold-pull and PTFE wiki pages, since its hardware is closer to P2S than to H2). Credit to @krautech for the report and the debug bundle, and to @legend813 for the initial PR (#989) that seeded most of the registry changes — the classification was corrected (X2D uses hardened steel rods like P2S, not carbon rods) and the dual-nozzle/K-profile gaps were added on top. - **Print Speed Icon Not Updating Live When Changed on Printer** ([#993](https://github.com/maziggy/bambuddy/issues/993)) — Changing the print speed mode from the printer's own panel (instead of from Bambuddy) did not update the speed icon on the Printers page card; the new value only appeared after a full page reload. The MQTT parser was already tracking `spd_lvl` and updating `state.speed_level` correctly, but the WebSocket serializer (`printer_state_to_dict`) was missing the field — so live status pushes never carried `speed_level`, and the frontend's merge-over-old-cache update left the icon stuck on its previous value. The REST `/status` endpoint used on initial page load already included it, which is why reloads worked. Added `speed_level` to the WebSocket payload. Thanks to @chesterakl for reporting. - **Camera Popup Shows "Valid camera stream token required" With Auth Enabled** ([#979](https://github.com/maziggy/bambuddy/issues/979)) — When Camera View Mode was set to "Window" and authentication was enabled, clicking the camera button opened a popup that immediately failed with `"Valid camera stream token required"`, while the embedded overlay kept working. Two root causes: (1) `window.open(...)` passed `noopener` in the popup features, which severed the opener link and prevented the browser from copying sessionStorage (where the auth token lives) into the popup — so the new window booted unauthenticated and the `POST /printers/camera/stream-token` fetch returned 401, leaving the `` src without the required `?token=` query param; (2) even once the token arrived, `CameraPage` computed its URL from the module-level stream-token cache on render and never re-rendered when the cache was updated in a `useEffect`, so the first paint locked in a tokenless URL that the backend kept rejecting. Fixed by dropping `noopener` from the camera popup features (same-origin, trusted window) so sessionStorage is inherited, subscribing `CameraPage` to the `camera-stream-token` React Query so it re-renders the moment the token resolves, and appending the token directly from the reactive query value instead of the effect-synced module cache — the `` src stays empty until the token is ready, so no tokenless request ever leaves the popup. Embedded-overlay mode was unaffected. Thanks to @VREmma for the reproducer. +- **AMS Slot Changes Stop Reaching Printer After Long Idle** ([#887](https://github.com/maziggy/bambuddy/issues/887)) — After printers sat idle for several hours, spool changes published by Bambuddy silently stopped reaching the printer — the UI updated but the printer ignored the command, and only a manual reconnect restored functionality. Root cause: the MQTT connection degraded into a zombie state where the receive path still worked (push_status telemetry kept flowing, so Bambuddy considered the connection alive) but the publish path was dead. The existing zombie detector — the developer mode probe — only ran on first connect when `developer_mode` was unknown; after the initial probe cached the value, subsequent zombie states went undetected because neither the staleness timer nor the keepalive could distinguish a half-open connection from a healthy one. The MQTT client now tracks `ams_filament_setting` command/response pairs: when a published command receives no response within 10 seconds, it's counted as unanswered. After two consecutive unanswered commands, the session is force-reconnected using the same `force_reconnect_stale_session()` mechanism. This catches zombie sessions at the moment the user encounters them — on their second failed spool change — rather than requiring a manual reconnect. Thanks to @RosdasHH for the detailed support bundles that made the diagnosis possible. - **Obico Detection Fails Behind Reverse Proxy with External Auth** ([#1003](https://github.com/maziggy/bambuddy/issues/1003), [#172](https://github.com/maziggy/bambuddy/issues/172)) — When Bambuddy sits behind a reverse proxy with external authentication (Authelia, Authentik, Cloudflare Access, etc.), the Obico ML API container couldn't fetch snapshots because it had to go through the proxy to reach Bambuddy and couldn't perform the external auth handshake. Previous iterations of #172 solved Bambuddy's own auth (token in URL) and the ML API's 5 s read timeout (nonce-cached frames), but both still relied on the ML API calling back into Bambuddy via `external_url` — which meant external auth layers on the reverse proxy still blocked the request. Eliminated the callback architecture entirely: the detection loop now captures the JPEG locally (with a 20 s timeout we control), then **POSTs the image bytes directly** to the ML API as multipart form data. The ML API never needs to reach Bambuddy at all, so reverse proxies, Docker networking, auth layers, and `external_url` configuration are all irrelevant. Removed the `/obico/cached-frame/{nonce}` endpoint, the in-memory nonce cache, and the `external_url` dependency from the detection service. The "External URL is not set" warning in the Failure Detection UI is also removed since it's no longer needed. Thanks to @felixjen for reporting the reverse-proxy scenario. - **Obico Detection Snapshot Killed by Stream Cleanup** ([#172](https://github.com/maziggy/bambuddy/issues/172)) — Third wave of #172 — once the cached-frame fix landed, `fblix` reported a permanent "Failed to capture snapshot" warning in the UI. The periodic camera stream cleanup task scans `/proc` for ffmpeg processes with Bambu RTSP URLs and kills any that aren't in the active-streams registry. The Obico detection service's `capture_camera_frame_bytes()` spawns its own short-lived ffmpeg process to grab a single JPEG frame, but that process was never registered with the stream cleanup — so when the 60-second cleanup cycle happened to run during the 5–10 s capture window, it killed the ffmpeg as "orphaned" (exit code -9). The detection service recovered on the next poll, but the kill produced unnecessary error logs and a missed detection frame. Fixed by tracking capture PIDs in a module-level set (`_active_capture_pids`) and excluding them from the `/proc`-scan kill list. Thanks to @fblix for the detailed timing analysis. - **Direct Print from Library Not Attributed to User** — Clicking the Print button on a library file dispatched the job with no `created_by_id`, so the resulting archive had no owner and the print didn't show up in per-user statistics. The Queue and Reprint paths already forwarded the authenticated user; the library `POST /files/{file_id}/print` endpoint now does the same, reading the user from the JWT and passing it through to the dispatcher so direct prints are attributed like queued and reprinted ones. diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 7a86420f3..9819f6419 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -367,6 +367,12 @@ class BambuMQTTClient: # when the frontend polls status faster than paho can reconnect. self._last_stale_reconnect: float = 0.0 + # Zombie session detection via ams_filament_setting response tracking (#887). + # The dev-mode probe only runs on first connect; this catches zombie sessions + # that develop later (telemetry flows but publishes silently fail). + self._last_ams_cmd_time: float = 0.0 # monotonic time of last published command + self._ams_cmd_unanswered: int = 0 # consecutive commands with no response + @property def topic_subscribe(self) -> str: return f"device/{self.serial_number}/report" @@ -457,6 +463,8 @@ class BambuMQTTClient: self._dev_mode_probe_time = 0.0 self._dev_mode_probe_failures = 0 self._connect_time = time.monotonic() + self._last_ams_cmd_time = 0.0 + self._ams_cmd_unanswered = 0 client.subscribe(self.topic_subscribe) # Subscribe to request topic for ams_mapping capture (if supported by broker) if self._request_topic_supported: @@ -771,6 +779,10 @@ class BambuMQTTClient: and print_data.get("sequence_id") == self._dev_mode_probe_seq ): self._handle_dev_mode_probe_response(print_data) + # Track user-initiated ams_filament_setting responses (#887 zombie detection) + elif cmd == "ams_filament_setting" and self._last_ams_cmd_time > 0: + self._last_ams_cmd_time = 0.0 + self._ams_cmd_unanswered = 0 if "command" in print_data and print_data.get("command") == "extrusion_cali_get": self._handle_kprofile_response(print_data) @@ -2549,6 +2561,23 @@ class BambuMQTTClient: # Allow retry on next full status message self._dev_mode_probed = False + # Zombie session detection: if an ams_filament_setting command has been + # pending for >10s with no response, the publish path is likely dead (#887). + if self._last_ams_cmd_time > 0: + elapsed = time.monotonic() - self._last_ams_cmd_time + if elapsed > 10.0: + self._ams_cmd_unanswered += 1 + logger.warning( + "[%s] ams_filament_setting unanswered for %.0fs (count=%d)", + self.serial_number, + elapsed, + self._ams_cmd_unanswered, + ) + self._last_ams_cmd_time = 0.0 # don't re-trigger on next push_status + if self._ams_cmd_unanswered >= 2: + self.force_reconnect_stale_session("ams_filament_setting unanswered 2\u00d7") + self._ams_cmd_unanswered = 0 + # Log mapping data when received (for usage tracking debugging) if "mapping" in data: logger.debug("[%s] MQTT mapping field: %s", self.serial_number, data["mapping"]) @@ -4328,6 +4357,7 @@ class BambuMQTTClient: ) logger.debug("[%s] ams_filament_setting command: %s", self.serial_number, command_json) self._client.publish(self.topic_publish, command_json, qos=1) + self._last_ams_cmd_time = time.monotonic() return True def reset_ams_slot(self, ams_id: int, tray_id: int) -> bool: @@ -4385,6 +4415,7 @@ class BambuMQTTClient: logger.info("[%s] Resetting AMS slot: AMS %s, tray %s", self.serial_number, ams_id, tray_id) logger.debug("[%s] reset_ams_slot command: %s", self.serial_number, command_json) self._client.publish(self.topic_publish, command_json, qos=1) + self._last_ams_cmd_time = time.monotonic() return True def extrusion_cali_sel( diff --git a/backend/tests/unit/services/test_bambu_mqtt.py b/backend/tests/unit/services/test_bambu_mqtt.py index 0255aa020..bba41acbf 100644 --- a/backend/tests/unit/services/test_bambu_mqtt.py +++ b/backend/tests/unit/services/test_bambu_mqtt.py @@ -3737,3 +3737,171 @@ class TestSdCardParsing: assert client.state.sdcard is True client._update_state({"sdcard": False}) assert client.state.sdcard is False + + +class TestZombieSessionDetection: + """Tests for ams_filament_setting response tracking (#887). + + When a printer's MQTT session degrades so that telemetry flows but + published commands never reach the printer, the zombie detector + counts consecutive unanswered ams_filament_setting commands and + force-reconnects after two. + """ + + @pytest.fixture + def mqtt_client(self): + import time + from unittest.mock import MagicMock + + from backend.app.services.bambu_mqtt import BambuMQTTClient + + client = BambuMQTTClient( + ip_address="192.168.1.100", + serial_number="TEST123", + access_code="12345678", + ) + client.state.connected = True + mock_paho = MagicMock() + mock_paho.socket.return_value = MagicMock() + client._client = mock_paho + client._connect_time = time.monotonic() - 10.0 + # Set developer_mode so the dev-mode probe branch doesn't interfere + client.state.developer_mode = True + return client + + def test_initial_state_is_clean(self, mqtt_client): + """Tracking fields start at zero / no pending command.""" + assert mqtt_client._last_ams_cmd_time == 0.0 + assert mqtt_client._ams_cmd_unanswered == 0 + + def test_publish_sets_pending_time(self, mqtt_client): + """set_ams_filament_setting records the publish timestamp.""" + import time + + before = time.monotonic() + mqtt_client.ams_set_filament_setting( + ams_id=0, + tray_id=0, + tray_info_idx="GFL99", + tray_type="PLA", + tray_sub_brands="", + tray_color="FF0000FF", + nozzle_temp_min=190, + nozzle_temp_max=230, + ) + assert mqtt_client._last_ams_cmd_time >= before + + def test_reset_slot_sets_pending_time(self, mqtt_client): + """reset_ams_slot also records the publish timestamp.""" + import time + + before = time.monotonic() + mqtt_client.reset_ams_slot(ams_id=0, tray_id=0) + assert mqtt_client._last_ams_cmd_time >= before + + def test_response_clears_pending(self, mqtt_client): + """An ams_filament_setting response clears the pending state.""" + import time + + mqtt_client._last_ams_cmd_time = time.monotonic() + mqtt_client._ams_cmd_unanswered = 1 + + # Simulate receiving a user-command response (sequence_id "0") + print_data = { + "command": "ams_filament_setting", + "sequence_id": "0", + "result": "success", + } + # Walk the same path as _on_message: command response check then _update_state + cmd = print_data.get("command") + if cmd == "ams_filament_setting" and mqtt_client._last_ams_cmd_time > 0: + mqtt_client._last_ams_cmd_time = 0.0 + mqtt_client._ams_cmd_unanswered = 0 + + assert mqtt_client._last_ams_cmd_time == 0.0 + assert mqtt_client._ams_cmd_unanswered == 0 + + def test_single_timeout_increments_counter(self, mqtt_client): + """One unanswered command increments the counter but does not reconnect.""" + import time + + mqtt_client._last_ams_cmd_time = time.monotonic() - 11.0 + + mqtt_client._update_state({"gcode_state": "IDLE"}) + + assert mqtt_client._ams_cmd_unanswered == 1 + assert mqtt_client._last_ams_cmd_time == 0.0 + # Should NOT force-reconnect after just one + assert mqtt_client.state.connected is True + + def test_two_timeouts_force_reconnect(self, mqtt_client): + """Two consecutive unanswered commands trigger force_reconnect.""" + import time + + state_change_called = [] + mqtt_client.on_state_change = lambda s: state_change_called.append(True) + + # First unanswered command + mqtt_client._last_ams_cmd_time = time.monotonic() - 11.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + assert mqtt_client._ams_cmd_unanswered == 1 + assert mqtt_client.state.connected is True + + # Second unanswered command + mqtt_client._last_ams_cmd_time = time.monotonic() - 11.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + + assert mqtt_client._ams_cmd_unanswered == 0 # reset after reconnect + assert mqtt_client.state.connected is False + assert mqtt_client._stale_reconnecting is True + mqtt_client._client.socket().close.assert_called() + assert len(state_change_called) > 0 + + def test_response_between_timeouts_resets_counter(self, mqtt_client): + """A successful response after one timeout resets the counter.""" + import time + + # First unanswered command + mqtt_client._last_ams_cmd_time = time.monotonic() - 11.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + assert mqtt_client._ams_cmd_unanswered == 1 + + # Now a response arrives — clear pending + mqtt_client._last_ams_cmd_time = time.monotonic() + mqtt_client._last_ams_cmd_time = 0.0 + mqtt_client._ams_cmd_unanswered = 0 + + # Next unanswered command should be count=1, not count=2 + mqtt_client._last_ams_cmd_time = time.monotonic() - 11.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + assert mqtt_client._ams_cmd_unanswered == 1 + assert mqtt_client.state.connected is True # no reconnect + + def test_on_connect_resets_tracking(self, mqtt_client): + """_on_connect resets zombie tracking fields.""" + import time + + mqtt_client._last_ams_cmd_time = time.monotonic() + mqtt_client._ams_cmd_unanswered = 5 + + # subscribe() must return (result, mid) tuple + mqtt_client._client.subscribe.return_value = (0, 1) + mqtt_client._on_connect(mqtt_client._client, None, None, 0) + + assert mqtt_client._last_ams_cmd_time == 0.0 + assert mqtt_client._ams_cmd_unanswered == 0 + + def test_no_check_when_no_command_pending(self, mqtt_client): + """If no command was published, push_status does not trigger detection.""" + assert mqtt_client._last_ams_cmd_time == 0.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + assert mqtt_client._ams_cmd_unanswered == 0 + + def test_no_timeout_within_window(self, mqtt_client): + """A command published <10s ago should not trigger a timeout.""" + import time + + mqtt_client._last_ams_cmd_time = time.monotonic() - 5.0 + mqtt_client._update_state({"gcode_state": "IDLE"}) + assert mqtt_client._ams_cmd_unanswered == 0 + assert mqtt_client._last_ams_cmd_time > 0 # still pending