diff --git a/CHANGELOG.md b/CHANGELOG.md index 66520446c..805c592dc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -37,6 +37,7 @@ All notable changes to Bambuddy will be documented in this file. - **Sort File Manager folder tree by recent activity (#1770, requested by @Kingbuzz0)** — Until now the folder tree was always sorted alphabetically by name, both backend (`order_by(LibraryFolder.name)`) and frontend. The reporter — a user with a lot of nested cad / slicer directories — wanted "find folders that just got a new 3MF" without scrolling the whole alphabet. **What changed.** The folder sidebar header gains a small dropdown (**By name** / **By recent activity**) plus an asc / desc arrow button, sitting alongside the existing Collapse + Wrap toggles. Choice persists per-browser via `localStorage` (`library-folder-sort-field`, `library-folder-sort-direction`) so the preference survives reloads. **Activity semantics.** `latest_activity_at` per folder = `MAX(folder.updated_at, MAX(immediate-child file.updated_at))`. The DB had the data — `LibraryFile.updated_at` is `onupdate=func.now()` and `LibraryFolder.updated_at` the same — but `LibraryFolder.updated_at` alone only bumps on rename / move, not on file-add inside the folder, which is exactly the wrong signal for "did I just drop a new model in here." The aggregate fixes that. Recursion across subfolders is intentionally **NOT** computed — a deeply nested new 3MF bubbles its immediate parent, not every ancestor up to the root. This keeps the route a single `GROUP BY` rather than a recursive CTE, matching the existing file_counts subquery shape sibling at `library.py:746`. A future Tier 3 follow-up could add the recursive-CTE variant if anyone reports deeply-nested updates not bubbling far enough. **Backend.** New `latest_activity_at: datetime | None` field on `FolderResponse` and `FolderTreeItem` schemas. The `/folders` tree route picks up a sibling `func.max(LibraryFile.updated_at)` group-by alongside the existing file-count subquery; resolves the field per row. The `/folders/by-project/{id}` and `/folders/by-archive/{id}` routes collapse their per-row file-count subquery to fetch `count + max` in one trip (one extra column, zero extra round-trips). All 5 single-folder constructors (POST `/folders`, GET `/folders/{id}`, PUT `/folders/{id}`, POST `/folders/external`, the create flows) populate the field with `max(folder.updated_at, latest_file)` or fall back to `folder.updated_at` when there are no files, so the API surface is consistent across every route that returns a folder. **External folders.** `LibraryFile` rows are created for scanned external files too (`library.py:526`), so the MAX aggregate works on them — but the timestamp reflects when Bambuddy last *scanned / re-indexed* the file, not the filesystem mtime. For a NAS that gets new files added outside Bambuddy, the activity-sort lags until the next scan. Documented in the file-manager wiki page rather than papered over with `os.stat()` on every list call, which would stall the route on slow mounts. **Frontend.** A new recursive `sortedFolders` `useMemo` applies the comparator uniformly to top-level + every nested `children` level so sort order is consistent at every depth. Comparator falls back to name when activity timestamps tie or are both null, so an empty folder never elbows a recently-used one to a random place — empties go to the end of the activity bucket regardless of direction. Both the desktop sidebar render and the mobile selector dropdown consume `sortedFolders` so the order is identical across breakpoints. The single-folder `findFolder()` traversal and `selectedFolder` memo still operate on the unsorted `folders` because they index by ID — sort-order-independent. **Recursion safety.** The sort creates fresh object refs at every level on every memo invocation; the `FolderTreeItem` keys stay ID-based (`${folder.id}-${collapseFoldersByDefault ? 'c' : 'e'}`) so React reconciliation by ID preserves folder expansion state across sort flips. **i18n.** 3 new keys in `fileManager.*` (`folderSort`, `folderSortByName`, `folderSortByActivity`) translated in all 11 locales (de / en / es / fr / it / ja / ko / pt-BR / tr / zh-CN / zh-TW), no English fallback. Parity 5238 leaves per locale. **Tests.** 2 new backend integration cases in `test_library_api.py` (file-in-folder bubbles `latest_activity_at` to the file's timestamp, empty folder falls back to `folder.updated_at`). All 152 library + folder + trash + slice integration tests still pass; 51/51 FileManagerPage frontend tests still pass; 26/26 QueuePage tests still pass; `npm run build` clean; `ruff` clean; i18n parity green. ### Fixed +- **Large prints uploaded twice at once and never landed (#2529, reporter @PDXDave23)** — On a 14-printer A1 farm, dispatches "failed over and over" and looked like flaky WiFi. The reporter's screen recording is the proof: the dispatch toast tracks a single job (96.1 MB, one printer), yet its byte counter alternates between two *independently rising* series — 69.4 → 70.8 MB and 1.6 → 2.9 MB, both climbing at ~75 KB/s. That is not a progress bar jumping. That is two FTP transfers of the same file, to the same printer, at the same time, reporting into the same bar. **Root cause.** `upload_file_async` carried a flat `timeout: float = 600.0` and ran the transfer as `asyncio.wait_for(loop.run_in_executor(...))`. `wait_for` cancels the *future*; it cannot cancel a thread already running in an executor. So on a link slow enough that a big file needs more than ten minutes — 96 MB at 75 KB/s needs twenty — the await gave up at 600 s, returned `False`, and `with_ftp_retry` started attempt two *while attempt one was still streaming*, both writing the same `remote_path`. Do the arithmetic and the stale series sits right where the ten-minute clock expires. With `ftp_retry_count: 3` plus the A1's prot_p→prot_c fallback that is up to six concurrent STORs onto one SD card; each orphaned thread also permanently held a slot in the default executor pool, which on a farm can starve every other FTP operation. The flat cap was never a failure detector in the first place — a link that has actually *died* is caught within `socket_timeout` (30 s) by the blocking `sendall`. It only ever punished large files. **Fix, three parts.** The deadline is now derived from the file size against a deliberately pessimistic 25 KB/s floor (`_upload_deadline`), so a slow-but-healthy transfer is allowed to finish. A deadline expiry now genuinely *stops* the transfer: it signals the worker, which raises `UploadCancelled` from its progress callback — the existing cancel path in `upload_file`, which breaks the send loop and deletes the partial file from the printer — and the caller waits for the thread to actually go before returning. And `with_ftp_retry` never retries an `UploadCancelled`: the deadline means the link sustained less than the floor rate for the whole transfer, so a retry would only spend another full deadline learning that again, and with `check_queue` serialized four of those would block the entire print queue for hours. A per-printer upload lock closes the last hole, so no two uploads can ever overlap on one printer regardless of how they were triggered. Queue items that hit the deadline now say the upload was too slow and to check the printer's WiFi, rather than the old (and here entirely misleading) "check if SD card is inserted". **Tests.** 6 cases: the deadline scales with file size and floors correctly; a timeout stops the worker thread and cleans its partial file off the printer; a timeout is not retried; concurrent dispatches to one printer serialize; and the real client's cancel path removes the partial file, driven end to end against the mock FTPS server. Verified by mutation — dropping the cancel signal, the retry guard, or the lock each fails its test. **Scope.** Backend only. No DB migration, no schema change, no new permission, no i18n change. - **"Start Drying" gave no feedback and reported success the printer never delivered (#2533, reporter @naldo29)** — On the reporter's P1S the button appeared dead: no toast, no badge, no drying. Their bundle shows Bambuddy doing everything right — the `ams_filament_drying` payload matches BambuStudio field-for-field, was sent three times with the printer idle, and the firmware answered `result: success` to each — while the AMS 2 Pro (`module_type: n3f`) stayed at `dry_status: 0`. The printer takes the command and drops it. Two gaps on our side made that indistinguishable from a broken button. **No confirmation.** `startDryingMutation` / `stopDryingMutation` closed the popover and invalidated the status cache without ever toasting, alone among the printer card's actions — so a user who clicked Start had nothing at all to tell them the click had registered. Both now toast on success — and the start toast says "Drying command sent", not "Drying started", because at that moment the printer has only *taken* the command. What says the cycle is genuinely live is the amber countdown badge, which is keyed on `dry_time` and therefore only appears when firmware reports one. **Success was inferred from the MQTT ack.** The #971 guard that turns firmware's refusal into a real message ("Plug in the external AMS power adapter", "AMS is already drying", …) reads the per-unit `dry_sf_reason` array — and P1-family firmware never publishes that field, so on a P1S the guard is inert and the ack is all we have. The card now watches the unit after the ack: `dry_status` and `dry_time` come straight from the `info` bitmask on every push, and firmware moves to `DryStatus 1` (Checking) within seconds of a real start. If the unit is still at zero 30 seconds later the cycle never began, and Bambuddy says so and names the two things that cause it (AMS power adapter not connected; printer not idle — P1S cannot dry mid-print, see `supports_drying_while_printing`). Unlike the `dry_sf_reason` guard this is model-agnostic: it catches any firmware that acks and declines. **Tests.** 4 component cases — the send toast, the stop toast, the warning firing when the AMS never leaves `dry_status: 0`, and no warning when it does enter a cycle. **Scope.** Frontend only; 3 new i18n keys across all 11 locales. No DB migration, no schema change, no new permission. - **Enabling authentication silently disconnected Bambu Cloud (#2530, reporter @hburn7)** — Cloud credentials live in two different places depending on auth state: `get_stored_token()` reads the global `Settings` rows (`bambu_cloud_token` / `_email` / `_region`) when auth is off, and `User.cloud_token` when it's on. Completing `POST /auth/setup` flipped which store the `/cloud/*` routes consult, but nothing carried the token across — so an operator who linked their Bambu account *before* turning on auth found the freshly-created admin had `cloud_token = NULL`. `build_authenticated_cloud()` then returned `None` and every cloud route degraded: `get_filament_info` skipped its cloud phase entirely and answered `200` from the local-preset and built-in-name fallbacks, while `/cloud/devices` began returning `401`. Nothing surfaced the disconnect. The reporter observed the *symptom inverted* — cloud `400` warnings vanished after enabling auth — and reasonably read that as a fix; in fact the warnings stopped because Bambuddy had stopped calling the cloud at all. The tell is in their own timestamps: the pre-auth request spent ~960 ms on cloud round-trips, the post-auth one answered immediately. **Fix.** `setup_auth()` now migrates a globally-stored token onto the owning admin (and deletes the global rows, so a live credential isn't left at rest in a table nothing reads), and `disable_auth()` performs the mirror hand-off back to global storage. Both refuse to guess when ownership is ambiguous: setup migrates only when it creates the admin or exactly one admin already exists — with several admins it leaves the credential in place and logs a warning rather than handing one admin another's Bambu session; disable declines to overwrite a pre-existing global token. The `region` survives both hops rather than silently resetting to `global`. **Note for existing installs.** The migration runs at the auth on/off transition, so instances that already crossed it must re-link their Bambu account once from Settings → Bambu Cloud; the stranded `bambu_cloud_*` rows in `settings` can then be deleted. **Tests.** 7 integration cases pinning both directions, the two refuse-to-guess paths, the `auth_enabled=false` no-op, and region preservation. **Scope.** No DB migration, no schema change, no new permission, no i18n change. - **Routine cloud preset misses no longer log at WARNING (#2530)** — The `Failed to get cloud preset … 400 {"message":"missing"}` lines that led to #2530 being filed are an *expected* answer, not a fault, and `get_filament_info`'s Phase 3 already resolves the name from local presets (a bare `GFL05` lands on "Overture Matte PLA" without the cloud). Two routine causes, both confirmed against the live Bambu catalog: many official presets are only addressable with a printer-variant suffix — `GFSA00` and `GFSL99` resolve bare, but `GFSL05` and `GFSG00` exist *only* as `GFSL05_07` (`@BBL A1`), `GFSG00_06` and so on, while the AMS reports the bare ID; and personal presets (`P…`, e.g. `Pb5b7d17`) belong to whichever Bambu account sliced the file, so no other account will ever resolve them. Emitting a WARNING per tray on every AMS tooltip refresh trains operators to ignore the log. `BambuCloudError` now carries the upstream `status_code`, and the preset lookup logs an HTTP 400 at DEBUG while leaving every other failure — expired token, 5xx, connection error — at WARNING, so a genuine fault is still loud. Deliberately *not* fixed here: resolving the variant suffix. The suffix selects a printer profile, and the endpoint returns `pressure_advance` (the K value), which is per-printer — picking a suffix arbitrarily would populate AMS tooltips with another printer's K value, which is worse than the current blank. Doing that correctly requires threading the tray's printer model into `get_filament_info`, which changes the endpoint contract. **Tests.** 4 parametrised cases drive the real route with a stubbed cloud and assert the 400 lands at DEBUG while 401 / 502 / transport failures stay at WARNING; verified by mutation (forcing the classification off fails the 400 case). diff --git a/backend/app/services/bambu_ftp.py b/backend/app/services/bambu_ftp.py index d7b5e1459..34a7ced27 100644 --- a/backend/app/services/bambu_ftp.py +++ b/backend/app/services/bambu_ftp.py @@ -6,6 +6,7 @@ import socket import ssl import threading import time +import weakref from collections.abc import Awaitable, Callable from enum import Enum from ftplib import FTP, FTP_TLS # nosec B402 @@ -17,6 +18,32 @@ logger = logging.getLogger(__name__) T = TypeVar("T") +# Overall upload deadline (#2529). A flat wall-clock cap punishes big files on +# slow links rather than catching broken ones: a 96 MB 3MF at the ~75 KB/s an A1 +# sustains over WiFi legitimately needs ~20 minutes, and the old flat 600 s +# declared it dead at ~70 MB. The deadline is therefore derived from the file +# size against a deliberately pessimistic floor rate. This is a backstop, not the +# failure detector — a link that has actually died is caught within +# ``socket_timeout`` by the blocking ``sendall``, long before this fires. +_UPLOAD_FLOOR_BYTES_PER_SEC = 25 * 1024 +_UPLOAD_MIN_TIMEOUT = 600.0 + +# How long to give the worker thread to notice the cancel flag, unwind, and +# delete its partial file. It checks the flag once per CHUNK_SIZE, so on a link +# slow enough to have hit the deadline this is one chunk plus the delete. +_UPLOAD_CANCEL_GRACE = 60.0 + + +class UploadCancelled(Exception): + """Raised inside the upload worker to abort an in-flight transfer. + + ``upload_file`` treats any exception from its progress callback as "stop + now": it breaks out of the send loop, deletes the partial file from the + printer, and re-raises. That is the only way to stop a transfer — an + executor thread cannot be cancelled from the event loop, so a bare + ``asyncio.wait_for`` leaves it streaming (see ``upload_file_async``). + """ + class DeleteResult(Enum): """Outcome of an FTP delete attempt. @@ -980,12 +1007,45 @@ async def download_file_try_paths_async( return await loop.run_in_executor(None, _download) +def _upload_deadline(local_path: Path) -> float: + """Derive an upload deadline from the file size (#2529). + + See ``_UPLOAD_FLOOR_BYTES_PER_SEC``. An unstat-able file falls back to the + floor timeout — ``upload_file`` will fail on the open() anyway. + """ + try: + size = local_path.stat().st_size + except OSError: + return _UPLOAD_MIN_TIMEOUT + return max(_UPLOAD_MIN_TIMEOUT, size / _UPLOAD_FLOOR_BYTES_PER_SEC) + + +# One upload at a time per printer. Two concurrent STOR commands for the same +# remote path leave a corrupt file on the SD card, and the printer reads as +# flaky rather than busy (#2529). Held for the duration of a transfer, so a +# second dispatch to the same printer queues behind the first instead of racing +# it. Keyed per event loop: an asyncio.Lock binds to the loop that first awaits +# it, and the test suite runs each case on a fresh loop. +_upload_locks: weakref.WeakKeyDictionary[asyncio.AbstractEventLoop, dict[str, asyncio.Lock]] = ( + weakref.WeakKeyDictionary() +) + + +def _upload_lock(loop: asyncio.AbstractEventLoop, ip_address: str) -> asyncio.Lock: + per_loop = _upload_locks.setdefault(loop, {}) + lock = per_loop.get(ip_address) + if lock is None: + lock = asyncio.Lock() + per_loop[ip_address] = lock + return lock + + async def upload_file_async( ip_address: str, access_code: str, local_path: Path, remote_path: str, - timeout: float = 600.0, + timeout: float | None = None, progress_callback: Callable[[int, int], None] | None = None, socket_timeout: float | None = None, printer_model: str | None = None, @@ -1000,19 +1060,31 @@ async def upload_file_async( access_code: Printer access code local_path: Local file path to upload remote_path: Remote path on printer - timeout: Overall operation timeout (asyncio) + timeout: Overall deadline. ``None`` (the default) derives it from the + file size — see ``_upload_deadline``. A caller that passes a number + gets exactly that, which is what the tests rely on. progress_callback: Optional callback for progress updates 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() is_a1 = printer_model in BambuFTPClient.A1_MODELS if printer_model else False + deadline = _upload_deadline(local_path) if timeout is None else timeout + + # Set when the deadline expires. The worker checks it once per chunk. + cancel = threading.Event() + + def _guarded_progress(uploaded: int, total: int) -> None: + if cancel.is_set(): + raise UploadCancelled(f"upload of {remote_path} exceeded its {deadline:.0f}s deadline") + if progress_callback: + progress_callback(uploaded, total) def _upload(force_prot_c: bool = False) -> bool: mode_str = "prot_c" if force_prot_c else "prot_p" logger.info( f"FTP connecting to {ip_address} for upload (model={printer_model}, " - f"mode={mode_str}, socket_timeout={socket_timeout}s)..." + f"mode={mode_str}, socket_timeout={socket_timeout}s, deadline={deadline:.0f}s)..." ) client = BambuFTPClient( ip_address, access_code, timeout=socket_timeout, printer_model=printer_model, force_prot_c=force_prot_c @@ -1020,7 +1092,7 @@ async def upload_file_async( if client.connect(): logger.info("FTP connected to %s", ip_address) try: - result = client.upload_file(local_path, remote_path, progress_callback) + result = client.upload_file(local_path, remote_path, _guarded_progress) if result: # Cache the working mode BambuFTPClient.cache_mode(ip_address, mode_str) @@ -1030,32 +1102,80 @@ async def upload_file_async( logger.warning("FTP connection failed to %s", ip_address) return False - try: + async def _attempt(force_prot_c: bool) -> bool: + """Run one upload attempt, and make a timeout actually stop the transfer. + + ``asyncio.wait_for`` cancels the *future*, never the executor thread + behind it. Before #2529 a slow-but-healthy upload that overran the + deadline left that thread streaming: it kept pushing bytes, kept firing + the progress callback, and the retry above put a *second* STOR of the + same file onto the same printer. The reporter's 96 MB job ran four + concurrent transfers and never landed. So on timeout we signal the + worker (it raises ``UploadCancelled`` from the progress callback, which + breaks the send loop and deletes the partial file) and wait for it to + actually go. + """ + fut = loop.run_in_executor(None, lambda: _upload(force_prot_c)) + try: + return await asyncio.wait_for(asyncio.shield(fut), timeout=deadline) + except TimeoutError: + cancel.set() + logger.warning( + "FTP upload of %s exceeded its %.0fs deadline — cancelling the transfer", + remote_path, + deadline, + ) + try: + await asyncio.wait_for(asyncio.shield(fut), timeout=_UPLOAD_CANCEL_GRACE) + except UploadCancelled: + logger.info("FTP upload of %s cancelled; partial file removed from the printer", remote_path) + except TimeoutError: + # The thread is wedged somewhere that never reaches the callback + # (a blocked sendall, say). Nothing more we can do from here — + # but consume the eventual result so asyncio doesn't log the + # future's exception as unretrieved when it is garbage-collected. + logger.error( + "FTP upload thread for %s did not stop within %.0fs of the cancel signal", + remote_path, + _UPLOAD_CANCEL_GRACE, + ) + fut.add_done_callback(_swallow_future_result) + except Exception as e: + logger.warning("FTP upload of %s errored while cancelling: %s", remote_path, e) + # Raise rather than return False: a deadline expiry means the link + # sustained less than the floor rate for the whole transfer, and a + # retry would only spend another full deadline finding that out + # again — with check_queue serialized, four of those block the + # entire print queue for hours. ``with_ftp_retry`` never retries it. + raise UploadCancelled( + f"Upload of {remote_path} to {ip_address} exceeded its {deadline:.0f}s deadline " + f"(link sustained less than {_UPLOAD_FLOOR_BYTES_PER_SEC // 1024} KB/s)" + ) from None + + async with _upload_lock(loop, ip_address): # Check if we have a cached mode for this printer cached_mode = BambuFTPClient._mode_cache.get(ip_address) if cached_mode: # Use cached mode - force_prot_c = cached_mode == "prot_c" - return await asyncio.wait_for(loop.run_in_executor(None, lambda: _upload(force_prot_c)), timeout=timeout) + return await _attempt(cached_mode == "prot_c") # No cached mode - try prot_p first - result = await asyncio.wait_for(loop.run_in_executor(None, lambda: _upload(False)), timeout=timeout) - - if result: + if await _attempt(False): return True # Upload failed - for A1 models, try prot_c fallback if is_a1: logger.info("FTP upload failed with prot_p for A1 model, trying prot_c fallback...") - result = await asyncio.wait_for(loop.run_in_executor(None, lambda: _upload(True)), timeout=timeout) - return result + return await _attempt(True) return False - except TimeoutError: - logger.warning("FTP upload timed out after %ss for %s", timeout, remote_path) - return False + +def _swallow_future_result(fut: asyncio.Future) -> None: + """Retrieve a future's exception so asyncio doesn't log it as unhandled.""" + if not fut.cancelled(): + fut.exception() async def list_files_async( @@ -1213,6 +1333,10 @@ async def with_ftp_retry( Returns: Result of the operation, or None if all attempts fail + + ``UploadCancelled`` is never retried, whatever the caller passes: it means + the transfer overran its size-derived deadline, so a retry would spend + another full deadline reaching the same conclusion (#2529). """ last_error = None @@ -1227,6 +1351,8 @@ async def with_ftp_retry( # Operation returned failure indicator if attempt > 0: logger.info("%s attempt %s/%s returned failure", operation_name, attempt + 1, max_retries + 1) + except UploadCancelled: + raise except Exception as e: if non_retry_exceptions and isinstance(e, non_retry_exceptions): raise diff --git a/backend/app/services/print_scheduler.py b/backend/app/services/print_scheduler.py index e7440ee97..86976b919 100644 --- a/backend/app/services/print_scheduler.py +++ b/backend/app/services/print_scheduler.py @@ -24,6 +24,7 @@ from backend.app.models.smart_plug import SmartPlug from backend.app.models.spool_assignment import SpoolAssignment from backend.app.models.spoolman_slot_assignment import SpoolmanSlotAssignment from backend.app.services.bambu_ftp import ( + UploadCancelled, cache_3mf_download, delete_file_async, get_ftp_retry_settings, @@ -2797,6 +2798,10 @@ class PrintScheduler: progress_bridge = _UploadProgressBridge(toast_uid, item.id) + # A deadline expiry gets its own message: "check your SD card" is the + # wrong advice for a link that was simply too slow to finish (#2529). + upload_error: str | None = None + try: if ftp_retry_enabled: uploaded = await with_ftp_retry( @@ -2822,6 +2827,13 @@ class PrintScheduler: printer_model=printer.model, progress_callback=progress_bridge, ) + except UploadCancelled as e: + uploaded = False + upload_error = ( + "Upload was too slow to finish and was cancelled. The printer's connection could not sustain " + "the transfer — check its Wi-Fi signal, or move it closer to the access point." + ) + logger.error("Queue item %s: upload deadline exceeded: %s", item.id, e) except Exception as e: uploaded = False logger.error("Queue item %s: FTP error: %s (type: %s)", item.id, e, type(e).__name__) @@ -2831,7 +2843,7 @@ class PrintScheduler: injected_path.unlink(missing_ok=True) if not uploaded: - error_msg = ( + error_msg = upload_error or ( "Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT). " "See server logs for detailed diagnostics." ) diff --git a/backend/tests/unit/services/test_bambu_ftp.py b/backend/tests/unit/services/test_bambu_ftp.py index f95bd18c4..da59e88d0 100644 --- a/backend/tests/unit/services/test_bambu_ftp.py +++ b/backend/tests/unit/services/test_bambu_ftp.py @@ -13,11 +13,14 @@ Tests against a real mock implicit FTPS server, covering: - Failure injection scenarios (regressions for 0.1.8 bugs) """ +import asyncio +import threading import time from pathlib import Path import pytest +from backend.app.services import bambu_ftp from backend.app.services.bambu_ftp import ( BambuFTPClient, FileNotOnPrinterError, @@ -1422,3 +1425,193 @@ class TestThreeMFCache: assert archive_file.exists(), "archive 3mf must not be deleted by cache cleanup" assert library_file.exists(), "library 3mf must not be deleted by cache cleanup" assert not temp_file.exists(), "temp file should still be cleaned up" + + +@pytest.fixture +def slow_upload_client(monkeypatch): + """Replace BambuFTPClient with a fake whose upload streams slowly. + + Mirrors the real client's contract for the bits that matter here: it fires + the progress callback once per chunk and treats a callback exception as + "stop now" — break out of the send loop, drop the partial file, re-raise. + The returned dict lets a test see what the worker thread actually did, + which is the whole point: the #2529 ghost transfer was invisible from the + event loop's side. + """ + state = { + "attempts": 0, + "concurrent": 0, + "max_concurrent": 0, + "completed": False, + "cancelled": False, + "deleted": [], + "chunks": 20, + "chunk_delay": 0.05, + } + lock = threading.Lock() + + class FakeClient: + def __init__(self, *args, **kwargs): + pass + + def connect(self): + return True + + def upload_file(self, local_path, remote_path, progress_callback=None): + with lock: + state["attempts"] += 1 + state["concurrent"] += 1 + state["max_concurrent"] = max(state["max_concurrent"], state["concurrent"]) + try: + total = state["chunks"] + for sent in range(1, total + 1): + time.sleep(state["chunk_delay"]) + if progress_callback: + try: + progress_callback(sent, total) + except Exception: + state["cancelled"] = True + state["deleted"].append(remote_path) + raise + state["completed"] = True + return True + finally: + with lock: + state["concurrent"] -= 1 + + def disconnect(self): + pass + + monkeypatch.setattr(bambu_ftp, "BambuFTPClient", FakeClient) + monkeypatch.setattr(FakeClient, "_mode_cache", {}, raising=False) + monkeypatch.setattr(FakeClient, "A1_MODELS", ("A1", "A1 Mini"), raising=False) + monkeypatch.setattr(FakeClient, "cache_mode", staticmethod(lambda ip, mode: None), raising=False) + return state + + +# --------------------------------------------------------------------------- +# TestUploadDeadline (#2529) +# --------------------------------------------------------------------------- +class TestUploadDeadline: + """The upload deadline must be size-aware, and must actually stop the transfer. + + Regression for #2529: a 96 MB 3MF to an A1 over WiFi sustains ~75 KB/s and + needs ~20 minutes. The old flat 600 s wall-clock cap declared it dead at + ~70 MB, `asyncio.wait_for` cancelled the *future* but not the executor + thread — which kept streaming — and `with_ftp_retry` then started a second + STOR of the same file onto the same printer. The reporter's video shows two + transfers of the same job climbing in parallel (2% and 72%), and the print + never landed. + """ + + def test_deadline_scales_with_file_size(self, tmp_path): + """A big file gets proportionally longer, a small one gets the floor.""" + small = tmp_path / "small.3mf" + small.write_bytes(b"x" * 1024) + assert bambu_ftp._upload_deadline(small) == bambu_ftp._UPLOAD_MIN_TIMEOUT + + # The reporter's file. At the 25 KB/s floor rate, 96 MB is ~64 minutes — + # far above the 600 s that killed it at 72%. + big = tmp_path / "big.3mf" + big.write_bytes(b"x" * (96 * 1024 * 1024)) + deadline = bambu_ftp._upload_deadline(big) + assert deadline > bambu_ftp._UPLOAD_MIN_TIMEOUT + assert deadline == pytest.approx((96 * 1024 * 1024) / bambu_ftp._UPLOAD_FLOOR_BYTES_PER_SEC) + + def test_deadline_falls_back_to_floor_for_unstatable_file(self, tmp_path): + assert bambu_ftp._upload_deadline(tmp_path / "nope.3mf") == bambu_ftp._UPLOAD_MIN_TIMEOUT + + @pytest.mark.asyncio + async def test_timeout_stops_the_worker_thread(self, tmp_path, monkeypatch, slow_upload_client): + """The transfer stops when the deadline expires, instead of streaming on. + + Mutation check: drop the `cancel.set()` in upload_file_async and the + worker runs to completion, which is exactly the ghost transfer #2529 + reported. + """ + state = slow_upload_client + local = tmp_path / "slow.3mf" + local.write_bytes(b"x" * 4096) + + with pytest.raises(bambu_ftp.UploadCancelled): + await upload_file_async("127.0.0.1", "12345678", local, "/cache/slow.3mf", timeout=0.2, printer_model="X1C") + + # The worker noticed the cancel and unwound — it did not run to the end. + await asyncio.sleep(0.5) + assert state["cancelled"] is True + assert state["completed"] is False + # And it cleaned the partial file off the printer on its way out. + assert state["deleted"] == ["/cache/slow.3mf"] + + @pytest.mark.asyncio + async def test_timeout_is_not_retried(self, tmp_path, monkeypatch, slow_upload_client): + """with_ftp_retry must not start a second transfer after a deadline expiry. + + This is the bug the reporter filmed: attempt 2 began while attempt 1 was + still sending. One attempt, then a hard failure. + """ + state = slow_upload_client + local = tmp_path / "slow.3mf" + local.write_bytes(b"x" * 4096) + + with pytest.raises(bambu_ftp.UploadCancelled): + await with_ftp_retry( + upload_file_async, + "127.0.0.1", + "12345678", + local, + "/cache/slow.3mf", + timeout=0.2, + printer_model="X1C", + max_retries=3, + retry_delay=0, + ) + + assert state["attempts"] == 1, "a timed-out upload must not be retried" + + @pytest.mark.asyncio + async def test_uploads_to_one_printer_are_serialized(self, tmp_path, monkeypatch, slow_upload_client): + """Two dispatches to the same printer queue up; they never overlap. + + Concurrent STORs of the same remote path leave a corrupt file on the SD + card and make the printer look like it has a flaky network. + """ + state = slow_upload_client + state["chunk_delay"] = 0.05 + local = tmp_path / "slow.3mf" + local.write_bytes(b"x" * 4096) + + async def _dispatch(name: str) -> bool: + return await upload_file_async( + "127.0.0.1", "12345678", local, f"/cache/{name}.3mf", timeout=30.0, printer_model="X1C" + ) + + results = await asyncio.gather(_dispatch("a"), _dispatch("b")) + + assert results == [True, True] + assert state["attempts"] == 2 + assert state["max_concurrent"] == 1, "two uploads ran against the same printer at once" + + def test_progress_callback_raising_deletes_the_partial_file(self, ftp_client_factory, ftp_root, tmp_path): + """The cancel path in the real client removes what it already wrote. + + This is the mechanism the deadline now hangs off, exercised end to end + against the mock FTPS server rather than a fake. + """ + client = ftp_client_factory() + assert client.connect() is True + try: + local = tmp_path / "cancelme.3mf" + # Two chunks, so the callback fires while there is a partial file. + local.write_bytes(b"x" * (BambuFTPClient.CHUNK_SIZE * 2)) + + def _stop_after_first_chunk(uploaded: int, total: int) -> None: + raise bambu_ftp.UploadCancelled("stop") + + with pytest.raises(bambu_ftp.UploadCancelled): + client.upload_file(local, "/cancelme.3mf", _stop_after_first_chunk) + finally: + client.disconnect() + + time.sleep(_UPLOAD_FLUSH_DELAY) + assert not (Path(ftp_root) / "cancelme.3mf").exists(), "partial file left on the printer"