test_scheduler_concurrent_dispatch.py 31 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724
  1. """Concurrent queue dispatch as a refillable upload pool (#2555, #2602).
  2. Reported first (#2555) as "prints are sent to the printer one by one, very
  3. slowly" on a 19-printer farm: ``check_queue`` awaited ``_start_print`` inline per
  4. item, and ``_start_print`` performs the FTP upload, so every printer queued
  5. behind every other printer's transfer. #2555 moved the uploads to a parallel
  6. ``asyncio.gather()`` — but that gather was *awaited before check_queue returned*,
  7. so the run loop stayed blocked until the slowest upload in the batch finished. On
  8. a 93-printer farm (#2602) a 513 s upload left 15 of 16 configured slots idle for
  9. 8.5 minutes while other printers came free.
  10. The uploads now run as independent background tasks tracked in
  11. ``scheduler._inflight``; each tick launches at most ``limit - len(_inflight)`` new
  12. ones and returns immediately, so a freed slot refills on the next fast tick.
  13. What must stay true:
  14. * Uploads to different printers overlap in time (the #2555 fix).
  15. * No more than ``queue_max_concurrent_uploads`` run at once — as a *pool*, across
  16. ticks, not just within one batch (#2602).
  17. * A freed slot is refilled by a later tick (#2602).
  18. * An item whose upload is in flight — and its printer — are excluded from the
  19. next pass, so a still-`pending` row is never dispatched twice (#2602).
  20. * check_queue returns *without* waiting for the uploads (#2602), reporting a
  21. productive/in-flight pass so ``run()`` re-checks on the fast interval.
  22. * Setting the cap to 1 restores serial behaviour; one printer failing must not
  23. cancel its siblings' in-flight uploads.
  24. Test model: the scheduler now launches uploads via ``spawn_background_task``, so
  25. the harness swaps in a real task-spawning shim and drains ``_inflight`` explicitly
  26. (inside the patched context, so the upload/session patches are still active while
  27. the pool workers run). ``_run_to_completion`` loops check_queue + drain to model
  28. the run loop draining a queue that exceeds the cap.
  29. """
  30. import asyncio
  31. from contextlib import ExitStack, asynccontextmanager
  32. from pathlib import Path
  33. from types import SimpleNamespace
  34. from unittest.mock import AsyncMock, MagicMock, patch
  35. import pytest
  36. from sqlalchemy import event, func, select
  37. from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine
  38. import backend.app.models # noqa: F401 - populate Base.metadata
  39. import backend.app.services.archive as archive_module
  40. import backend.app.services.print_scheduler as scheduler_module
  41. from backend.app.core.database import Base, _set_sqlite_pragmas
  42. from backend.app.models.archive import PrintArchive
  43. from backend.app.models.library import LibraryFile
  44. from backend.app.models.print_queue import PrintQueueItem
  45. from backend.app.models.printer import Printer
  46. from backend.app.models.settings import Settings
  47. from backend.app.services.print_scheduler import PrintScheduler
  48. UPLOAD_SECONDS = 0.15
  49. # Hard cap on assembling one batch, so a dispatch that has gone serial fails on
  50. # its peak assertion instead of hanging. See ``_UploadRecorder``.
  51. _BATCH_DEADLINE_SECONDS = 5.0
  52. def _test_engine(tmp_path):
  53. """An engine that gives every session its own connection.
  54. ``sqlite+aiosqlite:///:memory:`` is the obvious choice here and it is wrong:
  55. SQLAlchemy backs an in-memory SQLite with a ``StaticPool`` -- one DBAPI
  56. connection handed to every session, with nothing keeping them apart. That was
  57. harmless while ``check_queue`` awaited its uploads inline, because only one
  58. session was ever live. Under the pool model (#2602) the uploads run as
  59. concurrent tasks with a session each, so their transactions interleave on that
  60. single connection: a sibling session's ``close()`` rolls back another's
  61. flushed-but-uncommitted UPDATE -- rows read back ``pending`` although the log
  62. says ``Status set to 'printing'`` -- and a ``commit()`` landing while another
  63. session still holds a cursor raises "cannot commit transaction - SQL
  64. statements in progress". It failed on CI and passed locally purely on core
  65. count and interpreter version.
  66. A file gets ``AsyncAdaptedQueuePool`` and a connection per session, which is
  67. what the app runs with in production (``_resolve_pool_kwargs`` in
  68. ``backend/app/core/database.py``: pool_size 20, max_overflow 200).
  69. It also takes the app's own connect listener rather than a copy of it, so the
  70. file is opened exactly as the running system opens one: WAL instead of a
  71. whole-file DELETE journal, ``synchronous = NORMAL`` instead of an fsync per
  72. commit, and a 15 s busy timeout. Default SQLite settings would make a
  73. dispatch's preamble cost more than the upload it precedes, which is the
  74. difference between six uploads overlapping and four.
  75. """
  76. engine = create_async_engine(f"sqlite+aiosqlite:///{tmp_path / 'queue.db'}", echo=False)
  77. event.listen(engine.sync_engine, "connect", _set_sqlite_pragmas)
  78. return engine
  79. @pytest.fixture
  80. async def farm(tmp_path):
  81. """Build a farm of N printers, each with one pending queue item."""
  82. engine = _test_engine(tmp_path)
  83. async with engine.begin() as conn:
  84. await conn.run_sync(Base.metadata.create_all)
  85. session_maker = async_sessionmaker(engine, expire_on_commit=False)
  86. async def make_farm(printer_count: int, *, max_concurrent: int | None = None):
  87. base_dir = tmp_path / "farm"
  88. (base_dir / "archives").mkdir(parents=True, exist_ok=True)
  89. async with session_maker() as db:
  90. if max_concurrent is not None:
  91. db.add(Settings(key="queue_max_concurrent_uploads", value=str(max_concurrent)))
  92. printer_ids = []
  93. for n in range(printer_count):
  94. archive_rel = Path("archives") / f"job-{n}.3mf"
  95. (base_dir / archive_rel).write_bytes(b"archive payload")
  96. printer = Printer(
  97. name=f"Printer {n}",
  98. serial_number=f"SERIAL-{n}",
  99. ip_address=f"10.0.0.{n + 1}",
  100. access_code="access-code",
  101. model="A1",
  102. )
  103. db.add(printer)
  104. await db.flush()
  105. archive = PrintArchive(
  106. printer_id=printer.id,
  107. filename=f"job-{n}.3mf",
  108. file_path=str(archive_rel),
  109. file_size=15,
  110. print_time_seconds=120,
  111. status="completed",
  112. )
  113. db.add(archive)
  114. await db.flush()
  115. db.add(
  116. PrintQueueItem(
  117. printer_id=printer.id,
  118. archive_id=archive.id,
  119. status="pending",
  120. position=n,
  121. )
  122. )
  123. printer_ids.append(printer.id)
  124. await db.commit()
  125. return SimpleNamespace(
  126. session_maker=session_maker,
  127. base_dir=base_dir,
  128. printer_ids=printer_ids,
  129. )
  130. try:
  131. yield make_farm
  132. finally:
  133. await engine.dispose()
  134. class _UploadRecorder:
  135. """Stands in for ``upload_file_async``; records overlap.
  136. Each call stays open for a while, so genuinely concurrent uploads have
  137. overlapping lifetimes. ``peak`` is the high-water mark of simultaneous
  138. in-flight uploads — the number the pool cap turns on.
  139. How long a call stays open is the whole difficulty. ``peak == 6`` is really
  140. the claim that the sixth dispatch reaches its upload before the first one
  141. finishes, and the dispatches do not arrive together: each runs a preamble of
  142. database work first. Measured here that spread is ~14 ms; on a CI runner it
  143. passed 150 ms, and a fixed 0.15 s sleep then recorded a peak of 4 out of 6
  144. for a scheduler that was dispatching all six correctly. Padding the sleep
  145. only moves the threshold and slows every test that uses it.
  146. With ``assemble=True`` the call instead holds until every upload the pass
  147. launched has arrived — ``scheduler._inflight`` is populated synchronously at
  148. launch (see ``_launch_uploads``), so its length is the batch size and
  149. ``in_flight`` catching up to it means the batch is assembled. That is the
  150. property the peak assertions are about, stated directly and with no time in
  151. it, so machine speed cannot change the answer. It also ends sooner than the
  152. sleep it replaces. A batch that never assembles is the failure being looked
  153. for, and ``_BATCH_DEADLINE_SECONDS`` bounds it: a serialized dispatch fails
  154. on the peak assertion rather than hanging until the pytest timeout.
  155. Without ``assemble`` — for the tests whose assertion is an upper bound, where
  156. nothing has to assemble — the call just sleeps.
  157. """
  158. def __init__(self, *, fail_for_ip: str | None = None, assemble: bool = False):
  159. self.in_flight = 0
  160. self.peak = 0
  161. self.order: list[str] = []
  162. self.fail_for_ip = fail_for_ip
  163. self.assemble = assemble
  164. self.scheduler = None # bound by _scheduler_ctx when assemble is on
  165. self._deadline = 0.0
  166. self._assembled = False
  167. async def _await_batch(self):
  168. """Hold until every upload this pass launched has reached this point.
  169. ``_assembled`` latches, and has to: the moment the batch is complete its
  170. members start leaving and ``_inflight`` starts emptying, so a member
  171. still comparing the two counts would find them equal for the wrong
  172. reason. Latching releases the batch as one. It is cleared by the next
  173. batch's first arrival, since ``in_flight`` returns to 0 between ticks.
  174. """
  175. loop = asyncio.get_running_loop()
  176. if self.in_flight == 1:
  177. self._deadline = loop.time() + _BATCH_DEADLINE_SECONDS
  178. self._assembled = False
  179. while not self._assembled:
  180. if self.in_flight >= len(self.scheduler._inflight) or loop.time() >= self._deadline:
  181. self._assembled = True
  182. return
  183. await asyncio.sleep(0.005)
  184. async def __call__(self, ip_address, access_code, local_path, remote_path, **kwargs):
  185. self.in_flight += 1
  186. self.peak = max(self.peak, self.in_flight)
  187. self.order.append(ip_address)
  188. try:
  189. if self.assemble:
  190. await self._await_batch()
  191. else:
  192. await asyncio.sleep(UPLOAD_SECONDS)
  193. if self.fail_for_ip is not None and ip_address == self.fail_for_ip:
  194. raise OSError(f"simulated FTP failure for {ip_address}")
  195. return True
  196. finally:
  197. self.in_flight -= 1
  198. @asynccontextmanager
  199. async def _scheduler_ctx(ctx, upload, job_started=None):
  200. """Yield a scheduler with all I/O patched, and a real task-spawning shim.
  201. The scheduler launches uploads through ``spawn_background_task`` (#2602), so
  202. the harness gives it a real ``create_task`` shim rather than the no-op mock
  203. used before — otherwise the pool workers never run and rows stay ``pending``.
  204. The watchdog (also spawned per dispatch) is stubbed so it doesn't poll for
  205. the whole test. Drain ``_inflight`` *inside* this context so the workers run
  206. while the upload/session patches are still active.
  207. """
  208. scheduler = PrintScheduler()
  209. upload.scheduler = scheduler
  210. job_started = job_started or AsyncMock()
  211. def _real_spawn(coro, *, name=None):
  212. return asyncio.create_task(coro, name=name)
  213. patches = [
  214. patch.object(scheduler_module.settings, "base_dir", ctx.base_dir),
  215. patch.object(archive_module.settings, "base_dir", ctx.base_dir),
  216. patch.object(archive_module.settings, "archive_dir", ctx.base_dir / "archive"),
  217. patch("backend.app.services.print_scheduler.async_session", ctx.session_maker),
  218. patch("backend.app.core.database.async_session", ctx.session_maker),
  219. patch("backend.app.services.print_scheduler.printer_manager.is_connected", MagicMock(return_value=True)),
  220. patch("backend.app.services.print_scheduler.printer_manager.get_status", MagicMock(return_value=None)),
  221. patch("backend.app.services.print_scheduler.printer_manager.start_print", MagicMock(return_value=True)),
  222. patch("backend.app.services.print_scheduler.printer_manager.set_awaiting_plate_clear", MagicMock()),
  223. patch("backend.app.services.print_scheduler.upload_file_async", upload),
  224. patch("backend.app.services.print_scheduler.delete_file_async", AsyncMock(return_value=True)),
  225. patch(
  226. "backend.app.services.print_scheduler.get_ftp_retry_settings",
  227. AsyncMock(return_value=(False, 0, 0, 1.0)),
  228. ),
  229. patch("backend.app.services.print_scheduler.cache_3mf_download", MagicMock()),
  230. patch("backend.app.services.print_scheduler.spawn_background_task", _real_spawn),
  231. patch("backend.app.services.notification_service.notification_service.on_queue_job_started", job_started),
  232. patch("backend.app.services.notification_service.notification_service.on_queue_job_failed", AsyncMock()),
  233. patch("backend.app.services.mqtt_relay.mqtt_relay.on_queue_job_started", AsyncMock()),
  234. patch.object(scheduler, "_is_printer_idle", MagicMock(return_value=True)),
  235. patch.object(scheduler, "_propagate_owner_to_printer_manager", AsyncMock()),
  236. patch.object(scheduler, "_power_off_if_needed", AsyncMock()),
  237. patch.object(scheduler, "_preheat_and_soak", AsyncMock()),
  238. patch.object(scheduler, "_check_auto_drying", AsyncMock()),
  239. patch.object(scheduler, "_watchdog_print_start", AsyncMock()),
  240. ]
  241. with ExitStack() as stack:
  242. for patcher in patches:
  243. stack.enter_context(patcher)
  244. yield scheduler
  245. async def _drain(scheduler):
  246. """Run the currently in-flight pool workers to completion."""
  247. tasks = [task for (task, _pid) in scheduler._inflight.values()]
  248. if tasks:
  249. await asyncio.gather(*tasks, return_exceptions=True)
  250. async def _run_check_queue(ctx, upload, job_started=None, *, drain=True):
  251. """Run one check_queue pass; by default also drain the launched uploads.
  252. Returns the check_queue result (True if the pass was productive / has uploads
  253. still in flight).
  254. """
  255. async with _scheduler_ctx(ctx, upload, job_started) as scheduler:
  256. result = await scheduler.check_queue()
  257. if drain:
  258. await _drain(scheduler)
  259. return result
  260. async def _run_to_completion(ctx, upload, job_started=None, *, max_ticks: int = 50) -> int:
  261. """Model the run loop: check_queue + drain until the queue is empty.
  262. Draining fully between ticks makes each tick a fresh batch of at most the cap,
  263. which is enough to prove the cap holds across the whole drain and every item
  264. eventually goes out. Returns the number of ticks it took.
  265. """
  266. ticks = 0
  267. async with _scheduler_ctx(ctx, upload, job_started) as scheduler:
  268. while ticks < max_ticks:
  269. await scheduler.check_queue()
  270. await _drain(scheduler)
  271. ticks += 1
  272. if await _pending_count(ctx) == 0 and not scheduler._inflight:
  273. break
  274. return ticks
  275. async def _statuses(ctx):
  276. async with ctx.session_maker() as db:
  277. rows = (await db.execute(select(PrintQueueItem).order_by(PrintQueueItem.position))).scalars().all()
  278. return [r.status for r in rows]
  279. async def _pending_count(ctx) -> int:
  280. async with ctx.session_maker() as db:
  281. return await db.scalar(
  282. select(func.count()).select_from(PrintQueueItem).where(PrintQueueItem.status == "pending")
  283. )
  284. @pytest.mark.asyncio
  285. async def test_uploads_to_different_printers_overlap(farm):
  286. """The #2555 headline: six printers must not queue behind each other.
  287. Pre-fix this recorded peak == 1 no matter how many printers were pending.
  288. """
  289. ctx = await farm(6, max_concurrent=6)
  290. upload = _UploadRecorder(assemble=True)
  291. await _run_check_queue(ctx, upload)
  292. assert upload.peak == 6, (
  293. f"expected all 6 printers to be uploaded to concurrently, but the "
  294. f"high-water mark was {upload.peak} — uploads are still serialized"
  295. )
  296. assert await _statuses(ctx) == ["printing"] * 6
  297. @pytest.mark.asyncio
  298. async def test_pool_cap_holds_across_refills(farm):
  299. """Eight pending printers, cap of 3 — never more than 3 uploads at once.
  300. Under the pool model (#2602) one tick launches at most 3; the queue drains
  301. over several ticks. The cap must hold across the *whole* drain, and every
  302. item must still go out.
  303. """
  304. ctx = await farm(8, max_concurrent=3)
  305. upload = _UploadRecorder(assemble=True)
  306. ticks = await _run_to_completion(ctx, upload)
  307. assert upload.peak == 3, f"cap of 3 not honoured across the drain — peak was {upload.peak}"
  308. assert len(upload.order) == 8, "every pending item must still be dispatched, just not all at once"
  309. assert await _statuses(ctx) == ["printing"] * 8
  310. assert ticks >= 3, "8 items at a cap of 3 must take at least 3 ticks to drain"
  311. @pytest.mark.asyncio
  312. async def test_freed_slot_is_refilled_on_the_next_tick(farm):
  313. """The #2602 fix: a busy pool doesn't block, and a freed slot refills.
  314. Cap of 1, two printers. Tick 1 launches printer A. A second tick while A is
  315. still in flight must launch nothing (pool full) rather than block. Once A
  316. finishes, the next tick fills the freed slot with printer B.
  317. """
  318. ctx = await farm(2, max_concurrent=1)
  319. upload = _UploadRecorder()
  320. async with _scheduler_ctx(ctx, upload) as scheduler:
  321. # Tick 1: one slot, one launch. Don't drain — A is now "in flight".
  322. assert await scheduler.check_queue() is True
  323. assert len(scheduler._inflight) == 1
  324. # Tick 2 while A is in flight: pool full → no new launch, no blocking.
  325. assert await scheduler.check_queue() is True
  326. assert len(scheduler._inflight) == 1, "a full pool must not launch a second upload"
  327. # A completes, freeing the slot.
  328. await _drain(scheduler)
  329. assert not scheduler._inflight
  330. # Tick 3: the freed slot is refilled with the second printer.
  331. assert await scheduler.check_queue() is True
  332. assert len(scheduler._inflight) == 1
  333. await _drain(scheduler)
  334. assert await _statuses(ctx) == ["printing", "printing"]
  335. assert upload.peak == 1, "cap of 1 must never overlap two uploads"
  336. @pytest.mark.asyncio
  337. async def test_inflight_item_and_printer_are_excluded_from_reselection(farm):
  338. """A still-`pending` in-flight row must not be dispatched a second time (#2602).
  339. The row flips pending -> printing only after its upload completes, so the
  340. reservation that stops a fast tick re-dispatching it is the in-flight
  341. exclusion, not the DB status.
  342. """
  343. ctx = await farm(1, max_concurrent=4)
  344. upload = _UploadRecorder()
  345. async with _scheduler_ctx(ctx, upload) as scheduler:
  346. await scheduler.check_queue()
  347. inflight_before = set(scheduler._inflight)
  348. assert len(inflight_before) == 1
  349. # Second tick while the upload is in flight (row still pending): the item
  350. # and its printer must be excluded — no new task, pool unchanged.
  351. await scheduler.check_queue()
  352. assert set(scheduler._inflight) == inflight_before, "an in-flight item was re-selected"
  353. await _drain(scheduler)
  354. assert await _statuses(ctx) == ["printing"]
  355. assert len(upload.order) == 1, "the item must be uploaded exactly once, not twice"
  356. @pytest.mark.asyncio
  357. async def test_inflight_printer_is_kept_out_of_auto_drying(farm):
  358. """A printer with an upload in flight must not be auto-dried in the gap (#2602).
  359. Once check_queue returns while the upload runs, the only pending row is the
  360. in-flight one — so the pass takes the "no dispatchable items" path. That path
  361. must still exclude the in-flight printer from auto-drying, because its print
  362. is imminent (the row flips to printing the moment the upload finishes).
  363. """
  364. ctx = await farm(1, max_concurrent=4)
  365. printer_id = ctx.printer_ids[0]
  366. upload = _UploadRecorder()
  367. async with _scheduler_ctx(ctx, upload) as scheduler:
  368. await scheduler.check_queue() # launch the only item; now in flight
  369. scheduler._check_auto_drying.reset_mock()
  370. # Second tick: the sole pending row is in flight, so this hits the
  371. # empty-items path. It must report the in-flight printer as busy.
  372. result = await scheduler.check_queue()
  373. assert result is True, "in-flight uploads keep the loop on the fast interval"
  374. assert scheduler._check_auto_drying.await_count == 1
  375. busy_arg = scheduler._check_auto_drying.await_args.args[2]
  376. assert printer_id in busy_arg, "the in-flight printer must be excluded from auto-drying"
  377. await _drain(scheduler)
  378. @pytest.mark.asyncio
  379. async def test_limit_of_one_restores_serial_behaviour(farm):
  380. """An escape hatch for weak networks: 1 == one upload at a time."""
  381. ctx = await farm(4, max_concurrent=1)
  382. upload = _UploadRecorder()
  383. await _run_to_completion(ctx, upload)
  384. assert upload.peak == 1
  385. assert await _statuses(ctx) == ["printing"] * 4
  386. @pytest.mark.asyncio
  387. async def test_default_concurrency_applies_when_setting_absent(farm):
  388. """No Settings row (every existing install) must still dispatch in parallel.
  389. Default cap is 4.
  390. """
  391. ctx = await farm(5, max_concurrent=None)
  392. upload = _UploadRecorder(assemble=True)
  393. await _run_to_completion(ctx, upload)
  394. assert upload.peak == 4, f"expected the default cap of 4, got {upload.peak}"
  395. assert await _statuses(ctx) == ["printing"] * 5
  396. @pytest.mark.asyncio
  397. async def test_one_failing_upload_does_not_cancel_the_others(farm):
  398. """A dead printer must not take its siblings' in-flight uploads down with it.
  399. Each upload is an independent task, so one raising cannot cancel the others;
  400. _start_print marks that one item failed and the rest proceed.
  401. """
  402. ctx = await farm(4, max_concurrent=4)
  403. upload = _UploadRecorder(fail_for_ip="10.0.0.2") # printer index 1
  404. await _run_check_queue(ctx, upload)
  405. statuses = await _statuses(ctx)
  406. assert statuses[1] == "failed", "the unreachable printer's item should be marked failed"
  407. assert [s for i, s in enumerate(statuses) if i != 1] == ["printing"] * 3, (
  408. "the other three printers must have started despite the failure"
  409. )
  410. @pytest.mark.asyncio
  411. async def test_check_queue_reports_it_dispatched(farm):
  412. """A productive pass returns True so ``run()`` re-checks quickly (#2555)."""
  413. ctx = await farm(3, max_concurrent=3)
  414. dispatched = await _run_check_queue(ctx, _UploadRecorder())
  415. assert dispatched is True, "check_queue dispatched 3 items but did not report it"
  416. @pytest.mark.asyncio
  417. async def test_check_queue_reports_nothing_dispatched_when_empty(farm):
  418. """An empty queue returns False so ``run()`` falls back to the idle interval."""
  419. ctx = await farm(0, max_concurrent=3)
  420. dispatched = await _run_check_queue(ctx, _UploadRecorder())
  421. assert dispatched is False, "an empty pass must not trigger a fast re-tick"
  422. @pytest.mark.asyncio
  423. async def test_check_queue_returns_without_awaiting_the_uploads(farm):
  424. """The pass must return *before* the uploads finish (#2602).
  425. This is the inversion of the old contract: check_queue no longer blocks on
  426. the batch. It launches the uploads as tracked background tasks, leaves the
  427. rows ``pending`` (they flip to ``printing`` only when each upload completes),
  428. and returns True so the run loop keeps ticking fast while they drain.
  429. """
  430. ctx = await farm(3, max_concurrent=3)
  431. # Not assembling: this test reads the rows while the uploads are open, and
  432. # an assembled batch releases as soon as it is complete, which would let the
  433. # dispatches flip those rows to 'printing' mid-assertion.
  434. upload = _UploadRecorder()
  435. async with _scheduler_ctx(ctx, upload) as scheduler:
  436. result = await scheduler.check_queue()
  437. # Uploads are tracked but have not been awaited: rows are still pending.
  438. assert result is True
  439. assert len(scheduler._inflight) == 3
  440. assert await _statuses(ctx) == ["pending"] * 3
  441. await _drain(scheduler)
  442. assert await _statuses(ctx) == ["printing"] * 3
  443. assert upload.peak == 3
  444. class TestSharedLibraryRow:
  445. """Dispatching in parallel means two items can reach the same library row at
  446. the same time — impossible when dispatch was serial.
  447. Only the ``cleanup_library_after_dispatch`` flow (printer-card "upload and
  448. print") *mutates* that row: it deletes it and unlinks the 3MF once the print
  449. is away. Two of those against one row would race. An ordinary library print
  450. only reads the row, and the reporter's own batch was one File Manager file
  451. fanned out across his farm, so a blanket "never share a library row" guard
  452. would re-serialize the exact workload this exists to fix.
  453. """
  454. @staticmethod
  455. async def _library_farm(session_maker, tmp_path, printer_count, *, cleanup: bool):
  456. """One shared library file, one queue item per printer, all pointing at it."""
  457. base_dir = tmp_path / "libfarm"
  458. (base_dir / "library").mkdir(parents=True, exist_ok=True)
  459. shared = base_dir / "library" / "shared.3mf"
  460. shared.write_bytes(b"shared payload")
  461. async with session_maker() as db:
  462. db.add(Settings(key="queue_max_concurrent_uploads", value=str(printer_count)))
  463. library_file = LibraryFile(
  464. filename="shared.3mf",
  465. file_path=str(shared),
  466. file_type="3mf",
  467. file_size=shared.stat().st_size,
  468. )
  469. db.add(library_file)
  470. await db.flush()
  471. for n in range(printer_count):
  472. printer = Printer(
  473. name=f"Printer {n}",
  474. serial_number=f"LIB-SERIAL-{n}",
  475. ip_address=f"10.1.0.{n + 1}",
  476. access_code="access-code",
  477. model="A1",
  478. )
  479. db.add(printer)
  480. await db.flush()
  481. db.add(
  482. PrintQueueItem(
  483. printer_id=printer.id,
  484. library_file_id=library_file.id,
  485. cleanup_library_after_dispatch=cleanup,
  486. status="pending",
  487. position=n,
  488. )
  489. )
  490. await db.commit()
  491. return SimpleNamespace(session_maker=session_maker, base_dir=base_dir, printer_ids=None)
  492. @pytest.mark.asyncio
  493. async def test_plain_library_file_still_fans_out_in_parallel(self, tmp_path):
  494. """The reporter's actual workload: one File Manager file, four printers.
  495. Nothing here mutates the library row, so all four must upload at once.
  496. """
  497. engine = _test_engine(tmp_path)
  498. async with engine.begin() as conn:
  499. await conn.run_sync(Base.metadata.create_all)
  500. session_maker = async_sessionmaker(engine, expire_on_commit=False)
  501. try:
  502. ctx = await self._library_farm(session_maker, tmp_path, 4, cleanup=False)
  503. upload = _UploadRecorder(assemble=True)
  504. await _run_check_queue(ctx, upload)
  505. assert upload.peak == 4, f"a shared library file must not re-serialize the fan-out — peak was {upload.peak}"
  506. assert await _statuses(ctx) == ["printing"] * 4
  507. finally:
  508. await engine.dispose()
  509. @pytest.mark.asyncio
  510. async def test_cleanup_items_never_share_a_row_in_one_pass(self, tmp_path):
  511. """The mutating flow must be held to one dispatch per pass.
  512. Each of these deletes the library row and unlinks the 3MF when done.
  513. Exactly one may go per pass; the rest stay pending for a later one.
  514. """
  515. engine = _test_engine(tmp_path)
  516. async with engine.begin() as conn:
  517. await conn.run_sync(Base.metadata.create_all)
  518. session_maker = async_sessionmaker(engine, expire_on_commit=False)
  519. try:
  520. ctx = await self._library_farm(session_maker, tmp_path, 3, cleanup=True)
  521. upload = _UploadRecorder()
  522. await _run_check_queue(ctx, upload)
  523. assert upload.peak <= 1, (
  524. f"{upload.peak} dispatches raced over one consumable library row — "
  525. f"the loser's DELETE finds nothing and its 3MF can be unlinked mid-upload"
  526. )
  527. statuses = await _statuses(ctx)
  528. assert statuses.count("printing") == 1, "exactly one item should have gone out"
  529. assert statuses.count("pending") == 2, "the rest must stay queued, not fail"
  530. finally:
  531. await engine.dispose()
  532. @pytest.mark.asyncio
  533. async def test_library_print_without_a_parseable_print_time_does_not_crash(tmp_path):
  534. """Regression: `_start_print` read `library_file.print_time_seconds`, a column
  535. LibraryFile does not have.
  536. It only fired when the archive carried no print time — a plain .gcode, or a 3MF
  537. the parser could not read — and it fired *after* the printer had been sent the
  538. job. The started-notification was lost and the AttributeError unwound the
  539. dispatch. Two printers here: if the first one's dispatch blows up, the second
  540. must still go out.
  541. """
  542. engine = _test_engine(tmp_path)
  543. async with engine.begin() as conn:
  544. await conn.run_sync(Base.metadata.create_all)
  545. session_maker = async_sessionmaker(engine, expire_on_commit=False)
  546. try:
  547. base_dir = tmp_path / "nolibtime"
  548. (base_dir / "library").mkdir(parents=True, exist_ok=True)
  549. async with session_maker() as db:
  550. db.add(Settings(key="queue_max_concurrent_uploads", value="2"))
  551. for n in range(2):
  552. src = base_dir / "library" / f"job-{n}.gcode"
  553. src.write_bytes(b"G28\n")
  554. lib = LibraryFile(
  555. filename=f"job-{n}.gcode",
  556. file_path=str(src),
  557. file_type="gcode",
  558. file_size=src.stat().st_size,
  559. )
  560. db.add(lib)
  561. printer = Printer(
  562. name=f"Printer {n}",
  563. serial_number=f"NT-{n}",
  564. ip_address=f"10.2.0.{n + 1}",
  565. access_code="access-code",
  566. model="A1",
  567. )
  568. db.add(printer)
  569. await db.flush()
  570. db.add(
  571. PrintQueueItem(
  572. printer_id=printer.id,
  573. library_file_id=lib.id,
  574. status="pending",
  575. position=n,
  576. print_time_seconds=None, # nothing cached either — the crashing shape
  577. )
  578. )
  579. await db.commit()
  580. ctx = SimpleNamespace(session_maker=session_maker, base_dir=base_dir, printer_ids=None)
  581. job_started = AsyncMock()
  582. await _run_check_queue(ctx, _UploadRecorder(), job_started=job_started)
  583. assert await _statuses(ctx) == ["printing", "printing"]
  584. assert job_started.await_count == 2, (
  585. "the job-started notification was lost — _start_print raised after the "
  586. "printer had already been sent the job"
  587. )
  588. finally:
  589. await engine.dispose()