bambu_ftp.py 71 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455145614571458145914601461146214631464146514661467146814691470147114721473147414751476147714781479148014811482148314841485148614871488148914901491149214931494149514961497149814991500150115021503150415051506150715081509151015111512151315141515151615171518151915201521152215231524152515261527152815291530153115321533153415351536153715381539154015411542154315441545154615471548154915501551155215531554155515561557155815591560156115621563156415651566156715681569157015711572157315741575157615771578157915801581158215831584158515861587158815891590159115921593159415951596159715981599160016011602160316041605160616071608160916101611161216131614161516161617161816191620162116221623162416251626162716281629163016311632163316341635163616371638163916401641164216431644164516461647164816491650165116521653165416551656165716581659166016611662
  1. import asyncio
  2. import ftplib # nosec B402
  3. import logging
  4. import os
  5. import socket
  6. import ssl
  7. import threading
  8. import time
  9. import weakref
  10. from collections.abc import Awaitable, Callable
  11. from concurrent.futures import ThreadPoolExecutor
  12. from enum import Enum
  13. from ftplib import FTP, FTP_TLS # nosec B402
  14. from io import BytesIO
  15. from pathlib import Path
  16. from typing import TypeVar
  17. logger = logging.getLogger(__name__)
  18. T = TypeVar("T")
  19. # Every FTP call below is blocking ftplib work handed to a thread. They used to
  20. # run on asyncio's *default* executor, which is sized min(32, cpu_count + 4) —
  21. # six threads on a 2-core NAS — and is shared with every other ``to_thread`` /
  22. # ``run_in_executor`` caller in the app. That was survivable only because the
  23. # scheduler uploaded to exactly one printer at a time. Dispatching to several
  24. # printers at once (#2555) would park one thread per in-flight upload for
  25. # minutes at a stretch (a 41 MB 3MF at the ~150 KB/s a Bambu printer sustains
  26. # takes ~4 min), starving the default pool and stalling unrelated work.
  27. #
  28. # A dedicated pool keeps that blast radius inside the FTP layer: the scheduler's
  29. # own concurrency cap is what limits parallel uploads, and it can never exhaust
  30. # the executor everything else depends on. Threads are created lazily, so an
  31. # idle pool costs nothing.
  32. #
  33. # Sized well above `queue_max_concurrent_uploads` (max 16), because uploads are
  34. # not the only traffic here: SD browsing, timelapse/recording listing, cover
  35. # downloads, deletes and storage checks all run through this pool too, and on a
  36. # farm they fan out across every printer at once. The pool's work queue is
  37. # unbounded, so exceeding it does not fail — it queues. But `asyncio.wait_for`
  38. # starts its clock at submission, not at thread start, so a task that sits in the
  39. # queue can burn its whole timeout without ever running, and `list_files_async`
  40. # reports a timeout as an empty listing — a silent "this printer has no files".
  41. # Keep the headroom.
  42. _FTP_MAX_WORKERS = 48
  43. _ftp_executor = ThreadPoolExecutor(max_workers=_FTP_MAX_WORKERS, thread_name_prefix="bambu-ftp")
  44. # Overall upload deadline (#2529). A flat wall-clock cap punishes big files on
  45. # slow links rather than catching broken ones: a 96 MB 3MF at the ~75 KB/s an A1
  46. # sustains over WiFi legitimately needs ~20 minutes, and the old flat 600 s
  47. # declared it dead at ~70 MB. The deadline is therefore derived from the file
  48. # size against a deliberately pessimistic floor rate. This is a backstop, not the
  49. # failure detector — a link that has actually died is caught within
  50. # ``socket_timeout`` by the blocking ``sendall``, long before this fires.
  51. _UPLOAD_FLOOR_BYTES_PER_SEC = 25 * 1024
  52. _UPLOAD_MIN_TIMEOUT = 600.0
  53. # How long to give the worker thread to notice the cancel flag, unwind, and
  54. # delete its partial file. It checks the flag once per CHUNK_SIZE, so on a link
  55. # slow enough to have hit the deadline this is one chunk plus the delete.
  56. _UPLOAD_CANCEL_GRACE = 60.0
  57. class UploadCancelled(Exception):
  58. """Raised inside the upload worker to abort an in-flight transfer.
  59. ``upload_file`` treats any exception from its progress callback as "stop
  60. now": it breaks out of the send loop, deletes the partial file from the
  61. printer, and re-raises. That is the only way to stop a transfer — an
  62. executor thread cannot be cancelled from the event loop, so a bare
  63. ``asyncio.wait_for`` leaves it streaming (see ``upload_file_async``).
  64. """
  65. class DeleteResult(Enum):
  66. """Outcome of an FTP delete attempt.
  67. Distinguishes "file isn't on the printer" (550, recovery impossible by
  68. retrying) from "delete failed for some other reason" (network, auth,
  69. transient FTP error — worth retrying). The post-print SD-card cleanup in
  70. main.py used to flatten both into ``False`` and log a "may linger" WARNING
  71. on every successful print where the printer self-cleaned its SD card
  72. before our cleanup ran (#1721 reporter's A1).
  73. """
  74. DELETED = "deleted"
  75. NOT_FOUND = "not_found"
  76. FAILED = "failed"
  77. # How long to stop opening FTPS connections to a printer after its TLS
  78. # handshake failed (#2780).
  79. #
  80. # ``WRONG_VERSION_NUMBER`` on port 990 means the printer answered with
  81. # something that is not a TLS record at all — its file service is wedged, and
  82. # no path, retry or SSL option can talk to it until the printer is restarted.
  83. # Two support bundles show that state lasting for days: one X2D served clean
  84. # FTPS for five days, flipped on 2026-07-19, and then failed every single
  85. # handshake for the next eight (zero successes, 3511 failures).
  86. #
  87. # Without a gate every candidate path re-runs the same doomed handshake: the
  88. # 3MF lookup alone walks 6 filename variants x 5 directories x 4 retries, and
  89. # the cover and timelapse scans run their own sweeps on top. That is where
  90. # those thousands of failures come from — one wedged printer, hammered.
  91. #
  92. # Five minutes is short enough that a power-cycled printer is picked up on the
  93. # next print (and any successful connect clears the gate immediately), long
  94. # enough that a wedged one is contacted twice an hour instead of hundreds of
  95. # times a minute.
  96. _HANDSHAKE_COOLOFF_SECONDS = 300.0
  97. class FileNotOnPrinterError(Exception):
  98. """Raised when a remote FTP path returns 550 (file not found).
  99. 550 means the file does not exist at that path — retrying the same path
  100. will never succeed. Callers use this sentinel with with_ftp_retry's
  101. non_retry_exceptions to immediately move on to the next candidate path
  102. instead of burning the full retry budget (up to 11 × 30s per path) on
  103. a lookup that cannot recover.
  104. """
  105. class ImplicitFTP_TLS(FTP_TLS):
  106. """FTP_TLS subclass for implicit FTPS (port 990) with model-specific SSL handling.
  107. X1C/P1S printers (vsFTPd) require SSL with session reuse on the data channel.
  108. A1/A1 Mini printers have issues with SSL on the data channel entirely and
  109. timeout waiting for transfer completion. Set skip_session_reuse=True for A1
  110. printers to skip SSL on the data channel (control channel remains encrypted).
  111. Optionally caps the SSL context's maximum TLS version to v1.2 (P2S firmware
  112. 01.02.00.00 needs this — see :mod:`ftp_profiles` and #1401).
  113. """
  114. def __init__(self, *args, skip_session_reuse: bool = False, cap_tls_v1_2: bool = False, **kwargs):
  115. super().__init__(*args, **kwargs)
  116. self._sock = None
  117. self.skip_session_reuse = skip_session_reuse
  118. self.ssl_context = ssl.create_default_context()
  119. self.ssl_context.check_hostname = False
  120. self.ssl_context.verify_mode = ssl.CERT_NONE
  121. # ``create_default_context()`` does NOT guarantee a protocol floor: it
  122. # leaves ``minimum_version`` at ``MINIMUM_SUPPORTED``, and what that
  123. # resolves to is a property of the OpenSSL build, not of this code.
  124. # Measured on identical OpenSSL 3.5.6: python:3.13-slim-trixie (our
  125. # Docker base) reports TLSv1_2, a bare-metal venv reports
  126. # MINIMUM_SUPPORTED. Docker users have therefore always been floored at
  127. # 1.2 — every Bambu model is reachable under that floor — while
  128. # bare-metal and appliance installs could silently negotiate TLS 1.0.
  129. # State the floor rather than inheriting it.
  130. self.ssl_context.minimum_version = ssl.TLSVersion.TLSv1_2
  131. if cap_tls_v1_2:
  132. # With the floor above this pins the connection to exactly TLS 1.2.
  133. self.ssl_context.maximum_version = ssl.TLSVersion.TLSv1_2
  134. def connect(self, host="", port=990, timeout=-999, source_address=None):
  135. """Connect to host, wrapping socket in TLS immediately (implicit FTPS)."""
  136. if host:
  137. self.host = host
  138. if port > 0:
  139. self.port = port
  140. if timeout != -999:
  141. self.timeout = timeout
  142. if source_address:
  143. self.source_address = source_address
  144. # Create and wrap socket immediately (implicit TLS)
  145. self.sock = socket.create_connection((self.host, self.port), self.timeout, source_address=self.source_address)
  146. self.sock = self.ssl_context.wrap_socket(self.sock, server_hostname=self.host)
  147. self.af = self.sock.family
  148. self.file = self.sock.makefile("r", encoding=self.encoding)
  149. self.welcome = self.getresp()
  150. return self.welcome
  151. def ntransfercmd(self, cmd, rest=None):
  152. """Override to wrap data connection in SSL for X1C/P1S only.
  153. X1C/P1S printers (vsFTPd) require SSL session reuse on the data channel.
  154. A1/A1 Mini printers have issues with SSL on the data channel entirely -
  155. they timeout waiting for the transfer completion response. For A1, we
  156. skip SSL wrapping on the data channel (control channel remains encrypted).
  157. """
  158. conn, size = FTP.ntransfercmd(self, cmd, rest)
  159. if self._prot_p and not self.skip_session_reuse:
  160. # X1C/P1S: Wrap data channel with SSL session reuse (required by vsFTPd)
  161. conn = self.ssl_context.wrap_socket(
  162. conn,
  163. server_hostname=self.host,
  164. session=self.sock.session,
  165. )
  166. # A1/A1 Mini (skip_session_reuse=True): Don't wrap data channel in SSL
  167. # The control channel remains encrypted via implicit FTPS
  168. return conn, size
  169. class BambuFTPClient:
  170. """FTP client for retrieving files from Bambu Lab printers."""
  171. FTP_PORT = 990
  172. # Default timeout in seconds (increased for A1 printers)
  173. DEFAULT_TIMEOUT = 30
  174. # Models that may need SSL mode fallback (try prot_p first, fall back to prot_c)
  175. # These models have varying FTP SSL behavior depending on firmware version
  176. A1_MODELS = ("A1", "A1 Mini")
  177. # Chunk size for manual upload transfer (64KB)
  178. # Smaller chunks provide smoother progress reporting — at typical printer FTP
  179. # speeds (~50-100KB/s) this gives a progress update roughly every second.
  180. CHUNK_SIZE = 64 * 1024
  181. # Cache for working FTP modes per printer IP
  182. # Maps IP -> "prot_p" or "prot_c"
  183. _mode_cache: dict[str, str] = {}
  184. # Printers whose FTPS handshake just failed, mapped to the monotonic time
  185. # their cool-off expires. See ``_HANDSHAKE_COOLOFF_SECONDS``.
  186. _handshake_blocked_until: dict[str, float] = {}
  187. def __init__(
  188. self,
  189. ip_address: str,
  190. access_code: str,
  191. timeout: float | None = None,
  192. printer_model: str | None = None,
  193. force_prot_c: bool = False,
  194. ):
  195. self.ip_address = ip_address
  196. self.access_code = access_code
  197. self.timeout = timeout if timeout is not None else self.DEFAULT_TIMEOUT
  198. self.printer_model = printer_model
  199. self.force_prot_c = force_prot_c
  200. self._ftp: ImplicitFTP_TLS | None = None
  201. def _is_a1_model(self) -> bool:
  202. """Check if this is an A1 series printer."""
  203. if not self.printer_model:
  204. return False
  205. return self.printer_model in self.A1_MODELS
  206. def _get_cached_mode(self) -> str | None:
  207. """Get cached FTP mode for this printer."""
  208. return self._mode_cache.get(self.ip_address)
  209. @classmethod
  210. def cache_mode(cls, ip_address: str, mode: str):
  211. """Cache the working FTP mode for a printer."""
  212. cls._mode_cache[ip_address] = mode
  213. logger.info("FTP mode cached for %s: %s", ip_address, mode)
  214. def _should_use_prot_c(self) -> bool:
  215. """Determine if we should use prot_c (clear) mode."""
  216. # If explicitly forced, use prot_c
  217. if self.force_prot_c:
  218. return True
  219. # Check cache first
  220. cached = self._get_cached_mode()
  221. if cached:
  222. return cached == "prot_c"
  223. # Default: try prot_p first (will fall back if needed)
  224. return False
  225. @classmethod
  226. def handshake_blocked(cls, ip_address: str) -> bool:
  227. """True while *ip_address* is inside its post-handshake-failure cool-off.
  228. Public so a caller sweeping many candidate paths can stop after the
  229. first one rather than walking the rest against a printer that cannot
  230. complete a TLS handshake (#2780).
  231. """
  232. deadline = cls._handshake_blocked_until.get(ip_address)
  233. if deadline is None:
  234. return False
  235. if time.monotonic() >= deadline:
  236. # Drop it on the way past rather than leaving an entry per printer
  237. # this process has ever failed against.
  238. del cls._handshake_blocked_until[ip_address]
  239. return False
  240. return True
  241. def connect(self) -> bool:
  242. """Connect to the printer FTP server (implicit FTPS on port 990).
  243. Returns False without touching the network while the printer is inside
  244. the cool-off a previous TLS handshake failure opened (#2780).
  245. """
  246. if self.handshake_blocked(self.ip_address):
  247. logger.debug(
  248. "FTP connect to %s skipped: FTPS handshake failed recently, cooling off",
  249. self.ip_address,
  250. )
  251. return False
  252. try:
  253. use_prot_c = self._should_use_prot_c()
  254. from backend.app.services.ftp_profiles import get_ftp_profile
  255. profile = get_ftp_profile(self.printer_model)
  256. logger.debug(
  257. f"FTP connecting to {self.ip_address}:{self.FTP_PORT} "
  258. f"(timeout={self.timeout}s, model={self.printer_model}, prot_c={use_prot_c}, "
  259. f"cap_tls_v1_2={profile.cap_tls_v1_2})"
  260. )
  261. self._ftp = ImplicitFTP_TLS(
  262. skip_session_reuse=use_prot_c,
  263. cap_tls_v1_2=profile.cap_tls_v1_2,
  264. )
  265. self._ftp.connect(self.ip_address, self.FTP_PORT, timeout=self.timeout)
  266. logger.debug("FTP connected, logging in as bblp")
  267. self._ftp.login("bblp", self.access_code)
  268. if use_prot_c:
  269. # Use clear (unencrypted) data channel
  270. logger.debug("FTP logged in, setting prot_c (clear) and passive mode")
  271. self._ftp.prot_c()
  272. else:
  273. # Use protected (encrypted) data channel with session reuse
  274. logger.debug("FTP logged in, setting prot_p (protected) and passive mode")
  275. self._ftp.prot_p()
  276. self._ftp.set_pasv(True)
  277. # Log welcome message for debugging
  278. if hasattr(self._ftp, "welcome") and self._ftp.welcome:
  279. logger.debug("FTP server welcome: %s", self._ftp.welcome)
  280. logger.info(
  281. f"FTP connected successfully to {self.ip_address} (model={self.printer_model}, prot_c={use_prot_c})"
  282. )
  283. return True
  284. except ftplib.error_perm as e:
  285. logger.warning("FTP connection permission error to %s: %s", self.ip_address, e)
  286. self._ftp = None
  287. return False
  288. except TimeoutError as e:
  289. logger.warning("FTP connection timed out to %s: %s", self.ip_address, e)
  290. self._ftp = None
  291. return False
  292. except ssl.SSLError as e:
  293. # Not a transient failure and not something another path or another
  294. # retry can route around: the printer's file service answered port
  295. # 990 with something that isn't TLS. Say so once, in words the
  296. # reporter can act on, and stop knocking for a while (#2780).
  297. logger.warning(
  298. "FTP SSL error connecting to %s: %s — the printer's file service is not answering "
  299. "with TLS on port %s. Print files, covers and timelapses cannot be fetched from it "
  300. "until the printer is restarted. Pausing FTP to this printer for %.0fs.",
  301. self.ip_address,
  302. e,
  303. self.FTP_PORT,
  304. _HANDSHAKE_COOLOFF_SECONDS,
  305. )
  306. self._handshake_blocked_until[self.ip_address] = time.monotonic() + _HANDSHAKE_COOLOFF_SECONDS
  307. self._ftp = None
  308. return False
  309. except (OSError, ftplib.Error) as e:
  310. logger.warning("FTP connection failed to %s: %s (type: %s)", self.ip_address, e, type(e).__name__)
  311. self._ftp = None
  312. return False
  313. def disconnect(self):
  314. """Disconnect from the FTP server."""
  315. if self._ftp:
  316. try:
  317. self._ftp.quit()
  318. except (OSError, ftplib.Error, EOFError):
  319. pass # Best-effort FTP cleanup; connection may already be closed
  320. self._ftp = None
  321. def list_files(self, path: str = "/") -> list[dict]:
  322. """List files in a directory."""
  323. if not self._ftp:
  324. return []
  325. files = []
  326. try:
  327. self._ftp.cwd(path)
  328. items = []
  329. self._ftp.retrlines("LIST", items.append)
  330. for item in items:
  331. parts = item.split()
  332. if len(parts) >= 9:
  333. name = " ".join(parts[8:])
  334. is_dir = item.startswith("d")
  335. size = int(parts[4]) if not is_dir else 0
  336. # Parse modification time from FTP listing
  337. # Format: "Nov 30 10:15" or "Nov 30 2024"
  338. mtime = None
  339. try:
  340. from datetime import datetime
  341. month = parts[5]
  342. day = parts[6]
  343. time_or_year = parts[7]
  344. # Determine if it's time (HH:MM) or year
  345. if ":" in time_or_year:
  346. # Recent file: "Nov 30 10:15" - assume current year
  347. year = datetime.now().year
  348. time_str = f"{month} {day} {year} {time_or_year}"
  349. mtime = datetime.strptime(time_str, "%b %d %Y %H:%M")
  350. # If parsed date is in the future, use last year
  351. if mtime > datetime.now():
  352. mtime = mtime.replace(year=year - 1)
  353. else:
  354. # Older file: "Nov 30 2024" - no time, just date
  355. time_str = f"{month} {day} {time_or_year}"
  356. mtime = datetime.strptime(time_str, "%b %d %Y")
  357. except (ValueError, IndexError):
  358. pass # Non-critical: mtime parsing is best-effort; file entry works without it
  359. file_entry = {
  360. "name": name,
  361. "is_directory": is_dir,
  362. "size": size,
  363. "path": f"{path.rstrip('/')}/{name}",
  364. }
  365. if mtime:
  366. file_entry["mtime"] = mtime
  367. files.append(file_entry)
  368. logger.debug("Listed %s files in %s", len(files), path)
  369. except (OSError, ftplib.Error) as e:
  370. logger.info("FTP list_files failed for %s: %s", path, e)
  371. return files
  372. def download_file(self, remote_path: str, expected_size: int | None = None) -> bytes | None:
  373. """Download a file from the printer.
  374. ``expected_size`` is the byte count the directory listing reported for
  375. this file. Pass it whenever a short read must not be mistaken for a
  376. successful download: an FTPS data connection that closes early does
  377. not always raise, so ``retrbinary`` can hand back a partial buffer that
  378. looks like a perfectly good file to everything downstream. That is
  379. tolerable when the printer keeps its copy, and not tolerable when the
  380. caller goes on to delete the source (#2704).
  381. A zero-byte result is always treated as a failure, matching
  382. :meth:`download_to_file` — no caller has a use for an empty file.
  383. """
  384. if not self._ftp:
  385. return None
  386. try:
  387. buffer = BytesIO()
  388. self._ftp.retrbinary(f"RETR {remote_path}", buffer.write)
  389. data = buffer.getvalue()
  390. except (OSError, ftplib.Error):
  391. return None
  392. if not data:
  393. logger.warning("FTP download returned 0 bytes for %s", remote_path)
  394. return None
  395. if expected_size is not None and len(data) != expected_size:
  396. logger.warning(
  397. "FTP download of %s is short: got %s bytes, listing reported %s — treating as failed",
  398. remote_path,
  399. len(data),
  400. expected_size,
  401. )
  402. return None
  403. return data
  404. def download_to_file(self, remote_path: str, local_path: Path) -> bool:
  405. """Download a file from the printer to local filesystem."""
  406. if not self._ftp:
  407. logger.warning("download_to_file called but FTP not connected")
  408. return False
  409. try:
  410. local_path.parent.mkdir(parents=True, exist_ok=True)
  411. with open(local_path, "wb") as f:
  412. self._ftp.retrbinary(f"RETR {remote_path}", f.write)
  413. f.flush()
  414. os.fsync(f.fileno())
  415. file_size = local_path.stat().st_size if local_path.exists() else 0
  416. if file_size == 0:
  417. logger.warning("FTP download returned 0 bytes for %s", remote_path)
  418. if local_path.exists():
  419. local_path.unlink()
  420. return False
  421. logger.info("Successfully downloaded %s to %s (%s bytes)", remote_path, local_path, file_size)
  422. return True
  423. except (OSError, ftplib.Error) as e:
  424. # Clean up partial file if it exists
  425. if local_path.exists():
  426. try:
  427. local_path.unlink()
  428. except OSError:
  429. pass # Best-effort partial file cleanup; not critical if removal fails
  430. # 550 means the file is not at this path. Surface as a sentinel so
  431. # with_ftp_retry can abandon this path immediately and the caller
  432. # can advance to the next candidate instead of retrying 11× at
  433. # 30s intervals (the pattern that cost #972's reporter ~48min).
  434. if isinstance(e, ftplib.error_perm) and str(e).startswith("550"):
  435. logger.info("FTP download failed for %s: %s (not on printer)", remote_path, e)
  436. raise FileNotOnPrinterError(f"{remote_path}: {e}") from e
  437. # Log at INFO level so we can see failures in normal logs
  438. logger.info("FTP download failed for %s: %s", remote_path, e)
  439. return False
  440. def diagnose_storage(self) -> dict:
  441. """Run storage diagnostics and return results. For debugging upload issues."""
  442. results = {
  443. "connected": self._ftp is not None,
  444. "can_list_root": False,
  445. "root_files": [],
  446. "can_list_cache": False,
  447. "storage_info": None,
  448. "pwd": None,
  449. "errors": [],
  450. }
  451. if not self._ftp:
  452. results["errors"].append("FTP not connected")
  453. return results
  454. # Try to get current directory
  455. try:
  456. results["pwd"] = self._ftp.pwd()
  457. logger.debug("FTP current directory: %s", results["pwd"])
  458. except (OSError, ftplib.Error) as e:
  459. results["errors"].append(f"PWD failed: {e}")
  460. logger.debug("FTP PWD failed: %s", e)
  461. # Try to list root directory
  462. try:
  463. self._ftp.cwd("/")
  464. items = []
  465. self._ftp.retrlines("LIST", items.append)
  466. results["can_list_root"] = True
  467. results["root_files"] = items[:10] # First 10 entries
  468. logger.debug("FTP root listing (%s items): %s", len(items), items[:5])
  469. except (OSError, ftplib.Error) as e:
  470. results["errors"].append(f"LIST / failed: {e}")
  471. logger.debug("FTP LIST / failed: %s", e)
  472. # Try to list /cache (should exist on all printers)
  473. try:
  474. self._ftp.cwd("/cache")
  475. items = []
  476. self._ftp.retrlines("LIST", items.append)
  477. results["can_list_cache"] = True
  478. logger.debug("FTP /cache listing: %s items", len(items))
  479. except (OSError, ftplib.Error) as e:
  480. results["errors"].append(f"LIST /cache failed: {e}")
  481. logger.debug("FTP LIST /cache failed: %s", e)
  482. # Try to get storage info
  483. try:
  484. results["storage_info"] = self.get_storage_info()
  485. logger.debug("FTP storage info: %s", results["storage_info"])
  486. except (OSError, ftplib.Error) as e:
  487. results["errors"].append(f"Storage info failed: {e}")
  488. return results
  489. def upload_file(
  490. self,
  491. local_path: Path,
  492. remote_path: str,
  493. progress_callback: Callable[[int, int], None] | None = None,
  494. ) -> bool:
  495. """Upload a file to the printer with optional progress callback."""
  496. if not self._ftp:
  497. logger.warning("upload_file: FTP not connected")
  498. return False
  499. try:
  500. file_size = local_path.stat().st_size if local_path.exists() else 0
  501. logger.info("FTP uploading %s (%s bytes) to %s", local_path, file_size, remote_path)
  502. uploaded = 0
  503. callback_exception: Exception | None = None
  504. # Use manual transfer instead of storbinary() for A1 compatibility
  505. # A1 printers have issues with storbinary's voidresp() hanging after transfer
  506. with open(local_path, "rb") as f:
  507. logger.debug("FTP STOR command starting for %s", remote_path)
  508. t0 = time.monotonic()
  509. conn = self._ftp.transfercmd(f"STOR {remote_path}")
  510. logger.info(
  511. "FTP data channel ready in %.1fs (PASV + TLS handshake)",
  512. time.monotonic() - t0,
  513. )
  514. # Set explicit socket options for reliable transfer
  515. conn.setblocking(True)
  516. conn.settimeout(self.timeout)
  517. try:
  518. while True:
  519. chunk = f.read(self.CHUNK_SIZE)
  520. if not chunk:
  521. logger.debug("FTP upload: final chunk reached")
  522. break
  523. conn.sendall(chunk)
  524. uploaded += len(chunk)
  525. logger.debug("FTP upload progress: %s/%s bytes", uploaded, file_size)
  526. if progress_callback:
  527. try:
  528. progress_callback(uploaded, file_size)
  529. except Exception as e:
  530. callback_exception = e
  531. logger.info(
  532. "FTP upload callback requested stop for %s at %s/%s bytes: %s",
  533. remote_path,
  534. uploaded,
  535. file_size,
  536. e,
  537. )
  538. break
  539. except OSError as e:
  540. logger.error("FTP connection lost during upload: %s", e)
  541. raise
  542. finally:
  543. try:
  544. conn.close()
  545. except OSError:
  546. pass
  547. # Wait for the server's 226 "Transfer complete" response to confirm
  548. # the file has been flushed to the SD card. Without this, the printer
  549. # may try to read an incomplete file when the print command is sent,
  550. # causing 0500-C010 "MicroSD Card read/write exception" errors.
  551. # See: https://bugs.python.org/issue25458 (ftplib response desync)
  552. try:
  553. old_timeout = self._ftp.sock.gettimeout()
  554. # Use a generous timeout — H2D printers can take 30+ seconds
  555. # to send the 226 after the data channel closes.
  556. self._ftp.sock.settimeout(max(self.timeout, 60))
  557. try:
  558. resp = self._ftp.voidresp()
  559. logger.info("FTP STOR confirmed for %s: %s", remote_path, resp.strip())
  560. finally:
  561. self._ftp.sock.settimeout(old_timeout)
  562. except ftplib.Error as e:
  563. # Some P2S firmware revisions return ftplib.Error (e.g. 426
  564. # "Failure reading network stream") on voidresp() even when
  565. # the file landed fully on the SD card — the TLS data
  566. # channel close races the 226 confirmation (#1417 follow-up).
  567. # Verify via SIZE: if the server-side file size matches what
  568. # we just uploaded, the file is intact and we proceed with
  569. # a warning. If not — or SIZE itself fails — the transfer
  570. # was genuinely truncated and we must fail so the print
  571. # command doesn't go out for a partial 3MF (the original
  572. # reason this catch was tightened in the previous round).
  573. try:
  574. server_size = self._ftp.size(remote_path)
  575. except (OSError, ftplib.Error) as size_err:
  576. logger.debug("Post-error SIZE check failed: %s", size_err)
  577. server_size = None
  578. if server_size is not None and server_size == file_size:
  579. logger.warning(
  580. "FTP STOR returned %s for %s but file is intact on the "
  581. "printer (%s bytes match) — proceeding: %s",
  582. type(e).__name__,
  583. remote_path,
  584. file_size,
  585. e,
  586. )
  587. else:
  588. logger.error(
  589. "FTP STOR rejected by printer for %s: %s (%s); server size=%s expected=%s",
  590. remote_path,
  591. e,
  592. type(e).__name__,
  593. server_size,
  594. file_size,
  595. )
  596. raise
  597. except Exception as e:
  598. # Timeout or socket-level error reading 226 — the data was sent
  599. # on our side and the printer may still have written the file.
  600. # H2D can take 30+ seconds to send 226 after the data channel
  601. # closes, so we proceed with a warning rather than failing here.
  602. logger.warning(
  603. "FTP STOR confirmation not received for %s (proceeding): %s (%s)",
  604. remote_path,
  605. e,
  606. type(e).__name__,
  607. )
  608. if callback_exception is not None:
  609. cleanup_result: DeleteResult = DeleteResult.FAILED
  610. try:
  611. cleanup_result = self.delete_file(remote_path)
  612. except Exception as cleanup_error:
  613. logger.warning("FTP cancel cleanup failed for %s: %s", remote_path, cleanup_error)
  614. # NOT_FOUND is success here — the partial file is gone (printer
  615. # may have already swept on cancel), which is the goal.
  616. if cleanup_result in (DeleteResult.DELETED, DeleteResult.NOT_FOUND):
  617. logger.info("FTP cancel cleanup succeeded for %s (%s)", remote_path, cleanup_result.value)
  618. raise callback_exception
  619. raise RuntimeError(
  620. f"Upload cancelled but failed to remove partial file {remote_path} from printer"
  621. ) from callback_exception
  622. elapsed = time.monotonic() - t0
  623. speed_kbs = (file_size / 1024) / elapsed if elapsed > 0 else 0
  624. logger.info(
  625. "FTP upload complete: %s (%s bytes in %.1fs, %.0f KB/s)",
  626. remote_path,
  627. file_size,
  628. elapsed,
  629. speed_kbs,
  630. )
  631. return True
  632. except ftplib.error_perm as e:
  633. # Permanent FTP error (4xx/5xx response)
  634. error_code = str(e)[:3] if str(e) else "unknown"
  635. logger.error("FTP upload failed for %s: %s (error code: %s)", remote_path, e, error_code)
  636. if error_code == "553":
  637. logger.error(
  638. "FTP 553 error - Could not create file. Possible causes: "
  639. "1) No SD card inserted, 2) SD card full, 3) SD card not formatted correctly (needs FAT32/exFAT), "
  640. "4) Printer busy/not ready, 5) File path issue"
  641. )
  642. elif error_code == "550":
  643. logger.error("FTP 550 error - File/directory not found or permission denied")
  644. elif error_code == "552":
  645. logger.error("FTP 552 error - Storage quota exceeded (SD card full?)")
  646. return False
  647. except (OSError, ftplib.Error) as e:
  648. logger.error("FTP upload failed for %s: %s (type: %s)", remote_path, e, type(e).__name__)
  649. return False
  650. def upload_bytes(self, data: bytes, remote_path: str) -> bool:
  651. """Upload bytes to the printer."""
  652. if not self._ftp:
  653. return False
  654. try:
  655. # Use manual transfer instead of storbinary() for A1 compatibility
  656. conn = self._ftp.transfercmd(f"STOR {remote_path}")
  657. conn.setblocking(True)
  658. conn.settimeout(self.timeout)
  659. try:
  660. # Send data in chunks
  661. offset = 0
  662. while offset < len(data):
  663. chunk = data[offset : offset + self.CHUNK_SIZE]
  664. conn.sendall(chunk)
  665. offset += len(chunk)
  666. except OSError as e:
  667. logger.error("FTP connection lost during upload_bytes: %s", e)
  668. raise
  669. finally:
  670. try:
  671. conn.close()
  672. except OSError:
  673. pass
  674. # Wait for 226 confirmation (see upload_file for rationale).
  675. # ftplib.Error subclasses (e.g. 426 error_temp) mean the server
  676. # rejected the transfer and the file is partial — fail. Other
  677. # exceptions (timeout, socket-level) are tolerated as in upload_file.
  678. try:
  679. old_timeout = self._ftp.sock.gettimeout()
  680. self._ftp.sock.settimeout(max(self.timeout, 60))
  681. try:
  682. self._ftp.voidresp()
  683. finally:
  684. self._ftp.sock.settimeout(old_timeout)
  685. except ftplib.Error as e:
  686. # Same SIZE-verify path as upload_file (#1417 follow-up):
  687. # tolerate a transient 426 if the bytes are actually on the
  688. # printer, fail loudly if they aren't.
  689. try:
  690. server_size = self._ftp.size(remote_path)
  691. except (OSError, ftplib.Error) as size_err:
  692. logger.debug("Post-error SIZE check failed: %s", size_err)
  693. server_size = None
  694. if server_size is not None and server_size == len(data):
  695. logger.warning(
  696. "FTP STOR returned %s for %s but file is intact on the "
  697. "printer (%s bytes match) — proceeding: %s",
  698. type(e).__name__,
  699. remote_path,
  700. len(data),
  701. e,
  702. )
  703. else:
  704. logger.error(
  705. "FTP STOR rejected by printer for %s: %s (%s); server size=%s expected=%s",
  706. remote_path,
  707. e,
  708. type(e).__name__,
  709. server_size,
  710. len(data),
  711. )
  712. return False
  713. except Exception:
  714. pass # Timeout / socket-level — proceed, data was sent.
  715. return True
  716. except (OSError, ftplib.Error):
  717. return False
  718. def delete_file(self, remote_path: str) -> DeleteResult:
  719. """Delete a file from the printer.
  720. Returns :class:`DeleteResult` distinguishing the file-not-found case
  721. (550) from network / auth / transient FTP failure. Callers that just
  722. want "did it work" should check ``result == DeleteResult.DELETED``.
  723. """
  724. if not self._ftp:
  725. return DeleteResult.FAILED
  726. try:
  727. self._ftp.delete(remote_path)
  728. return DeleteResult.DELETED
  729. except ftplib.error_perm as e:
  730. if str(e).startswith("550"):
  731. logger.debug("FTP delete: %s not on printer (550)", remote_path)
  732. return DeleteResult.NOT_FOUND
  733. logger.warning("Failed to delete %s: %s", remote_path, e)
  734. return DeleteResult.FAILED
  735. except (OSError, ftplib.Error) as e:
  736. logger.warning("Failed to delete %s: %s", remote_path, e)
  737. return DeleteResult.FAILED
  738. def get_file_size(self, remote_path: str) -> int | None:
  739. """Get the size of a file."""
  740. if not self._ftp:
  741. return None
  742. try:
  743. return self._ftp.size(remote_path)
  744. except (OSError, ftplib.Error):
  745. return None
  746. def get_storage_info(self) -> dict | None:
  747. """Get storage information from the printer."""
  748. if not self._ftp:
  749. return None
  750. result = {}
  751. # Try AVBL command (available space) - some FTP servers support this
  752. try:
  753. response = self._ftp.sendcmd("AVBL")
  754. logger.debug("AVBL response: %s", response)
  755. # Response format: "213 <bytes available>"
  756. if response.startswith("213"):
  757. parts = response.split()
  758. if len(parts) >= 2:
  759. result["free_bytes"] = int(parts[1])
  760. except (OSError, ftplib.Error) as e:
  761. logger.debug("AVBL command not supported: %s", e)
  762. # Try STAT command as fallback
  763. try:
  764. response = self._ftp.sendcmd("STAT")
  765. logger.debug("STAT response: %s", response)
  766. except (OSError, ftplib.Error):
  767. pass # Both AVBL and STAT unsupported; storage info will rely on directory scan
  768. # Calculate used space by listing root directories
  769. try:
  770. total_used = 0
  771. dirs_to_scan = ["/cache", "/timelapse", "/model", "/data", "/data/Metadata", "/"]
  772. for dir_path in dirs_to_scan:
  773. try:
  774. self._ftp.cwd(dir_path)
  775. items = []
  776. self._ftp.retrlines("LIST", items.append)
  777. for item in items:
  778. parts = item.split()
  779. if len(parts) >= 5 and not item.startswith("d"):
  780. try:
  781. total_used += int(parts[4])
  782. except ValueError:
  783. pass # Skip entries with non-numeric size fields
  784. except (OSError, ftplib.Error):
  785. pass # Directory may not exist on this printer model; skip it
  786. result["used_bytes"] = total_used
  787. except (OSError, ftplib.Error):
  788. pass # Storage scan failed; return whatever info was collected above
  789. return result if result else None
  790. def ftps_handshake_blocked(ip_address: str) -> bool:
  791. """True while this printer's FTPS handshake cool-off is still running.
  792. Callers that walk a list of candidate paths use this to give up on the
  793. remaining candidates: the failure is at the transport, below any path, so
  794. every one of them would fail identically (#2780).
  795. """
  796. return BambuFTPClient.handshake_blocked(ip_address)
  797. # Shared 3MF download cache (#972).
  798. #
  799. # Both the cover thumbnail endpoint (api/routes/printers.py) and the archive
  800. # metadata flow (main.py) fetch the same 3MF file over FTP during a print.
  801. # On slow / contended links (A1 Wi-Fi, large files) the duplicate transfers
  802. # compete for the printer's single FTP socket and trigger 425 "can't open
  803. # data channel" errors, feeding back into cause-2's retry storm.
  804. #
  805. # This cache stores the local path of a successfully-downloaded 3MF keyed
  806. # by (printer_id, normalized_name). Whichever flow downloads first populates
  807. # the cache; the other flow reuses the file read-only. Evicted on print
  808. # completion so a later print with the same name re-downloads fresh bytes.
  809. _threemf_path_cache: dict[tuple[int, str], Path] = {}
  810. def normalize_3mf_name(name: str) -> str:
  811. """Collapse various 3MF filename variants to a cache key.
  812. Bambu tooling produces names as bare subtask ("Part"), with .3mf, with
  813. .gcode.3mf, or (Studio-normalized) with spaces → underscores. All of
  814. these refer to the same print job on the same printer, so they must
  815. hash to the same cache key.
  816. """
  817. # Lowercase first so .3MF / .GCODE.3MF variants strip cleanly — a
  818. # real-world case since Windows-side tooling sometimes uppercases
  819. # extensions.
  820. cleaned = name.strip().lower().replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  821. return cleaned.replace(" ", "_")
  822. def cache_3mf_download(printer_id: int, name: str, local_path: Path) -> None:
  823. """Record a successfully-downloaded 3MF so a sibling flow can reuse it."""
  824. _threemf_path_cache[(printer_id, normalize_3mf_name(name))] = local_path
  825. def get_cached_3mf(printer_id: int, name: str) -> Path | None:
  826. """Return a cached 3MF path for this printer/name if the file still exists."""
  827. key = (printer_id, normalize_3mf_name(name))
  828. cached = _threemf_path_cache.get(key)
  829. if cached and cached.exists() and cached.stat().st_size > 0:
  830. return cached
  831. # Evict dead entry — the file was cleaned up (temp dir clean, manual
  832. # deletion, restart) so the cache value is no longer usable.
  833. if cached:
  834. _threemf_path_cache.pop(key, None)
  835. return None
  836. def clear_3mf_cache(printer_id: int | None = None, delete_files: bool = True) -> None:
  837. """Drop cache entries for one printer (or all with None).
  838. When ``delete_files`` is True (default) the on-disk 3MF is removed as well
  839. — called from on_print_complete so temp files don't accumulate across
  840. prints. Tests that want to inspect the cache contents disable this.
  841. Only paths inside ``archive_dir/temp`` are unlinked. The dispatch sites
  842. added in #1166 also cache the live archive copy and library file bytes
  843. so /cover can skip FTP — those are *user data*, never the cache's to
  844. delete. Pre-fix this branch silently removed archive 3mfs on every print
  845. completion (#1212 + private reports of "file disappeared overnight").
  846. """
  847. from backend.app.core.config import settings as _config_settings
  848. temp_root = _config_settings.archive_dir / "temp"
  849. def _is_temp_path(path: Path) -> bool:
  850. try:
  851. return path.is_relative_to(temp_root)
  852. except (OSError, ValueError):
  853. return False
  854. def _maybe_unlink(path: Path) -> None:
  855. if not delete_files or not path.exists():
  856. return
  857. if not _is_temp_path(path):
  858. return
  859. try:
  860. path.unlink()
  861. except OSError as exc:
  862. logger.debug("3MF cache cleanup skipped %s: %s", path, exc)
  863. if printer_id is None:
  864. for path in list(_threemf_path_cache.values()):
  865. _maybe_unlink(path)
  866. _threemf_path_cache.clear()
  867. return
  868. for key in [k for k in _threemf_path_cache if k[0] == printer_id]:
  869. _maybe_unlink(_threemf_path_cache[key])
  870. _threemf_path_cache.pop(key, None)
  871. async def download_file_async(
  872. ip_address: str,
  873. access_code: str,
  874. remote_path: str,
  875. local_path: Path,
  876. timeout: float = 60.0,
  877. socket_timeout: float | None = None,
  878. printer_model: str | None = None,
  879. ) -> bool:
  880. """Async wrapper for downloading a file with timeout.
  881. For A1/A1 Mini printers, automatically tries prot_p first, then falls back
  882. to prot_c if the download fails. The working mode is cached for future operations.
  883. Args:
  884. ip_address: Printer IP address
  885. access_code: Printer access code
  886. remote_path: Remote file path on printer
  887. local_path: Local path to save file
  888. timeout: Overall operation timeout (asyncio)
  889. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  890. printer_model: Printer model for A1-specific workarounds
  891. """
  892. loop = asyncio.get_event_loop()
  893. is_a1 = printer_model in BambuFTPClient.A1_MODELS if printer_model else False
  894. # Per-attempt completion state: asyncio.wait_for cannot cancel
  895. # run_in_executor threads, so on timeout the executor may still complete
  896. # the download after we stop waiting. The thread flips `success` to True
  897. # ONLY after the file is fully written — a post-timeout check lets us
  898. # salvage the download without mistaking an in-progress partial write
  899. # for a completed one. Each attempt gets its own dict and event so a
  900. # zombie from an earlier attempt can't flip the flag for a later one.
  901. # The event is set in `_download`'s finally block so the post-timeout
  902. # path can wait for genuine thread completion instead of a fixed sleep.
  903. def _download(force_prot_c: bool, completion: dict, done: threading.Event) -> bool:
  904. mode_str = "prot_c" if force_prot_c else "prot_p"
  905. try:
  906. client = BambuFTPClient(
  907. ip_address,
  908. access_code,
  909. timeout=socket_timeout,
  910. printer_model=printer_model,
  911. force_prot_c=force_prot_c,
  912. )
  913. if client.connect():
  914. try:
  915. result = client.download_to_file(remote_path, local_path)
  916. if result:
  917. BambuFTPClient.cache_mode(ip_address, mode_str)
  918. completion["success"] = True
  919. return result
  920. finally:
  921. client.disconnect()
  922. return False
  923. finally:
  924. done.set()
  925. async def _run(force_prot_c: bool) -> bool:
  926. completion = {"success": False}
  927. done = threading.Event()
  928. try:
  929. return await asyncio.wait_for(
  930. loop.run_in_executor(_ftp_executor, _download, force_prot_c, completion, done), timeout=timeout
  931. )
  932. except TimeoutError:
  933. # Slow WiFi links commonly overshoot ftp_timeout by 10–30 s without
  934. # actually being stuck, so starting attempt 2 now would just contend
  935. # with the still-progressing RETR on attempt 1 and produce the
  936. # zombie-write race reported in #1014 (file landed on disk minutes
  937. # after the retry loop had already given up). Wait for the worker
  938. # thread to genuinely finish — capped at 30 s so a truly stuck
  939. # connection can't stall a whole attempt indefinitely, with a 0.5 s
  940. # floor so artificially small test timeouts still give zombies a
  941. # realistic window to finish.
  942. grace = max(min(timeout, 30.0), 0.5)
  943. # Deliberately the DEFAULT executor, not `_ftp_executor`: this thread
  944. # blocks waiting on `_download`, which is itself an `_ftp_executor`
  945. # worker. Parking waiters in the same bounded pool as the workers they
  946. # wait for is how you build a deadlock — with enough concurrent
  947. # timeouts the waiters would occupy every slot and the downloads they
  948. # are waiting for could never be scheduled.
  949. await loop.run_in_executor(None, done.wait, grace)
  950. if completion["success"] and local_path.exists() and local_path.stat().st_size > 0:
  951. logger.info(
  952. "FTP download wait_for timed out after %ss for %s, but thread completed within %ss grace (%s bytes) — salvaging",
  953. timeout,
  954. remote_path,
  955. grace,
  956. local_path.stat().st_size,
  957. )
  958. return True
  959. logger.warning(
  960. "FTP download timed out after %ss (plus %ss grace) for %s",
  961. timeout,
  962. grace,
  963. remote_path,
  964. )
  965. return False
  966. # Check if we have a cached mode for this printer
  967. cached_mode = BambuFTPClient._mode_cache.get(ip_address)
  968. if cached_mode:
  969. force_prot_c = cached_mode == "prot_c"
  970. return await _run(force_prot_c)
  971. # No cached mode - try prot_p first
  972. if await _run(False):
  973. return True
  974. # Download failed - for A1 models, try prot_c fallback
  975. if is_a1:
  976. logger.info("FTP download failed with prot_p for A1 model, trying prot_c fallback...")
  977. return await _run(True)
  978. return False
  979. async def download_file_try_paths_async(
  980. ip_address: str,
  981. access_code: str,
  982. remote_paths: list[str],
  983. local_path: Path,
  984. socket_timeout: float | None = None,
  985. printer_model: str | None = None,
  986. timeout: float = 90.0,
  987. ) -> bool:
  988. """Try downloading a file from multiple paths using a single connection.
  989. Args:
  990. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  991. printer_model: Printer model for A1-specific workarounds
  992. timeout: overall async cap. The per-socket timeout only bounds an
  993. in-flight worker; it does NOT bound how long this coroutine waits
  994. for a free slot in the fixed-size ``_ftp_executor``. On a large
  995. farm where offline printers keep every worker busy on dead
  996. connects, that queue wait is otherwise unbounded — and any caller
  997. holding a DB connection while awaiting this would pin it until the
  998. pool is exhausted (#2572). The cap converts that into a bounded
  999. wait; the orphaned worker finishes and its result is discarded.
  1000. """
  1001. loop = asyncio.get_event_loop()
  1002. def _download():
  1003. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1004. if not client.connect():
  1005. return False
  1006. try:
  1007. # FileNotOnPrinterError signals "try the next path", not "give up" —
  1008. # this function's whole purpose is to walk a list of candidates
  1009. # over one connection. Only a real transport error should bubble.
  1010. for remote_path in remote_paths:
  1011. try:
  1012. if client.download_to_file(remote_path, local_path):
  1013. return True
  1014. except FileNotOnPrinterError:
  1015. continue
  1016. return False
  1017. finally:
  1018. client.disconnect()
  1019. try:
  1020. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _download), timeout=timeout)
  1021. except TimeoutError:
  1022. logger.warning("FTP download_try_paths exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  1023. return False
  1024. def _upload_deadline(local_path: Path) -> float:
  1025. """Derive an upload deadline from the file size (#2529).
  1026. See ``_UPLOAD_FLOOR_BYTES_PER_SEC``. An unstat-able file falls back to the
  1027. floor timeout — ``upload_file`` will fail on the open() anyway.
  1028. """
  1029. try:
  1030. size = local_path.stat().st_size
  1031. except OSError:
  1032. return _UPLOAD_MIN_TIMEOUT
  1033. return max(_UPLOAD_MIN_TIMEOUT, size / _UPLOAD_FLOOR_BYTES_PER_SEC)
  1034. # One upload at a time per printer. Two concurrent STOR commands for the same
  1035. # remote path leave a corrupt file on the SD card, and the printer reads as
  1036. # flaky rather than busy (#2529). Held for the duration of a transfer, so a
  1037. # second dispatch to the same printer queues behind the first instead of racing
  1038. # it. Keyed per event loop: an asyncio.Lock binds to the loop that first awaits
  1039. # it, and the test suite runs each case on a fresh loop.
  1040. _upload_locks: weakref.WeakKeyDictionary[asyncio.AbstractEventLoop, dict[str, asyncio.Lock]] = (
  1041. weakref.WeakKeyDictionary()
  1042. )
  1043. def _upload_lock(loop: asyncio.AbstractEventLoop, ip_address: str) -> asyncio.Lock:
  1044. per_loop = _upload_locks.setdefault(loop, {})
  1045. lock = per_loop.get(ip_address)
  1046. if lock is None:
  1047. lock = asyncio.Lock()
  1048. per_loop[ip_address] = lock
  1049. return lock
  1050. async def upload_file_async(
  1051. ip_address: str,
  1052. access_code: str,
  1053. local_path: Path,
  1054. remote_path: str,
  1055. timeout: float | None = None,
  1056. progress_callback: Callable[[int, int], None] | None = None,
  1057. socket_timeout: float | None = None,
  1058. printer_model: str | None = None,
  1059. ) -> bool:
  1060. """Async wrapper for uploading a file with timeout and progress callback.
  1061. For A1/A1 Mini printers, automatically tries prot_p first, then falls back
  1062. to prot_c if the upload fails. The working mode is cached for future uploads.
  1063. Args:
  1064. ip_address: Printer IP address
  1065. access_code: Printer access code
  1066. local_path: Local file path to upload
  1067. remote_path: Remote path on printer
  1068. timeout: Overall deadline. ``None`` (the default) derives it from the
  1069. file size — see ``_upload_deadline``. A caller that passes a number
  1070. gets exactly that, which is what the tests rely on.
  1071. progress_callback: Optional callback for progress updates
  1072. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1073. printer_model: Printer model for A1-specific workarounds
  1074. """
  1075. loop = asyncio.get_event_loop()
  1076. is_a1 = printer_model in BambuFTPClient.A1_MODELS if printer_model else False
  1077. deadline = _upload_deadline(local_path) if timeout is None else timeout
  1078. # Set when the deadline expires. The worker checks it once per chunk.
  1079. cancel = threading.Event()
  1080. def _guarded_progress(uploaded: int, total: int) -> None:
  1081. if cancel.is_set():
  1082. raise UploadCancelled(f"upload of {remote_path} exceeded its {deadline:.0f}s deadline")
  1083. if progress_callback:
  1084. progress_callback(uploaded, total)
  1085. def _upload(force_prot_c: bool = False) -> bool:
  1086. mode_str = "prot_c" if force_prot_c else "prot_p"
  1087. logger.info(
  1088. f"FTP connecting to {ip_address} for upload (model={printer_model}, "
  1089. f"mode={mode_str}, socket_timeout={socket_timeout}s, deadline={deadline:.0f}s)..."
  1090. )
  1091. client = BambuFTPClient(
  1092. ip_address, access_code, timeout=socket_timeout, printer_model=printer_model, force_prot_c=force_prot_c
  1093. )
  1094. if client.connect():
  1095. logger.info("FTP connected to %s", ip_address)
  1096. try:
  1097. result = client.upload_file(local_path, remote_path, _guarded_progress)
  1098. if result:
  1099. # Cache the working mode
  1100. BambuFTPClient.cache_mode(ip_address, mode_str)
  1101. return result
  1102. finally:
  1103. client.disconnect()
  1104. logger.warning("FTP connection failed to %s", ip_address)
  1105. return False
  1106. async def _attempt(force_prot_c: bool) -> bool:
  1107. """Run one upload attempt, and make a timeout actually stop the transfer.
  1108. ``asyncio.wait_for`` cancels the *future*, never the executor thread
  1109. behind it. Before #2529 a slow-but-healthy upload that overran the
  1110. deadline left that thread streaming: it kept pushing bytes, kept firing
  1111. the progress callback, and the retry above put a *second* STOR of the
  1112. same file onto the same printer. The reporter's 96 MB job ran four
  1113. concurrent transfers and never landed. So on timeout we signal the
  1114. worker (it raises ``UploadCancelled`` from the progress callback, which
  1115. breaks the send loop and deletes the partial file) and wait for it to
  1116. actually go.
  1117. """
  1118. fut = loop.run_in_executor(_ftp_executor, lambda: _upload(force_prot_c))
  1119. try:
  1120. return await asyncio.wait_for(asyncio.shield(fut), timeout=deadline)
  1121. except TimeoutError:
  1122. cancel.set()
  1123. logger.warning(
  1124. "FTP upload of %s exceeded its %.0fs deadline — cancelling the transfer",
  1125. remote_path,
  1126. deadline,
  1127. )
  1128. try:
  1129. await asyncio.wait_for(asyncio.shield(fut), timeout=_UPLOAD_CANCEL_GRACE)
  1130. except UploadCancelled:
  1131. logger.info("FTP upload of %s cancelled; partial file removed from the printer", remote_path)
  1132. except TimeoutError:
  1133. # The thread is wedged somewhere that never reaches the callback
  1134. # (a blocked sendall, say). Nothing more we can do from here —
  1135. # but consume the eventual result so asyncio doesn't log the
  1136. # future's exception as unretrieved when it is garbage-collected.
  1137. logger.error(
  1138. "FTP upload thread for %s did not stop within %.0fs of the cancel signal",
  1139. remote_path,
  1140. _UPLOAD_CANCEL_GRACE,
  1141. )
  1142. fut.add_done_callback(_swallow_future_result)
  1143. except Exception as e:
  1144. logger.warning("FTP upload of %s errored while cancelling: %s", remote_path, e)
  1145. # Raise rather than return False: a deadline expiry means the link
  1146. # sustained less than the floor rate for the whole transfer, and a
  1147. # retry would only spend another full deadline finding that out
  1148. # again — with check_queue serialized, four of those block the
  1149. # entire print queue for hours. ``with_ftp_retry`` never retries it.
  1150. raise UploadCancelled(
  1151. f"Upload of {remote_path} to {ip_address} exceeded its {deadline:.0f}s deadline "
  1152. f"(link sustained less than {_UPLOAD_FLOOR_BYTES_PER_SEC // 1024} KB/s)"
  1153. ) from None
  1154. async with _upload_lock(loop, ip_address):
  1155. # Check if we have a cached mode for this printer
  1156. cached_mode = BambuFTPClient._mode_cache.get(ip_address)
  1157. if cached_mode:
  1158. # Use cached mode
  1159. return await _attempt(cached_mode == "prot_c")
  1160. # No cached mode - try prot_p first
  1161. if await _attempt(False):
  1162. return True
  1163. # Upload failed - for A1 models, try prot_c fallback
  1164. if is_a1:
  1165. logger.info("FTP upload failed with prot_p for A1 model, trying prot_c fallback...")
  1166. return await _attempt(True)
  1167. return False
  1168. def _swallow_future_result(fut: asyncio.Future) -> None:
  1169. """Retrieve a future's exception so asyncio doesn't log it as unhandled."""
  1170. if not fut.cancelled():
  1171. fut.exception()
  1172. async def list_files_async(
  1173. ip_address: str,
  1174. access_code: str,
  1175. path: str = "/",
  1176. timeout: float = 30.0,
  1177. socket_timeout: float | None = None,
  1178. printer_model: str | None = None,
  1179. ) -> list[dict]:
  1180. """Async wrapper for listing files with timeout.
  1181. Args:
  1182. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1183. printer_model: Printer model for A1-specific workarounds
  1184. """
  1185. loop = asyncio.get_event_loop()
  1186. def _list():
  1187. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1188. if client.connect():
  1189. try:
  1190. return client.list_files(path)
  1191. finally:
  1192. client.disconnect()
  1193. return []
  1194. try:
  1195. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _list), timeout=timeout)
  1196. except TimeoutError:
  1197. logger.warning("FTP list_files timed out after %ss for %s", timeout, path)
  1198. return []
  1199. async def delete_file_async(
  1200. ip_address: str,
  1201. access_code: str,
  1202. remote_path: str,
  1203. socket_timeout: float | None = None,
  1204. printer_model: str | None = None,
  1205. timeout: float = 60.0,
  1206. ) -> DeleteResult:
  1207. """Async wrapper for deleting a file.
  1208. Returns :class:`DeleteResult` so callers can distinguish ``NOT_FOUND``
  1209. (550 — file isn't on the printer, no retry value) from ``FAILED``
  1210. (network / auth / transient — worth retrying or surfacing).
  1211. Args:
  1212. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1213. printer_model: Printer model for A1-specific workarounds
  1214. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  1215. the caller (and any DB connection it holds) indefinitely (#2572).
  1216. """
  1217. loop = asyncio.get_event_loop()
  1218. def _delete() -> DeleteResult:
  1219. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1220. if client.connect():
  1221. try:
  1222. return client.delete_file(remote_path)
  1223. finally:
  1224. client.disconnect()
  1225. return DeleteResult.FAILED
  1226. try:
  1227. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _delete), timeout=timeout)
  1228. except TimeoutError:
  1229. logger.warning("FTP delete_file exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  1230. return DeleteResult.FAILED
  1231. async def download_file_bytes_async(
  1232. ip_address: str,
  1233. access_code: str,
  1234. remote_path: str,
  1235. socket_timeout: float | None = None,
  1236. printer_model: str | None = None,
  1237. timeout: float = 300.0,
  1238. expected_size: int | None = None,
  1239. ) -> bytes | None:
  1240. """Async wrapper for downloading file as bytes.
  1241. Args:
  1242. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1243. printer_model: Printer model for A1-specific workarounds
  1244. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  1245. the caller (and any DB connection it holds) indefinitely (#2572).
  1246. Generous by default because this pulls whole files (timelapse
  1247. video, gcode) which can legitimately take minutes over slow Wi-Fi —
  1248. the cap only guards against a permanently-starved pool, not a
  1249. slow-but-progressing transfer.
  1250. expected_size: size from the directory listing; a mismatch fails the
  1251. download instead of returning a truncated file. See
  1252. :meth:`BambuFTPClient.download_file`.
  1253. """
  1254. loop = asyncio.get_event_loop()
  1255. def _download():
  1256. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1257. if client.connect():
  1258. try:
  1259. return client.download_file(remote_path, expected_size=expected_size)
  1260. finally:
  1261. client.disconnect()
  1262. return None
  1263. try:
  1264. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _download), timeout=timeout)
  1265. except TimeoutError:
  1266. logger.warning("FTP download_bytes exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  1267. return None
  1268. async def remote_file_settled(
  1269. ip_address: str,
  1270. access_code: str,
  1271. remote_path: str,
  1272. downloaded_bytes: int,
  1273. *,
  1274. printer_model: str | None = None,
  1275. ) -> bool:
  1276. """Confirm the printer has finished writing the file we just downloaded.
  1277. Matching the download against the size from the directory listing proves we
  1278. received what the listing *said*, not that the file was *finished*. The
  1279. timelapse scan's first look happens seconds after the print ends, which is
  1280. exactly when the printer is writing the video — so a file still growing can
  1281. be listed at a partial size, served at that size, and pass the length check
  1282. as a complete video (#2704).
  1283. That was survivable while the printer kept its copy. It isn't now that a
  1284. successful attach deletes the source, so re-list afterwards: if the file has
  1285. grown, what we hold is a prefix and the caller should discard it and try
  1286. again on the next round.
  1287. Returns True when the remote file can no longer differ from what we hold —
  1288. the size still matches, or the file is gone from the listing entirely and
  1289. so cannot grow any further. Returns False when it has changed size, and on
  1290. a listing failure, because "we could not check" must not read as "safe to
  1291. delete".
  1292. """
  1293. directory, _, name = remote_path.rpartition("/")
  1294. files = await list_files_async(ip_address, access_code, directory or "/", printer_model=printer_model)
  1295. if not files:
  1296. logger.warning("[TIMELAPSE] Could not re-list %s to confirm %s is complete", directory or "/", name)
  1297. return False
  1298. for f in files:
  1299. if f.get("name") == name:
  1300. size = f.get("size")
  1301. if size == downloaded_bytes:
  1302. return True
  1303. logger.info(
  1304. "[TIMELAPSE] %s is still being written (%s bytes now, %s when downloaded) — will retry",
  1305. name,
  1306. size,
  1307. downloaded_bytes,
  1308. )
  1309. return False
  1310. # Vanished between the download and now. Nothing left that could grow, and
  1311. # nothing left to delete either.
  1312. logger.debug("[TIMELAPSE] %s is no longer on the printer after download", name)
  1313. return True
  1314. async def delete_archived_timelapse(
  1315. ip_address: str,
  1316. access_code: str,
  1317. remote_path: str,
  1318. *,
  1319. verified: bool,
  1320. printer_model: str | None = None,
  1321. printer_name: str = "",
  1322. ) -> bool:
  1323. """Remove a timelapse from the printer once it is safely in the archive.
  1324. Call this only after the attach succeeded (#2704). Keeping ``/timelapse``
  1325. down to just the unclaimed videos is what makes the snapshot diff
  1326. unambiguous rather than merely usually-right, and it stops P1S cards
  1327. filling with AVIs.
  1328. ``verified`` must say whether the downloaded byte count was checked against
  1329. the size the directory listing reported. It is required rather than
  1330. defaulted because this is the one irreversible step in the flow: an FTPS
  1331. data connection that closes early does not always raise, so an unverified
  1332. transfer can be a partial file that looks complete, and deleting the source
  1333. would then destroy the only good copy. The check lives here rather than at
  1334. each call site so no future caller can omit it.
  1335. Best-effort otherwise: a printer that refuses the delete keeps its copy, the
  1336. diff still excludes that filename next time because it is attached to an
  1337. archive, and nothing else in the flow cares. Returns True only on an actual
  1338. delete or a 550 (already gone).
  1339. """
  1340. if not verified:
  1341. logger.warning(
  1342. "[TIMELAPSE] Not deleting %s from printer %s: the download was never size-checked",
  1343. remote_path,
  1344. printer_name,
  1345. )
  1346. return False
  1347. for attempt in range(1, 4):
  1348. try:
  1349. result = await delete_file_async(ip_address, access_code, remote_path, printer_model=printer_model)
  1350. except Exception as e:
  1351. result = DeleteResult.FAILED
  1352. logger.warning("[TIMELAPSE] Delete attempt %d/3 raised for %s: %s", attempt, remote_path, e)
  1353. if result == DeleteResult.DELETED:
  1354. logger.info("[TIMELAPSE] Deleted %s from printer %s after archiving", remote_path, printer_name)
  1355. return True
  1356. if result == DeleteResult.NOT_FOUND:
  1357. # 550 never recovers by waiting — the printer already cleaned up.
  1358. logger.debug("[TIMELAPSE] %s already gone from printer %s", remote_path, printer_name)
  1359. return True
  1360. if attempt < 3:
  1361. await asyncio.sleep(2)
  1362. logger.warning(
  1363. "[TIMELAPSE] Could not delete %s from printer %s (it stays on the card; the archive copy is unaffected)",
  1364. remote_path,
  1365. printer_name,
  1366. )
  1367. return False
  1368. async def get_storage_info_async(
  1369. ip_address: str,
  1370. access_code: str,
  1371. socket_timeout: float | None = None,
  1372. printer_model: str | None = None,
  1373. timeout: float = 60.0,
  1374. ) -> dict | None:
  1375. """Async wrapper for getting storage info.
  1376. Args:
  1377. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1378. printer_model: Printer model for A1-specific workarounds
  1379. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  1380. the caller (and any DB connection it holds) indefinitely (#2572).
  1381. """
  1382. loop = asyncio.get_event_loop()
  1383. def _get_storage():
  1384. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1385. if client.connect():
  1386. try:
  1387. return client.get_storage_info()
  1388. finally:
  1389. client.disconnect()
  1390. return None
  1391. try:
  1392. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _get_storage), timeout=timeout)
  1393. except TimeoutError:
  1394. logger.warning("FTP get_storage_info exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  1395. return None
  1396. async def get_ftp_retry_settings() -> tuple[bool, int, float, float]:
  1397. """Get FTP retry settings from database.
  1398. Returns:
  1399. Tuple of (retry_enabled, retry_count, retry_delay, timeout)
  1400. """
  1401. from backend.app.api.routes.settings import get_setting
  1402. from backend.app.core.database import async_session
  1403. async with async_session() as db:
  1404. enabled = (await get_setting(db, "ftp_retry_enabled") or "true") == "true"
  1405. count = int(await get_setting(db, "ftp_retry_count") or "3")
  1406. delay = float(await get_setting(db, "ftp_retry_delay") or "2")
  1407. timeout = float(await get_setting(db, "ftp_timeout") or "30")
  1408. return enabled, count, delay, timeout
  1409. async def with_ftp_retry(
  1410. operation: Callable[..., Awaitable[T]],
  1411. *args,
  1412. max_retries: int = 3,
  1413. retry_delay: float = 2.0,
  1414. operation_name: str = "FTP operation",
  1415. non_retry_exceptions: tuple[type[BaseException], ...] = (),
  1416. **kwargs,
  1417. ) -> T | None:
  1418. """Execute FTP operation with retry logic.
  1419. Args:
  1420. operation: Async function to execute
  1421. *args: Positional arguments for the operation
  1422. max_retries: Number of retry attempts (default: 3)
  1423. retry_delay: Seconds to wait between retries (default: 2.0)
  1424. operation_name: Name for logging purposes
  1425. non_retry_exceptions: Exception types that should immediately abort retries
  1426. **kwargs: Keyword arguments for the operation
  1427. Returns:
  1428. Result of the operation, or None if all attempts fail
  1429. ``UploadCancelled`` is never retried, whatever the caller passes: it means
  1430. the transfer overran its size-derived deadline, so a retry would spend
  1431. another full deadline reaching the same conclusion (#2529).
  1432. """
  1433. last_error = None
  1434. for attempt in range(max_retries + 1):
  1435. try:
  1436. result = await operation(*args, **kwargs)
  1437. # Check for "falsy" success indicators
  1438. if result not in (False, None, []):
  1439. if attempt > 0:
  1440. logger.info("%s succeeded on attempt %s/%s", operation_name, attempt + 1, max_retries + 1)
  1441. return result
  1442. # Operation returned failure indicator
  1443. if attempt > 0:
  1444. logger.info("%s attempt %s/%s returned failure", operation_name, attempt + 1, max_retries + 1)
  1445. except UploadCancelled:
  1446. raise
  1447. except Exception as e:
  1448. if non_retry_exceptions and isinstance(e, non_retry_exceptions):
  1449. raise
  1450. last_error = e
  1451. logger.warning("%s attempt %s/%s failed: %s", operation_name, attempt + 1, max_retries + 1, e)
  1452. # Don't wait after the last attempt
  1453. if attempt < max_retries:
  1454. logger.info("%s will retry in %ss...", operation_name, retry_delay)
  1455. await asyncio.sleep(retry_delay)
  1456. logger.error("%s failed after %s attempts", operation_name, max_retries + 1)
  1457. if last_error:
  1458. logger.debug("Last error: %s", last_error)
  1459. return None