diff --git a/CHANGELOG.md b/CHANGELOG.md index 71b834587..3cea306bf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes to Bambuddy will be documented in this file. ## [0.2.5b1] - Unreleased ### Fixed +- **Support-bundle log noise: VP bridge nudge + SD-card cleanup (#1721 adjacent, observed on reporter's A1)** — Two warnings polluting every A1 support bundle on a healthy print. Neither was the cause of #1721's timelapse complaint — both are adjacent noise. **(1) `request_status_update: not connected`** — `mqtt_bridge.py::_resolve_client` calls `_request_version` + `request_status_update` immediately after attaching a raw-message handler so the bridge cache populates without waiting for the next periodic pushall. The bind frequently races the real printer's MQTT TLS handshake — a slicer-side reconnect re-resolves the client before the underlying session has reconnected, especially on A1 firmware which reconnects more aggressively than X1/H2/P. `request_status_update` logs `[serial] request_status_update: not connected` at WARNING on the not-connected return path. The nudge is a best-effort optimisation; the fall-through (next periodic pushall) populates the cache anyway, so the WARNING fires on routine, expected, recoverable state. **Fix:** gate both nudges on `current.state.connected` at the bind site. When the client comes up, the next `_resolve_client` tick re-enters this branch on identity change OR the periodic pushall in `bambu_mqtt.py` fills the cache — same end state, no benign WARNING. The WARNING in `bambu_mqtt.py:3224` is unchanged: it's still a real signal for the other callers (`/printers/{id}/refresh-status` user API, bug-reporter helper) where "you asked for a refresh on a dead client" is genuinely worth logging. New `test_post_bind_nudge_skipped_when_target_not_connected` in `test_vp_mqtt_bridge.py::TestBridgeLifecycle` pins the contract. **(2) `SD card cleanup failed after 3 attempts ... (file may linger on SD card)`** — The post-finish helper in `main.py` deletes the uploaded file from the printer's SD card to prevent the ghost-print-on-power-cycle behaviour (#374, #1542). It tries up to three candidate paths (`derive_remote_filename(archive.filename)`, then `{subtask_name}.3mf`, then `{subtask_name}.gcode`), each up to 3 times with 2 s backoff, then logs WARNING if all fail. `delete_file_async` returned `bool` — `True` for success, `False` for ANYTHING else (FTP 550 file-not-found, network error, auth fail, transient FTP error). The A1 firmware (and most other Bambu firmwares post-print) cleans the SD-card upload itself before our cleanup runs, every candidate FTP-DELE returns 550, all three retries × three candidates × 2 s sleeps fire, then WARNING. That WARNING shouldn't exist on a healthy print where the printer self-cleaned. The same shape exists in `_cleanup_forced_timelapse` (#1397) walking the four timelapse dirs. **Fix:** `bambu_ftp.py` now exports a `DeleteResult` enum (`DELETED` / `NOT_FOUND` / `FAILED`). `BambuFTPClient.delete_file` detects the 550 case via `isinstance(e, ftplib.error_perm) and str(e).startswith("550")` (same pattern already used in the download path for the symmetric `FileNotOnPrinterError` sentinel from #972). `delete_file_async` now returns `DeleteResult`. Both post-finish cleanup helpers (`main.py::on_print_finished` SD branch + `_cleanup_forced_timelapse`) only WARN when at least one candidate returned `FAILED`; an all-`NOT_FOUND` outcome logs DEBUG ("nothing to delete — printer likely self-cleaned"). The cleanup helper also no longer burns the 2 s × 3 retry budget on a `NOT_FOUND` result (550 will never recover by waiting); only `FAILED` triggers backoff. `DELETE /printers/{id}/files/...` returns 404 (not 500) on `NOT_FOUND`, more accurate for the user-facing UI. Three other production callers (`print_scheduler` pre-upload delete, two `background_dispatch` fire-and-forget cleanups) are unchanged at the call site — they discard the return value. **Tests:** `test_delete_file` and `test_delete_file_async` in `test_bambu_ftp.py` switched to the enum (3 cases each). 2 new regression tests in `test_cleanup_forced_timelapse.py`: `test_forced_no_warning_when_every_dir_returns_not_found` pins the #1721 path (every candidate dir → 550 → no WARNING, one DEBUG summary), `test_forced_warns_when_any_dir_returns_failed` pins the counterpart (any FAILED keeps the WARNING — that's the signal the maintainer wants). `caplog` asserts the log record's level + content directly. Full backend suite 5941/5941 green; ruff clean; frontend untouched (rebuild + i18n parity confirmed clean per `feedback_run_all_ci_checks`). No migration, no new i18n keys, no schema changes. - **Virtual printer external spool (`vt_tray`) went "invalid" right after a slicer filament pick (#1622 round 5, reported by @shaddowlink)** — On a P1S in non-proxy VP mode, the reporter picked a filament for the external spool slot in BambuStudio's Device tab and the slot immediately rendered as invalid (color only, no profile, no K-profile, no nozzle temps), but recovered after a virtual-printer reload. AMS slot picks worked correctly. Wire dumps (BAMBUDDY_VP_DUMP_WIRE=1) captured the asymmetry: the bridge's outgoing 1 Hz cached-as-base push delivered `vt_tray = {tray_info_idx, tray_color}` — 2 fields — where a real P1S sends ~20 (`tray_type`, `state`, `remain`, `k`, `n`, `cali_idx`, `nozzle_temp_min/max`, `tray_uuid`, `xcam_info`, ...). The same `_out.json` showed AMS slots with the full 24-field dict because `_merge_ams_dict` deep-merged them. **Root cause:** Bambu firmware sends a partial `vt_tray` incremental right after acknowledging an `ams_filament_setting` for `ams_id=255` (external spool) — carrying just the fields the slicer's pick changed. The round-4 per-field accumulate (#1622 / da799447) carried over prev keys NOT present in new, but `vt_tray` IS present in new, so the cached dict was REPLACED wholesale with the 2-field partial. The next 1 Hz cached-as-base push handed the slicer the stripped vt_tray; BambuStudio rendered the slot as invalid. Reloading the VP forced a reconnect → pushall → full vt_tray restored, and the cycle repeated on the next pick. **Fix:** `mqtt_bridge.py::_on_printer_raw` now applies the same per-field accumulate one level deeper: for every top-level key whose prev AND new are both dicts, overlay new onto prev rather than replace. `ams` is explicitly excluded (already deep-merged by `_merge_ams_dict`). The same overlay protects `device`, `online`, `upgrade_state`, `ipcam`, `upload`, `net` against future firmware partials with the same shape; the `net.info` IP rewrite path is unaffected because `_rewrite_net_info_ips` runs against `new_state["net"]` before caching and the rewritten list overrides the cached one on overlay (only `net.conf` and friends, when sent without `info`, draw from prev now). **Tests:** new `test_partial_vt_tray_update_overlays_onto_cached_full_dict` regression case in `test_vp_mqtt_bridge.py::TestPushStatusCache` constructs the exact P1S wire shape — pushall with the full ~20-field vt_tray, followed by the `{tray_info_idx, tray_color}` partial that shaddowlink's dump captured — and asserts `tray_type`, `state`, `remain`, `k`, `n`, `cali_idx`, `nozzle_temp_min/max`, `tray_uuid`, `id` all survive while the two incoming fields take their new values. All 53 bridge tests stay green; 287/287 across the broader VP test surface (mqtt_bridge / mqtt_server / vp_wire / virtual_printer); ruff clean. Bridge code path only; no migration, no new i18n keys, no frontend touch. - **Library G-code preview returned raw ZIP bytes as `text/plain` for sidecar-sliced rows (#1709, root cause + fix from @yanglei1980)** — `slice_and_persist` writes its output as a `.gcode.3mf` (a ZIP container with embedded G-code) but persisted the LibraryFile row with `file_type="gcode"`. The G-code preview endpoint at `library.py::get_gcode` short-circuits on `file_type == "gcode"` and streams the on-disk bytes with `media_type="text/plain"`, so every preview of a sidecar-sliced row handed the embedded viewer the raw ZIP body (`PK\x03\x04…`) instead of toolpath text — the viewer rendered nothing. External-folder scans (#1600) already typed `.gcode.3mf` rows correctly and hit the unzip branch, so the bug was specific to the sidecar slice path. Plain `.gcode` uploads were unaffected (their on-disk bytes really are text). **Fix:** (1) forward — `slice_and_persist` now persists `file_type="gcode.3mf"`, matching what `_classify_file_type` returns for the `.gcode.3mf` extension and what external-scan rows already use; (2) back-compat — `get_gcode` also routes to the unzip branch when the filename ends with `.gcode.3mf`, so rows already written under the bug self-heal on first preview without a DB migration. **UI gates:** three frontend call sites that gated badge colour or the preview-eye icon on `file_type == "gcode"` were extended to also accept `"gcode.3mf"` — `FileManagerPage.tsx` badge + viewer-affordance gate, `ProjectDetailPage.tsx` badge — so the new typing doesn't regress visuals. The print / queue / slice action buttons use filename-based helpers (`isSlicedFilename`, `isSliceableFilename`) that already accept `.gcode.3mf`, so they need no change. **Tests:** new `test_library_get_gcode_recovers_legacy_gcode_type_for_3mf` regression case in `test_library_api.py` constructs a row with `file_type="gcode"` + `.gcode.3mf` filename pointing at a real ZIP, asserts the response is `text/plain`, contains `G28`, and does NOT start with `PK` — pins the legacy-row recovery path. Existing `test_library_get_gcode_endpoint_accepts_compound_file_type` continues to cover the forward path. Full backend suite 5920/5920 green; ruff clean; frontend ESLint + `npm run build` clean; FileManagerPage / ProjectDetailPage / FileManagerExternalFolder vitests 69/69 green; i18n parity unchanged (no new keys). PR #1709 closed for CONTRIBUTING.md non-compliance (branched from main, no issue, template incomplete); root cause + fix shape preserved here on `dev`. - **Cloud + Orca Cloud preset resolver: pin `type` and `from` to CLI-accepted values (#1712 follow-up, reported by maziggy on the Mecha Mewtwo slice)** — Removing bundle mode (entry above) routed every slot through the cross-tier preset resolver. Cloud-tier presets surfaced two latent shape mismatches that bundle dispatch had been masking by materialising preset JSONs from `.bbscfg`-on-disk. (1) **`type` field**: Bambu Cloud labels presets with `type: "printer"` / `"print"` / `"filament"`, but the BambuStudio CLI's `--load-settings` parser only accepts `"machine"` / `"process"` / `"filament"`. The user's first failing slice produced `operator(): unknown config type print of file preset.json in load-settings` with exit code -5; the sidecar surfaces this as a generic "The input preset file is invalid and can not be parsed." (2) **`from` field**: Bambu Cloud's filament detail endpoint routinely ships presets with empty `from` (or no `from` at all). The CLI's compatibility check rejects either with `operator(): file ... 's from unsupported` (the double space in stderr = empty value). Same -5 exit, same generic "input preset invalid" surface. The sidecar's `normalizeFromField` already maps `"User"` / `"System"` → `"system"`, but it doesn't touch empty / missing values. **Fix:** `_resolve_cloud` and `_resolve_orca_cloud` now force `type = _SLOT_TO_PROFILE_TYPE[slot]` and `from = "system"` on the payload before `json.dumps`, mirroring what `_resolve_standard` already does for the standard-tier stub. Both fields are unconditionally rewritten — idempotent on already-correct payloads, and pinning to "system" is consistent with how Bambuddy presents these post-flatten presets to the CLI (no parent walk needed, the cloud detail comes back fully expanded). **Tests:** new `test_cloud_rewrites_type_field_for_cli` (7 parametric cases covering all six type-name variants Bambu Cloud emits plus the missing-type case), `test_cloud_pins_from_field_to_system` (4 cases: empty, already-system, GUI User, GUI System), and `test_cloud_synthesises_from_field_when_missing` (the actual Mecha Mewtwo failure shape) pin the resolver-level contract. Existing happy-path assertions for `_resolve_cloud` / `_resolve_orca_cloud` updated to include the new fields. 28/28 preset-resolver tests green, full backend suite 5919/5919 green, ruff clean. **What this can NOT recover:** if Bambu Cloud later starts emitting a `from` value other than empty / "User" / "System" that genuinely means something (e.g. "project"), Bambuddy will silently flatten it to "system" too. We accept that trade-off because the alternative is leaving "input preset invalid" failures on every cloud slice, and "system" matches how the sidecar's own resolver normalises the post-flatten state. diff --git a/backend/app/api/routes/printers.py b/backend/app/api/routes/printers.py index 7f90cef7b..c6741bab9 100644 --- a/backend/app/api/routes/printers.py +++ b/backend/app/api/routes/printers.py @@ -1535,8 +1535,12 @@ async def delete_printer_file( if not printer: raise HTTPException(404, "Printer not found") - success = await delete_file_async(printer.ip_address, printer.access_code, path, printer_model=printer.model) - if not success: + from backend.app.services.bambu_ftp import DeleteResult + + result = await delete_file_async(printer.ip_address, printer.access_code, path, printer_model=printer.model) + if result == DeleteResult.NOT_FOUND: + raise HTTPException(404, f"File not found on printer: {path}") + if result == DeleteResult.FAILED: raise HTTPException(500, f"Failed to delete file: {path}") return {"status": "deleted", "path": path} diff --git a/backend/app/main.py b/backend/app/main.py index 206b43418..928f44ed1 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -3375,11 +3375,14 @@ async def _cleanup_forced_timelapse(archive_id: int, printer_id: int) -> None: # _scan_for_timelapse_with_retries used the original filename when it # attached, so the basename of timelapse_path matches the printer-side # filename. Try the directories the scanner walks (#1397). + from backend.app.services.bambu_ftp import DeleteResult + filename = Path(local_relpath).name + any_real_failure = False for remote_dir in ("/timelapse", "/timelapse/video", "/record", "/recording"): remote_path = f"{remote_dir}/{filename}" try: - ok = await delete_file_async( + result = await delete_file_async( printer.ip_address, printer.access_code, remote_path, @@ -3388,15 +3391,29 @@ async def _cleanup_forced_timelapse(archive_id: int, printer_id: int) -> None: except Exception as e: logger.debug("[FORCED-TIMELAPSE] FTP delete attempt failed for %s: %s", remote_path, e) continue - if ok: + if result == DeleteResult.DELETED: logger.info("[FORCED-TIMELAPSE] Deleted printer-side timelapse %s", remote_path) return + if result == DeleteResult.FAILED: + any_real_failure = True - logger.warning( - "[FORCED-TIMELAPSE] Could not delete printer-side timelapse %s for archive %s (file may already be gone)", - filename, - archive_id, - ) + # All four dirs returned NOT_FOUND with no actual failures: the printer + # never wrote a file under any expected path (or already swept). That's + # the normal post-print state on most models — debug, not warning. + if any_real_failure: + logger.warning( + "[FORCED-TIMELAPSE] Could not delete printer-side timelapse %s for archive %s " + "(network/auth/transient error)", + filename, + archive_id, + ) + else: + logger.debug( + "[FORCED-TIMELAPSE] No printer-side timelapse to delete for %s (archive %s) — " + "every candidate dir returned 550", + filename, + archive_id, + ) async def on_print_running_observed(printer_id: int, data: dict): @@ -3786,7 +3803,7 @@ async def on_print_complete(printer_id: int, data: dict): archive_filename = archive_row.scalar_one_or_none() if printer: - from backend.app.services.bambu_ftp import delete_file_async + from backend.app.services.bambu_ftp import DeleteResult, delete_file_async from backend.app.utils.filename import derive_remote_filename # Primary candidate: the exact path the dispatcher uploaded to @@ -3804,8 +3821,23 @@ async def on_print_complete(printer_id: int, data: dict): if fallback not in candidate_paths: candidate_paths.append(fallback) + # Three outcomes track across all candidates so the final log + # line reflects what actually happened. The A1 in #1721 always + # ends here with ``any_not_found=True`` and the others False + # — its firmware auto-cleans the SD card before our cleanup + # runs, every candidate FTP-DELE returns 550, and the old + # code burned 3 retries × 2 s × 3 candidates per print + # logging a misleading "may linger" WARNING on a successful + # print. + any_deleted = False + any_real_failure = False + any_not_found = False + for remote_path in candidate_paths: - # Retry up to 3 times — the printer may still lock the filesystem briefly after a print ends + # Retry only the FAILED case — 550 NOT_FOUND will never + # recover by waiting, so a "file isn't here" answer + # advances immediately to the next candidate without + # consuming the retry budget. for attempt in range(1, 4): try: delete_result = await delete_file_async( @@ -3814,24 +3846,43 @@ async def on_print_complete(printer_id: int, data: dict): remote_path, printer_model=printer.model, ) - if delete_result: - logger.info("Deleted %s from printer %s SD card", remote_path, printer.name) - break except Exception as e: - delete_result = False + delete_result = DeleteResult.FAILED logger.warning( "SD card cleanup attempt %d/3 raised for %s: %s", attempt, remote_path, e, ) - if not delete_result and attempt < 3: + + if delete_result == DeleteResult.DELETED: + any_deleted = True + logger.info("Deleted %s from printer %s SD card", remote_path, printer.name) + break + if delete_result == DeleteResult.NOT_FOUND: + any_not_found = True + break # 550 will not recover; try next candidate + # FAILED: real error — retry with backoff, then give up + if attempt < 3: await asyncio.sleep(2) - elif not delete_result: + else: + any_real_failure = True logger.warning( - "SD card cleanup failed after 3 attempts for %s (file may linger on SD card)", + "SD card cleanup failed after 3 attempts for %s " + "(network/auth/transient error — file may linger on SD card)", remote_path, ) + + if not any_deleted and not any_real_failure and any_not_found: + # Every candidate said "not here." Either the printer + # firmware swept the SD card itself (common on A1) or the + # dispatcher's upload path doesn't match our candidate + # rule. Either way: nothing to clean up, no warning. + logger.debug( + "SD card cleanup: nothing to delete on %s — every candidate returned 550 " + "(printer likely self-cleaned)", + printer.name, + ) except Exception as e: logger.warning("SD card file cleanup failed for printer %s: %s", printer_id, e) diff --git a/backend/app/services/bambu_ftp.py b/backend/app/services/bambu_ftp.py index 1fd909a31..2f7e3228d 100644 --- a/backend/app/services/bambu_ftp.py +++ b/backend/app/services/bambu_ftp.py @@ -7,6 +7,7 @@ import ssl import threading import time from collections.abc import Awaitable, Callable +from enum import Enum from ftplib import FTP, FTP_TLS # nosec B402 from io import BytesIO from pathlib import Path @@ -17,6 +18,22 @@ logger = logging.getLogger(__name__) T = TypeVar("T") +class DeleteResult(Enum): + """Outcome of an FTP delete attempt. + + Distinguishes "file isn't on the printer" (550, recovery impossible by + retrying) from "delete failed for some other reason" (network, auth, + transient FTP error — worth retrying). The post-print SD-card cleanup in + main.py used to flatten both into ``False`` and log a "may linger" WARNING + on every successful print where the printer self-cleaned its SD card + before our cleanup ran (#1721 reporter's A1). + """ + + DELETED = "deleted" + NOT_FOUND = "not_found" + FAILED = "failed" + + class FileNotOnPrinterError(Exception): """Raised when a remote FTP path returns 550 (file not found). @@ -507,14 +524,16 @@ class BambuFTPClient: ) if callback_exception is not None: - cleanup_ok = False + cleanup_result: DeleteResult = DeleteResult.FAILED try: - cleanup_ok = self.delete_file(remote_path) + cleanup_result = self.delete_file(remote_path) except Exception as cleanup_error: logger.warning("FTP cancel cleanup failed for %s: %s", remote_path, cleanup_error) - if cleanup_ok: - logger.info("FTP cancel cleanup succeeded for %s", remote_path) + # NOT_FOUND is success here — the partial file is gone (printer + # may have already swept on cancel), which is the goal. + if cleanup_result in (DeleteResult.DELETED, DeleteResult.NOT_FOUND): + logger.info("FTP cancel cleanup succeeded for %s (%s)", remote_path, cleanup_result.value) raise callback_exception raise RuntimeError( @@ -621,17 +640,28 @@ class BambuFTPClient: except (OSError, ftplib.Error): return False - def delete_file(self, remote_path: str) -> bool: - """Delete a file from the printer.""" + def delete_file(self, remote_path: str) -> DeleteResult: + """Delete a file from the printer. + + Returns :class:`DeleteResult` distinguishing the file-not-found case + (550) from network / auth / transient FTP failure. Callers that just + want "did it work" should check ``result == DeleteResult.DELETED``. + """ if not self._ftp: - return False + return DeleteResult.FAILED try: self._ftp.delete(remote_path) - return True + return DeleteResult.DELETED + except ftplib.error_perm as e: + if str(e).startswith("550"): + logger.debug("FTP delete: %s not on printer (550)", remote_path) + return DeleteResult.NOT_FOUND + logger.warning("Failed to delete %s: %s", remote_path, e) + return DeleteResult.FAILED except (OSError, ftplib.Error) as e: logger.warning("Failed to delete %s: %s", remote_path, e) - return False + return DeleteResult.FAILED def get_file_size(self, remote_path: str) -> int | None: """Get the size of a file.""" @@ -1055,23 +1085,27 @@ async def delete_file_async( remote_path: str, socket_timeout: float | None = None, printer_model: str | None = None, -) -> bool: +) -> DeleteResult: """Async wrapper for deleting a file. + Returns :class:`DeleteResult` so callers can distinguish ``NOT_FOUND`` + (550 — file isn't on the printer, no retry value) from ``FAILED`` + (network / auth / transient — worth retrying or surfacing). + Args: socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers) printer_model: Printer model for A1-specific workarounds """ loop = asyncio.get_event_loop() - def _delete(): + def _delete() -> DeleteResult: client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model) if client.connect(): try: return client.delete_file(remote_path) finally: client.disconnect() - return False + return DeleteResult.FAILED return await loop.run_in_executor(None, _delete) diff --git a/backend/app/services/virtual_printer/mqtt_bridge.py b/backend/app/services/virtual_printer/mqtt_bridge.py index 328b72e83..4365760c7 100644 --- a/backend/app/services/virtual_printer/mqtt_bridge.py +++ b/backend/app/services/virtual_printer/mqtt_bridge.py @@ -371,18 +371,38 @@ class MQTTBridge: # but that fires before the bridge attaches as a raw-message consumer, # so without this nudge the cache stays empty until the next periodic # query (which can be minutes away). - request_fn = getattr(current, "_request_version", None) - if callable(request_fn): - try: - request_fn() - except Exception: - logger.exception("[%s] MQTT bridge: _request_version failed", self.vp_name) - request_status_fn = getattr(current, "request_status_update", None) - if callable(request_status_fn): - try: - request_status_fn() - except Exception: - logger.exception("[%s] MQTT bridge: request_status_update failed", self.vp_name) + # + # The bind frequently races the real printer's MQTT TLS handshake — a + # slicer-side reconnect re-resolves the client before the underlying + # session has reconnected, especially on A1 firmware where the bridge + # cycles more aggressively (#1721). When that happens, the nudge is a + # no-op — the next periodic pushall populates the cache anyway — but + # `request_status_update` logs WARNING on the not-connected return path + # and pollutes every support bundle with a benign line. + # + # Gate both nudges on the client being actually connected. The fall- + # through path is unchanged: when the client comes up, the next + # `_resolve_client` tick re-enters this branch on identity change OR + # the periodic pushall in `bambu_mqtt.py` fills the cache. + client_connected = bool(getattr(getattr(current, "state", None), "connected", False)) + if not client_connected: + logger.debug( + "[%s] MQTT bridge: post-bind nudge skipped (printer client not connected yet)", + self.vp_name, + ) + else: + request_fn = getattr(current, "_request_version", None) + if callable(request_fn): + try: + request_fn() + except Exception: + logger.exception("[%s] MQTT bridge: _request_version failed", self.vp_name) + request_status_fn = getattr(current, "request_status_update", None) + if callable(request_status_fn): + try: + request_status_fn() + except Exception: + logger.exception("[%s] MQTT bridge: request_status_update failed", self.vp_name) def _unbind_client(self) -> None: if self._target_client is None: diff --git a/backend/tests/unit/services/test_bambu_ftp.py b/backend/tests/unit/services/test_bambu_ftp.py index 10e52bd11..f95bd18c4 100644 --- a/backend/tests/unit/services/test_bambu_ftp.py +++ b/backend/tests/unit/services/test_bambu_ftp.py @@ -575,26 +575,32 @@ class TestDelete: def test_delete_success(self, ftp_client_factory, ftp_server): """Successful file deletion.""" + from backend.app.services.bambu_ftp import DeleteResult + ftp_server.add_file("cache/to_delete.bin", b"delete me") client = ftp_client_factory() client.connect() result = client.delete_file("/cache/to_delete.bin") - assert result is True + assert result == DeleteResult.DELETED assert not ftp_server.file_exists("cache/to_delete.bin") client.disconnect() def test_delete_not_found(self, ftp_client_factory): - """Deleting a nonexistent file returns False.""" + """Deleting a nonexistent file returns NOT_FOUND (550, #1721).""" + from backend.app.services.bambu_ftp import DeleteResult + client = ftp_client_factory() client.connect() result = client.delete_file("/cache/no_such_file.bin") - assert result is False + assert result == DeleteResult.NOT_FOUND client.disconnect() def test_delete_not_connected(self): - """Delete when not connected returns False.""" + """Delete when not connected returns FAILED.""" + from backend.app.services.bambu_ftp import DeleteResult + client = BambuFTPClient("127.0.0.1", "12345678") - assert client.delete_file("/cache/test.bin") is False + assert client.delete_file("/cache/test.bin") == DeleteResult.FAILED # --------------------------------------------------------------------------- @@ -1053,6 +1059,8 @@ class TestAsyncWrappers: @pytest.mark.asyncio async def test_delete_file_async_success(self, patch_ftp_port): """delete_file_async deletes a file.""" + from backend.app.services.bambu_ftp import DeleteResult + server = patch_ftp_port server.add_file("cache/to_async_del.bin", b"delete me") result = await delete_file_async( @@ -1061,9 +1069,22 @@ class TestAsyncWrappers: "/cache/to_async_del.bin", printer_model="X1C", ) - assert result is True + assert result == DeleteResult.DELETED assert not server.file_exists("cache/to_async_del.bin") + @pytest.mark.asyncio + async def test_delete_file_async_not_found(self, patch_ftp_port): + """delete_file_async distinguishes 550 from real failure (#1721).""" + from backend.app.services.bambu_ftp import DeleteResult + + result = await delete_file_async( + "127.0.0.1", + "12345678", + "/cache/never_existed.bin", + printer_model="X1C", + ) + assert result == DeleteResult.NOT_FOUND + # --------------------------------------------------------------------------- # TestFailureScenarios diff --git a/backend/tests/unit/test_cleanup_forced_timelapse.py b/backend/tests/unit/test_cleanup_forced_timelapse.py index 1745661bc..a6d0fa95c 100644 --- a/backend/tests/unit/test_cleanup_forced_timelapse.py +++ b/backend/tests/unit/test_cleanup_forced_timelapse.py @@ -25,6 +25,7 @@ import pytest from backend.app import main as main_module from backend.app.main import _cleanup_forced_timelapse +from backend.app.services.bambu_ftp import DeleteResult def _fake_session_factory(rows: dict): @@ -92,7 +93,7 @@ async def test_not_forced_is_noop(monkeypatch, tmp_path): video_path.parent.mkdir(parents=True, exist_ok=True) video_path.write_bytes(b"x" * 100) - delete_mock = AsyncMock(return_value=True) + delete_mock = AsyncMock(return_value=DeleteResult.DELETED) with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): await _cleanup_forced_timelapse(archive_id=99, printer_id=10) @@ -123,7 +124,7 @@ async def test_forced_deletes_local_and_remote(monkeypatch, tmp_path): video_path.write_bytes(b"x" * 100) # FTP DELE succeeds on the first directory we try. - delete_mock = AsyncMock(return_value=True) + delete_mock = AsyncMock(return_value=DeleteResult.DELETED) with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): await _cleanup_forced_timelapse(archive_id=99, printer_id=10) @@ -158,9 +159,10 @@ async def test_forced_walks_alternate_dirs_when_first_fails(monkeypatch, tmp_pat video_path.parent.mkdir(parents=True, exist_ok=True) video_path.write_bytes(b"x" * 100) - # First two attempts fail (False), third succeeds (True). Cleanup - # should stop after the third. - delete_mock = AsyncMock(side_effect=[False, False, True]) + # First two dirs report NOT_FOUND (file not there), third succeeds. + # Cleanup should stop after the third — and crucially must NOT WARN + # because no real network/auth failure happened (#1721). + delete_mock = AsyncMock(side_effect=[DeleteResult.NOT_FOUND, DeleteResult.NOT_FOUND, DeleteResult.DELETED]) with patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock): await _cleanup_forced_timelapse(archive_id=99, printer_id=10) @@ -203,3 +205,87 @@ async def test_forced_local_cleanup_runs_even_if_ftp_unreachable(monkeypatch, tm assert archive.timelapse_path is None # All four dirs were attempted before giving up. assert delete_mock.await_count == 4 + + +@pytest.mark.asyncio +async def test_forced_no_warning_when_every_dir_returns_not_found(monkeypatch, tmp_path, caplog): + """#1721: when every candidate dir returns 550 (file not there) the + helper used to emit "Could not delete printer-side timelapse ... + (file may already be gone)" at WARNING. That message landed in support + bundles for healthy printers whose firmware swept the SD card itself. + With DeleteResult.NOT_FOUND signalling, no real failure happened → + must be DEBUG, not WARNING. + """ + import logging + + archive = SimpleNamespace( + bambuddy_forced_timelapse=True, + timelapse_path="archive/1/myprint.mp4", + ) + printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="N2S") + monkeypatch.setattr( + main_module, + "async_session", + _fake_session_factory({"PrintArchive": archive, "Printer": printer}), + ) + + video_path = tmp_path / archive.timelapse_path + video_path.parent.mkdir(parents=True, exist_ok=True) + video_path.write_bytes(b"x" * 100) + + delete_mock = AsyncMock(return_value=DeleteResult.NOT_FOUND) + with ( + caplog.at_level(logging.DEBUG, logger="backend.app.main"), + patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock), + ): + await _cleanup_forced_timelapse(archive_id=99, printer_id=10) + + assert delete_mock.await_count == 4 + warnings = [r for r in caplog.records if r.levelno >= logging.WARNING and "[FORCED-TIMELAPSE]" in r.message] + assert warnings == [], f"unexpected WARNING(s): {[w.message for w in warnings]}" + debugs = [ + r for r in caplog.records if r.levelno == logging.DEBUG and "No printer-side timelapse to delete" in r.message + ] + assert len(debugs) == 1, "expected the 'nothing to delete' debug summary" + + +@pytest.mark.asyncio +async def test_forced_warns_when_any_dir_returns_failed(monkeypatch, tmp_path, caplog): + """Counterpart to the above: a real network/auth/transient FAILED on any + dir keeps the WARNING — that's the signal the maintainer actually wants + to see. + """ + import logging + + archive = SimpleNamespace( + bambuddy_forced_timelapse=True, + timelapse_path="archive/1/myprint.mp4", + ) + printer = SimpleNamespace(ip_address="10.0.0.5", access_code="12345678", model="O1C") + monkeypatch.setattr( + main_module, + "async_session", + _fake_session_factory({"PrintArchive": archive, "Printer": printer}), + ) + + video_path = tmp_path / archive.timelapse_path + video_path.parent.mkdir(parents=True, exist_ok=True) + video_path.write_bytes(b"x" * 100) + + delete_mock = AsyncMock( + side_effect=[ + DeleteResult.NOT_FOUND, + DeleteResult.FAILED, + DeleteResult.NOT_FOUND, + DeleteResult.NOT_FOUND, + ] + ) + with ( + caplog.at_level(logging.WARNING, logger="backend.app.main"), + patch("backend.app.services.bambu_ftp.delete_file_async", new=delete_mock), + ): + await _cleanup_forced_timelapse(archive_id=99, printer_id=10) + + warnings = [r for r in caplog.records if r.levelno >= logging.WARNING and "[FORCED-TIMELAPSE]" in r.message] + assert len(warnings) == 1 + assert "network/auth/transient" in warnings[0].message diff --git a/backend/tests/unit/test_vp_mqtt_bridge.py b/backend/tests/unit/test_vp_mqtt_bridge.py index 7a2fbc839..fdb7bc46a 100644 --- a/backend/tests/unit/test_vp_mqtt_bridge.py +++ b/backend/tests/unit/test_vp_mqtt_bridge.py @@ -150,6 +150,22 @@ class TestBridgeLifecycle: target.request_status_update.assert_called_once() await bridge.stop() + @pytest.mark.asyncio + async def test_post_bind_nudge_skipped_when_target_not_connected(self): + """#1721: the bridge can attach before the real printer's MQTT TLS + handshake completes. Calling request_status_update on a disconnected + client logs WARNING (bambu_mqtt.py:3224); on A1 firmware that + reconnects aggressively, every bind cycle pollutes the support bundle + with a benign line. The bridge must check state.connected before + nudging — the next periodic pushall picks up the cache anyway. + """ + target = _make_paho_client(connected=False) + bridge = _make_bridge(_make_server(), target) + await bridge.start() + target._request_version.assert_not_called() + target.request_status_update.assert_not_called() + await bridge.stop() + # --------------------------------------------------------------------------- # Caching: push_status