diff --git a/CHANGELOG.md b/CHANGELOG.md index 007ea8cd6..b6275834c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,8 @@ All notable changes to Bambuddy will be documented in this file. - **Print Log page: per-row delete (#1687 part 1, reported by @IndividualGhost1905)** — Reporter noted that the existing "Also remove this print from Quick Stats" toggle on archive delete is one-shot: if you tick "keep stats" at delete time, there was no later way to drop the row from /stats; and rows that aren't tied to an archive (errors, aborts, manual entries) had no delete affordance at all. **Fix:** every row in the Archives → Print Log table now has a trash icon next to the filament cell, gated on `archives:delete_own` (own rows) or `archives:delete_all` (any row), matching the archive-delete permission shape. Click → confirm modal → row is gone, and because /archives/stats aggregates over `PrintLogEntry` the filament / time / cost contribution drops out of Quick Stats in the same response cycle. The matching archive (if any) is untouched — the log row is a sibling, not a child. **Backend:** new `DELETE /print-log/{entry_id}` mirrors `delete_archive`'s ownership flow via `require_ownership_permission(ARCHIVES_DELETE_ALL, ARCHIVES_DELETE_OWN)`; owners can drop their own rows, admins can drop any row, missing IDs return 404 rather than 200-silently. **Frontend:** new `deletePrintLogEntry` API helper, per-row mutation that invalidates both `print-log` and `archives-stats` query keys so the totals re-render without a manual refresh. **i18n:** 4 new keys (`deleteEntryTitle`, `deleteEntryConfirm`, `entryDeleted`, `entryDeleteFailed`) translated across all 11 locales (de / en / es / fr / it / ja / ko / pt-BR / tr / zh-CN / zh-TW). **Tests:** 3 backend integration cases — delete drops the row from /stats while keeping the linked archive listed, missing ID returns 404, delete-one does not touch siblings (regression guard against an accidental `delete(PrintLogEntry)` without a `where`). Frontend ArchivesPage / PrintLogModal vitests stay green (31 / 31). i18n parity green (5099 leaves × 11 locales). Issue #1687 also asks for per-row tagging (already covered by `EditArchiveModal`'s tags field) and per-row filament-usage-history edits (deferred — see the issue thread for the reasoning). ### Fixed +- **Virtual Printer MQTT no longer disconnects idle OrcaSlicer at keepalive×1.5 (#1548 round 2, reported by @hollajandro)** — Round 1 (commits b6636053 + 4ffefa60) shipped the keepalive parser + 1.5× idle disconnect per MQTT spec §4.4 and a per-minute status-push diagnostic. Reporter's follow-up pcap proved the round-1 logic was correct as designed, but exposed the actual root cause: the same OrcaSlicer install which stays connected to a real Bambu P1S indefinitely sends zero MQTT packets after the initial CONNECT / SUBSCRIBE / pushall / get_version burst — no PINGREQ at all — so any §4.4-compliant server disconnects it at `keep_alive × 1.5`. **Real Bambu firmware does not enforce §4.4** (verified: the reporter's identical Orca install holds an idle session against real hardware on the same network), so spec compliance is itself the regression. **Fix:** after CONNECT/auth, drop the application-level read timeout entirely (`read_timeout = None`) and set `SO_KEEPALIVE` on the underlying socket so the OS TCP stack detects truly dead connections within a few minutes. The 60 s pre-CONNECT timeout is preserved — a client that opens TCP but never sends CONNECT still gets reaped to prevent half-open resource leaks. Negotiated keepalive is still parsed and now logged at INFO ("MQTT client … authenticated (negotiated keepalive=Xs, idle disconnect disabled)") for support-bundle visibility. **Tests:** TestHandleClientIdleConnection adds `test_idle_client_stays_open_past_one_and_a_half_times_keepalive` (negotiates keep_alive=2, sits idle for 4 s, asserts handler still running and writer not closed — direct round-1 inversion), `test_so_keepalive_set_on_socket_after_connect` pins `setsockopt(SOL_SOCKET, SO_KEEPALIVE, 1)` runs on the wrapped socket the moment auth succeeds. PINGREQ test docstring updated since there's no longer a timeout for it to "reset". All 33 VP MQTT server tests green; ruff clean. After this ships, OrcaSlicer should stay connected to the VP indefinitely while idle and reconnect cleanly on real network drops. + - **System page now reports the container's uptime / boot time, not the host's (#1690, reported by @IndividualGhost1905)** — Reporter on Proxmox LXC observed that System → Uptime / Boot Time matched the Proxmox host's values, not the container's. **Root cause:** `psutil.boot_time()` reads `/proc/stat:btime`, which on shared-kernel containers (Docker, LXC) is the host kernel's boot time — leaking the host's lifecycle into Bambuddy's UI. **Fix:** read PID 1's create_time instead — `psutil.Process(1).create_time()` returns the POSIX timestamp of the init/entrypoint process, which in a container is the container's start time, and on bare metal / VMs is the host init (effectively identical to `psutil.boot_time()` within a sub-second). Defensive `psutil.Error` / `OSError` fallback to the old `psutil.boot_time()` for the rare case where /proc/1/stat is unreadable (locked-down container, custom seccomp policy). No frontend / i18n change — the field shape is unchanged, only the value is now correct on container installs. **Tests:** 2 new integration cases — one pins that the route reads `Process(1).create_time` and that the response uses that timestamp (not `boot_time`), the other pins the fallback path via a real `psutil.NoSuchProcess(1)` so the endpoint still returns 200 with the best-available answer. All 8 pre-existing system-info tests updated to also mock the new code path; full system API suite 20/20 green; ruff clean. - **Profile editor filament type dropdown now lists PLA-CF and the other Bambu CF / GF / specialty materials (#1686, reported by @Bgabor997)** — Creating or editing a filament preset on the Profiles page (BL Cloud, Orca Cloud, and Local Profiles all open the same shared editor) only offered 11 base materials (PLA, ABS, PETG, TPU, PA, PA-CF, PET-CF, PC, ASA, PVA, HIPS). Reporter on P1S wanted to tag a custom preset as PLA-CF — the dropdown source had no entry, so the saved preset's `filament_type` was wrong and the printer received the wrong material code at dispatch. **Root cause:** `backend/app/data/filament_fields.json` (served by `GET /cloud/fields/filament` and consumed by `ProfilesPage` via `getCloudFields`) shipped a curated subset that pre-dated Bambu's CF/GF lineup expansion. Other surfaces in the codebase already named the canonical list (`utils/filament_ids.py` `GENERIC_FILAMENT_IDS`, `spool-form/utils.ts` MATERIALS, the Bambu filament-id catalog in `cloud.py`), so the gap was specifically in the editor's allowed-values JSON. **Fix:** expanded the `filament_type` select to 25 BambuStudio-aligned options grouped by family — PLA (+ CF/GF/AERO), PETG (+ CF), ABS (+ GF), ASA (+ CF/GF), PC, PCTG, PA family (+ CF/PAHT-CF/PA6-CF/PA6-GF), PET-CF, TPU, PPS family (+ CF/GF for X1E), PVA, HIPS. No frontend, no i18n (material codes are universal). K-profiles editor unaffected — it picks `filament_id`, not `filament_type`. **Tests:** 15 unit cases in `test_filament_fields_options.py` pin every newly-added variant (PLA-CF, PLA-GF, PLA-AERO, PETG-CF, ABS-GF, ASA-CF, ASA-GF, PCTG, PAHT-CF, PA6-CF, PA6-GF, PPS, PPS-CF, PPS-GF) plus the baseline-must-still-be-present guard so a future curation pass can't silently drop them. diff --git a/backend/app/services/virtual_printer/mqtt_server.py b/backend/app/services/virtual_printer/mqtt_server.py index 1346d5bdc..02f7621e6 100644 --- a/backend/app/services/virtual_printer/mqtt_server.py +++ b/backend/app/services/virtual_printer/mqtt_server.py @@ -9,6 +9,7 @@ import copy import hmac import json import logging +import socket import ssl from collections.abc import Callable from pathlib import Path @@ -519,10 +520,14 @@ class SimpleMQTTServer: authenticated = False # Per-packet read timeout. Before CONNECT we default to 60 s so a - # client that opens TCP but never sends anything still gets reaped; - # after CONNECT the value is updated to 1.5× the keepalive the - # client negotiated (MQTT spec §4.4). ``None`` means no timeout, - # which is what spec §3.1.2.10 mandates for keep_alive == 0. + # client that opens TCP but never sends anything still gets reaped. + # After CONNECT we drop the application-level read timeout entirely + # and rely on TCP keepalive (SO_KEEPALIVE) to detect dead connections + # — this matches real Bambu firmware, which does not enforce MQTT + # spec §4.4's 1.5× idle disconnect (#1548 round 2). OrcaSlicer's + # MQTT client on some platforms does not emit PINGREQ at all on idle + # connections; the same install that stays connected to a real P1S + # indefinitely was disconnecting from us at keepalive×1.5. read_timeout: float | None = 60.0 try: @@ -565,13 +570,29 @@ class SimpleMQTTServer: self._record_auth_failure(source_ip) break self._clear_auth_failures(source_ip) - # Honour the client's negotiated keepalive (#1548). Before - # this fix, the hardcoded 60 s above would close - # OrcaSlicer's idle connection at the keepalive boundary - # instead of waiting 1.5× as the spec requires — Orca - # sends PINGREQ within its own keepalive interval but - # we'd already have closed the socket. - read_timeout = keep_alive * 1.5 if keep_alive > 0 else None + # Drop the application-level read timeout; rely on + # SO_KEEPALIVE below for dead-connection detection. + # Real Bambu firmware does the same — accept any + # negotiated keepalive but never enforce §4.4's 1.5× + # disconnect on the otherwise-idle MQTT session + # (#1548 round 2). keep_alive is logged for support + # bundles but no longer drives a disconnect. + read_timeout = None + logger.info( + "%sMQTT client %s authenticated (negotiated keepalive=%ds, idle disconnect disabled)", + self._log_prefix, + client_id, + keep_alive, + ) + # Enable TCP keepalive so a hard network drop is detected + # by the OS within a few minutes rather than waiting for + # the next outbound write to ECONNRESET. + sock = writer.get_extra_info("socket") + if sock is not None: + try: + sock.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1) + except OSError as e: + logger.debug("%sFailed to set SO_KEEPALIVE on %s: %s", self._log_prefix, client_id, e) # Register client for periodic status pushes; start with # self.serial as the fallback until we learn the slicer's # preferred serial from the first SUBSCRIBE/PUBLISH. diff --git a/backend/tests/unit/test_vp_mqtt_server.py b/backend/tests/unit/test_vp_mqtt_server.py index 5a6717db9..0eb97b161 100644 --- a/backend/tests/unit/test_vp_mqtt_server.py +++ b/backend/tests/unit/test_vp_mqtt_server.py @@ -276,16 +276,24 @@ class TestHandleConnectKeepalive: assert result == (False, 0) -class TestHandleClientHonoursKeepalive: - """`_handle_client` must use the client-negotiated keepalive for its - read-loop timeout, not the hardcoded 60 s default (#1548).""" +class TestHandleClientIdleConnection: + """`_handle_client` must NOT close idle authenticated clients on a + keepalive boundary (#1548 round 2). + + Round 1 shipped the keepalive parser + 1.5× read timeout per MQTT spec + §4.4. The reporter then confirmed that the same OrcaSlicer install which + stays connected to a real Bambu P1S indefinitely was being disconnected + by Bambuddy at exactly ``keep_alive × 1.5`` — pcap showed Orca sends + zero MQTT packets after the initial burst (no PINGREQ at all). Real + Bambu firmware does not enforce §4.4; we now match that and rely on + TCP keepalive (SO_KEEPALIVE) for dead-connection detection. + """ @pytest.mark.asyncio async def test_idle_client_kept_alive_beyond_60s_when_keepalive_is_long(self): - """The literal #1548 repro: a client negotiates keepalive=180 and - then sits idle. Pre-fix the read loop closed the connection after - 60 s (hardcoded). Post-fix the timeout is 1.5×180=270 s — so the - connection is still open after the original 60 s boundary.""" + """A client negotiates keepalive=180 and then sits idle. Pre-round-1 + the read loop closed the connection after a hardcoded 60 s. Now the + connection stays open indefinitely.""" server = _make_server() server._running = True @@ -303,7 +311,7 @@ class TestHandleClientHonoursKeepalive: writer.drain = AsyncMock() writer.close = MagicMock() writer.wait_closed = AsyncMock() - writer.get_extra_info = MagicMock(return_value=("1.2.3.4", 12345)) + writer.get_extra_info = MagicMock(side_effect=lambda name: ("1.2.3.4", 12345) if name == "peername" else None) # Patch the post-auth status-report send so the handler doesn't # depend on a real serial/payload path. @@ -331,9 +339,12 @@ class TestHandleClientHonoursKeepalive: pass @pytest.mark.asyncio - async def test_idle_client_closed_after_one_and_a_half_times_keepalive(self): - """Tight verification: keepalive=2 must close the connection in - ~3 s (1.5×) of idle, well above the noise floor for an async test.""" + async def test_idle_client_stays_open_past_one_and_a_half_times_keepalive(self): + """Round-2 regression guard: a client negotiates keepalive=2 and + then sits idle. Round 1 would have closed at ~3 s (1.5×). Now the + handler must still be running well past that boundary — the only + thing that ends the loop is a DISCONNECT, peer close, or server + shutdown.""" server = _make_server() server._running = True @@ -348,22 +359,74 @@ class TestHandleClientHonoursKeepalive: writer.drain = AsyncMock() writer.close = MagicMock() writer.wait_closed = AsyncMock() - writer.get_extra_info = MagicMock(return_value=("1.2.3.4", 12345)) + writer.get_extra_info = MagicMock(side_effect=lambda name: ("1.2.3.4", 12345) if name == "peername" else None) server._send_status_report = AsyncMock() - start = asyncio.get_event_loop().time() - await server._handle_client(reader, writer) - elapsed = asyncio.get_event_loop().time() - start + task = asyncio.create_task(server._handle_client(reader, writer)) - # 1.5×2s = 3s expected. Allow ±1s slop for the read of CONNECT - # itself + scheduler jitter on a loaded CI box. - assert 2.0 < elapsed < 4.5, f"expected ~3s timeout, got {elapsed:.2f}s" + # Give the loop time to process CONNECT and settle into the idle + # read. 4 s is well past round-1's 3 s timeout and any conceivable + # async-scheduler drift. + await asyncio.sleep(4.0) + + assert not task.done(), "handler must still be waiting on idle reader" + assert not writer.close.called, "connection must not be closed by keepalive timeout" + + task.cancel() + try: + await task + except asyncio.CancelledError: + pass @pytest.mark.asyncio - async def test_pingreq_resets_idle_timeout(self): - """A PINGREQ within the keepalive window must keep the connection - open — the per-packet read timeout is restarted on every byte - delivered, so the next idle window is measured from the PINGREQ.""" + async def test_so_keepalive_set_on_socket_after_connect(self): + """The application-level read timeout was removed; TCP keepalive + replaces it for dead-connection detection. Verify the handler sets + SO_KEEPALIVE on the underlying socket the moment auth succeeds.""" + import socket + + server = _make_server() + server._running = True + + reader = asyncio.StreamReader() + connect_payload = _build_connect_payload(keep_alive=60) + rl = len(connect_payload) + assert rl < 128 + reader.feed_data(bytes([0x10, rl]) + connect_payload) + + sock = MagicMock() + writer = MagicMock() + writer.write = MagicMock() + writer.drain = AsyncMock() + writer.close = MagicMock() + writer.wait_closed = AsyncMock() + + def _get_extra_info(name): + if name == "socket": + return sock + if name == "peername": + return ("1.2.3.4", 12345) + return None + + writer.get_extra_info = MagicMock(side_effect=_get_extra_info) + server._send_status_report = AsyncMock() + + task = asyncio.create_task(server._handle_client(reader, writer)) + await asyncio.sleep(0.2) + task.cancel() + try: + await task + except asyncio.CancelledError: + pass + + sock.setsockopt.assert_any_call(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1) + + @pytest.mark.asyncio + async def test_pingreq_is_processed_and_does_not_close_connection(self): + """PINGREQ from a still-active client must be honoured (PINGRESP + sent, connection kept open). After round 2 there is no idle timeout + for PINGREQ to "reset" — the relevant invariant is that the packet + is parsed and routed without disconnecting.""" server = _make_server() server._running = True @@ -378,7 +441,7 @@ class TestHandleClientHonoursKeepalive: writer.drain = AsyncMock() writer.close = MagicMock() writer.wait_closed = AsyncMock() - writer.get_extra_info = MagicMock(return_value=("1.2.3.4", 12345)) + writer.get_extra_info = MagicMock(side_effect=lambda name: ("1.2.3.4", 12345) if name == "peername" else None) server._send_status_report = AsyncMock() async def _drive():