bambu_ftp.py 126 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455145614571458145914601461146214631464146514661467146814691470147114721473147414751476147714781479148014811482148314841485148614871488148914901491149214931494149514961497149814991500150115021503150415051506150715081509151015111512151315141515151615171518151915201521152215231524152515261527152815291530153115321533153415351536153715381539154015411542154315441545154615471548154915501551155215531554155515561557155815591560156115621563156415651566156715681569157015711572157315741575157615771578157915801581158215831584158515861587158815891590159115921593159415951596159715981599160016011602160316041605160616071608160916101611161216131614161516161617161816191620162116221623162416251626162716281629163016311632163316341635163616371638163916401641164216431644164516461647164816491650165116521653165416551656165716581659166016611662166316641665166616671668166916701671167216731674167516761677167816791680168116821683168416851686168716881689169016911692169316941695169616971698169917001701170217031704170517061707170817091710171117121713171417151716171717181719172017211722172317241725172617271728172917301731173217331734173517361737173817391740174117421743174417451746174717481749175017511752175317541755175617571758175917601761176217631764176517661767176817691770177117721773177417751776177717781779178017811782178317841785178617871788178917901791179217931794179517961797179817991800180118021803180418051806180718081809181018111812181318141815181618171818181918201821182218231824182518261827182818291830183118321833183418351836183718381839184018411842184318441845184618471848184918501851185218531854185518561857185818591860186118621863186418651866186718681869187018711872187318741875187618771878187918801881188218831884188518861887188818891890189118921893189418951896189718981899190019011902190319041905190619071908190919101911191219131914191519161917191819191920192119221923192419251926192719281929193019311932193319341935193619371938193919401941194219431944194519461947194819491950195119521953195419551956195719581959196019611962196319641965196619671968196919701971197219731974197519761977197819791980198119821983198419851986198719881989199019911992199319941995199619971998199920002001200220032004200520062007200820092010201120122013201420152016201720182019202020212022202320242025202620272028202920302031203220332034203520362037203820392040204120422043204420452046204720482049205020512052205320542055205620572058205920602061206220632064206520662067206820692070207120722073207420752076207720782079208020812082208320842085208620872088208920902091209220932094209520962097209820992100210121022103210421052106210721082109211021112112211321142115211621172118211921202121212221232124212521262127212821292130213121322133213421352136213721382139214021412142214321442145214621472148214921502151215221532154215521562157215821592160216121622163216421652166216721682169217021712172217321742175217621772178217921802181218221832184218521862187218821892190219121922193219421952196219721982199220022012202220322042205220622072208220922102211221222132214221522162217221822192220222122222223222422252226222722282229223022312232223322342235223622372238223922402241224222432244224522462247224822492250225122522253225422552256225722582259226022612262226322642265226622672268226922702271227222732274227522762277227822792280228122822283228422852286228722882289229022912292229322942295229622972298229923002301230223032304230523062307230823092310231123122313231423152316231723182319232023212322232323242325232623272328232923302331233223332334233523362337233823392340234123422343234423452346234723482349235023512352235323542355235623572358235923602361236223632364236523662367236823692370237123722373237423752376237723782379238023812382238323842385238623872388238923902391239223932394239523962397239823992400240124022403240424052406240724082409241024112412241324142415241624172418241924202421242224232424242524262427242824292430243124322433243424352436243724382439244024412442244324442445244624472448244924502451245224532454245524562457245824592460246124622463246424652466246724682469247024712472247324742475247624772478247924802481248224832484248524862487248824892490249124922493249424952496249724982499250025012502250325042505250625072508250925102511251225132514251525162517251825192520252125222523252425252526252725282529253025312532253325342535253625372538253925402541254225432544254525462547254825492550255125522553255425552556255725582559256025612562256325642565256625672568256925702571257225732574257525762577257825792580258125822583258425852586258725882589259025912592259325942595259625972598259926002601260226032604260526062607260826092610261126122613261426152616261726182619262026212622262326242625262626272628262926302631263226332634263526362637263826392640264126422643264426452646264726482649265026512652265326542655265626572658265926602661266226632664266526662667266826692670267126722673267426752676267726782679268026812682268326842685268626872688268926902691269226932694269526962697269826992700270127022703270427052706270727082709271027112712271327142715271627172718271927202721272227232724272527262727272827292730273127322733273427352736273727382739274027412742274327442745274627472748274927502751275227532754275527562757275827592760276127622763276427652766276727682769277027712772277327742775277627772778277927802781278227832784278527862787278827892790279127922793279427952796279727982799280028012802
  1. import asyncio
  2. import ftplib # nosec B402
  3. import logging
  4. import os
  5. import shutil
  6. import socket
  7. import ssl
  8. import threading
  9. import time
  10. import weakref
  11. from collections.abc import AsyncIterator, Awaitable, Callable
  12. from concurrent.futures import ThreadPoolExecutor
  13. from contextlib import asynccontextmanager
  14. from dataclasses import dataclass
  15. from datetime import datetime, timedelta, timezone
  16. from enum import Enum
  17. from ftplib import FTP, FTP_TLS # nosec B402
  18. from io import BytesIO
  19. from pathlib import Path
  20. from typing import TypeVar
  21. logger = logging.getLogger(__name__)
  22. T = TypeVar("T")
  23. # Every FTP call below is blocking ftplib work handed to a thread. They used to
  24. # run on asyncio's *default* executor, which is sized min(32, cpu_count + 4) —
  25. # six threads on a 2-core NAS — and is shared with every other ``to_thread`` /
  26. # ``run_in_executor`` caller in the app. That was survivable only because the
  27. # scheduler uploaded to exactly one printer at a time. Dispatching to several
  28. # printers at once (#2555) would park one thread per in-flight upload for
  29. # minutes at a stretch (a 41 MB 3MF at the ~150 KB/s a Bambu printer sustains
  30. # takes ~4 min), starving the default pool and stalling unrelated work.
  31. #
  32. # A dedicated pool keeps that blast radius inside the FTP layer: the scheduler's
  33. # own concurrency cap is what limits parallel uploads, and it can never exhaust
  34. # the executor everything else depends on. Threads are created lazily, so an
  35. # idle pool costs nothing.
  36. #
  37. # Sized well above `queue_max_concurrent_uploads` (max 16), because uploads are
  38. # not the only traffic here: SD browsing, timelapse/recording listing, cover
  39. # downloads, deletes and storage checks all run through this pool too, and on a
  40. # farm they fan out across every printer at once. The pool's work queue is
  41. # unbounded, so exceeding it does not fail — it queues. But `asyncio.wait_for`
  42. # starts its clock at submission, not at thread start, so a task that sits in the
  43. # queue can burn its whole timeout without ever running, and `list_files_async`
  44. # reports a timeout as an empty listing — a silent "this printer has no files".
  45. # Keep the headroom.
  46. _FTP_MAX_WORKERS = 48
  47. _ftp_executor = ThreadPoolExecutor(max_workers=_FTP_MAX_WORKERS, thread_name_prefix="bambu-ftp")
  48. # Overall upload deadline (#2529). A flat wall-clock cap punishes big files on
  49. # slow links rather than catching broken ones: a 96 MB 3MF at the ~75 KB/s an A1
  50. # sustains over WiFi legitimately needs ~20 minutes, and the old flat 600 s
  51. # declared it dead at ~70 MB. The deadline is therefore derived from the file
  52. # size against a deliberately pessimistic floor rate. This is a backstop, not the
  53. # failure detector — a link that has actually died is caught within
  54. # ``socket_timeout`` by the blocking ``sendall``, long before this fires.
  55. _UPLOAD_FLOOR_BYTES_PER_SEC = 25 * 1024
  56. _UPLOAD_MIN_TIMEOUT = 600.0
  57. # The same idea for the other direction (#2957). ``ftp_timeout`` is handed to
  58. # every download as BOTH the socket inactivity timeout and the whole-transfer
  59. # deadline, so its 30 s default is a cap on how big a file the printer is
  60. # allowed to serve. A reporter measured the same 5.4 MB 3MF at 45 s off a worn
  61. # P1S SD card and 25 s off a new one, and a 15.15 MB 3MF at 105 s; a 7.8 MB
  62. # archive in his older logs survived only because it finished inside the retry
  63. # grace. None of those transfers were unhealthy -- they were slow, which is what
  64. # the inactivity timeout is for and what a total deadline cannot tell apart.
  65. #
  66. # So the total deadline follows the file instead, at the same pessimistic floor
  67. # rate the upload path uses. The extension is granted only once the printer has
  68. # answered SIZE, which it can only do from a running worker: the queue wait that
  69. # #2572's cap exists to bound is not lengthened by any of this.
  70. _DOWNLOAD_FLOOR_BYTES_PER_SEC = 25 * 1024
  71. # ...but not without a ceiling, and for a reason that has nothing to do with FTP:
  72. # ``on_print_start`` runs its whole 3MF hunt inside one ``async_session``, so
  73. # every second a download is allowed is a second a pooled DB connection is held
  74. # (the same coupling behind #2572's cap). 300 s is ~7.5 MB at the floor rate and
  75. # covers the reporter's 15.15 MB / 105 s measurement three times over, because
  76. # the floor is pessimistic by design and a real link is not that slow.
  77. _DOWNLOAD_MAX_TIMEOUT = 300.0
  78. # The archive recovery retry holds no database session while it downloads, so
  79. # a large 3MF may take longer there: ~22 MB at the floor rate.
  80. RECOVERY_DOWNLOAD_MAX_TIMEOUT = 900.0
  81. def _download_extension(size: int | None, base_timeout: float, ceiling: float = _DOWNLOAD_MAX_TIMEOUT) -> float:
  82. """Extra seconds to allow a download the printer says is this big.
  83. Zero when the size is unknown -- no SIZE reply means no transfer got under
  84. way, so the base deadline stands and a printer that is not answering still
  85. fails on schedule. Zero, too, once the base deadline is already the more
  86. generous of the two: this only ever lengthens a deadline.
  87. ``ceiling`` caps the whole deadline. It defaults to the 300 s print start
  88. can afford while it holds a database session; a caller that holds none and
  89. has its own budget (the printer file browser) passes that instead.
  90. """
  91. if not size or size <= 0:
  92. return 0.0
  93. return max(0.0, min(size / _DOWNLOAD_FLOOR_BYTES_PER_SEC, ceiling) - base_timeout)
  94. # How long a download will wait for another one on the same printer to finish
  95. # before going ahead alongside it (#2957). A P1S at print start is already
  96. # serving the print off the same SD card and talking MQTT to the slicer, and a
  97. # reporter watched Bambu Studio itself lose its connection while Bambuddy pulled
  98. # a 12 MB 3MF -- with a second Bambuddy transfer for the same file running at
  99. # the same time. 30 s covers the transfer sizes that actually overlap at print
  100. # start -- the reporter's 5.4 MB 3MF took 25 s off a healthy SD card -- and the
  101. # wait is deliberately no longer, because the gate is contention relief and not
  102. # a correctness control. Whoever cannot have it goes anyway, exactly as every
  103. # download did before this existed: a print must never lose its 3MF to queueing,
  104. # and the caller's own deadline stays untouched either way.
  105. _DOWNLOAD_GATE_WAIT_SECONDS = 30.0
  106. # How long to wait for a cancelled path-walk worker to unwind before releasing
  107. # the printer to the next download. It checks the flag once per 8 KiB chunk, so
  108. # this is one chunk on a link slow enough to have blown the deadline.
  109. _DOWNLOAD_UNWIND_SECONDS = 30.0
  110. def _discard_worker_outcome(worker: asyncio.Future) -> None:
  111. """Read a shielded worker's result so asyncio does not complain about it.
  112. ``asyncio.wait_for`` cancels the shield, not the executor thread behind it,
  113. so the worker future outlives the call and nobody is left to look at what it
  114. raised. An unretrieved exception surfaces later as a loop-level
  115. ``Future exception was never retrieved`` ERROR with a traceback, logged
  116. after the caller has already reported the real failure -- the same class of
  117. noise as #2968, and measurably reproducible with a transport error that
  118. lands just after the cap. The value is genuinely unwanted here; only the
  119. fact that something read it matters.
  120. """
  121. def _read(fut: asyncio.Future) -> None:
  122. if fut.cancelled():
  123. return
  124. exc = fut.exception()
  125. if exc is not None:
  126. logger.debug("FTP path-walk worker failed after its caller gave up: %s", exc)
  127. if worker.done():
  128. _read(worker)
  129. else:
  130. worker.add_done_callback(_read)
  131. # One heavy download at a time per printer. Keyed per event loop for the same
  132. # reason ``_upload_locks`` is: an asyncio.Lock binds to the loop that first
  133. # awaits it, and the test suite runs each case on a fresh loop.
  134. _download_locks: weakref.WeakKeyDictionary[asyncio.AbstractEventLoop, dict[str, asyncio.Lock]] = (
  135. weakref.WeakKeyDictionary()
  136. )
  137. def _download_lock(loop: asyncio.AbstractEventLoop, ip_address: str) -> asyncio.Lock:
  138. per_loop = _download_locks.setdefault(loop, {})
  139. lock = per_loop.get(ip_address)
  140. if lock is None:
  141. lock = asyncio.Lock()
  142. per_loop[ip_address] = lock
  143. return lock
  144. @asynccontextmanager
  145. async def _serialized_download(ip_address: str, what: str, *, enabled: bool = True) -> AsyncIterator[bool]:
  146. """Hold this printer's download gate for the block, or go without it.
  147. Yields whether the gate was actually held, which is what the tests assert on
  148. -- from the outside a serialized download and a concurrent one differ only
  149. in timing. The wait is its own budget rather than a slice of the caller's
  150. transfer deadline: a print-start download that queued behind a thumbnail
  151. would otherwise fail on a timer and leave the print with no archive, which
  152. is a worse outcome than the contention this is here to relieve.
  153. ``enabled=False`` skips the gate entirely, for the callers that documented
  154. themselves as lock-free before this existed -- see ``serialize`` on
  155. :func:`download_file_async`.
  156. """
  157. if not enabled:
  158. yield False
  159. return
  160. loop = asyncio.get_event_loop()
  161. lock = _download_lock(loop, ip_address)
  162. started = loop.time()
  163. held = False
  164. try:
  165. await asyncio.wait_for(lock.acquire(), timeout=_DOWNLOAD_GATE_WAIT_SECONDS)
  166. held = True
  167. waited = loop.time() - started
  168. if waited > 1.0:
  169. logger.info("Waited %.1fs for printer %s to finish its other download before %s", waited, ip_address, what)
  170. except TimeoutError:
  171. logger.warning(
  172. "Printer %s is still busy with another download after %ss — starting %s alongside it",
  173. ip_address,
  174. _DOWNLOAD_GATE_WAIT_SECONDS,
  175. what,
  176. )
  177. try:
  178. yield held
  179. finally:
  180. if held:
  181. lock.release()
  182. # How long to give the worker thread to notice the cancel flag, unwind, and
  183. # delete its partial file. It checks the flag once per CHUNK_SIZE, so on a link
  184. # slow enough to have hit the deadline this is one chunk plus the delete.
  185. _UPLOAD_CANCEL_GRACE = 60.0
  186. class UploadCancelled(Exception):
  187. """Raised inside the upload worker to abort an in-flight transfer.
  188. ``upload_file`` treats any exception from its progress callback as "stop
  189. now": it breaks out of the send loop, deletes the partial file from the
  190. printer, and re-raises. That is the only way to stop a transfer — an
  191. executor thread cannot be cancelled from the event loop, so a bare
  192. ``asyncio.wait_for`` leaves it streaming (see ``upload_file_async``).
  193. """
  194. class DownloadCancelled(Exception):
  195. """Raised in an FTP callback to stop a disk-backed download cooperatively."""
  196. class DownloadLimitExceeded(Exception):
  197. """Raised before an FTP callback writes beyond its caller-supplied limit."""
  198. class DownloadInsufficientSpace(Exception):
  199. """Raised before an FTP callback consumes the application's disk reserve."""
  200. class DownloadDeadlineExceeded(Exception):
  201. """A transfer overran the deadline derived from the size the printer reported.
  202. Never retried, for the reason ``UploadCancelled`` is not (#2529): the
  203. deadline was already stretched to fit the file at a floor rate no working
  204. link falls below, so another attempt would spend another full deadline
  205. reaching the same conclusion -- and ``on_print_start`` spends it holding a
  206. pooled database connection. Raised instead of returning False so
  207. ``with_ftp_retry`` can tell this apart from an ordinary failed attempt
  208. (#2957); callers that do not retry see it through their existing handlers,
  209. which is why the archive flow advances to its next candidate path.
  210. """
  211. def _parse_list_mtime(month: str, day: str, time_or_year: str, *, now_utc: datetime | None = None) -> datetime | None:
  212. """The time of an FTP LIST entry, naive, in the printer's own basis.
  213. "Nov 30 10:15" carries no year: it is the year the entry is not in the
  214. future in. Printers report UTC (tested X1C/H2D firmware; see
  215. printer_media.match_ipcam_chunks), so "now" is UTC, not the host's local
  216. clock -- on a host behind UTC an evening entry read as a future one and
  217. went a year back (DB-C8). A day of slack keeps firmware that reports its
  218. local time, up to 14 h ahead, in this year too. "Nov 30 2024" has a year
  219. and no time. None when the entry cannot be read; mtime is best-effort.
  220. """
  221. now_utc = now_utc or datetime.now(timezone.utc).replace(tzinfo=None)
  222. try:
  223. if ":" in time_or_year:
  224. mtime = datetime.strptime(f"{month} {day} {now_utc.year} {time_or_year}", "%b %d %Y %H:%M")
  225. if mtime > now_utc + timedelta(days=1):
  226. mtime = mtime.replace(year=now_utc.year - 1)
  227. return mtime
  228. return datetime.strptime(f"{month} {day} {time_or_year}", "%b %d %Y")
  229. except ValueError:
  230. return None
  231. @dataclass(frozen=True)
  232. class FileListResult:
  233. """A directory listing that distinguishes empty from unreachable."""
  234. files: list[dict]
  235. available: bool
  236. # The printer did not answer within the wait: slow, not necessarily gone
  237. # (a large /ipcam on a slow card), so not reported as unavailable (TO-C13).
  238. timed_out: bool = False
  239. # Listings still running, by printer and folder: a refresh joins the one in
  240. # progress instead of starting another thread, which ftplib cannot cancel and
  241. # which would otherwise pile up in the shared FTP pool (TO-C13).
  242. _inflight_listings: dict[tuple[str, str, str], tuple[asyncio.Future, threading.Event]] = {}
  243. class DeleteResult(Enum):
  244. """Outcome of an FTP delete attempt.
  245. Distinguishes "file isn't on the printer" (550, recovery impossible by
  246. retrying) from "delete failed for some other reason" (network, auth,
  247. transient FTP error — worth retrying). The post-print SD-card cleanup in
  248. main.py used to flatten both into ``False`` and log a "may linger" WARNING
  249. on every successful print where the printer self-cleaned its SD card
  250. before our cleanup ran (#1721 reporter's A1).
  251. """
  252. DELETED = "deleted"
  253. NOT_FOUND = "not_found"
  254. FAILED = "failed"
  255. # How long to stop opening FTPS connections to a printer after its TLS
  256. # handshake failed (#2780).
  257. #
  258. # ``WRONG_VERSION_NUMBER`` on port 990 means the printer answered with
  259. # something that is not a TLS record at all, so no path, retry or SSL option
  260. # gets further. Two support bundles show that state lasting for days: one X2D
  261. # served clean FTPS for five days, flipped on 2026-07-19, and then failed every
  262. # single handshake for the next eight (zero successes, 3511 failures).
  263. #
  264. # What it is NOT is a wedged file service, which is what this comment used to
  265. # claim. #2780's reporter power-cycled both affected printers and the state
  266. # survived it, and ``openssl s_client`` against the same port completes a clean
  267. # handshake and returns a valid certificate while Bambuddy is failing. The
  268. # leading theory is now a connection-count refusal — vsFTPd answers one in
  269. # cleartext, which is exactly this error to an implicit-TLS client, and answers
  270. # the global limit by accepting and never speaking, which is the handshake
  271. # timeout we also see. Unproven: confirming it needs a capture taken while a
  272. # printer is in the failing state.
  273. #
  274. # Without a gate every candidate path re-runs the same doomed handshake: the
  275. # 3MF lookup alone walks 6 filename variants x 5 directories x 4 retries, and
  276. # the cover and timelapse scans run their own sweeps on top. That is where
  277. # those thousands of failures come from — one wedged printer, hammered.
  278. #
  279. # Five minutes is short enough that a power-cycled printer is picked up on the
  280. # next print (and any successful connect clears the gate immediately), long
  281. # enough that a wedged one is contacted twice an hour instead of hundreds of
  282. # times a minute.
  283. _HANDSHAKE_COOLOFF_SECONDS = 300.0
  284. # How long to wait for a printer to say something in cleartext on the TLS port.
  285. # The failing case answers immediately -- the banner is the first thing a
  286. # vsFTPd refusal sends -- so this only ever elapses in full when the service has
  287. # gone back to speaking TLS and is waiting for a ClientHello that will not come.
  288. _CLEARTEXT_PROBE_TIMEOUT = 2.0
  289. def _read_cleartext_reply(ip_address: str, port: int) -> str | None:
  290. """Read what a printer answers the TLS port with, when it is not TLS.
  291. ``WRONG_VERSION_NUMBER`` means the peer's first bytes were not a TLS
  292. record -- measured, not inferred: a cleartext ``421`` banner reproduces
  293. that exact error and message, while a genuine version mismatch produces
  294. ``TLSV1_ALERT_PROTOCOL_VERSION`` instead (#2780).
  295. What it does not say is *which* cleartext message, and that is the part
  296. that would identify the fault. OpenSSL has already consumed those bytes by
  297. the time the error surfaces, so this opens one plain connection and reads
  298. them directly. Answering it from the reporter's own printers beats waiting
  299. on a packet capture from the one farm that can take one.
  300. Returns the reply, or None when the printer said nothing readable -- which
  301. is itself informative: a healthy implicit-FTPS service sends nothing until
  302. it has a ClientHello, so silence means the fault had already passed.
  303. """
  304. sock = None
  305. # One budget for connect *and* read. Given a timeout each, a printer that
  306. # is slow to accept would then get the full read window on top of it, and
  307. # the wait this adds to a failed connect would be double what it says.
  308. deadline = time.monotonic() + _CLEARTEXT_PROBE_TIMEOUT
  309. try:
  310. sock = socket.create_connection((ip_address, port), _CLEARTEXT_PROBE_TIMEOUT)
  311. sock.settimeout(max(0.05, deadline - time.monotonic()))
  312. # One read. A refusal is a single short line; anything longer is not
  313. # the thing being looked for, and this must not become a transfer.
  314. raw = sock.recv(256)
  315. except OSError as e:
  316. # Refused or reset is a different fact from "answered in cleartext",
  317. # and worth having in the log rather than flattened into silence.
  318. logger.debug("Cleartext probe of %s:%s could not connect: %s", ip_address, port, e)
  319. return None
  320. finally:
  321. if sock is not None:
  322. try:
  323. sock.close()
  324. except OSError:
  325. pass
  326. if not raw:
  327. return None
  328. # latin-1 cannot fail, and an FTP reply line is ASCII in practice. Control
  329. # characters are stripped so a stray byte cannot mangle the log line.
  330. text = raw.decode("latin-1").strip()
  331. return "".join(c for c in text if c.isprintable()) or None
  332. def _ftp_reply_code(error: BaseException) -> str | None:
  333. """The three-digit reply code an ftplib error carries, if it carries one.
  334. ``ftplib`` puts the server's whole reply line in the exception message, so
  335. the code is the first token: "553 Could not create file." Anything that is
  336. not three digits (an ``OSError``, a library-side message) has no code, and
  337. saying so beats inventing one.
  338. """
  339. head = str(error)[:3]
  340. return head if head.isdigit() else None
  341. class FtpFailureKind(Enum):
  342. """Why an FTP operation failed, at the granularity the client can tell.
  343. ``connect`` and ``upload_file`` already separate every one of these -- each
  344. has its own log line, and 553 even gets a spelled-out list of storage
  345. causes -- and then both returned a bare ``False``. So the dispatch that
  346. reports the failure to the operator had nothing to go on, and used one
  347. string for all of them: "check if SD card is inserted and properly
  348. formatted". #2899's reporter acted on that after a TLS handshake failure
  349. and restarted the printer, which could not have helped: the handshake never
  350. got near the printer's filesystem.
  351. """
  352. COOLOFF = "cooloff" # skipped without contacting the printer (#2780)
  353. HANDSHAKE = "handshake" # port 990 answered with something that is not TLS
  354. AUTH = "auth" # permanent refusal, typically a rejected access code
  355. TIMEOUT = "timeout"
  356. STORAGE = "storage" # 553/552 -- the case the SD-card advice was written for
  357. NOT_FOUND = "not_found" # 550
  358. NETWORK = "network" # socket dropped, or an FTP error with no clearer reading
  359. UNKNOWN = "unknown"
  360. @dataclass(frozen=True)
  361. class FtpFailure:
  362. """What went wrong, kept next to the log line that already said it."""
  363. kind: FtpFailureKind
  364. detail: str
  365. code: str | None = None # FTP reply code where the server gave one
  366. @dataclass
  367. class FtpFailureReport:
  368. """A slot the *caller* owns for the reason its upload failed.
  369. Deliberately not a per-IP dict on the client, the way ``_mode_cache`` and
  370. ``_handshake_blocked_until`` are. Those describe a printer, and are
  371. correct to share. This describes one operation, and a background timelapse
  372. fetch running beside a dispatch would overwrite the dispatch's reason with
  373. its own -- reporting the wrong cause with total confidence, which is the
  374. bug being fixed rather than a new way to hit it (#2899).
  375. """
  376. failure: FtpFailure | None = None
  377. class FileNotOnPrinterError(Exception):
  378. """Raised when a remote FTP path returns 550 (file not found).
  379. 550 means the file does not exist at that path — retrying the same path
  380. will never succeed. Callers use this sentinel with with_ftp_retry's
  381. non_retry_exceptions to immediately move on to the next candidate path
  382. instead of burning the full retry budget (up to 11 × 30s per path) on
  383. a lookup that cannot recover.
  384. """
  385. class ImplicitFTP_TLS(FTP_TLS):
  386. """FTP_TLS subclass for implicit FTPS (port 990) with model-specific SSL handling.
  387. X1C/P1S printers (vsFTPd) require SSL with session reuse on the data channel.
  388. A1/A1 Mini printers have issues with SSL on the data channel entirely and
  389. timeout waiting for transfer completion. Set skip_session_reuse=True for A1
  390. printers to skip SSL on the data channel (control channel remains encrypted).
  391. Optionally caps the SSL context's maximum TLS version to v1.2 (P2S firmware
  392. 01.02.00.00 needs this — see :mod:`ftp_profiles` and #1401).
  393. """
  394. def __init__(self, *args, skip_session_reuse: bool = False, cap_tls_v1_2: bool = False, **kwargs):
  395. super().__init__(*args, **kwargs)
  396. self._sock = None
  397. self.skip_session_reuse = skip_session_reuse
  398. self.ssl_context = ssl.create_default_context()
  399. self.ssl_context.check_hostname = False
  400. self.ssl_context.verify_mode = ssl.CERT_NONE
  401. # ``create_default_context()`` does NOT guarantee a protocol floor: it
  402. # leaves ``minimum_version`` at ``MINIMUM_SUPPORTED``, and what that
  403. # resolves to is a property of the OpenSSL build, not of this code.
  404. # Measured on identical OpenSSL 3.5.6: python:3.13-slim-trixie (our
  405. # Docker base) reports TLSv1_2, a bare-metal venv reports
  406. # MINIMUM_SUPPORTED. Docker users have therefore always been floored at
  407. # 1.2 — every Bambu model is reachable under that floor — while
  408. # bare-metal and appliance installs could silently negotiate TLS 1.0.
  409. # State the floor rather than inheriting it.
  410. self.ssl_context.minimum_version = ssl.TLSVersion.TLSv1_2
  411. if cap_tls_v1_2:
  412. # With the floor above this pins the connection to exactly TLS 1.2.
  413. self.ssl_context.maximum_version = ssl.TLSVersion.TLSv1_2
  414. def connect(self, host="", port=990, timeout=-999, source_address=None):
  415. """Connect to host, wrapping socket in TLS immediately (implicit FTPS)."""
  416. if host:
  417. self.host = host
  418. if port > 0:
  419. self.port = port
  420. if timeout != -999:
  421. self.timeout = timeout
  422. if source_address:
  423. self.source_address = source_address
  424. # Create and wrap socket immediately (implicit TLS)
  425. self.sock = socket.create_connection((self.host, self.port), self.timeout, source_address=self.source_address)
  426. self.sock = self.ssl_context.wrap_socket(self.sock, server_hostname=self.host)
  427. self.af = self.sock.family
  428. self.file = self.sock.makefile("r", encoding=self.encoding)
  429. self.welcome = self.getresp()
  430. return self.welcome
  431. def ntransfercmd(self, cmd, rest=None):
  432. """Override to wrap data connection in SSL for X1C/P1S only.
  433. X1C/P1S printers (vsFTPd) require SSL session reuse on the data channel.
  434. A1/A1 Mini printers have issues with SSL on the data channel entirely -
  435. they timeout waiting for the transfer completion response. For A1, we
  436. skip SSL wrapping on the data channel (control channel remains encrypted).
  437. """
  438. conn, size = FTP.ntransfercmd(self, cmd, rest)
  439. if self._prot_p and not self.skip_session_reuse:
  440. # X1C/P1S: Wrap data channel with SSL session reuse (required by vsFTPd)
  441. conn = self.ssl_context.wrap_socket(
  442. conn,
  443. server_hostname=self.host,
  444. session=self.sock.session,
  445. )
  446. # A1/A1 Mini (skip_session_reuse=True): Don't wrap data channel in SSL
  447. # The control channel remains encrypted via implicit FTPS
  448. return conn, size
  449. class BambuFTPClient:
  450. """FTP client for retrieving files from Bambu Lab printers."""
  451. FTP_PORT = 990
  452. # Default timeout in seconds (increased for A1 printers)
  453. DEFAULT_TIMEOUT = 30
  454. # Models that may need SSL mode fallback (try prot_p first, fall back to prot_c)
  455. # These models have varying FTP SSL behavior depending on firmware version
  456. A1_MODELS = ("A1", "A1 Mini")
  457. # Chunk size for manual upload transfer (64KB)
  458. # Smaller chunks provide smoother progress reporting — at typical printer FTP
  459. # speeds (~50-100KB/s) this gives a progress update roughly every second.
  460. CHUNK_SIZE = 64 * 1024
  461. # Cache for working FTP modes per printer IP
  462. # Maps IP -> "prot_p" or "prot_c"
  463. _mode_cache: dict[str, str] = {}
  464. # Printers whose FTPS handshake just failed, mapped to the monotonic time
  465. # their cool-off expires. See ``_HANDSHAKE_COOLOFF_SECONDS``.
  466. _handshake_blocked_until: dict[str, float] = {}
  467. # Which cool-off deadline each printer's "not attempted" warning was last
  468. # logged for, so the warning is said once per cool-off. See ``connect``.
  469. _handshake_skip_logged: dict[str, float] = {}
  470. def __init__(
  471. self,
  472. ip_address: str,
  473. access_code: str,
  474. timeout: float | None = None,
  475. printer_model: str | None = None,
  476. force_prot_c: bool = False,
  477. respect_handshake_cooloff: bool = True,
  478. records_handshake_cooloff: bool = True,
  479. ):
  480. """Set ``respect_handshake_cooloff=False`` for bounded, user-initiated work.
  481. The cool-off exists to stop an unbounded sweep re-running one doomed
  482. handshake a hundred times over (#2780). Dispatching a print is not
  483. that: it is one delete plus at most four upload attempts, with someone
  484. waiting on the result. Sharing the sweep's gate cost those attempts
  485. their whole retry budget, and failed every further job queued for that
  486. printer for the rest of the 300s window (#2898).
  487. Leave it at the default everywhere else. Opting out is only defensible
  488. because the caller's own connection count is bounded and small.
  489. ``records_handshake_cooloff=False`` keeps a failed handshake on this
  490. client from opening the cool-off for everyone: for a side check whose
  491. refusal says nothing about the printer's file service at large.
  492. """
  493. self.ip_address = ip_address
  494. self.access_code = access_code
  495. self.timeout = timeout if timeout is not None else self.DEFAULT_TIMEOUT
  496. self.printer_model = printer_model
  497. self.force_prot_c = force_prot_c
  498. self.respect_handshake_cooloff = respect_handshake_cooloff
  499. self.records_handshake_cooloff = records_handshake_cooloff
  500. # Why the last connect/upload on this client failed, for a caller that
  501. # only gets a bool back (#2899). Per instance, so it describes one
  502. # operation and cannot be overwritten by work against another printer.
  503. self.last_failure: FtpFailure | None = None
  504. self._ftp: ImplicitFTP_TLS | None = None
  505. # When the control socket to the printer was opened, so the close log
  506. # can say how long the session was held (#3009).
  507. self._connected_at: float | None = None
  508. def _is_a1_model(self) -> bool:
  509. """Check if this is an A1 series printer."""
  510. if not self.printer_model:
  511. return False
  512. return self.printer_model in self.A1_MODELS
  513. def _get_cached_mode(self) -> str | None:
  514. """Get cached FTP mode for this printer."""
  515. return self._mode_cache.get(self.ip_address)
  516. @classmethod
  517. def cache_mode(cls, ip_address: str, mode: str):
  518. """Cache the working FTP mode for a printer."""
  519. cls._mode_cache[ip_address] = mode
  520. logger.info("FTP mode cached for %s: %s", ip_address, mode)
  521. def _should_use_prot_c(self) -> bool:
  522. """Determine if we should use prot_c (clear) mode."""
  523. # If explicitly forced, use prot_c
  524. if self.force_prot_c:
  525. return True
  526. # Check cache first
  527. cached = self._get_cached_mode()
  528. if cached:
  529. return cached == "prot_c"
  530. # Default: try prot_p first (will fall back if needed)
  531. return False
  532. @classmethod
  533. def handshake_blocked(cls, ip_address: str) -> bool:
  534. """True while *ip_address* is inside its post-handshake-failure cool-off.
  535. Public so a caller sweeping many candidate paths can stop after the
  536. first one rather than walking the rest against a printer that cannot
  537. complete a TLS handshake (#2780).
  538. """
  539. deadline = cls._handshake_blocked_until.get(ip_address)
  540. if deadline is None:
  541. return False
  542. if time.monotonic() >= deadline:
  543. # Drop it on the way past rather than leaving an entry per printer
  544. # this process has ever failed against.
  545. del cls._handshake_blocked_until[ip_address]
  546. cls._handshake_skip_logged.pop(ip_address, None)
  547. return False
  548. return True
  549. def connect(self) -> bool:
  550. """Connect to the printer FTP server (implicit FTPS on port 990).
  551. Returns False without touching the network while the printer is inside
  552. the cool-off a previous TLS handshake failure opened (#2780) -- unless
  553. this client was built with ``respect_handshake_cooloff=False``.
  554. """
  555. self.last_failure = None
  556. if self.respect_handshake_cooloff and self.handshake_blocked(self.ip_address):
  557. # WARNING, not DEBUG. This is the one connect() failure path that
  558. # reported without its cause, so at default log level four
  559. # reason-free "FTP connection failed" lines two seconds apart gave
  560. # no hint that nothing had been sent (#2898). Every caller reaching
  561. # here is already gated by handshake_blocked() at its own sweep
  562. # boundary, so this costs about one line per print, not a flood.
  563. deadline = self._handshake_blocked_until.get(self.ip_address)
  564. remaining = max(0.0, deadline - time.monotonic()) if deadline is not None else 0.0
  565. if deadline is not None and self._handshake_skip_logged.get(self.ip_address) != deadline:
  566. self._handshake_skip_logged[self.ip_address] = deadline
  567. logger.warning(
  568. "FTP connect to %s not attempted: its FTPS handshake failed recently and it is "
  569. "cooling off for another %.0fs. Nothing was sent to the printer.",
  570. self.ip_address,
  571. remaining,
  572. )
  573. else:
  574. # Said once already for this cool-off. Repeating it per candidate
  575. # path is the log flood #2780 set out to stop -- a download-zip
  576. # of 200 files would print the same sentence 200 times.
  577. logger.debug(
  578. "FTP connect to %s skipped: still cooling off for another %.0fs",
  579. self.ip_address,
  580. remaining,
  581. )
  582. self.last_failure = FtpFailure(
  583. FtpFailureKind.COOLOFF,
  584. f"cooling off for another {remaining:.0f}s after a recent FTPS handshake failure",
  585. )
  586. return False
  587. try:
  588. use_prot_c = self._should_use_prot_c()
  589. from backend.app.services.ftp_profiles import get_ftp_profile
  590. profile = get_ftp_profile(self.printer_model)
  591. logger.debug(
  592. f"FTP connecting to {self.ip_address}:{self.FTP_PORT} "
  593. f"(timeout={self.timeout}s, model={self.printer_model}, prot_c={use_prot_c}, "
  594. f"cap_tls_v1_2={profile.cap_tls_v1_2})"
  595. )
  596. self._ftp = ImplicitFTP_TLS(
  597. skip_session_reuse=use_prot_c,
  598. cap_tls_v1_2=profile.cap_tls_v1_2,
  599. )
  600. self._ftp.connect(self.ip_address, self.FTP_PORT, timeout=self.timeout)
  601. # Stamped here rather than after login: the socket exists from this
  602. # point on, and a session that dies during login is exactly the one
  603. # whose lifetime someone reading the log wants accounted for.
  604. self._connected_at = time.monotonic()
  605. logger.debug("FTP connected, logging in as bblp")
  606. self._ftp.login("bblp", self.access_code)
  607. if use_prot_c:
  608. # Use clear (unencrypted) data channel
  609. logger.debug("FTP logged in, setting prot_c (clear) and passive mode")
  610. self._ftp.prot_c()
  611. else:
  612. # Use protected (encrypted) data channel with session reuse
  613. logger.debug("FTP logged in, setting prot_p (protected) and passive mode")
  614. self._ftp.prot_p()
  615. self._ftp.set_pasv(True)
  616. # Log welcome message for debugging
  617. if hasattr(self._ftp, "welcome") and self._ftp.welcome:
  618. logger.debug("FTP server welcome: %s", self._ftp.welcome)
  619. logger.info(
  620. f"FTP connected successfully to {self.ip_address} (model={self.printer_model}, prot_c={use_prot_c})"
  621. )
  622. return True
  623. except ftplib.error_perm as e:
  624. logger.warning("FTP connection permission error to %s: %s", self.ip_address, e)
  625. self.last_failure = FtpFailure(FtpFailureKind.AUTH, str(e), _ftp_reply_code(e))
  626. self._abandon_connection("login rejected")
  627. return False
  628. except TimeoutError as e:
  629. logger.warning("FTP connection timed out to %s: %s", self.ip_address, e)
  630. self.last_failure = FtpFailure(FtpFailureKind.TIMEOUT, str(e))
  631. self._abandon_connection("connect timed out")
  632. return False
  633. except ssl.SSLError as e:
  634. # Not a transient failure and not something another path or another
  635. # retry can route around: the printer's file service answered port
  636. # 990 with something that isn't TLS. Say so once and stop knocking
  637. # for a while (#2780).
  638. #
  639. # Deliberately no advice about what to do. This message used to
  640. # tell the operator to restart the printer; #2780's reporter did
  641. # that twice, to no effect, and a single manual connect to the
  642. # same printer completes a clean handshake. We do not yet know the
  643. # trigger, so stating the observation and stopping there beats
  644. # sending people to do the one thing already known not to work.
  645. logger.warning(
  646. "FTP SSL error connecting to %s: %s — the printer answered port %s with something "
  647. "that is not TLS, so print files, covers and timelapses cannot be fetched from it.%s",
  648. self.ip_address,
  649. e,
  650. self.FTP_PORT,
  651. f" Pausing FTP to this printer for {_HANDSHAKE_COOLOFF_SECONDS:.0f}s."
  652. if self.records_handshake_cooloff
  653. else "",
  654. )
  655. # Close the dead socket before asking this printer for anything
  656. # else. The probe below opens a second connection, and the leading
  657. # theory for this failure is a printer out of connection slots --
  658. # holding a failed handshake open across that is the exact thing
  659. # #2780's cleanup was added to stop. Idempotent, so the call that
  660. # used to sit at the end of this branch simply moved up.
  661. self._abandon_connection("TLS handshake failed")
  662. # Ask the printer what it actually said, once per cool-off window.
  663. # Checked before the deadline below is written, so a live entry here
  664. # means an earlier failure already opened this window and already
  665. # asked -- which keeps a dispatch that ignores the cool-off from
  666. # probing on each of its four attempts.
  667. detail = str(e)
  668. if getattr(e, "reason", None) == "WRONG_VERSION_NUMBER" and not self.handshake_blocked(self.ip_address):
  669. reply = _read_cleartext_reply(self.ip_address, self.FTP_PORT)
  670. if reply:
  671. logger.warning(
  672. "Printer %s answered port %s in cleartext with: %s — that is what the TLS "
  673. "handshake read as a malformed record. Please include this line if you report it.",
  674. self.ip_address,
  675. self.FTP_PORT,
  676. reply,
  677. )
  678. detail = f"{e} (printer answered in cleartext: {reply})"
  679. else:
  680. logger.warning(
  681. "Printer %s sent nothing readable in cleartext on port %s, so its file service "
  682. "was speaking TLS again by the time we asked — the refusal was momentary.",
  683. self.ip_address,
  684. self.FTP_PORT,
  685. )
  686. if self.records_handshake_cooloff:
  687. self._handshake_blocked_until[self.ip_address] = time.monotonic() + _HANDSHAKE_COOLOFF_SECONDS
  688. self.last_failure = FtpFailure(FtpFailureKind.HANDSHAKE, detail)
  689. return False
  690. except (OSError, ftplib.Error) as e:
  691. logger.warning("FTP connection failed to %s: %s (type: %s)", self.ip_address, e, type(e).__name__)
  692. self.last_failure = FtpFailure(FtpFailureKind.NETWORK, str(e), _ftp_reply_code(e))
  693. self._abandon_connection("connect failed")
  694. return False
  695. def _held_for(self) -> str:
  696. """How long the control socket has been open, for the close log.
  697. "unknown" when :meth:`connect` never got as far as opening one -- the
  698. cool-off skip and a DNS/refused failure both land in
  699. :meth:`_abandon_connection` without a socket ever existing.
  700. """
  701. if self._connected_at is None:
  702. return "unknown"
  703. return f"{time.monotonic() - self._connected_at:.1f}s"
  704. def _abandon_connection(self, reason: str = "connection never became usable") -> None:
  705. """Drop a connection that never became usable, closing its socket.
  706. Every failure path in :meth:`connect` used to clear ``self._ftp`` and
  707. nothing else, leaving a connected socket for the garbage collector.
  708. That is survivable once; it is not survivable at this volume. A single
  709. print used to walk ~110 candidate paths, so a printer refusing FTPS
  710. got ~110 sockets opened and abandoned in a couple of minutes, and one
  711. support bundle recorded 1813 of them in a day (#2780). If the refusal
  712. is the printer running out of connection slots -- which fits the
  713. evidence better than a wedged service, since a single manual connect
  714. to the same printer succeeds -- then abandoning sockets is not just
  715. untidy, it is what keeps the printer refusing.
  716. Uses ``close()`` rather than ``quit()``: QUIT is a command, and there
  717. is no working control channel to send it on.
  718. """
  719. ftp = self._ftp
  720. self._ftp = None
  721. held = self._held_for()
  722. self._connected_at = None
  723. if ftp is None:
  724. return
  725. try:
  726. ftp.close()
  727. except (OSError, ftplib.Error, EOFError):
  728. pass # Best-effort; the socket may already be gone
  729. # See the note in ``disconnect``: every session that opens a socket
  730. # says how it closed, so the log carries matched pairs (#3009).
  731. logger.debug(
  732. "FTP session to %s closed without QUIT (%s), held %s",
  733. self.ip_address,
  734. reason,
  735. held,
  736. )
  737. def disconnect(self):
  738. """Disconnect from the FTP server."""
  739. if self._ftp:
  740. held = self._held_for()
  741. try:
  742. self._ftp.quit()
  743. except (OSError, ftplib.Error, EOFError) as e:
  744. # ``quit()`` sends QUIT and only then closes; when the send
  745. # raises, ftplib never reaches its own close and the socket
  746. # stays open. Close it here rather than leaving it to the GC.
  747. self._abandon_connection(f"QUIT failed: {e}")
  748. else:
  749. # One line per session, at DEBUG. Neither this method nor
  750. # ``_abandon_connection`` used to log anything at any level, so
  751. # a session closed cleanly and a socket genuinely left open
  752. # produced identical logs -- nothing. #3009 read that silence
  753. # after a print as proof the connections were never closed, and
  754. # nothing in the log could have shown otherwise. Now every
  755. # connect has a matching close, so the next person can settle it
  756. # from a support bundle instead of by inference.
  757. logger.debug(
  758. "FTP session to %s closed after QUIT, held %s",
  759. self.ip_address,
  760. held,
  761. )
  762. self._ftp = None
  763. self._connected_at = None
  764. def list_files(self, path: str = "/", *, raise_on_error: bool = False) -> list[dict]:
  765. """List files in a directory."""
  766. if not self._ftp:
  767. return []
  768. files = []
  769. try:
  770. self._ftp.cwd(path)
  771. items = []
  772. self._ftp.retrlines("LIST", items.append)
  773. for item in items:
  774. parts = item.split()
  775. if len(parts) >= 9:
  776. name = " ".join(parts[8:])
  777. is_dir = item.startswith("d")
  778. size = int(parts[4]) if not is_dir else 0
  779. # Parse modification time from FTP listing
  780. # Format: "Nov 30 10:15" or "Nov 30 2024"
  781. mtime = _parse_list_mtime(parts[5], parts[6], parts[7])
  782. file_entry = {
  783. "name": name,
  784. "is_directory": is_dir,
  785. "size": size,
  786. "path": f"{path.rstrip('/')}/{name}",
  787. }
  788. if mtime:
  789. file_entry["mtime"] = mtime
  790. files.append(file_entry)
  791. logger.debug("Listed %s files in %s", len(files), path)
  792. except (OSError, ftplib.Error) as e:
  793. logger.info("FTP list_files failed for %s: %s", path, e)
  794. if raise_on_error:
  795. raise
  796. return files
  797. def download_file(
  798. self,
  799. remote_path: str,
  800. expected_size: int | None = None,
  801. cancel_event: threading.Event | None = None,
  802. size_callback: Callable[[int], None] | None = None,
  803. report_missing: bool = False,
  804. ) -> bytes | None:
  805. """Download a file from the printer.
  806. ``expected_size`` is the byte count the directory listing reported for
  807. this file. Pass it whenever a short read must not be mistaken for a
  808. successful download: an FTPS data connection that closes early does
  809. not always raise, so ``retrbinary`` can hand back a partial buffer that
  810. looks like a perfectly good file to everything downstream. That is
  811. tolerable when the printer keeps its copy, and not tolerable when the
  812. caller goes on to delete the source (#2704).
  813. A zero-byte result is always treated as a failure, matching
  814. :meth:`download_to_file` — no caller has a use for an empty file.
  815. ``size_callback`` is handed the size the printer reports (SIZE) before
  816. the transfer starts, for a caller that sets its deadline from it.
  817. ``report_missing`` raises :class:`FileNotOnPrinterError` when RETR is
  818. answered 550, as :meth:`download_to_file` does, instead of returning
  819. None: every other caller reads a failed download as None.
  820. """
  821. if not self._ftp:
  822. return None
  823. if size_callback is not None:
  824. # Only a hint for the deadline: a SIZE refusal (missing command, a
  825. # file still being written) is left to RETR to judge.
  826. try:
  827. server_size = self._ftp.size(remote_path)
  828. except (OSError, ftplib.Error):
  829. server_size = None
  830. if server_size is not None and server_size > 0:
  831. size_callback(server_size)
  832. buffer = BytesIO()
  833. def _write(block: bytes) -> None:
  834. # Checked as data arrives: ``download_file_bytes_async`` sets it at
  835. # its deadline, so the transfer stops instead of running on in its
  836. # worker thread beside whatever the caller does next.
  837. if cancel_event is not None and cancel_event.is_set():
  838. raise DownloadCancelled(remote_path)
  839. buffer.write(block)
  840. try:
  841. self._ftp.retrbinary(f"RETR {remote_path}", _write)
  842. data = buffer.getvalue()
  843. except DownloadCancelled:
  844. raise
  845. except ftplib.error_perm as exc:
  846. if report_missing and str(exc).startswith("550"):
  847. raise FileNotOnPrinterError(f"{remote_path}: {exc}") from exc
  848. return None
  849. except (OSError, ftplib.Error):
  850. return None
  851. if not data:
  852. logger.warning("FTP download returned 0 bytes for %s", remote_path)
  853. return None
  854. if expected_size is not None and len(data) != expected_size:
  855. logger.warning(
  856. "FTP download of %s is short: got %s bytes, listing reported %s — treating as failed",
  857. remote_path,
  858. len(data),
  859. expected_size,
  860. )
  861. return None
  862. return data
  863. def download_to_file(
  864. self,
  865. remote_path: str,
  866. local_path: Path,
  867. *,
  868. expected_size: int | None = None,
  869. max_bytes: int | None = None,
  870. cancel_event: threading.Event | None = None,
  871. min_free_bytes: int | None = None,
  872. size_callback: Callable[[int], None] | None = None,
  873. ) -> bool:
  874. """Download a file with cooperative cancellation and byte bounds.
  875. ``size_callback`` is handed the size the printer reported for this file,
  876. once, before the transfer starts. The async wrappers use it to grow a
  877. whole-transfer deadline that was set before anyone knew how big the file
  878. was (#2957); it must not raise.
  879. """
  880. if not self._ftp:
  881. logger.warning("download_to_file called but FTP not connected")
  882. return False
  883. try:
  884. local_path.parent.mkdir(parents=True, exist_ok=True)
  885. # SIZE is the printer's own current view of the file and is more
  886. # trustworthy than a browser round-tripped listing hint. Some
  887. # firmware does not implement SIZE, so retain expected_size as a
  888. # compatibility fallback when the command is unavailable.
  889. try:
  890. server_size = self._ftp.size(remote_path)
  891. except (OSError, ftplib.Error):
  892. server_size = None
  893. authoritative_size = server_size if server_size is not None and server_size >= 0 else expected_size
  894. if max_bytes is not None and authoritative_size is not None and authoritative_size > max_bytes:
  895. raise DownloadLimitExceeded(remote_path)
  896. if min_free_bytes is not None and authoritative_size is not None:
  897. if shutil.disk_usage(local_path.parent).free < min_free_bytes + authoritative_size:
  898. raise DownloadInsufficientSpace(remote_path)
  899. if size_callback is not None and authoritative_size is not None and authoritative_size > 0:
  900. size_callback(authoritative_size)
  901. with open(local_path, "wb") as f:
  902. written = 0
  903. # retrbinary hands over 8 KiB at a time, so checking the volume
  904. # on every callback is ~30k statvfs calls per 250 MB chunk for a
  905. # reserve measured in hundreds of megabytes. Sampling every few
  906. # MB cannot overshoot it by more than one interval.
  907. free_check_interval = 8 * 1024 * 1024
  908. next_free_check = 0
  909. def _write(chunk: bytes) -> None:
  910. nonlocal written, next_free_check
  911. if cancel_event is not None and cancel_event.is_set():
  912. raise DownloadCancelled(remote_path)
  913. if max_bytes is not None and written + len(chunk) > max_bytes:
  914. raise DownloadLimitExceeded(remote_path)
  915. if min_free_bytes is not None and written >= next_free_check:
  916. next_free_check = written + free_check_interval
  917. if shutil.disk_usage(local_path.parent).free < min_free_bytes + free_check_interval:
  918. raise DownloadInsufficientSpace(remote_path)
  919. f.write(chunk)
  920. written += len(chunk)
  921. self._ftp.retrbinary(f"RETR {remote_path}", _write)
  922. f.flush()
  923. os.fsync(f.fileno())
  924. file_size = local_path.stat().st_size if local_path.exists() else 0
  925. if file_size == 0:
  926. logger.warning("FTP download returned 0 bytes for %s", remote_path)
  927. if local_path.exists():
  928. local_path.unlink()
  929. return False
  930. if authoritative_size is not None and file_size != authoritative_size:
  931. logger.warning(
  932. "FTP download of %s is short: got %s bytes, listing reported %s — treating as failed",
  933. remote_path,
  934. file_size,
  935. authoritative_size,
  936. )
  937. local_path.unlink(missing_ok=True)
  938. return False
  939. logger.info("Successfully downloaded %s to %s (%s bytes)", remote_path, local_path, file_size)
  940. return True
  941. except (OSError, ftplib.Error, DownloadCancelled, DownloadLimitExceeded, DownloadInsufficientSpace) as e:
  942. # Clean up partial file if it exists
  943. if local_path.exists():
  944. try:
  945. local_path.unlink()
  946. except OSError:
  947. pass # Best-effort partial file cleanup; not critical if removal fails
  948. # 550 means the file is not at this path. Surface as a sentinel so
  949. # with_ftp_retry can abandon this path immediately and the caller
  950. # can advance to the next candidate instead of retrying 11× at
  951. # 30s intervals (the pattern that cost #972's reporter ~48min).
  952. if isinstance(e, (DownloadCancelled, DownloadLimitExceeded, DownloadInsufficientSpace)):
  953. raise
  954. if isinstance(e, ftplib.error_perm) and str(e).startswith("550"):
  955. logger.info("FTP download failed for %s: %s (not on printer)", remote_path, e)
  956. raise FileNotOnPrinterError(f"{remote_path}: {e}") from e
  957. # Log at INFO level so we can see failures in normal logs
  958. logger.info("FTP download failed for %s: %s", remote_path, e)
  959. return False
  960. def diagnose_storage(self) -> dict:
  961. """Run storage diagnostics and return results. For debugging upload issues."""
  962. results = {
  963. "connected": self._ftp is not None,
  964. "can_list_root": False,
  965. "root_files": [],
  966. "can_list_cache": False,
  967. "storage_info": None,
  968. "pwd": None,
  969. "errors": [],
  970. }
  971. if not self._ftp:
  972. results["errors"].append("FTP not connected")
  973. return results
  974. # Try to get current directory
  975. try:
  976. results["pwd"] = self._ftp.pwd()
  977. logger.debug("FTP current directory: %s", results["pwd"])
  978. except (OSError, ftplib.Error) as e:
  979. results["errors"].append(f"PWD failed: {e}")
  980. logger.debug("FTP PWD failed: %s", e)
  981. # Try to list root directory
  982. try:
  983. self._ftp.cwd("/")
  984. items = []
  985. self._ftp.retrlines("LIST", items.append)
  986. results["can_list_root"] = True
  987. results["root_files"] = items[:10] # First 10 entries
  988. logger.debug("FTP root listing (%s items): %s", len(items), items[:5])
  989. except (OSError, ftplib.Error) as e:
  990. results["errors"].append(f"LIST / failed: {e}")
  991. logger.debug("FTP LIST / failed: %s", e)
  992. # Try to list /cache (should exist on all printers)
  993. try:
  994. self._ftp.cwd("/cache")
  995. items = []
  996. self._ftp.retrlines("LIST", items.append)
  997. results["can_list_cache"] = True
  998. logger.debug("FTP /cache listing: %s items", len(items))
  999. except (OSError, ftplib.Error) as e:
  1000. results["errors"].append(f"LIST /cache failed: {e}")
  1001. logger.debug("FTP LIST /cache failed: %s", e)
  1002. # Try to get storage info
  1003. try:
  1004. results["storage_info"] = self.get_storage_info()
  1005. logger.debug("FTP storage info: %s", results["storage_info"])
  1006. except (OSError, ftplib.Error) as e:
  1007. results["errors"].append(f"Storage info failed: {e}")
  1008. return results
  1009. def upload_file(
  1010. self,
  1011. local_path: Path,
  1012. remote_path: str,
  1013. progress_callback: Callable[[int, int], None] | None = None,
  1014. ) -> bool:
  1015. """Upload a file to the printer with optional progress callback."""
  1016. self.last_failure = None
  1017. if not self._ftp:
  1018. logger.warning("upload_file: FTP not connected")
  1019. self.last_failure = FtpFailure(FtpFailureKind.UNKNOWN, "no FTP connection")
  1020. return False
  1021. try:
  1022. file_size = local_path.stat().st_size if local_path.exists() else 0
  1023. logger.info("FTP uploading %s (%s bytes) to %s", local_path, file_size, remote_path)
  1024. uploaded = 0
  1025. callback_exception: Exception | None = None
  1026. # Use manual transfer instead of storbinary() for A1 compatibility
  1027. # A1 printers have issues with storbinary's voidresp() hanging after transfer
  1028. with open(local_path, "rb") as f:
  1029. logger.debug("FTP STOR command starting for %s", remote_path)
  1030. t0 = time.monotonic()
  1031. conn = self._ftp.transfercmd(f"STOR {remote_path}")
  1032. logger.info(
  1033. "FTP data channel ready in %.1fs (PASV + TLS handshake)",
  1034. time.monotonic() - t0,
  1035. )
  1036. # Set explicit socket options for reliable transfer
  1037. conn.setblocking(True)
  1038. conn.settimeout(self.timeout)
  1039. try:
  1040. while True:
  1041. chunk = f.read(self.CHUNK_SIZE)
  1042. if not chunk:
  1043. logger.debug("FTP upload: final chunk reached")
  1044. break
  1045. conn.sendall(chunk)
  1046. uploaded += len(chunk)
  1047. logger.debug("FTP upload progress: %s/%s bytes", uploaded, file_size)
  1048. if progress_callback:
  1049. try:
  1050. progress_callback(uploaded, file_size)
  1051. except Exception as e:
  1052. callback_exception = e
  1053. logger.info(
  1054. "FTP upload callback requested stop for %s at %s/%s bytes: %s",
  1055. remote_path,
  1056. uploaded,
  1057. file_size,
  1058. e,
  1059. )
  1060. break
  1061. except OSError as e:
  1062. logger.error("FTP connection lost during upload: %s", e)
  1063. raise
  1064. finally:
  1065. try:
  1066. conn.close()
  1067. except OSError:
  1068. pass
  1069. # Wait for the server's 226 "Transfer complete" response to confirm
  1070. # the file has been flushed to the SD card. Without this, the printer
  1071. # may try to read an incomplete file when the print command is sent,
  1072. # causing 0500-C010 "MicroSD Card read/write exception" errors.
  1073. # See: https://bugs.python.org/issue25458 (ftplib response desync)
  1074. try:
  1075. old_timeout = self._ftp.sock.gettimeout()
  1076. # Use a generous timeout — H2D printers can take 30+ seconds
  1077. # to send the 226 after the data channel closes.
  1078. self._ftp.sock.settimeout(max(self.timeout, 60))
  1079. try:
  1080. resp = self._ftp.voidresp()
  1081. logger.info("FTP STOR confirmed for %s: %s", remote_path, resp.strip())
  1082. finally:
  1083. self._ftp.sock.settimeout(old_timeout)
  1084. except ftplib.Error as e:
  1085. # Some P2S firmware revisions return ftplib.Error (e.g. 426
  1086. # "Failure reading network stream") on voidresp() even when
  1087. # the file landed fully on the SD card — the TLS data
  1088. # channel close races the 226 confirmation (#1417 follow-up).
  1089. # Verify via SIZE: if the server-side file size matches what
  1090. # we just uploaded, the file is intact and we proceed with
  1091. # a warning. If not — or SIZE itself fails — the transfer
  1092. # was genuinely truncated and we must fail so the print
  1093. # command doesn't go out for a partial 3MF (the original
  1094. # reason this catch was tightened in the previous round).
  1095. try:
  1096. server_size = self._ftp.size(remote_path)
  1097. except (OSError, ftplib.Error) as size_err:
  1098. logger.debug("Post-error SIZE check failed: %s", size_err)
  1099. server_size = None
  1100. if server_size is not None and server_size == file_size:
  1101. # INFO, not WARNING: a 426 whose bytes verify is the normal
  1102. # way Bambu FTPS ends a transfer, not a fault. It fired 54
  1103. # times in one support bundle and every one was followed by
  1104. # a completed upload, which buried the 26 handshake failures
  1105. # in the same log that actually cost the user two prints
  1106. # (#2987). The unverified branch below is still an error.
  1107. logger.info(
  1108. "FTP STOR returned %s for %s but file is intact on the "
  1109. "printer (%s bytes match) — proceeding: %s",
  1110. type(e).__name__,
  1111. remote_path,
  1112. file_size,
  1113. e,
  1114. )
  1115. else:
  1116. logger.error(
  1117. "FTP STOR rejected by printer for %s: %s (%s); server size=%s expected=%s",
  1118. remote_path,
  1119. e,
  1120. type(e).__name__,
  1121. server_size,
  1122. file_size,
  1123. )
  1124. raise
  1125. except Exception as e:
  1126. # Timeout or socket-level error reading 226 — the data was sent
  1127. # on our side and the printer may still have written the file.
  1128. # H2D can take 30+ seconds to send 226 after the data channel
  1129. # closes, so we proceed with a warning rather than failing here.
  1130. logger.warning(
  1131. "FTP STOR confirmation not received for %s (proceeding): %s (%s)",
  1132. remote_path,
  1133. e,
  1134. type(e).__name__,
  1135. )
  1136. if callback_exception is None:
  1137. # A cancelled upload is deleted below; its size says nothing.
  1138. self._check_unconfirmed_upload(remote_path, file_size)
  1139. if callback_exception is not None:
  1140. cleanup_result: DeleteResult = DeleteResult.FAILED
  1141. try:
  1142. cleanup_result = self.delete_file(remote_path)
  1143. except Exception as cleanup_error:
  1144. logger.warning("FTP cancel cleanup failed for %s: %s", remote_path, cleanup_error)
  1145. # NOT_FOUND is success here — the partial file is gone (printer
  1146. # may have already swept on cancel), which is the goal.
  1147. if cleanup_result in (DeleteResult.DELETED, DeleteResult.NOT_FOUND):
  1148. logger.info("FTP cancel cleanup succeeded for %s (%s)", remote_path, cleanup_result.value)
  1149. raise callback_exception
  1150. raise RuntimeError(
  1151. f"Upload cancelled but failed to remove partial file {remote_path} from printer"
  1152. ) from callback_exception
  1153. elapsed = time.monotonic() - t0
  1154. speed_kbs = (file_size / 1024) / elapsed if elapsed > 0 else 0
  1155. logger.info(
  1156. "FTP upload complete: %s (%s bytes in %.1fs, %.0f KB/s)",
  1157. remote_path,
  1158. file_size,
  1159. elapsed,
  1160. speed_kbs,
  1161. )
  1162. return True
  1163. except ftplib.error_perm as e:
  1164. # Permanent FTP error (4xx/5xx response)
  1165. error_code = str(e)[:3] if str(e) else "unknown"
  1166. logger.error("FTP upload failed for %s: %s (error code: %s)", remote_path, e, error_code)
  1167. # 553 and 552 are the printer telling us about its own storage --
  1168. # the one case where advice about the card is worth giving, and
  1169. # the case the dispatch's blanket SD-card message was written for
  1170. # before it was applied to every failure alike (#2899).
  1171. if error_code == "553":
  1172. logger.error(
  1173. "FTP 553 error - Could not create file. Possible causes: "
  1174. "1) No SD card inserted, 2) SD card full, 3) SD card not formatted correctly (needs FAT32/exFAT), "
  1175. "4) Printer busy/not ready, 5) File path issue"
  1176. )
  1177. kind = FtpFailureKind.STORAGE
  1178. elif error_code == "550":
  1179. logger.error("FTP 550 error - File/directory not found or permission denied")
  1180. kind = FtpFailureKind.NOT_FOUND
  1181. elif error_code == "552":
  1182. logger.error("FTP 552 error - Storage quota exceeded (SD card full?)")
  1183. kind = FtpFailureKind.STORAGE
  1184. else:
  1185. kind = FtpFailureKind.UNKNOWN
  1186. self.last_failure = FtpFailure(kind, str(e), _ftp_reply_code(e))
  1187. return False
  1188. except (OSError, ftplib.Error) as e:
  1189. logger.error("FTP upload failed for %s: %s (type: %s)", remote_path, e, type(e).__name__)
  1190. code = _ftp_reply_code(e)
  1191. # 452 is "insufficient storage" -- a 4xx, so ftplib raises it as
  1192. # error_temp rather than error_perm, but it is the printer talking
  1193. # about its card just as 552/553 are. As NETWORK it would read as a
  1194. # connection problem, and the queue would retry it forever (#3210).
  1195. is_storage = isinstance(e, ftplib.Error) and code == "452"
  1196. kind = FtpFailureKind.STORAGE if is_storage else FtpFailureKind.NETWORK
  1197. self.last_failure = FtpFailure(kind, str(e), code)
  1198. return False
  1199. def upload_bytes(self, data: bytes, remote_path: str) -> bool:
  1200. """Upload bytes to the printer."""
  1201. if not self._ftp:
  1202. return False
  1203. try:
  1204. # Use manual transfer instead of storbinary() for A1 compatibility
  1205. conn = self._ftp.transfercmd(f"STOR {remote_path}")
  1206. conn.setblocking(True)
  1207. conn.settimeout(self.timeout)
  1208. try:
  1209. # Send data in chunks
  1210. offset = 0
  1211. while offset < len(data):
  1212. chunk = data[offset : offset + self.CHUNK_SIZE]
  1213. conn.sendall(chunk)
  1214. offset += len(chunk)
  1215. except OSError as e:
  1216. logger.error("FTP connection lost during upload_bytes: %s", e)
  1217. raise
  1218. finally:
  1219. try:
  1220. conn.close()
  1221. except OSError:
  1222. pass
  1223. # Wait for 226 confirmation (see upload_file for rationale).
  1224. # ftplib.Error subclasses (e.g. 426 error_temp) mean the server
  1225. # rejected the transfer and the file is partial — fail. Other
  1226. # exceptions (timeout, socket-level) are tolerated as in upload_file.
  1227. try:
  1228. old_timeout = self._ftp.sock.gettimeout()
  1229. self._ftp.sock.settimeout(max(self.timeout, 60))
  1230. try:
  1231. self._ftp.voidresp()
  1232. finally:
  1233. self._ftp.sock.settimeout(old_timeout)
  1234. except ftplib.Error as e:
  1235. # Same SIZE-verify path as upload_file (#1417 follow-up):
  1236. # tolerate a transient 426 if the bytes are actually on the
  1237. # printer, fail loudly if they aren't.
  1238. try:
  1239. server_size = self._ftp.size(remote_path)
  1240. except (OSError, ftplib.Error) as size_err:
  1241. logger.debug("Post-error SIZE check failed: %s", size_err)
  1242. server_size = None
  1243. if server_size is not None and server_size == len(data):
  1244. # INFO for the same reason as upload_file above (#2987).
  1245. logger.info(
  1246. "FTP STOR returned %s for %s but file is intact on the "
  1247. "printer (%s bytes match) — proceeding: %s",
  1248. type(e).__name__,
  1249. remote_path,
  1250. len(data),
  1251. e,
  1252. )
  1253. else:
  1254. logger.error(
  1255. "FTP STOR rejected by printer for %s: %s (%s); server size=%s expected=%s",
  1256. remote_path,
  1257. e,
  1258. type(e).__name__,
  1259. server_size,
  1260. len(data),
  1261. )
  1262. return False
  1263. except Exception:
  1264. # Timeout / socket-level — proceed, data was sent.
  1265. self._check_unconfirmed_upload(remote_path, len(data))
  1266. return True
  1267. except (OSError, ftplib.Error):
  1268. return False
  1269. def _check_unconfirmed_upload(self, remote_path: str, expected_size: int) -> None:
  1270. """Read an upload's size back when its 226 never came.
  1271. The upload still counts (an H2D can take 30+ s to answer), but a
  1272. printer that kept a partial file should not go unnoticed. A fresh
  1273. connection, because this one may be waiting for that late reply.
  1274. """
  1275. server_size = _size_on_new_connection(self, remote_path)
  1276. if server_size is None:
  1277. logger.warning("FTP upload of %s could not be read back to check its size", remote_path)
  1278. elif server_size != expected_size:
  1279. logger.error(
  1280. "FTP upload of %s is %s bytes on the printer, expected %s: the file may be incomplete",
  1281. remote_path,
  1282. server_size,
  1283. expected_size,
  1284. )
  1285. else:
  1286. logger.info("FTP upload of %s verified on a new connection (%s bytes)", remote_path, server_size)
  1287. def delete_file(self, remote_path: str) -> DeleteResult:
  1288. """Delete a file from the printer.
  1289. Returns :class:`DeleteResult` distinguishing the file-not-found case
  1290. (550) from network / auth / transient FTP failure. Callers that just
  1291. want "did it work" should check ``result == DeleteResult.DELETED``.
  1292. """
  1293. if not self._ftp:
  1294. return DeleteResult.FAILED
  1295. try:
  1296. self._ftp.delete(remote_path)
  1297. return DeleteResult.DELETED
  1298. except ftplib.error_perm as e:
  1299. if str(e).startswith("550"):
  1300. logger.debug("FTP delete: %s not on printer (550)", remote_path)
  1301. return DeleteResult.NOT_FOUND
  1302. logger.warning("Failed to delete %s: %s", remote_path, e)
  1303. return DeleteResult.FAILED
  1304. except (OSError, ftplib.Error) as e:
  1305. logger.warning("Failed to delete %s: %s", remote_path, e)
  1306. return DeleteResult.FAILED
  1307. def get_file_size(self, remote_path: str) -> int | None:
  1308. """Get the size of a file."""
  1309. if not self._ftp:
  1310. return None
  1311. try:
  1312. return self._ftp.size(remote_path)
  1313. except (OSError, ftplib.Error):
  1314. return None
  1315. def get_storage_info(self) -> dict | None:
  1316. """Get storage information from the printer."""
  1317. if not self._ftp:
  1318. return None
  1319. result = {}
  1320. # Try AVBL command (available space) - some FTP servers support this
  1321. try:
  1322. response = self._ftp.sendcmd("AVBL")
  1323. logger.debug("AVBL response: %s", response)
  1324. # Response format: "213 <bytes available>"
  1325. if response.startswith("213"):
  1326. parts = response.split()
  1327. if len(parts) >= 2:
  1328. result["free_bytes"] = int(parts[1])
  1329. except (OSError, ftplib.Error) as e:
  1330. logger.debug("AVBL command not supported: %s", e)
  1331. # Try STAT command as fallback
  1332. try:
  1333. response = self._ftp.sendcmd("STAT")
  1334. logger.debug("STAT response: %s", response)
  1335. except (OSError, ftplib.Error):
  1336. pass # Both AVBL and STAT unsupported; storage info will rely on directory scan
  1337. # Calculate used space by listing root directories
  1338. try:
  1339. total_used = 0
  1340. dirs_to_scan = ["/cache", "/timelapse", "/model", "/data", "/data/Metadata", "/"]
  1341. for dir_path in dirs_to_scan:
  1342. try:
  1343. self._ftp.cwd(dir_path)
  1344. items = []
  1345. self._ftp.retrlines("LIST", items.append)
  1346. for item in items:
  1347. parts = item.split()
  1348. if len(parts) >= 5 and not item.startswith("d"):
  1349. try:
  1350. total_used += int(parts[4])
  1351. except ValueError:
  1352. pass # Skip entries with non-numeric size fields
  1353. except (OSError, ftplib.Error):
  1354. pass # Directory may not exist on this printer model; skip it
  1355. result["used_bytes"] = total_used
  1356. except (OSError, ftplib.Error):
  1357. pass # Storage scan failed; return whatever info was collected above
  1358. return result if result else None
  1359. def _size_on_new_connection(client: BambuFTPClient, remote_path: str) -> int | None:
  1360. """The size of ``remote_path`` read on a connection of its own, or None."""
  1361. fresh = BambuFTPClient(
  1362. client.ip_address,
  1363. client.access_code,
  1364. timeout=client.timeout,
  1365. printer_model=client.printer_model,
  1366. force_prot_c=client.force_prot_c,
  1367. # A second session while the first still waits for its reply may be
  1368. # refused (the printer's connection slots); that must not block the
  1369. # printer's downloads for the cool-off.
  1370. respect_handshake_cooloff=False,
  1371. records_handshake_cooloff=False,
  1372. )
  1373. fresh.FTP_PORT = client.FTP_PORT
  1374. try:
  1375. if not fresh.connect():
  1376. return None
  1377. return fresh.get_file_size(remote_path)
  1378. except Exception:
  1379. return None
  1380. finally:
  1381. fresh.disconnect()
  1382. def describe_upload_failure(failure: FtpFailure | None) -> str:
  1383. """One sentence for the operator, chosen from what actually went wrong.
  1384. Every upload failure used to get the same one: "Failed to upload file to
  1385. printer. Check if SD card is inserted and properly formatted
  1386. (FAT32/exFAT)." #2899's reporter got that after a TLS handshake failure and
  1387. restarted the printer, which could not have helped -- the handshake never
  1388. reached the printer's filesystem, and the state that produced it lives in
  1389. Bambuddy's own memory. #2780 had already removed advice from this failure's
  1390. *log* line for the same reason; it survived in the string people read.
  1391. So the card is named only where the printer itself raised storage, and
  1392. where nothing here can say more, this says so and points at the log rather
  1393. than picking a plausible cause. A wrong instruction costs more than a
  1394. vague one: it sends someone to work on hardware that is fine.
  1395. """
  1396. if failure is None:
  1397. return (
  1398. "Could not upload the file to the printer. See the server log for the reason — "
  1399. "it records what the printer's file service said."
  1400. )
  1401. if failure.kind is FtpFailureKind.STORAGE:
  1402. return (
  1403. f"The printer refused to store the file ({failure.code or 'storage error'}). Check that its SD card "
  1404. "is inserted, has space free, and is formatted FAT32 or exFAT."
  1405. )
  1406. if failure.kind is FtpFailureKind.HANDSHAKE:
  1407. return (
  1408. "The printer's file service answered, but not with TLS, so no file could be sent to it. "
  1409. "Its SD card is not involved. This usually clears by itself; if it does not, power-cycling "
  1410. "the printer has not been found to help either, so please report it."
  1411. )
  1412. if failure.kind is FtpFailureKind.COOLOFF:
  1413. return (
  1414. "Bambuddy is holding off from this printer's file service after a recent failed TLS handshake, "
  1415. "so the file was not sent. This clears on its own within a few minutes."
  1416. )
  1417. if failure.kind is FtpFailureKind.AUTH:
  1418. return (
  1419. "The printer refused the file transfer connection. If the printer's access code changed, "
  1420. "update it on Bambuddy's Printers page."
  1421. )
  1422. if failure.kind is FtpFailureKind.TIMEOUT:
  1423. return (
  1424. "The printer's file service did not respond in time, so the file was not sent. "
  1425. "Check that the printer is on the network and reachable."
  1426. )
  1427. if failure.kind is FtpFailureKind.NOT_FOUND:
  1428. return (
  1429. "The printer rejected the upload path (550). See the server log — this is a Bambuddy-side "
  1430. "problem, not something to fix on the printer."
  1431. )
  1432. return (
  1433. "Could not upload the file to the printer. See the server log for the reason — "
  1434. "it records what the printer's file service said."
  1435. )
  1436. def ftps_handshake_blocked(ip_address: str) -> bool:
  1437. """True while this printer's FTPS handshake cool-off is still running.
  1438. Callers that walk a list of candidate paths use this to give up on the
  1439. remaining candidates: the failure is at the transport, below any path, so
  1440. every one of them would fail identically (#2780).
  1441. """
  1442. return BambuFTPClient.handshake_blocked(ip_address)
  1443. # Shared 3MF download cache (#972).
  1444. #
  1445. # Both the cover thumbnail endpoint (api/routes/printers.py) and the archive
  1446. # metadata flow (main.py) fetch the same 3MF file over FTP during a print.
  1447. # On slow / contended links (A1 Wi-Fi, large files) the duplicate transfers
  1448. # compete for the printer's single FTP socket and trigger 425 "can't open
  1449. # data channel" errors, feeding back into cause-2's retry storm.
  1450. #
  1451. # This cache stores the local path of a successfully-downloaded 3MF keyed
  1452. # by (printer_id, normalized_name). Whichever flow downloads first populates
  1453. # the cache; the other flow reuses the file read-only. Evicted on print
  1454. # completion so a later print with the same name re-downloads fresh bytes.
  1455. _threemf_path_cache: dict[tuple[int, str], Path] = {}
  1456. def normalize_3mf_name(name: str) -> str:
  1457. """Collapse various 3MF filename variants to a cache key.
  1458. Bambu tooling produces names as bare subtask ("Part"), with .3mf, with
  1459. .gcode.3mf, or (Studio-normalized) with spaces → underscores. All of
  1460. these refer to the same print job on the same printer, so they must
  1461. hash to the same cache key.
  1462. """
  1463. # Lowercase first so .3MF / .GCODE.3MF variants strip cleanly — a
  1464. # real-world case since Windows-side tooling sometimes uppercases
  1465. # extensions.
  1466. cleaned = name.strip().lower().replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  1467. return cleaned.replace(" ", "_")
  1468. def cache_3mf_download(printer_id: int, name: str, local_path: Path) -> None:
  1469. """Record a successfully-downloaded 3MF so a sibling flow can reuse it."""
  1470. _threemf_path_cache[(printer_id, normalize_3mf_name(name))] = local_path
  1471. def get_cached_3mf(printer_id: int, name: str) -> Path | None:
  1472. """Return a cached 3MF path for this printer/name if the file still exists."""
  1473. key = (printer_id, normalize_3mf_name(name))
  1474. cached = _threemf_path_cache.get(key)
  1475. if cached and cached.exists() and cached.stat().st_size > 0:
  1476. return cached
  1477. # Evict dead entry — the file was cleaned up (temp dir clean, manual
  1478. # deletion, restart) so the cache value is no longer usable.
  1479. if cached:
  1480. _threemf_path_cache.pop(key, None)
  1481. return None
  1482. def clear_3mf_cache(printer_id: int | None = None, delete_files: bool = True) -> None:
  1483. """Drop cache entries for one printer (or all with None).
  1484. When ``delete_files`` is True (default) the on-disk 3MF is removed as well
  1485. — called from on_print_complete so temp files don't accumulate across
  1486. prints. Tests that want to inspect the cache contents disable this.
  1487. Only paths inside ``archive_dir/temp`` are unlinked. The dispatch sites
  1488. added in #1166 also cache the live archive copy and library file bytes
  1489. so /cover can skip FTP — those are *user data*, never the cache's to
  1490. delete. Pre-fix this branch silently removed archive 3mfs on every print
  1491. completion (#1212 + private reports of "file disappeared overnight").
  1492. """
  1493. from backend.app.core.config import settings as _config_settings
  1494. temp_root = _config_settings.archive_dir / "temp"
  1495. def _is_temp_path(path: Path) -> bool:
  1496. try:
  1497. return path.is_relative_to(temp_root)
  1498. except (OSError, ValueError):
  1499. return False
  1500. def _maybe_unlink(path: Path) -> None:
  1501. if not delete_files or not path.exists():
  1502. return
  1503. if not _is_temp_path(path):
  1504. return
  1505. try:
  1506. path.unlink()
  1507. except OSError as exc:
  1508. logger.debug("3MF cache cleanup skipped %s: %s", path, exc)
  1509. if printer_id is None:
  1510. for path in list(_threemf_path_cache.values()):
  1511. _maybe_unlink(path)
  1512. _threemf_path_cache.clear()
  1513. return
  1514. for key in [k for k in _threemf_path_cache if k[0] == printer_id]:
  1515. _maybe_unlink(_threemf_path_cache[key])
  1516. _threemf_path_cache.pop(key, None)
  1517. async def download_file_async(
  1518. ip_address: str,
  1519. access_code: str,
  1520. remote_path: str,
  1521. local_path: Path,
  1522. timeout: float = 60.0,
  1523. socket_timeout: float | None = None,
  1524. printer_model: str | None = None,
  1525. expected_size: int | None = None,
  1526. max_bytes: int | None = None,
  1527. cancel_event: threading.Event | None = None,
  1528. min_free_bytes: int | None = None,
  1529. serialize: bool = True,
  1530. max_total_timeout: float = _DOWNLOAD_MAX_TIMEOUT,
  1531. ) -> bool:
  1532. """Async wrapper for downloading a file with timeout.
  1533. For A1/A1 Mini printers, automatically tries prot_p first, then falls back
  1534. to prot_c if the download fails. The working mode is cached for future operations.
  1535. ``timeout`` bounds the wait for a *result*, not the call: when it expires
  1536. this waits for the FTP worker thread to unwind before returning, because
  1537. the thread owns ``local_path`` until it does and a caller that came back
  1538. early would delete a file still being written. That wait is bounded by the
  1539. socket timeout, so pass ``socket_timeout`` on any path that must not block
  1540. indefinitely -- every caller here does.
  1541. Args:
  1542. ip_address: Printer IP address
  1543. access_code: Printer access code
  1544. remote_path: Remote file path on printer
  1545. local_path: Local path to save file
  1546. timeout: Overall operation timeout (asyncio)
  1547. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1548. printer_model: Printer model for A1-specific workarounds
  1549. max_total_timeout: the most the size-based extension may stretch the
  1550. deadline to (see ``_download_extension``). The default suits print
  1551. start; the printer file browser passes its own job budget.
  1552. serialize: take this printer's download gate for the transfer (#2957).
  1553. Pass False from a path that must neither queue behind another
  1554. download nor make one queue behind it -- the printer file browser
  1555. is both, and says so: a preview must not wait out somebody else's
  1556. ten-gigabyte selection, and that selection must not hold the printer
  1557. for the twenty minutes it legitimately takes.
  1558. """
  1559. loop = asyncio.get_event_loop()
  1560. is_a1 = printer_model in BambuFTPClient.A1_MODELS if printer_model else False
  1561. # Per-attempt completion state: asyncio.wait_for cannot cancel
  1562. # run_in_executor threads, so on timeout the executor may still complete
  1563. # the download after we stop waiting. The thread flips `success` to True
  1564. # ONLY after the file is fully written — a post-timeout check lets us
  1565. # salvage the download without mistaking an in-progress partial write
  1566. # for a completed one. Each attempt gets its own dict and event so a
  1567. # zombie from an earlier attempt can't flip the flag for a later one.
  1568. # The event is set in `_download`'s finally block so the post-timeout
  1569. # path can wait for genuine thread completion instead of a fixed sleep.
  1570. class _CombinedCancelEvent:
  1571. def __init__(self, attempt_event: threading.Event):
  1572. self._attempt_event = attempt_event
  1573. def is_set(self) -> bool:
  1574. return self._attempt_event.is_set() or (cancel_event is not None and cancel_event.is_set())
  1575. def _download(
  1576. force_prot_c: bool,
  1577. completion: dict,
  1578. done: threading.Event,
  1579. attempt_cancel: threading.Event,
  1580. ) -> bool:
  1581. mode_str = "prot_c" if force_prot_c else "prot_p"
  1582. try:
  1583. combined_cancel = _CombinedCancelEvent(attempt_cancel)
  1584. if combined_cancel.is_set():
  1585. raise DownloadCancelled(remote_path)
  1586. client = BambuFTPClient(
  1587. ip_address,
  1588. access_code,
  1589. timeout=socket_timeout,
  1590. printer_model=printer_model,
  1591. force_prot_c=force_prot_c,
  1592. )
  1593. if client.connect():
  1594. try:
  1595. result = client.download_to_file(
  1596. remote_path,
  1597. local_path,
  1598. expected_size=expected_size,
  1599. max_bytes=max_bytes,
  1600. cancel_event=combined_cancel,
  1601. min_free_bytes=min_free_bytes,
  1602. size_callback=lambda n: completion.__setitem__("size", n),
  1603. )
  1604. if result:
  1605. BambuFTPClient.cache_mode(ip_address, mode_str)
  1606. completion["success"] = True
  1607. return result
  1608. finally:
  1609. client.disconnect()
  1610. return False
  1611. finally:
  1612. done.set()
  1613. async def _run(force_prot_c: bool) -> bool:
  1614. completion = {"success": False}
  1615. done = threading.Event()
  1616. attempt_cancel = threading.Event()
  1617. worker = loop.run_in_executor(_ftp_executor, _download, force_prot_c, completion, done, attempt_cancel)
  1618. # What this attempt was actually allowed, for the log lines below: the
  1619. # size-derived extension moves it after the fact.
  1620. allowed = timeout
  1621. extended = False
  1622. try:
  1623. try:
  1624. return await asyncio.wait_for(asyncio.shield(worker), timeout=timeout)
  1625. except TimeoutError:
  1626. # The deadline was set before anyone knew the file's size. Now
  1627. # the printer has told us, so give a transfer that is genuinely
  1628. # under way the time that size needs (#2957). Re-raises into the
  1629. # handler below when the size is unknown or already covered.
  1630. extension = _download_extension(completion.get("size"), timeout, max_total_timeout)
  1631. if extension <= 0:
  1632. raise
  1633. logger.info(
  1634. "FTP download of %s passed its %ss deadline but the printer reports %s bytes — "
  1635. "allowing %.0fs more rather than declaring a slow transfer dead (#2957)",
  1636. remote_path,
  1637. timeout,
  1638. completion.get("size"),
  1639. extension,
  1640. )
  1641. allowed = timeout + extension
  1642. extended = True
  1643. return await asyncio.wait_for(asyncio.shield(worker), timeout=extension)
  1644. except asyncio.CancelledError:
  1645. # Cancelling an asyncio Future cannot stop its executor thread. Set
  1646. # the callback-visible flag and do not let the caller unlink the
  1647. # staging file until the worker has genuinely unwound.
  1648. attempt_cancel.set()
  1649. try:
  1650. await asyncio.shield(worker)
  1651. except (DownloadCancelled, OSError, ftplib.Error):
  1652. pass
  1653. raise
  1654. except TimeoutError:
  1655. # Slow WiFi links commonly overshoot ftp_timeout by 10–30 s without
  1656. # actually being stuck, so starting attempt 2 now would just contend
  1657. # with the still-progressing RETR on attempt 1 and produce the
  1658. # zombie-write race reported in #1014 (file landed on disk minutes
  1659. # after the retry loop had already given up). Wait for the worker
  1660. # thread to genuinely finish — capped at 30 s so a truly stuck
  1661. # connection can't stall a whole attempt indefinitely, with a 0.5 s
  1662. # floor so artificially small test timeouts still give zombies a
  1663. # realistic window to finish.
  1664. grace = max(min(timeout, 30.0), 0.5)
  1665. # Deliberately the DEFAULT executor, not `_ftp_executor`: this thread
  1666. # blocks waiting on `_download`, which is itself an `_ftp_executor`
  1667. # worker. Parking waiters in the same bounded pool as the workers they
  1668. # wait for is how you build a deadlock — with enough concurrent
  1669. # timeouts the waiters would occupy every slot and the downloads they
  1670. # are waiting for could never be scheduled.
  1671. attempt_cancel.set()
  1672. await loop.run_in_executor(None, done.wait, grace)
  1673. # Wait for the thread either way. If the grace period was enough it
  1674. # returns at once; if it was not, the blocking socket still has to
  1675. # reach its own timeout, and returning before it does would let the
  1676. # caller unlink a file the executor is still writing.
  1677. try:
  1678. await asyncio.shield(worker)
  1679. except (DownloadCancelled, OSError, ftplib.Error):
  1680. pass
  1681. if completion["success"] and local_path.exists() and local_path.stat().st_size > 0:
  1682. logger.info(
  1683. "FTP download wait_for timed out after %ss for %s, but thread completed within %ss grace (%s bytes) — salvaging",
  1684. allowed,
  1685. remote_path,
  1686. grace,
  1687. local_path.stat().st_size,
  1688. )
  1689. return True
  1690. if extended:
  1691. # The transfer had already been given the time its own reported
  1692. # size needs. Retrying spends that again to learn the same
  1693. # thing, so say so rather than reporting an ordinary miss.
  1694. logger.warning(
  1695. "FTP download of %s did not finish inside the %ss its size bought it (plus %ss grace)",
  1696. remote_path,
  1697. allowed,
  1698. grace,
  1699. )
  1700. raise DownloadDeadlineExceeded(remote_path)
  1701. logger.warning(
  1702. "FTP download timed out after %ss (plus %ss grace) for %s",
  1703. allowed,
  1704. grace,
  1705. remote_path,
  1706. )
  1707. return False
  1708. # Check if we have a cached mode for this printer
  1709. cached_mode = BambuFTPClient._mode_cache.get(ip_address)
  1710. # The gate spans the prot_c fallback too: those are two attempts at one
  1711. # transfer, and letting go between them would hand the printer to a waiter
  1712. # mid-download (#2957).
  1713. async with _serialized_download(ip_address, f"a download of {remote_path}", enabled=serialize):
  1714. if cached_mode:
  1715. force_prot_c = cached_mode == "prot_c"
  1716. return await _run(force_prot_c)
  1717. # No cached mode - try prot_p first
  1718. if await _run(False):
  1719. return True
  1720. # Download failed - for A1 models, try prot_c fallback
  1721. if is_a1:
  1722. logger.info("FTP download failed with prot_p for A1 model, trying prot_c fallback...")
  1723. return await _run(True)
  1724. return False
  1725. async def download_file_try_paths_async(
  1726. ip_address: str,
  1727. access_code: str,
  1728. remote_paths: list[str],
  1729. local_path: Path,
  1730. socket_timeout: float | None = None,
  1731. printer_model: str | None = None,
  1732. timeout: float = 90.0,
  1733. max_total_timeout: float | None = None,
  1734. ) -> str | None:
  1735. """Try downloading a file from multiple paths using a single connection.
  1736. Returns the path that served the file, or ``None``. The path rather than a
  1737. bare flag because the caller usually cannot tell afterwards which candidate
  1738. hit, and on a printer that keeps uploads around for weeks that is the
  1739. difference between a diagnosable stale-copy match and an invisible one
  1740. (#1820). Callers testing it for truth are unaffected: a served path is
  1741. always a non-empty string.
  1742. Args:
  1743. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1744. printer_model: Printer model for A1-specific workarounds
  1745. timeout: overall async cap. The per-socket timeout only bounds an
  1746. in-flight worker; it does NOT bound how long this coroutine waits
  1747. for a free slot in the fixed-size ``_ftp_executor``. On a large
  1748. farm where offline printers keep every worker busy on dead
  1749. connects, that queue wait is otherwise unbounded — and any caller
  1750. holding a DB connection while awaiting this would pin it until the
  1751. pool is exhausted (#2572). The cap converts that into a bounded
  1752. wait; the worker is then cancelled and waited out rather than
  1753. orphaned (#2957), so a DB-holding caller's worst case is the gate
  1754. wait plus this cap plus one unwind -- still bounded, and the
  1755. orphaned worker no longer keeps the printer's socket after it.
  1756. max_total_timeout: how far a path that answered SIZE may stretch that
  1757. cap (see ``_download_extension``), as ``download_file_async`` does.
  1758. None (the default) stretches nothing: a caller holding a DB session
  1759. keeps the bound above.
  1760. """
  1761. loop = asyncio.get_event_loop()
  1762. # An executor thread cannot be cancelled, so the cap alone used to leave a
  1763. # worker walking the remaining paths -- still holding the printer's FTP
  1764. # socket -- long after this coroutine had given up on it. A reporter's log
  1765. # shows one of those still going as the archive flow's own download landed,
  1766. # two Bambuddy transfers deep into a P1S that was mid-print (#2957). The
  1767. # flag stops it at the next chunk instead.
  1768. cancel = threading.Event()
  1769. done = threading.Event()
  1770. reported: dict = {}
  1771. def _download():
  1772. try:
  1773. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  1774. if not client.connect():
  1775. return None
  1776. try:
  1777. # FileNotOnPrinterError signals "try the next path", not "give up" —
  1778. # this function's whole purpose is to walk a list of candidates
  1779. # over one connection. Only a real transport error should bubble.
  1780. for remote_path in remote_paths:
  1781. if cancel.is_set():
  1782. return None
  1783. try:
  1784. if client.download_to_file(
  1785. remote_path,
  1786. local_path,
  1787. cancel_event=cancel,
  1788. size_callback=lambda n: reported.__setitem__("size", n),
  1789. ):
  1790. return remote_path
  1791. except FileNotOnPrinterError:
  1792. continue
  1793. except DownloadCancelled:
  1794. return None
  1795. return None
  1796. finally:
  1797. client.disconnect()
  1798. finally:
  1799. done.set()
  1800. async with _serialized_download(ip_address, f"a {len(remote_paths)}-path lookup"):
  1801. worker = loop.run_in_executor(_ftp_executor, _download)
  1802. try:
  1803. try:
  1804. return await asyncio.wait_for(asyncio.shield(worker), timeout=timeout)
  1805. except TimeoutError:
  1806. # A path the printer is serving has told us its size: give it
  1807. # the time that size needs, as download_file_async does.
  1808. extension = (
  1809. _download_extension(reported.get("size"), timeout, max_total_timeout)
  1810. if max_total_timeout is not None
  1811. else 0.0
  1812. )
  1813. if extension <= 0:
  1814. raise
  1815. logger.info(
  1816. "FTP download_try_paths passed its %ss cap but the printer reports %s bytes — allowing %.0fs more",
  1817. timeout,
  1818. reported.get("size"),
  1819. extension,
  1820. )
  1821. timeout += extension
  1822. return await asyncio.wait_for(asyncio.shield(worker), timeout=extension)
  1823. except asyncio.CancelledError:
  1824. # The caller is going away and should not be made to wait, but the
  1825. # worker must not keep the printer to itself either.
  1826. cancel.set()
  1827. _discard_worker_outcome(worker)
  1828. raise
  1829. except TimeoutError:
  1830. logger.warning("FTP download_try_paths exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  1831. cancel.set()
  1832. # Do not hand the printer to the next download while this worker is
  1833. # still on its socket. The DEFAULT executor, never ``_ftp_executor``:
  1834. # parking a waiter in the same bounded pool as the worker it waits
  1835. # for is how a deadlock gets built.
  1836. await loop.run_in_executor(None, done.wait, _DOWNLOAD_UNWIND_SECONDS)
  1837. _discard_worker_outcome(worker)
  1838. return None
  1839. def _upload_deadline(local_path: Path) -> float:
  1840. """Derive an upload deadline from the file size (#2529).
  1841. See ``_UPLOAD_FLOOR_BYTES_PER_SEC``. An unstat-able file falls back to the
  1842. floor timeout — ``upload_file`` will fail on the open() anyway.
  1843. """
  1844. try:
  1845. size = local_path.stat().st_size
  1846. except OSError:
  1847. return _UPLOAD_MIN_TIMEOUT
  1848. return max(_UPLOAD_MIN_TIMEOUT, size / _UPLOAD_FLOOR_BYTES_PER_SEC)
  1849. # One upload at a time per printer. Two concurrent STOR commands for the same
  1850. # remote path leave a corrupt file on the SD card, and the printer reads as
  1851. # flaky rather than busy (#2529). Held for the duration of a transfer, so a
  1852. # second dispatch to the same printer queues behind the first instead of racing
  1853. # it. Keyed per event loop: an asyncio.Lock binds to the loop that first awaits
  1854. # it, and the test suite runs each case on a fresh loop.
  1855. _upload_locks: weakref.WeakKeyDictionary[asyncio.AbstractEventLoop, dict[str, asyncio.Lock]] = (
  1856. weakref.WeakKeyDictionary()
  1857. )
  1858. def _upload_lock(loop: asyncio.AbstractEventLoop, ip_address: str) -> asyncio.Lock:
  1859. per_loop = _upload_locks.setdefault(loop, {})
  1860. lock = per_loop.get(ip_address)
  1861. if lock is None:
  1862. lock = asyncio.Lock()
  1863. per_loop[ip_address] = lock
  1864. return lock
  1865. async def upload_file_async(
  1866. ip_address: str,
  1867. access_code: str,
  1868. local_path: Path,
  1869. remote_path: str,
  1870. timeout: float | None = None,
  1871. progress_callback: Callable[[int, int], None] | None = None,
  1872. socket_timeout: float | None = None,
  1873. printer_model: str | None = None,
  1874. respect_handshake_cooloff: bool = True,
  1875. failure: FtpFailureReport | None = None,
  1876. ) -> bool:
  1877. """Async wrapper for uploading a file with timeout and progress callback.
  1878. For A1/A1 Mini printers, automatically tries prot_p first, then falls back
  1879. to prot_c if the upload fails. The working mode is cached for future uploads.
  1880. Args:
  1881. ip_address: Printer IP address
  1882. access_code: Printer access code
  1883. local_path: Local file path to upload
  1884. remote_path: Remote path on printer
  1885. timeout: Overall deadline. ``None`` (the default) derives it from the
  1886. file size — see ``_upload_deadline``. A caller that passes a number
  1887. gets exactly that, which is what the tests rely on.
  1888. progress_callback: Optional callback for progress updates
  1889. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  1890. printer_model: Printer model for A1-specific workarounds
  1891. respect_handshake_cooloff: see ``BambuFTPClient.__init__``. False for a
  1892. user-initiated upload, whose attempts are bounded and were being
  1893. spent against a cool-off that outlives them (#2898).
  1894. failure: caller-owned slot filled in with why the upload failed, so the
  1895. caller can say something true about it instead of guessing (#2899).
  1896. Passed through ``with_ftp_retry`` unchanged, so it ends up holding
  1897. the last attempt's reason -- which is the one that decided the
  1898. outcome.
  1899. """
  1900. loop = asyncio.get_event_loop()
  1901. is_a1 = printer_model in BambuFTPClient.A1_MODELS if printer_model else False
  1902. deadline = _upload_deadline(local_path) if timeout is None else timeout
  1903. # Set when the deadline expires. The worker checks it once per chunk.
  1904. cancel = threading.Event()
  1905. def _guarded_progress(uploaded: int, total: int) -> None:
  1906. if cancel.is_set():
  1907. raise UploadCancelled(f"upload of {remote_path} exceeded its {deadline:.0f}s deadline")
  1908. if progress_callback:
  1909. progress_callback(uploaded, total)
  1910. def _upload(force_prot_c: bool = False) -> bool:
  1911. mode_str = "prot_c" if force_prot_c else "prot_p"
  1912. logger.info(
  1913. f"FTP connecting to {ip_address} for upload (model={printer_model}, "
  1914. f"mode={mode_str}, socket_timeout={socket_timeout}s, deadline={deadline:.0f}s)..."
  1915. )
  1916. client = BambuFTPClient(
  1917. ip_address,
  1918. access_code,
  1919. timeout=socket_timeout,
  1920. printer_model=printer_model,
  1921. force_prot_c=force_prot_c,
  1922. respect_handshake_cooloff=respect_handshake_cooloff,
  1923. )
  1924. try:
  1925. if client.connect():
  1926. logger.info("FTP connected to %s", ip_address)
  1927. try:
  1928. result = client.upload_file(local_path, remote_path, _guarded_progress)
  1929. if result:
  1930. # Cache the working mode
  1931. BambuFTPClient.cache_mode(ip_address, mode_str)
  1932. return result
  1933. finally:
  1934. client.disconnect()
  1935. logger.warning("FTP connection failed to %s", ip_address)
  1936. return False
  1937. finally:
  1938. # In a finally so a transfer that leaves by raising -- a cancelled
  1939. # upload, a re-raised STOR rejection -- still reports what the
  1940. # client recorded on its way out.
  1941. if failure is not None and client.last_failure is not None:
  1942. failure.failure = client.last_failure
  1943. async def _attempt(force_prot_c: bool) -> bool:
  1944. """Run one upload attempt, and make a timeout actually stop the transfer.
  1945. ``asyncio.wait_for`` cancels the *future*, never the executor thread
  1946. behind it. Before #2529 a slow-but-healthy upload that overran the
  1947. deadline left that thread streaming: it kept pushing bytes, kept firing
  1948. the progress callback, and the retry above put a *second* STOR of the
  1949. same file onto the same printer. The reporter's 96 MB job ran four
  1950. concurrent transfers and never landed. So on timeout we signal the
  1951. worker (it raises ``UploadCancelled`` from the progress callback, which
  1952. breaks the send loop and deletes the partial file) and wait for it to
  1953. actually go.
  1954. """
  1955. fut = loop.run_in_executor(_ftp_executor, lambda: _upload(force_prot_c))
  1956. try:
  1957. return await asyncio.wait_for(asyncio.shield(fut), timeout=deadline)
  1958. except TimeoutError:
  1959. cancel.set()
  1960. logger.warning(
  1961. "FTP upload of %s exceeded its %.0fs deadline — cancelling the transfer",
  1962. remote_path,
  1963. deadline,
  1964. )
  1965. try:
  1966. await asyncio.wait_for(asyncio.shield(fut), timeout=_UPLOAD_CANCEL_GRACE)
  1967. except UploadCancelled:
  1968. logger.info("FTP upload of %s cancelled; partial file removed from the printer", remote_path)
  1969. except TimeoutError:
  1970. # The thread is wedged somewhere that never reaches the callback
  1971. # (a blocked sendall, say). Nothing more we can do from here —
  1972. # but consume the eventual result so asyncio doesn't log the
  1973. # future's exception as unretrieved when it is garbage-collected.
  1974. logger.error(
  1975. "FTP upload thread for %s did not stop within %.0fs of the cancel signal",
  1976. remote_path,
  1977. _UPLOAD_CANCEL_GRACE,
  1978. )
  1979. fut.add_done_callback(_swallow_future_result)
  1980. except Exception as e:
  1981. logger.warning("FTP upload of %s errored while cancelling: %s", remote_path, e)
  1982. # Raise rather than return False: a deadline expiry means the link
  1983. # sustained less than the floor rate for the whole transfer, and a
  1984. # retry would only spend another full deadline finding that out
  1985. # again — with check_queue serialized, four of those block the
  1986. # entire print queue for hours. ``with_ftp_retry`` never retries it.
  1987. raise UploadCancelled(
  1988. f"Upload of {remote_path} to {ip_address} exceeded its {deadline:.0f}s deadline "
  1989. f"(link sustained less than {_UPLOAD_FLOOR_BYTES_PER_SEC // 1024} KB/s)"
  1990. ) from None
  1991. async with _upload_lock(loop, ip_address):
  1992. # Check if we have a cached mode for this printer
  1993. cached_mode = BambuFTPClient._mode_cache.get(ip_address)
  1994. if cached_mode:
  1995. # Use cached mode
  1996. return await _attempt(cached_mode == "prot_c")
  1997. # No cached mode - try prot_p first
  1998. if await _attempt(False):
  1999. return True
  2000. # Upload failed - for A1 models, try prot_c fallback
  2001. if is_a1:
  2002. logger.info("FTP upload failed with prot_p for A1 model, trying prot_c fallback...")
  2003. return await _attempt(True)
  2004. return False
  2005. def _swallow_future_result(fut: asyncio.Future) -> None:
  2006. """Retrieve a future's exception so asyncio doesn't log it as unhandled."""
  2007. if not fut.cancelled():
  2008. fut.exception()
  2009. async def list_files_async(
  2010. ip_address: str,
  2011. access_code: str,
  2012. path: str = "/",
  2013. timeout: float = 30.0,
  2014. socket_timeout: float | None = None,
  2015. printer_model: str | None = None,
  2016. ) -> list[dict]:
  2017. """Async wrapper for listing files with timeout.
  2018. Args:
  2019. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  2020. printer_model: Printer model for A1-specific workarounds
  2021. """
  2022. loop = asyncio.get_event_loop()
  2023. def _list():
  2024. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  2025. if client.connect():
  2026. try:
  2027. return client.list_files(path)
  2028. finally:
  2029. client.disconnect()
  2030. return []
  2031. try:
  2032. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _list), timeout=timeout)
  2033. except TimeoutError:
  2034. logger.warning("FTP list_files timed out after %ss for %s", timeout, path)
  2035. return []
  2036. async def list_files_result_async(
  2037. ip_address: str,
  2038. access_code: str,
  2039. path: str = "/",
  2040. timeout: float = 30.0,
  2041. socket_timeout: float | None = None,
  2042. printer_model: str | None = None,
  2043. ) -> FileListResult:
  2044. """List a directory without collapsing transport failure into empty."""
  2045. loop = asyncio.get_event_loop()
  2046. key = (ip_address, access_code, path)
  2047. running = _inflight_listings.get(key)
  2048. if running is None or running[0].done():
  2049. # Set once the printer has answered: only then is a timeout a slow
  2050. # listing rather than a printer that is not there.
  2051. connected = threading.Event()
  2052. def _list() -> FileListResult:
  2053. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  2054. if not client.connect():
  2055. return FileListResult(files=[], available=False)
  2056. connected.set()
  2057. try:
  2058. return FileListResult(files=client.list_files(path, raise_on_error=True), available=True)
  2059. except (OSError, ftplib.Error):
  2060. return FileListResult(files=[], available=False)
  2061. finally:
  2062. client.disconnect()
  2063. running = (loop.run_in_executor(_ftp_executor, _list), connected)
  2064. _inflight_listings[key] = running
  2065. def _forget(done: asyncio.Future, key: tuple[str, str, str] = key) -> None:
  2066. entry = _inflight_listings.get(key)
  2067. if entry is not None and entry[0] is done:
  2068. del _inflight_listings[key]
  2069. running[0].add_done_callback(_forget)
  2070. future, connected = running
  2071. try:
  2072. # shield: one caller giving up must not cancel the listing another
  2073. # caller joined.
  2074. result = await asyncio.wait_for(asyncio.shield(future), timeout=timeout)
  2075. except TimeoutError:
  2076. logger.warning("FTP list_files timed out after %ss for %s", timeout, path)
  2077. return FileListResult(files=[], available=False, timed_out=connected.is_set())
  2078. # Joined callers share the listing; each gets entries of its own to edit.
  2079. return FileListResult(files=[dict(f) for f in result.files], available=result.available)
  2080. async def find_remote_file_async(
  2081. ip_address: str,
  2082. access_code: str,
  2083. remote_paths: list[str],
  2084. timeout: float = 30.0,
  2085. socket_timeout: float | None = None,
  2086. printer_model: str | None = None,
  2087. ) -> str | None:
  2088. """First of *remote_paths* the printer actually has, or None.
  2089. Answers "is this file there?" without fetching it, over a single
  2090. connection: one listing per distinct directory, reused across the
  2091. candidates that share it, and stops at the first hit. Written for the
  2092. connection diagnostic (#2856), which needs the answer for a file that can
  2093. be tens of megabytes and has no use for its contents.
  2094. Listing rather than ``SIZE``: LIST is what every Bambu firmware here is
  2095. known to answer, and a ``SIZE`` the server simply does not implement would
  2096. read as "the file is missing".
  2097. """
  2098. loop = asyncio.get_event_loop()
  2099. def _find() -> str | None:
  2100. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  2101. if not client.connect():
  2102. return None
  2103. try:
  2104. listed: dict[str, set[str]] = {}
  2105. for remote_path in remote_paths:
  2106. directory, _, name = remote_path.rpartition("/")
  2107. directory = directory or "/"
  2108. if directory not in listed:
  2109. listed[directory] = {
  2110. entry.get("name") for entry in client.list_files(directory) if not entry.get("is_directory")
  2111. }
  2112. if name in listed[directory]:
  2113. return remote_path
  2114. return None
  2115. finally:
  2116. client.disconnect()
  2117. try:
  2118. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _find), timeout=timeout)
  2119. except TimeoutError:
  2120. logger.warning("FTP find_remote_file timed out after %ss on %s", timeout, ip_address)
  2121. return None
  2122. async def delete_file_async(
  2123. ip_address: str,
  2124. access_code: str,
  2125. remote_path: str,
  2126. socket_timeout: float | None = None,
  2127. printer_model: str | None = None,
  2128. timeout: float = 60.0,
  2129. respect_handshake_cooloff: bool = True,
  2130. ) -> DeleteResult:
  2131. """Async wrapper for deleting a file.
  2132. Returns :class:`DeleteResult` so callers can distinguish ``NOT_FOUND``
  2133. (550 — file isn't on the printer, no retry value) from ``FAILED``
  2134. (network / auth / transient — worth retrying or surfacing).
  2135. Args:
  2136. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  2137. printer_model: Printer model for A1-specific workarounds
  2138. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  2139. the caller (and any DB connection it holds) indefinitely (#2572).
  2140. respect_handshake_cooloff: see ``BambuFTPClient.__init__``. The delete
  2141. that clears the way for a dispatch shares the upload's exemption --
  2142. it is one connection, and in #2898's trace it is the one that armed
  2143. the cool-off the upload then spent all four attempts against.
  2144. """
  2145. loop = asyncio.get_event_loop()
  2146. def _delete() -> DeleteResult:
  2147. client = BambuFTPClient(
  2148. ip_address,
  2149. access_code,
  2150. timeout=socket_timeout,
  2151. printer_model=printer_model,
  2152. respect_handshake_cooloff=respect_handshake_cooloff,
  2153. )
  2154. if client.connect():
  2155. try:
  2156. return client.delete_file(remote_path)
  2157. finally:
  2158. client.disconnect()
  2159. return DeleteResult.FAILED
  2160. try:
  2161. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _delete), timeout=timeout)
  2162. except TimeoutError:
  2163. logger.warning("FTP delete_file exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  2164. return DeleteResult.FAILED
  2165. async def download_file_bytes_async(
  2166. ip_address: str,
  2167. access_code: str,
  2168. remote_path: str,
  2169. socket_timeout: float | None = None,
  2170. printer_model: str | None = None,
  2171. timeout: float = 300.0,
  2172. expected_size: int | None = None,
  2173. report_missing: bool = False,
  2174. max_total_timeout: float = _DOWNLOAD_MAX_TIMEOUT,
  2175. ) -> bytes | None:
  2176. """Async wrapper for downloading file as bytes.
  2177. Args:
  2178. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  2179. printer_model: Printer model for A1-specific workarounds
  2180. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  2181. the caller (and any DB connection it holds) indefinitely (#2572).
  2182. Raised to fit ``expected_size`` at the pessimistic floor rate when
  2183. that is longer (#3272): a 75 MB timelapse took 358 s on a healthy
  2184. P1S link, and a flat cap cannot tell slow from stuck. A dead link
  2185. is still caught by ``socket_timeout``.
  2186. expected_size: size from the directory listing; a mismatch fails the
  2187. download instead of returning a truncated file. See
  2188. :meth:`BambuFTPClient.download_file`.
  2189. report_missing: raise :class:`FileNotOnPrinterError` for a path the
  2190. printer says is not there, so a caller can answer 404 for that
  2191. and 502 for a download that failed.
  2192. max_total_timeout: without ``expected_size``, the size the printer
  2193. reports when the transfer starts stretches the deadline up to this
  2194. (see ``_download_extension``).
  2195. At the deadline the transfer is stopped and its thread waited for (bounded
  2196. by the socket timeout), so a retry never opens a second session beside it.
  2197. A deadline that fitted the file's size raises
  2198. :class:`DownloadDeadlineExceeded`, which ``with_ftp_retry`` does not retry.
  2199. """
  2200. # Unlike ``_download_extension`` there is no 300 s ceiling here: that one
  2201. # exists because ``on_print_start`` holds a DB session across its 3MF hunt.
  2202. # Every caller that passes a size releases its session before the transfer.
  2203. if expected_size and expected_size > 0:
  2204. timeout = max(timeout, expected_size / _DOWNLOAD_FLOOR_BYTES_PER_SEC)
  2205. loop = asyncio.get_event_loop()
  2206. cancel = threading.Event()
  2207. reported: dict[str, int] = {}
  2208. sized = bool(expected_size and expected_size > 0)
  2209. def _download():
  2210. if cancel.is_set():
  2211. return None
  2212. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  2213. if client.connect():
  2214. try:
  2215. return client.download_file(
  2216. remote_path,
  2217. expected_size=expected_size,
  2218. cancel_event=cancel,
  2219. size_callback=None if sized else (lambda n: reported.__setitem__("size", n)),
  2220. report_missing=report_missing,
  2221. )
  2222. finally:
  2223. client.disconnect()
  2224. return None
  2225. async def _stop(worker) -> bytes | None:
  2226. """Tell the transfer to stop and wait for its thread to end.
  2227. Waited for unconditionally, like ``download_file_async``: a thread left
  2228. running would hold its FTP session while a retry opens another. The
  2229. wait is bounded by the socket timeout (a blocked read, then the QUIT).
  2230. A result that arrives meanwhile is kept; anything it raises is not the
  2231. caller's concern any more.
  2232. """
  2233. cancel.set()
  2234. try:
  2235. return await asyncio.shield(worker)
  2236. except Exception:
  2237. return None
  2238. worker = loop.run_in_executor(_ftp_executor, _download)
  2239. allowed = timeout
  2240. try:
  2241. try:
  2242. return await asyncio.wait_for(asyncio.shield(worker), timeout=timeout)
  2243. except TimeoutError:
  2244. # No listing size: the size the printer reported when the transfer
  2245. # started buys a slow link its time, as in download_file_async.
  2246. extension = 0.0 if sized else _download_extension(reported.get("size"), timeout, max_total_timeout)
  2247. if extension <= 0:
  2248. raise
  2249. allowed = timeout + extension
  2250. sized = True
  2251. return await asyncio.wait_for(asyncio.shield(worker), timeout=extension)
  2252. except asyncio.CancelledError:
  2253. await asyncio.shield(_stop(worker))
  2254. raise
  2255. except DownloadCancelled:
  2256. return None
  2257. except TimeoutError:
  2258. data = await _stop(worker)
  2259. if data:
  2260. # Finished inside the grace period: keep it.
  2261. return data
  2262. logger.warning(
  2263. "FTP download of %s (%s bytes) exceeded its %.0fs cap for %s",
  2264. remote_path,
  2265. expected_size or reported.get("size") or "unknown",
  2266. allowed,
  2267. ip_address,
  2268. )
  2269. if sized:
  2270. # The deadline already fitted the file at a floor rate no working
  2271. # link falls below: another attempt would reach the same end.
  2272. raise DownloadDeadlineExceeded(remote_path) from None
  2273. return None
  2274. async def remote_file_settled(
  2275. ip_address: str,
  2276. access_code: str,
  2277. remote_path: str,
  2278. downloaded_bytes: int,
  2279. *,
  2280. printer_model: str | None = None,
  2281. ) -> bool:
  2282. """Confirm the printer has finished writing the file we just downloaded.
  2283. Matching the download against the size from the directory listing proves we
  2284. received what the listing *said*, not that the file was *finished*. The
  2285. timelapse scan's first look happens seconds after the print ends, which is
  2286. exactly when the printer is writing the video — so a file still growing can
  2287. be listed at a partial size, served at that size, and pass the length check
  2288. as a complete video (#2704).
  2289. That was survivable while the printer kept its copy. It isn't now that a
  2290. successful attach deletes the source, so re-list afterwards: if the file has
  2291. grown, what we hold is a prefix and the caller should discard it and try
  2292. again on the next round.
  2293. Returns True when the remote file can no longer differ from what we hold —
  2294. the size still matches, or the file is gone from the listing entirely and
  2295. so cannot grow any further. Returns False when it has changed size, and on
  2296. a listing failure, because "we could not check" must not read as "safe to
  2297. delete".
  2298. """
  2299. directory, _, name = remote_path.rpartition("/")
  2300. files = await list_files_async(ip_address, access_code, directory or "/", printer_model=printer_model)
  2301. if not files:
  2302. logger.warning("[TIMELAPSE] Could not re-list %s to confirm %s is complete", directory or "/", name)
  2303. return False
  2304. for f in files:
  2305. if f.get("name") == name:
  2306. size = f.get("size")
  2307. if size == downloaded_bytes:
  2308. return True
  2309. logger.info(
  2310. "[TIMELAPSE] %s is still being written (%s bytes now, %s when downloaded) — will retry",
  2311. name,
  2312. size,
  2313. downloaded_bytes,
  2314. )
  2315. return False
  2316. # Vanished between the download and now. Nothing left that could grow, and
  2317. # nothing left to delete either.
  2318. logger.debug("[TIMELAPSE] %s is no longer on the printer after download", name)
  2319. return True
  2320. async def delete_archived_timelapse(
  2321. ip_address: str,
  2322. access_code: str,
  2323. remote_path: str,
  2324. *,
  2325. verified: bool,
  2326. printer_model: str | None = None,
  2327. printer_name: str = "",
  2328. ) -> bool:
  2329. """Remove a timelapse from the printer once it is safely in the archive.
  2330. Call this only after the attach succeeded (#2704). Keeping ``/timelapse``
  2331. down to just the unclaimed videos is what makes the snapshot diff
  2332. unambiguous rather than merely usually-right, and it stops P1S cards
  2333. filling with AVIs.
  2334. ``verified`` must say whether the downloaded byte count was checked against
  2335. the size the directory listing reported. It is required rather than
  2336. defaulted because this is the one irreversible step in the flow: an FTPS
  2337. data connection that closes early does not always raise, so an unverified
  2338. transfer can be a partial file that looks complete, and deleting the source
  2339. would then destroy the only good copy. The check lives here rather than at
  2340. each call site so no future caller can omit it.
  2341. Best-effort otherwise: a printer that refuses the delete keeps its copy, the
  2342. diff still excludes that filename next time because it is attached to an
  2343. archive, and nothing else in the flow cares. Returns True only on an actual
  2344. delete or a 550 (already gone).
  2345. """
  2346. if not verified:
  2347. logger.warning(
  2348. "[TIMELAPSE] Not deleting %s from printer %s: the download was never size-checked",
  2349. remote_path,
  2350. printer_name,
  2351. )
  2352. return False
  2353. for attempt in range(1, 4):
  2354. try:
  2355. result = await delete_file_async(ip_address, access_code, remote_path, printer_model=printer_model)
  2356. except Exception as e:
  2357. result = DeleteResult.FAILED
  2358. logger.warning("[TIMELAPSE] Delete attempt %d/3 raised for %s: %s", attempt, remote_path, e)
  2359. if result == DeleteResult.DELETED:
  2360. logger.info("[TIMELAPSE] Deleted %s from printer %s after archiving", remote_path, printer_name)
  2361. return True
  2362. if result == DeleteResult.NOT_FOUND:
  2363. # 550 never recovers by waiting — the printer already cleaned up.
  2364. logger.debug("[TIMELAPSE] %s already gone from printer %s", remote_path, printer_name)
  2365. return True
  2366. if attempt < 3:
  2367. await asyncio.sleep(2)
  2368. logger.warning(
  2369. "[TIMELAPSE] Could not delete %s from printer %s (it stays on the card; the archive copy is unaffected)",
  2370. remote_path,
  2371. printer_name,
  2372. )
  2373. return False
  2374. async def get_storage_info_async(
  2375. ip_address: str,
  2376. access_code: str,
  2377. socket_timeout: float | None = None,
  2378. printer_model: str | None = None,
  2379. timeout: float = 60.0,
  2380. ) -> dict | None:
  2381. """Async wrapper for getting storage info.
  2382. Args:
  2383. socket_timeout: FTP socket timeout for slow connections (e.g., A1 printers)
  2384. printer_model: Printer model for A1-specific workarounds
  2385. timeout: overall async cap so a saturated ``_ftp_executor`` can't pin
  2386. the caller (and any DB connection it holds) indefinitely (#2572).
  2387. """
  2388. loop = asyncio.get_event_loop()
  2389. def _get_storage():
  2390. client = BambuFTPClient(ip_address, access_code, timeout=socket_timeout, printer_model=printer_model)
  2391. if client.connect():
  2392. try:
  2393. return client.get_storage_info()
  2394. finally:
  2395. client.disconnect()
  2396. return None
  2397. try:
  2398. return await asyncio.wait_for(loop.run_in_executor(_ftp_executor, _get_storage), timeout=timeout)
  2399. except TimeoutError:
  2400. logger.warning("FTP get_storage_info exceeded its %ss cap for %s (#2572)", timeout, ip_address)
  2401. return None
  2402. async def get_ftp_retry_settings() -> tuple[bool, int, float, float]:
  2403. """Get FTP retry settings from database.
  2404. Returns:
  2405. Tuple of (retry_enabled, retry_count, retry_delay, timeout)
  2406. """
  2407. from backend.app.api.routes.settings import get_setting
  2408. from backend.app.core.database import async_session
  2409. async with async_session() as db:
  2410. enabled = (await get_setting(db, "ftp_retry_enabled") or "true") == "true"
  2411. count = int(await get_setting(db, "ftp_retry_count") or "3")
  2412. delay = float(await get_setting(db, "ftp_retry_delay") or "2")
  2413. timeout = float(await get_setting(db, "ftp_timeout") or "30")
  2414. return enabled, count, delay, timeout
  2415. async def with_ftp_retry(
  2416. operation: Callable[..., Awaitable[T]],
  2417. *args,
  2418. max_retries: int = 3,
  2419. retry_delay: float = 2.0,
  2420. operation_name: str = "FTP operation",
  2421. non_retry_exceptions: tuple[type[BaseException], ...] = (),
  2422. cooloff_ip: str | None = None,
  2423. **kwargs,
  2424. ) -> T | None:
  2425. """Execute FTP operation with retry logic.
  2426. Args:
  2427. operation: Async function to execute
  2428. *args: Positional arguments for the operation
  2429. max_retries: Number of retry attempts (default: 3)
  2430. retry_delay: Seconds to wait between retries (default: 2.0)
  2431. operation_name: Name for logging purposes
  2432. non_retry_exceptions: Exception types that should immediately abort retries
  2433. cooloff_ip: printer IP whose FTPS handshake cool-off should end the loop
  2434. early. Pass it from any caller that respects the cool-off; leave it
  2435. unset for one that opted out, or the loop would stop on a gate its
  2436. own attempts are ignoring (#2898).
  2437. **kwargs: Keyword arguments for the operation
  2438. Returns:
  2439. Result of the operation, or None if all attempts fail
  2440. ``UploadCancelled`` is never retried, whatever the caller passes: it means
  2441. the transfer overran its size-derived deadline, so a retry would spend
  2442. another full deadline reaching the same conclusion (#2529).
  2443. ``DownloadDeadlineExceeded`` is the same thing in the other direction
  2444. (#2957) and is treated the same way.
  2445. """
  2446. last_error = None
  2447. attempts_made = 0
  2448. for attempt in range(max_retries + 1):
  2449. attempts_made = attempt + 1
  2450. try:
  2451. result = await operation(*args, **kwargs)
  2452. # Check for "falsy" success indicators
  2453. if result not in (False, None, []):
  2454. if attempt > 0:
  2455. logger.info("%s succeeded on attempt %s/%s", operation_name, attempt + 1, max_retries + 1)
  2456. return result
  2457. # Operation returned failure indicator
  2458. if attempt > 0:
  2459. logger.info("%s attempt %s/%s returned failure", operation_name, attempt + 1, max_retries + 1)
  2460. except (UploadCancelled, DownloadDeadlineExceeded):
  2461. raise
  2462. except Exception as e:
  2463. if non_retry_exceptions and isinstance(e, non_retry_exceptions):
  2464. raise
  2465. last_error = e
  2466. logger.warning("%s attempt %s/%s failed: %s", operation_name, attempt + 1, max_retries + 1, e)
  2467. # Don't wait after the last attempt
  2468. if attempt < max_retries:
  2469. # A cool-off outlasts this loop by two orders of magnitude, so once
  2470. # it is armed every remaining attempt returns False without opening
  2471. # a socket. Spending them anyway bought nothing and cost the caller
  2472. # `max_retries * retry_delay` seconds of sleeping, then reported the
  2473. # failure with the wrong reason (#2898).
  2474. if cooloff_ip and ftps_handshake_blocked(cooloff_ip):
  2475. logger.warning(
  2476. "%s: stopping after attempt %s/%s — %s is inside its FTPS handshake cool-off, "
  2477. "so the remaining attempts would not reach it",
  2478. operation_name,
  2479. attempt + 1,
  2480. max_retries + 1,
  2481. cooloff_ip,
  2482. )
  2483. break
  2484. logger.info("%s will retry in %ss...", operation_name, retry_delay)
  2485. await asyncio.sleep(retry_delay)
  2486. # attempts_made, not max_retries + 1: the loop can stop early on a cool-off,
  2487. # and reporting attempts that were never made is how #2898 read as a network
  2488. # problem when nothing had gone near the network.
  2489. logger.error("%s failed after %s attempts", operation_name, attempts_made)
  2490. if last_error:
  2491. logger.debug("Last error: %s", last_error)
  2492. return None