test_scheduler_upload_requeue_3210.py 33 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757
  1. """A failed upload must not eat the queue (#3210).
  2. The reporter queued 20 jobs for "any P2S". One P2S's file service was out of
  3. connection slots -- it answered port 990 with ``421 There are too many
  4. connections from your internet address`` -- so every upload to it failed. Each
  5. failure marked the item ``failed``, which left that printer idle, so the next
  6. pass handed it the next item. One item died about every nine seconds: 43 jobs
  7. gone in ten minutes, none printed on that printer.
  8. Two changes, pinned here:
  9. * An upload whose file never reached the printer (handshake refused, cool-off,
  10. timeout, dropped connection, and since #3409 a refused card or access code)
  11. puts the item back in the queue. A path problem, an unknown failure and an
  12. upload too slow to finish still fail it.
  13. * The printer is out of dispatch for a backoff window, so nothing else is
  14. sent to it, and the item that was put back waits there with a reason.
  15. """
  16. import asyncio
  17. import time
  18. from contextlib import ExitStack, asynccontextmanager
  19. from pathlib import Path
  20. from types import SimpleNamespace
  21. from unittest.mock import AsyncMock, MagicMock, patch
  22. import pytest
  23. from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine
  24. import backend.app.models # noqa: F401 - populate Base.metadata
  25. import backend.app.services.archive as archive_module
  26. import backend.app.services.print_scheduler as scheduler_module
  27. from backend.app.core.database import Base
  28. from backend.app.models.archive import PrintArchive
  29. from backend.app.models.print_queue import PrintQueueItem
  30. from backend.app.models.printer import Printer
  31. from backend.app.services.bambu_ftp import BambuFTPClient, FtpFailure, FtpFailureKind, UploadCancelled
  32. from backend.app.services.print_scheduler import (
  33. UPLOAD_FAILURE_BACKOFF_MAX_SECONDS,
  34. UPLOAD_FAILURE_BACKOFF_SECONDS,
  35. PrintScheduler,
  36. )
  37. pytestmark = pytest.mark.unit
  38. REFUSING_IP = "10.0.0.8"
  39. HEALTHY_IP = "10.0.0.9"
  40. @pytest.fixture
  41. async def farm(tmp_path):
  42. """Two printers -- one whose file service refuses everything -- and an item factory."""
  43. engine = create_async_engine("sqlite+aiosqlite:///:memory:", echo=False)
  44. async with engine.begin() as conn:
  45. await conn.run_sync(Base.metadata.create_all)
  46. session_maker = async_sessionmaker(engine, expire_on_commit=False)
  47. base_dir = tmp_path / "farm"
  48. (base_dir / "archives").mkdir(parents=True, exist_ok=True)
  49. async with session_maker() as db:
  50. refusing = Printer(
  51. name="P2S-8", serial_number="S8", ip_address=REFUSING_IP, access_code="12345678", model="P2S"
  52. )
  53. healthy = Printer(name="P2S-9", serial_number="S9", ip_address=HEALTHY_IP, access_code="12345678", model="P2S")
  54. db.add_all([refusing, healthy])
  55. await db.commit()
  56. ids = SimpleNamespace(refusing=refusing.id, healthy=healthy.id)
  57. counter = iter(range(1000))
  58. async def add_item(
  59. *, printer_id: int | None = None, target_model: str | None = None, filename: str | None = None
  60. ) -> int:
  61. n = next(counter)
  62. async with session_maker() as db:
  63. archive_rel = Path("archives") / f"job-{n}.3mf"
  64. (base_dir / archive_rel).write_bytes(b"archive payload")
  65. archive = PrintArchive(
  66. printer_id=printer_id,
  67. filename=filename or f"job-{n}.3mf",
  68. file_path=str(archive_rel),
  69. file_size=15,
  70. status="completed",
  71. )
  72. db.add(archive)
  73. await db.flush()
  74. item = PrintQueueItem(
  75. printer_id=printer_id,
  76. target_model=target_model,
  77. archive_id=archive.id,
  78. status="pending",
  79. position=n,
  80. )
  81. db.add(item)
  82. await db.commit()
  83. return item.id
  84. try:
  85. yield SimpleNamespace(session_maker=session_maker, base_dir=base_dir, ids=ids, add_item=add_item)
  86. finally:
  87. await engine.dispose()
  88. def _upload_refused_by(ip: str, failure: FtpFailure):
  89. """An upload that fails with *failure* on *ip* and succeeds everywhere else."""
  90. async def _upload(ip_address, *_args, **kwargs):
  91. if ip_address != ip:
  92. return True
  93. if kwargs.get("failure") is not None:
  94. kwargs["failure"].failure = failure
  95. return False
  96. return _upload
  97. @asynccontextmanager
  98. async def _scheduler(
  99. ctx,
  100. upload,
  101. *,
  102. busy: set[int] | None = None,
  103. scheduler: PrintScheduler | None = None,
  104. waiting_notify: AsyncMock | None = None,
  105. ):
  106. """A scheduler wired to *ctx*'s database, with every printer idle unless in *busy*.
  107. Pass the same *waiting_notify* to several passes to count notifications
  108. across them.
  109. """
  110. scheduler = scheduler or PrintScheduler()
  111. busy = busy if busy is not None else set()
  112. failed_notify = AsyncMock()
  113. waiting_notify = waiting_notify or AsyncMock()
  114. def _real_spawn(coro, *, name=None):
  115. return asyncio.create_task(coro, name=name)
  116. patches = [
  117. patch.object(scheduler_module.settings, "base_dir", ctx.base_dir),
  118. patch.object(archive_module.settings, "base_dir", ctx.base_dir),
  119. patch.object(archive_module.settings, "archive_dir", ctx.base_dir / "archive"),
  120. patch("backend.app.services.print_scheduler.async_session", ctx.session_maker),
  121. patch("backend.app.core.database.async_session", ctx.session_maker),
  122. patch("backend.app.services.print_scheduler.printer_manager.is_connected", MagicMock(return_value=True)),
  123. patch(
  124. "backend.app.services.print_scheduler.printer_manager.get_status",
  125. MagicMock(return_value=SimpleNamespace(state="IDLE", subtask_id=None, gcode_file=None, raw_data={})),
  126. ),
  127. patch(
  128. "backend.app.services.print_scheduler.printer_manager.is_awaiting_plate_clear",
  129. MagicMock(return_value=False),
  130. ),
  131. patch("backend.app.services.print_scheduler.printer_manager.start_print", MagicMock(return_value=True)),
  132. patch("backend.app.services.print_scheduler.printer_manager.set_awaiting_plate_clear", MagicMock()),
  133. patch("backend.app.services.print_scheduler.upload_file_async", upload),
  134. patch("backend.app.services.print_scheduler.delete_file_async", AsyncMock(return_value=True)),
  135. patch(
  136. "backend.app.services.print_scheduler.get_ftp_retry_settings",
  137. AsyncMock(return_value=(False, 0, 0, 1.0)),
  138. ),
  139. patch("backend.app.services.print_scheduler.cache_3mf_download", MagicMock()),
  140. patch("backend.app.services.print_scheduler.spawn_background_task", _real_spawn),
  141. patch("backend.app.services.notification_service.notification_service.on_queue_job_started", AsyncMock()),
  142. patch("backend.app.services.notification_service.notification_service.on_queue_job_failed", failed_notify),
  143. patch("backend.app.services.notification_service.notification_service.on_queue_job_assigned", AsyncMock()),
  144. patch("backend.app.services.notification_service.notification_service.on_queue_job_waiting", waiting_notify),
  145. patch("backend.app.services.mqtt_relay.mqtt_relay.on_queue_job_started", AsyncMock()),
  146. patch.object(scheduler, "_is_printer_idle", MagicMock(side_effect=lambda pid, *_a, **_k: pid not in busy)),
  147. patch.object(scheduler, "_ensure_ams_mapping", AsyncMock(return_value=None)),
  148. patch.object(scheduler, "_block_on_filament_deficit", AsyncMock(return_value=False)),
  149. patch.object(scheduler, "_propagate_owner_to_printer_manager", AsyncMock()),
  150. patch.object(scheduler, "_power_off_if_needed", AsyncMock()),
  151. patch.object(scheduler, "_preheat_and_soak", AsyncMock()),
  152. patch.object(scheduler, "_check_auto_drying", AsyncMock()),
  153. patch.object(scheduler, "_watchdog_print_start", AsyncMock()),
  154. ]
  155. with ExitStack() as stack:
  156. for patcher in patches:
  157. stack.enter_context(patcher)
  158. scheduler.failed_notify = failed_notify
  159. yield scheduler
  160. tasks = [task for (task, _pid) in scheduler._inflight.values()]
  161. if tasks:
  162. await asyncio.gather(*tasks, return_exceptions=True)
  163. async def _item(ctx, item_id: int) -> PrintQueueItem:
  164. async with ctx.session_maker() as db:
  165. return await db.get(PrintQueueItem, item_id)
  166. HANDSHAKE = FtpFailure(FtpFailureKind.HANDSHAKE, "WRONG_VERSION_NUMBER (printer answered in cleartext: 421 ...)")
  167. # ---------------------------------------------------------------------------
  168. # What one failed upload does to its item
  169. # ---------------------------------------------------------------------------
  170. class TestOneFailedUpload:
  171. @pytest.mark.asyncio
  172. @pytest.mark.parametrize(
  173. "kind",
  174. [
  175. FtpFailureKind.HANDSHAKE,
  176. FtpFailureKind.COOLOFF,
  177. FtpFailureKind.TIMEOUT,
  178. FtpFailureKind.NETWORK,
  179. FtpFailureKind.STORAGE,
  180. FtpFailureKind.AUTH,
  181. ],
  182. )
  183. async def test_a_file_that_never_arrived_keeps_the_item(self, farm, kind):
  184. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  185. upload = _upload_refused_by(REFUSING_IP, FtpFailure(kind, "detail"))
  186. async with _scheduler(farm, upload) as scheduler:
  187. await scheduler.check_queue()
  188. item = await _item(farm, item_id)
  189. assert item.status == "pending"
  190. assert item.printer_id == farm.ids.refusing
  191. assert item.error_message is None
  192. assert item.dispatch_attempts == 0, "the start-watchdog budget is for a printer that took the file"
  193. scheduler.failed_notify.assert_not_awaited()
  194. assert farm.ids.refusing in scheduler._upload_backoff
  195. @pytest.mark.asyncio
  196. @pytest.mark.parametrize(
  197. "failure",
  198. [
  199. FtpFailure(FtpFailureKind.NOT_FOUND, "550 Permission denied.", "550"),
  200. FtpFailure(FtpFailureKind.UNKNOWN, "500 what"),
  201. None,
  202. ],
  203. ids=["not_found", "unknown", "unreported"],
  204. )
  205. async def test_a_failure_that_would_repeat_still_fails_the_item(self, farm, failure):
  206. """A 550 can be this one file's path, and an unknown failure says nothing about the printer."""
  207. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  208. async def upload(*_args, **kwargs):
  209. if failure is not None:
  210. kwargs["failure"].failure = failure
  211. return False
  212. async with _scheduler(farm, upload) as scheduler:
  213. await scheduler.check_queue()
  214. item = await _item(farm, item_id)
  215. assert item.status == "failed"
  216. assert item.error_message
  217. scheduler.failed_notify.assert_awaited_once()
  218. assert farm.ids.refusing not in scheduler._upload_backoff
  219. @pytest.mark.asyncio
  220. async def test_an_upload_that_overran_its_deadline_still_fails(self, farm):
  221. """A link too slow to finish would be just as slow next time (#2529)."""
  222. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  223. async def upload(*_args, **kwargs):
  224. kwargs["failure"].failure = FtpFailure(FtpFailureKind.TIMEOUT, "deadline")
  225. raise UploadCancelled("too slow")
  226. async with _scheduler(farm, upload) as scheduler:
  227. await scheduler.check_queue()
  228. assert (await _item(farm, item_id)).status == "failed"
  229. @pytest.mark.asyncio
  230. async def test_a_cancel_during_the_upload_is_not_undone(self, farm):
  231. """The row is never written back to pending, so a cancel that won stays won."""
  232. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  233. async def upload(*_args, **kwargs):
  234. async with farm.session_maker() as other:
  235. row = await other.get(PrintQueueItem, item_id)
  236. row.status = "cancelled"
  237. await other.commit()
  238. kwargs["failure"].failure = HANDSHAKE
  239. return False
  240. async with _scheduler(farm, upload) as scheduler:
  241. await scheduler.check_queue()
  242. assert (await _item(farm, item_id)).status == "cancelled"
  243. # ---------------------------------------------------------------------------
  244. # The report: a refusing printer must not drain the queue
  245. # ---------------------------------------------------------------------------
  246. class TestTheQueueIsNotDrained:
  247. @pytest.mark.asyncio
  248. async def test_any_model_items_stop_going_to_the_refusing_printer(self, farm):
  249. """#3210's shape: "any P2S" items, one P2S refusing every upload.
  250. Pass 1 sends one item to each printer; the refusing one gives its item
  251. back to the pool (#3409). Pass 2 has the healthy printer busy printing
  252. and the refusing one in backoff, so the rest wait instead of being fed
  253. to it one by one.
  254. """
  255. ids = [await farm.add_item(target_model="P2S") for _ in range(5)]
  256. upload = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  257. scheduler = PrintScheduler()
  258. async with _scheduler(farm, upload, scheduler=scheduler):
  259. await scheduler.check_queue()
  260. async with _scheduler(farm, upload, scheduler=scheduler, busy={farm.ids.healthy}):
  261. for _ in range(3):
  262. await scheduler.check_queue()
  263. items = [await _item(farm, i) for i in ids]
  264. assert [i.status for i in items].count("failed") == 0, [(i.id, i.status, i.error_message) for i in items]
  265. assert [i.status for i in items].count("printing") == 1
  266. assert not [i for i in items if i.printer_id == farm.ids.refusing], "nothing waits on the refusing printer"
  267. waiting = [i for i in items if i.status == "pending" and i.printer_id is None]
  268. assert len(waiting) == 4, "the rest stay unassigned, free for any printer that comes free"
  269. @pytest.mark.asyncio
  270. async def test_the_item_kept_on_the_printer_says_why(self, farm):
  271. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  272. upload = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  273. scheduler = PrintScheduler()
  274. async with _scheduler(farm, upload, scheduler=scheduler):
  275. await scheduler.check_queue()
  276. async with _scheduler(farm, upload, scheduler=scheduler):
  277. await scheduler.check_queue()
  278. item = await _item(farm, item_id)
  279. assert item.status == "pending"
  280. assert item.waiting_reason == "P2S-8 is not accepting files — Bambuddy will retry automatically"
  281. @pytest.mark.asyncio
  282. async def test_the_printer_is_tried_again_once_the_backoff_ends(self, farm):
  283. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  284. scheduler = PrintScheduler()
  285. async with _scheduler(farm, _upload_refused_by(REFUSING_IP, HANDSHAKE), scheduler=scheduler):
  286. await scheduler.check_queue()
  287. retry_at = scheduler._upload_backoff[farm.ids.refusing]
  288. assert retry_at - time.monotonic() == pytest.approx(UPLOAD_FAILURE_BACKOFF_SECONDS, abs=5)
  289. # The printer recovered and the window has passed.
  290. scheduler._upload_backoff[farm.ids.refusing] = time.monotonic() - 1
  291. async with _scheduler(farm, AsyncMock(return_value=True), scheduler=scheduler):
  292. await scheduler.check_queue()
  293. assert (await _item(farm, item_id)).status == "printing"
  294. assert farm.ids.refusing not in scheduler._upload_backoff
  295. # ---------------------------------------------------------------------------
  296. # A printer that stays broken: retries thin out, and say so once
  297. # ---------------------------------------------------------------------------
  298. def _expire_backoff(scheduler: PrintScheduler, printer_id: int) -> None:
  299. """Jump past the printer's backoff window, as if the time had passed."""
  300. scheduler._upload_backoff[printer_id] = time.monotonic() - 1
  301. def _remaining(scheduler: PrintScheduler, printer_id: int) -> float:
  302. return scheduler._upload_backoff[printer_id] - time.monotonic()
  303. async def _finish(ctx, scheduler: PrintScheduler, item_id: int) -> None:
  304. """Mark a dispatched item's print done, so its printer can take the next one."""
  305. async with ctx.session_maker() as db:
  306. row = await db.get(PrintQueueItem, item_id)
  307. assert row.status == "printing"
  308. row.status = "completed"
  309. await db.commit()
  310. scheduler._release_dispatch_hold(row.printer_id)
  311. class TestAPrinterThatStaysBroken:
  312. @pytest.mark.asyncio
  313. async def test_each_refusal_in_a_row_doubles_the_wait_up_to_the_cap(self, farm):
  314. """#3210's printer refused for about 40 hours.
  315. At a flat five minutes that is ~480 retries, each one a preheat cycle
  316. where preheat is on, five connection attempts and a page of log.
  317. """
  318. await farm.add_item(printer_id=farm.ids.refusing)
  319. upload = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  320. scheduler = PrintScheduler()
  321. waits = []
  322. for _ in range(6):
  323. async with _scheduler(farm, upload, scheduler=scheduler):
  324. await scheduler.check_queue()
  325. waits.append(_remaining(scheduler, farm.ids.refusing))
  326. _expire_backoff(scheduler, farm.ids.refusing)
  327. expected = [300, 600, 1200, 2400, 3600, 3600]
  328. assert expected[0] == UPLOAD_FAILURE_BACKOFF_SECONDS
  329. assert expected[-1] == UPLOAD_FAILURE_BACKOFF_MAX_SECONDS
  330. assert waits == [pytest.approx(w, abs=5) for w in expected]
  331. @pytest.mark.asyncio
  332. async def test_a_successful_upload_resets_the_wait(self, farm):
  333. first = await farm.add_item(printer_id=farm.ids.refusing)
  334. refused = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  335. scheduler = PrintScheduler()
  336. for _ in range(3):
  337. async with _scheduler(farm, refused, scheduler=scheduler):
  338. await scheduler.check_queue()
  339. _expire_backoff(scheduler, farm.ids.refusing)
  340. async with _scheduler(farm, AsyncMock(return_value=True), scheduler=scheduler):
  341. await scheduler.check_queue()
  342. assert farm.ids.refusing not in scheduler._upload_refusals
  343. await _finish(farm, scheduler, first)
  344. # It breaks again later: back to the first window, not the fourth.
  345. await farm.add_item(printer_id=farm.ids.refusing)
  346. async with _scheduler(farm, refused, scheduler=scheduler, busy=set()):
  347. await scheduler.check_queue()
  348. assert _remaining(scheduler, farm.ids.refusing) == pytest.approx(UPLOAD_FAILURE_BACKOFF_SECONDS, abs=5)
  349. @pytest.mark.asyncio
  350. async def test_one_outage_sends_one_waiting_notification(self, farm):
  351. """Every retry clears the waiting reason and the next refusal sets it again.
  352. `hold_item` reads that as a new reason each time, and "Job Waiting" is
  353. on by default -- so without a guard a 40-hour outage notifies ~480 times.
  354. """
  355. await farm.add_item(printer_id=farm.ids.refusing)
  356. upload = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  357. scheduler = PrintScheduler()
  358. waiting = AsyncMock()
  359. for _ in range(4):
  360. # The pass that dispatches and is refused...
  361. async with _scheduler(farm, upload, scheduler=scheduler, waiting_notify=waiting):
  362. await scheduler.check_queue()
  363. # ...and the pass that holds the item while the printer waits.
  364. async with _scheduler(farm, upload, scheduler=scheduler, waiting_notify=waiting):
  365. await scheduler.check_queue()
  366. _expire_backoff(scheduler, farm.ids.refusing)
  367. assert waiting.await_count == 1
  368. assert "not accepting files" in waiting.await_args.kwargs["waiting_reason"]
  369. @pytest.mark.asyncio
  370. async def test_a_new_outage_after_a_recovery_notifies_again(self, farm):
  371. first = await farm.add_item(printer_id=farm.ids.refusing)
  372. refused = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  373. scheduler = PrintScheduler()
  374. waiting = AsyncMock()
  375. async def outage():
  376. async with _scheduler(farm, refused, scheduler=scheduler, waiting_notify=waiting):
  377. await scheduler.check_queue()
  378. async with _scheduler(farm, refused, scheduler=scheduler, waiting_notify=waiting):
  379. await scheduler.check_queue()
  380. _expire_backoff(scheduler, farm.ids.refusing)
  381. await outage()
  382. async with _scheduler(farm, AsyncMock(return_value=True), scheduler=scheduler, waiting_notify=waiting):
  383. await scheduler.check_queue()
  384. await _finish(farm, scheduler, first)
  385. await farm.add_item(printer_id=farm.ids.refusing)
  386. await outage()
  387. assert waiting.await_count == 2
  388. @pytest.mark.asyncio
  389. async def test_keep_warm_does_not_hold_a_bed_for_a_printer_in_backoff(self, farm):
  390. """There is no print coming to keep the bed warm for.
  391. The printer is in busy_printers and has a pending item, which is
  392. exactly what keep-warm looks for -- and each retry would restart its
  393. time cap, so the bed could stay hot for the whole outage.
  394. """
  395. await farm.add_item(printer_id=farm.ids.refusing)
  396. upload = _upload_refused_by(REFUSING_IP, HANDSHAKE)
  397. scheduler = PrintScheduler()
  398. async with _scheduler(farm, upload, scheduler=scheduler):
  399. await scheduler.check_queue()
  400. keep_warm = AsyncMock()
  401. async with _scheduler(farm, upload, scheduler=scheduler):
  402. with patch.object(scheduler, "_apply_keep_warm", keep_warm):
  403. await scheduler.check_queue()
  404. busy_seen = keep_warm.await_args.args[3]
  405. assert farm.ids.refusing not in busy_seen
  406. # ---------------------------------------------------------------------------
  407. # 452 is the card, not the network
  408. # ---------------------------------------------------------------------------
  409. class TestA452IsAStorageReply:
  410. def _upload_raising(self, error, tmp_path):
  411. local = tmp_path / "job.3mf"
  412. local.write_bytes(b"x" * 16)
  413. client = BambuFTPClient(REFUSING_IP, "12345678")
  414. client._ftp = MagicMock()
  415. client._ftp.transfercmd.side_effect = error
  416. assert client.upload_file(local, "/job.3mf") is False
  417. return client.last_failure
  418. def test_452_is_storage(self, tmp_path):
  419. """ftplib raises it as error_temp, but it says the card is full.
  420. Read as NETWORK it would be retried forever instead of failing with
  421. the advice to check the card.
  422. """
  423. import ftplib # nosec B402 -- tests construct real ftplib error types
  424. failure = self._upload_raising(ftplib.error_temp("452 Insufficient storage space."), tmp_path)
  425. assert failure.kind is FtpFailureKind.STORAGE
  426. assert failure.code == "452"
  427. def test_other_transient_replies_are_still_network(self, tmp_path):
  428. import ftplib # nosec B402 -- tests construct real ftplib error types
  429. failure = self._upload_raising(ftplib.error_temp("421 There are too many connections."), tmp_path)
  430. assert failure.kind is FtpFailureKind.NETWORK
  431. def test_a_socket_error_is_never_read_as_a_reply_code(self, tmp_path):
  432. failure = self._upload_raising(OSError("452 looks like a code but is not a reply"), tmp_path)
  433. assert failure.kind is FtpFailureKind.NETWORK
  434. # ---------------------------------------------------------------------------
  435. # #3409: a printer whose card refuses the file, or whose access code is wrong
  436. # ---------------------------------------------------------------------------
  437. STORAGE = FtpFailure(FtpFailureKind.STORAGE, "553 Could not create file.", "553")
  438. AUTH = FtpFailure(FtpFailureKind.AUTH, "530 Login incorrect.", "530")
  439. def _counting(upload):
  440. """*upload*, counting the calls that reached the refusing printer."""
  441. calls = []
  442. async def _upload(ip_address, *args, **kwargs):
  443. if ip_address == REFUSING_IP:
  444. calls.append(ip_address)
  445. return await upload(ip_address, *args, **kwargs)
  446. _upload.calls = calls
  447. return _upload
  448. class TestARefusedCard:
  449. @pytest.mark.asyncio
  450. async def test_jobs_pinned_to_the_printer_wait_instead_of_failing_one_by_one(self, farm):
  451. """#3409's shape: an H2D with an unusable USB stick, seven jobs failed within an hour."""
  452. ids = [await farm.add_item(printer_id=farm.ids.refusing) for _ in range(4)]
  453. upload = _counting(_upload_refused_by(REFUSING_IP, STORAGE))
  454. scheduler = PrintScheduler()
  455. for _ in range(4):
  456. async with _scheduler(farm, upload, scheduler=scheduler):
  457. await scheduler.check_queue()
  458. items = [await _item(farm, i) for i in ids]
  459. assert [i.status for i in items] == ["pending"] * 4, [(i.id, i.status, i.error_message) for i in items]
  460. assert len(upload.calls) == 1, "one refusal, then the printer is out of dispatch"
  461. assert items[0].waiting_reason == (
  462. "P2S-8 refused to store the file — check its SD card or USB drive. Bambuddy will retry automatically"
  463. )
  464. @pytest.mark.asyncio
  465. async def test_a_wrong_access_code_says_where_to_fix_it(self, farm):
  466. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  467. upload = _upload_refused_by(REFUSING_IP, AUTH)
  468. scheduler = PrintScheduler()
  469. for _ in range(2):
  470. async with _scheduler(farm, upload, scheduler=scheduler):
  471. await scheduler.check_queue()
  472. item = await _item(farm, item_id)
  473. assert item.status == "pending"
  474. assert "access code on the Printers page" in item.waiting_reason
  475. @pytest.mark.asyncio
  476. async def test_the_job_is_sent_once_the_card_is_back(self, farm):
  477. item_id = await farm.add_item(printer_id=farm.ids.refusing)
  478. scheduler = PrintScheduler()
  479. async with _scheduler(farm, _upload_refused_by(REFUSING_IP, STORAGE), scheduler=scheduler):
  480. await scheduler.check_queue()
  481. _expire_backoff(scheduler, farm.ids.refusing)
  482. async with _scheduler(farm, AsyncMock(return_value=True), scheduler=scheduler):
  483. await scheduler.check_queue()
  484. assert (await _item(farm, item_id)).status == "printing"
  485. assert farm.ids.refusing not in scheduler._upload_refusal_kind
  486. class TestAnyModelJobsMoveOn:
  487. @pytest.mark.asyncio
  488. async def test_the_job_goes_to_another_printer_of_the_model(self, farm):
  489. """ "Any H2D" means any: the refused job should not wait for the broken one."""
  490. item_id = await farm.add_item(target_model="P2S")
  491. upload = _upload_refused_by(REFUSING_IP, STORAGE)
  492. scheduler = PrintScheduler()
  493. # Only the refusing printer is free, so it gets the job and refuses it.
  494. async with _scheduler(farm, upload, scheduler=scheduler, busy={farm.ids.healthy}):
  495. await scheduler.check_queue()
  496. item = await _item(farm, item_id)
  497. assert item.status == "pending"
  498. assert item.printer_id is None, "back in the pool, not waiting on the refusing printer"
  499. # The healthy printer comes free.
  500. async with _scheduler(farm, upload, scheduler=scheduler):
  501. await scheduler.check_queue()
  502. item = await _item(farm, item_id)
  503. assert item.status == "printing"
  504. assert item.printer_id == farm.ids.healthy
  505. @pytest.mark.asyncio
  506. async def test_what_the_job_carries_for_any_printer_stays(self, farm):
  507. """Only the assignment goes; the next model assignment sorts out the rest, as for every model job."""
  508. item_id = await farm.add_item(target_model="P2S")
  509. async with farm.session_maker() as db:
  510. row = await db.get(PrintQueueItem, item_id)
  511. row.skip_filament_check = True
  512. row.nozzle_rack_choice = '{"0": 1}'
  513. row.nozzle_mapping = "[0, 1]"
  514. await db.commit()
  515. async with _scheduler(farm, _upload_refused_by(REFUSING_IP, STORAGE), busy={farm.ids.healthy}) as scheduler:
  516. await scheduler.check_queue()
  517. item = await _item(farm, item_id)
  518. assert item.printer_id is None
  519. assert item.skip_filament_check is True
  520. assert item.nozzle_rack_choice == '{"0": 1}'
  521. assert item.nozzle_mapping == "[0, 1]"
  522. @pytest.mark.asyncio
  523. async def test_the_released_job_says_why_rather_than_busy(self, farm):
  524. """With the refusing printer in backoff, "Busy: P2S-8" would read as printing."""
  525. item_id = await farm.add_item(target_model="P2S")
  526. upload = _upload_refused_by(REFUSING_IP, STORAGE)
  527. scheduler = PrintScheduler()
  528. waiting = AsyncMock()
  529. for _ in range(3):
  530. async with _scheduler(farm, upload, scheduler=scheduler, busy={farm.ids.healthy}, waiting_notify=waiting):
  531. await scheduler.check_queue()
  532. item = await _item(farm, item_id)
  533. assert item.waiting_reason == (
  534. "P2S-8 refused to store the file — check its SD card or USB drive. Bambuddy will retry automatically"
  535. " | Busy: P2S-9"
  536. )
  537. assert waiting.await_count == 1, "the refusal said it already; the row's reason adds nothing new"
  538. @pytest.mark.asyncio
  539. async def test_a_cancel_during_the_upload_is_not_undone(self, farm):
  540. item_id = await farm.add_item(target_model="P2S")
  541. async def upload(ip_address, *_args, **kwargs):
  542. async with farm.session_maker() as other:
  543. row = await other.get(PrintQueueItem, item_id)
  544. row.status = "cancelled"
  545. await other.commit()
  546. kwargs["failure"].failure = STORAGE
  547. return False
  548. async with _scheduler(farm, upload, busy={farm.ids.healthy}) as scheduler:
  549. await scheduler.check_queue()
  550. item = await _item(farm, item_id)
  551. assert item.status == "cancelled"
  552. assert item.printer_id == farm.ids.refusing, "a cancelled row is left as the cancel wrote it"
  553. @pytest.mark.asyncio
  554. async def test_a_released_job_still_says_why_once(self, farm):
  555. """Nothing waits on the printer to carry the notification, so the refusal sends it."""
  556. await farm.add_item(target_model="P2S")
  557. upload = _upload_refused_by(REFUSING_IP, STORAGE)
  558. scheduler = PrintScheduler()
  559. waiting = AsyncMock()
  560. for _ in range(3):
  561. async with _scheduler(farm, upload, scheduler=scheduler, busy={farm.ids.healthy}, waiting_notify=waiting):
  562. await scheduler.check_queue()
  563. _expire_backoff(scheduler, farm.ids.refusing)
  564. assert waiting.await_count == 1
  565. kwargs = waiting.await_args.kwargs
  566. assert "SD card or USB drive" in kwargs["waiting_reason"]
  567. assert kwargs["printer_id"] == farm.ids.refusing
  568. class TestNotifyingARun:
  569. @pytest.mark.asyncio
  570. async def test_a_run_that_turns_into_a_card_problem_says_so(self, farm):
  571. """ "Will retry automatically" asks nothing of anyone; a refused card does."""
  572. await farm.add_item(printer_id=farm.ids.refusing)
  573. scheduler = PrintScheduler()
  574. waiting = AsyncMock()
  575. for failure in (HANDSHAKE, FtpFailure(FtpFailureKind.COOLOFF, "cooloff"), STORAGE, STORAGE):
  576. async with _scheduler(
  577. farm, _upload_refused_by(REFUSING_IP, failure), scheduler=scheduler, waiting_notify=waiting
  578. ):
  579. await scheduler.check_queue()
  580. _expire_backoff(scheduler, farm.ids.refusing)
  581. reasons = [c.kwargs["waiting_reason"] for c in waiting.await_args_list]
  582. assert len(reasons) == 2, reasons
  583. assert "not accepting files" in reasons[0]
  584. assert "SD card or USB drive" in reasons[1]
  585. @pytest.mark.asyncio
  586. @pytest.mark.parametrize("target_model", [None, "P2S"], ids=["pinned", "any_model"])
  587. async def test_a_job_cancelled_during_the_upload_sends_none(self, farm, target_model):
  588. item_id = await farm.add_item(
  589. printer_id=farm.ids.refusing if target_model is None else None, target_model=target_model
  590. )
  591. async def upload(ip_address, *_args, **kwargs):
  592. async with farm.session_maker() as other:
  593. row = await other.get(PrintQueueItem, item_id)
  594. row.status = "cancelled"
  595. await other.commit()
  596. kwargs["failure"].failure = STORAGE
  597. return False
  598. waiting = AsyncMock()
  599. async with _scheduler(farm, upload, busy={farm.ids.healthy}, waiting_notify=waiting) as scheduler:
  600. await scheduler.check_queue()
  601. waiting.assert_not_awaited()
  602. assert farm.ids.refusing in scheduler._upload_backoff, "the printer still refused"
  603. class TestAFileNameNoCardCanHold:
  604. @pytest.mark.asyncio
  605. @pytest.mark.parametrize("target_model", [None, "P2S"], ids=["pinned", "any_model"])
  606. async def test_its_553_fails_the_job_and_leaves_the_printer_in_service(self, farm, target_model):
  607. """A ':' is refused by every card on every printer: waiting would block the queue for good."""
  608. bad = await farm.add_item(
  609. printer_id=farm.ids.refusing if target_model is None else None,
  610. target_model=target_model,
  611. filename="Bracket: v2.3mf",
  612. )
  613. upload = _upload_refused_by(REFUSING_IP, STORAGE)
  614. async with _scheduler(farm, upload, busy={farm.ids.healthy}) as scheduler:
  615. await scheduler.check_queue()
  616. item = await _item(farm, bad)
  617. assert item.status == "failed"
  618. assert "Rename the file" in item.error_message
  619. assert "contains invalid character: :" in item.error_message
  620. scheduler.failed_notify.assert_awaited_once()
  621. assert farm.ids.refusing not in scheduler._upload_backoff