test_scheduler_scheduled_drying.py 32 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768
  1. """Tests for PrintScheduler scheduled-drying dispatch (#2638)."""
  2. from datetime import datetime, timedelta, timezone
  3. from unittest.mock import AsyncMock, MagicMock, patch
  4. import pytest
  5. from sqlalchemy import select
  6. from backend.app.models.scheduled_drying import ScheduledDrying
  7. from backend.app.services.print_scheduler import (
  8. SCHEDULED_DRYING_PRUNE_INTERVAL_SECONDS,
  9. SCHEDULED_DRYING_RETENTION_DAYS,
  10. PrintScheduler,
  11. )
  12. def _utcnow_naive() -> datetime:
  13. return datetime.now(timezone.utc).replace(tzinfo=None)
  14. # Above the X1C drying minimum, so the shared preflight lets dispatch through.
  15. DRYING_CAPABLE_FIRMWARE = "01.09.00.00"
  16. def _mock_state(ams_id=0, dry_time=0, dry_sf_reason=None, firmware=DRYING_CAPABLE_FIRMWARE):
  17. state = MagicMock()
  18. state.firmware_version = firmware
  19. state.raw_data = {"ams": [{"id": ams_id, "dry_time": dry_time, "dry_sf_reason": dry_sf_reason or []}]}
  20. return state
  21. async def _make_row(db_session, printer_factory, **kwargs):
  22. printer = await printer_factory()
  23. defaults = {"printer_id": printer.id, "ams_id": 0, "temp": 65, "duration_hours": 8}
  24. defaults.update(kwargs)
  25. row = ScheduledDrying(**defaults)
  26. db_session.add(row)
  27. await db_session.commit()
  28. await db_session.refresh(row)
  29. return row
  30. @pytest.fixture
  31. def scheduler():
  32. return PrintScheduler()
  33. @pytest.mark.asyncio
  34. async def test_future_start_after_not_dispatched(scheduler, db_session, printer_factory):
  35. row = await _make_row(db_session, printer_factory, start_after=_utcnow_naive() + timedelta(hours=2))
  36. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  37. await scheduler._check_scheduled_dryings(db_session)
  38. mock_pm.send_drying_command.assert_not_called()
  39. await db_session.refresh(row)
  40. assert row.status == "pending"
  41. @pytest.mark.asyncio
  42. async def test_due_row_dispatches_and_goes_running(scheduler, db_session, printer_factory):
  43. row = await _make_row(
  44. db_session, printer_factory, start_after=_utcnow_naive() - timedelta(minutes=1), filament="PETG"
  45. )
  46. with (
  47. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  48. patch.object(scheduler, "_is_printer_idle", return_value=True),
  49. ):
  50. mock_pm.get_status.return_value = _mock_state()
  51. mock_pm.send_drying_command.return_value = True
  52. await scheduler._check_scheduled_dryings(db_session)
  53. mock_pm.send_drying_command.assert_called_once_with(
  54. row.printer_id, 0, 65, 8, mode=1, filament="PETG", rotate_tray=False
  55. )
  56. await db_session.refresh(row)
  57. assert row.status == "running"
  58. assert row.started_at is not None
  59. assert scheduler._drying_in_progress.get(row.printer_id)
  60. @pytest.mark.asyncio
  61. async def test_null_start_after_dispatches_immediately(scheduler, db_session, printer_factory):
  62. row = await _make_row(db_session, printer_factory, start_after=None)
  63. with (
  64. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  65. patch.object(scheduler, "_is_printer_idle", return_value=True),
  66. ):
  67. mock_pm.get_status.return_value = _mock_state()
  68. mock_pm.send_drying_command.return_value = True
  69. await scheduler._check_scheduled_dryings(db_session)
  70. await db_session.refresh(row)
  71. assert row.status == "running"
  72. @pytest.mark.asyncio
  73. async def test_busy_printer_stays_pending_with_reason(scheduler, db_session, printer_factory):
  74. row = await _make_row(db_session, printer_factory, start_after=None)
  75. with (
  76. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  77. patch.object(scheduler, "_is_printer_idle", return_value=False),
  78. ):
  79. mock_pm.get_status.return_value = _mock_state()
  80. await scheduler._check_scheduled_dryings(db_session)
  81. mock_pm.send_drying_command.assert_not_called()
  82. await db_session.refresh(row)
  83. assert row.status == "pending"
  84. assert row.waiting_reason == "printer_busy"
  85. @pytest.mark.asyncio
  86. async def test_offline_printer_stays_pending(scheduler, db_session, printer_factory):
  87. row = await _make_row(db_session, printer_factory, start_after=None)
  88. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  89. mock_pm.get_status.return_value = None
  90. await scheduler._check_scheduled_dryings(db_session)
  91. await db_session.refresh(row)
  92. assert row.status == "pending"
  93. assert row.waiting_reason == "printer_offline"
  94. @pytest.mark.asyncio
  95. async def test_ams_blocked_stays_pending(scheduler, db_session, printer_factory):
  96. row = await _make_row(db_session, printer_factory, start_after=None)
  97. with (
  98. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  99. patch.object(scheduler, "_is_printer_idle", return_value=True),
  100. ):
  101. mock_pm.get_status.return_value = _mock_state(dry_sf_reason=[2])
  102. await scheduler._check_scheduled_dryings(db_session)
  103. mock_pm.send_drying_command.assert_not_called()
  104. await db_session.refresh(row)
  105. assert row.status == "pending"
  106. assert row.waiting_reason == "ams_blocked"
  107. @pytest.mark.asyncio
  108. async def test_retract_block_gets_its_own_waiting_reason(scheduler, db_session, printer_factory):
  109. """Code 3 is user-actionable (retract the filament), so it says so rather
  110. than bucketing into the generic blocked message.
  111. """
  112. row = await _make_row(db_session, printer_factory, start_after=None)
  113. with (
  114. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  115. patch.object(scheduler, "_is_printer_idle", return_value=True),
  116. ):
  117. mock_pm.get_status.return_value = _mock_state(dry_sf_reason=[3])
  118. await scheduler._check_scheduled_dryings(db_session)
  119. mock_pm.send_drying_command.assert_not_called()
  120. await db_session.refresh(row)
  121. assert row.status == "pending"
  122. assert row.waiting_reason == "ams_retract_filament"
  123. @pytest.mark.asyncio
  124. async def test_power_block_outranks_retract(scheduler, db_session, printer_factory):
  125. """Both blocking at once: power is the one that has to be fixed first."""
  126. row = await _make_row(db_session, printer_factory, start_after=None)
  127. with (
  128. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  129. patch.object(scheduler, "_is_printer_idle", return_value=True),
  130. ):
  131. mock_pm.get_status.return_value = _mock_state(dry_sf_reason=[3, 8])
  132. await scheduler._check_scheduled_dryings(db_session)
  133. await db_session.refresh(row)
  134. assert row.waiting_reason == "ams_power_required"
  135. @pytest.mark.asyncio
  136. @pytest.mark.parametrize("code", [1, 8])
  137. async def test_power_block_gets_its_own_waiting_reason(scheduler, db_session, printer_factory, code):
  138. """A run the user has to unblock says so, rather than waiting silently."""
  139. row = await _make_row(db_session, printer_factory, start_after=None)
  140. with (
  141. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  142. patch.object(scheduler, "_is_printer_idle", return_value=True),
  143. ):
  144. mock_pm.get_status.return_value = _mock_state(dry_sf_reason=[code])
  145. await scheduler._check_scheduled_dryings(db_session)
  146. mock_pm.send_drying_command.assert_not_called()
  147. await db_session.refresh(row)
  148. assert row.status == "pending"
  149. assert row.waiting_reason == "ams_power_required"
  150. @pytest.mark.asyncio
  151. async def test_screen_only_model_fails_instead_of_dispatching(scheduler, db_session, printer_factory):
  152. """A P1S acks the publish and ignores it; dispatching would silently self-cancel."""
  153. printer = await printer_factory(model="P1S")
  154. row = ScheduledDrying(printer_id=printer.id, ams_id=0, temp=65, duration_hours=8)
  155. db_session.add(row)
  156. await db_session.commit()
  157. with (
  158. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  159. patch.object(scheduler, "_is_printer_idle", return_value=True),
  160. ):
  161. mock_pm.get_status.return_value = _mock_state()
  162. await scheduler._check_scheduled_dryings(db_session)
  163. mock_pm.send_drying_command.assert_not_called()
  164. await db_session.refresh(row)
  165. assert row.status == "failed"
  166. assert row.error_message
  167. # The code the card translates; error_message stays English for the API.
  168. assert row.error_code == "screen_only"
  169. assert row.completed_at is not None
  170. @pytest.mark.asyncio
  171. async def test_firmware_below_minimum_fails(scheduler, db_session, printer_factory):
  172. row = await _make_row(db_session, printer_factory, start_after=None)
  173. with (
  174. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  175. patch.object(scheduler, "_is_printer_idle", return_value=True),
  176. ):
  177. mock_pm.get_status.return_value = _mock_state(firmware="01.05.00.00")
  178. await scheduler._check_scheduled_dryings(db_session)
  179. mock_pm.send_drying_command.assert_not_called()
  180. await db_session.refresh(row)
  181. assert row.status == "failed"
  182. assert row.error_message
  183. assert row.error_code == "unsupported"
  184. assert row.completed_at is not None
  185. @pytest.mark.asyncio
  186. async def test_empty_filament_backfills_from_loaded_tray(scheduler, db_session, printer_factory):
  187. """Matches the immediate endpoint, which sends the loaded type rather than PLA."""
  188. row = await _make_row(db_session, printer_factory, start_after=None, filament="")
  189. state = _mock_state()
  190. state.raw_data["ams"][0]["tray"] = [{"tray_type": ""}, {"tray_type": "PETG"}]
  191. with (
  192. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  193. patch.object(scheduler, "_is_printer_idle", return_value=True),
  194. ):
  195. mock_pm.get_status.return_value = state
  196. mock_pm.send_drying_command.return_value = True
  197. await scheduler._check_scheduled_dryings(db_session)
  198. assert mock_pm.send_drying_command.call_args.kwargs["filament"] == "PETG"
  199. await db_session.refresh(row)
  200. assert row.filament == "PETG"
  201. @pytest.mark.asyncio
  202. async def test_empty_filament_falls_back_to_pla(scheduler, db_session, printer_factory):
  203. await _make_row(db_session, printer_factory, start_after=None, filament="")
  204. with (
  205. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  206. patch.object(scheduler, "_is_printer_idle", return_value=True),
  207. ):
  208. mock_pm.get_status.return_value = _mock_state()
  209. mock_pm.send_drying_command.return_value = True
  210. await scheduler._check_scheduled_dryings(db_session)
  211. assert mock_pm.send_drying_command.call_args.kwargs["filament"] == "PLA"
  212. @pytest.mark.asyncio
  213. async def test_finished_rows_pruned_after_retention(scheduler, db_session, printer_factory):
  214. printer = await printer_factory()
  215. stale = ScheduledDrying(
  216. printer_id=printer.id,
  217. ams_id=0,
  218. temp=65,
  219. duration_hours=8,
  220. status="completed",
  221. completed_at=_utcnow_naive() - timedelta(days=SCHEDULED_DRYING_RETENTION_DAYS + 1),
  222. )
  223. recent = ScheduledDrying(
  224. printer_id=printer.id,
  225. ams_id=0,
  226. temp=65,
  227. duration_hours=8,
  228. status="cancelled",
  229. completed_at=_utcnow_naive() - timedelta(hours=1),
  230. )
  231. db_session.add_all([stale, recent])
  232. await db_session.commit()
  233. with patch("backend.app.services.print_scheduler.printer_manager"):
  234. await scheduler._check_scheduled_dryings(db_session)
  235. remaining = (await db_session.execute(select(ScheduledDrying.id))).scalars().all()
  236. assert stale.id not in remaining
  237. assert recent.id in remaining
  238. @pytest.mark.asyncio
  239. async def test_prune_does_not_run_on_every_pass(scheduler, db_session, printer_factory):
  240. """The prune is throttled, because issuing the DELETE is what starts a
  241. write transaction and this method runs every 3s while the queue dispatches.
  242. Rows only become prunable a week after they finish, so nothing is lost by
  243. waiting an hour to reap them."""
  244. printer = await printer_factory()
  245. async def _stale_row() -> ScheduledDrying:
  246. row = ScheduledDrying(
  247. printer_id=printer.id,
  248. ams_id=0,
  249. temp=65,
  250. duration_hours=8,
  251. status="completed",
  252. completed_at=_utcnow_naive() - timedelta(days=SCHEDULED_DRYING_RETENTION_DAYS + 1),
  253. )
  254. db_session.add(row)
  255. await db_session.commit()
  256. await db_session.refresh(row)
  257. return row
  258. with patch("backend.app.services.print_scheduler.printer_manager"):
  259. # First pass after a restart always prunes, so rows left behind by the
  260. # process that died are still reaped.
  261. first = await _stale_row()
  262. await scheduler._check_scheduled_dryings(db_session)
  263. assert first.id not in (await db_session.execute(select(ScheduledDrying.id))).scalars().all()
  264. # A second pass moments later leaves an equally stale row alone.
  265. second = await _stale_row()
  266. await scheduler._check_scheduled_dryings(db_session)
  267. assert second.id in (await db_session.execute(select(ScheduledDrying.id))).scalars().all()
  268. # ...and reaps it once the interval has elapsed.
  269. scheduler._last_scheduled_drying_prune -= SCHEDULED_DRYING_PRUNE_INTERVAL_SECONDS
  270. await scheduler._check_scheduled_dryings(db_session)
  271. assert second.id not in (await db_session.execute(select(ScheduledDrying.id))).scalars().all()
  272. @pytest.mark.asyncio
  273. async def test_a_finished_run_releases_the_printer_without_auto_drying(scheduler, db_session, printer_factory):
  274. """_drying_in_progress must not outlive the run that set it.
  275. Auto-drying's _sync_drying_state() prunes that map, but it sits behind the
  276. enabled check, so on a default install (both auto-drying modes off) it never
  277. runs. Nothing else drops the entry unless a print is dispatched to the same
  278. printer, and a nightly off-peak dry with no printing in between is exactly
  279. the case this feature is for: the second night's run would sit on
  280. "already_drying" forever, and with queue_drying_block on the printer would
  281. stop taking prints as well.
  282. """
  283. row = await _make_row(
  284. db_session, printer_factory, start_after=_utcnow_naive() - timedelta(minutes=1), duration_hours=1
  285. )
  286. printer_id = row.printer_id
  287. with (
  288. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  289. patch.object(scheduler, "_is_printer_idle", return_value=True),
  290. ):
  291. mock_pm.get_status.return_value = _mock_state()
  292. mock_pm.send_drying_command.return_value = True
  293. await scheduler._check_scheduled_dryings(db_session)
  294. await db_session.refresh(row)
  295. assert row.status == "running"
  296. assert printer_id in scheduler._drying_in_progress
  297. # The firmware has stopped reporting a dry_time, well past the duration.
  298. row.started_at = _utcnow_naive() - timedelta(hours=2)
  299. await db_session.commit()
  300. with (
  301. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  302. patch.object(scheduler, "_is_printer_idle", return_value=True),
  303. ):
  304. mock_pm.get_status.return_value = _mock_state(dry_time=0)
  305. await scheduler._check_scheduled_dryings(db_session)
  306. await db_session.refresh(row)
  307. assert row.status == "completed"
  308. assert printer_id not in scheduler._drying_in_progress
  309. # And the next night's run still dispatches.
  310. tomorrow = ScheduledDrying(
  311. printer_id=printer_id,
  312. ams_id=0,
  313. temp=65,
  314. duration_hours=8,
  315. start_after=_utcnow_naive() - timedelta(minutes=1),
  316. )
  317. db_session.add(tomorrow)
  318. await db_session.commit()
  319. with (
  320. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  321. patch.object(scheduler, "_is_printer_idle", return_value=True),
  322. ):
  323. mock_pm.get_status.return_value = _mock_state()
  324. mock_pm.send_drying_command.return_value = True
  325. await scheduler._check_scheduled_dryings(db_session)
  326. await db_session.refresh(tomorrow)
  327. assert tomorrow.status == "running"
  328. assert tomorrow.waiting_reason is None
  329. @pytest.mark.asyncio
  330. async def test_a_route_cancel_releases_the_printer(scheduler, db_session, printer_factory):
  331. """The DELETE route flips the row to cancelled in the database and sends the
  332. stop, but knows nothing about the scheduler's in-memory map. The next pass
  333. has to notice the run is gone and release the printer, or it stays marked as
  334. drying until a restart."""
  335. row = await _make_row(db_session, printer_factory, start_after=_utcnow_naive() - timedelta(minutes=1))
  336. printer_id = row.printer_id
  337. with (
  338. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  339. patch.object(scheduler, "_is_printer_idle", return_value=True),
  340. ):
  341. mock_pm.get_status.return_value = _mock_state()
  342. mock_pm.send_drying_command.return_value = True
  343. await scheduler._check_scheduled_dryings(db_session)
  344. assert printer_id in scheduler._drying_in_progress
  345. # What DELETE /scheduled-dryings/{id} leaves behind.
  346. row.status = "cancelled"
  347. row.completed_at = _utcnow_naive()
  348. await db_session.commit()
  349. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  350. mock_pm.get_status.return_value = _mock_state()
  351. await scheduler._check_scheduled_dryings(db_session)
  352. assert printer_id not in scheduler._drying_in_progress
  353. assert printer_id not in scheduler._scheduled_drying_printer_ids
  354. @pytest.mark.asyncio
  355. async def test_running_completes_after_duration(scheduler, db_session, printer_factory):
  356. row = await _make_row(
  357. db_session,
  358. printer_factory,
  359. status="running",
  360. duration_hours=1,
  361. started_at=_utcnow_naive() - timedelta(minutes=58), # >= 90% of 1h
  362. )
  363. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  364. mock_pm.get_status.return_value = _mock_state(dry_time=0)
  365. await scheduler._check_scheduled_dryings(db_session)
  366. await db_session.refresh(row)
  367. assert row.status == "completed"
  368. assert row.completed_at is not None
  369. @pytest.mark.asyncio
  370. async def test_running_interrupted_by_print_requeues(scheduler, db_session, printer_factory):
  371. row = await _make_row(
  372. db_session,
  373. printer_factory,
  374. status="running",
  375. duration_hours=8,
  376. started_at=_utcnow_naive() - timedelta(minutes=30), # well past grace, far from done
  377. )
  378. with (
  379. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  380. patch.object(scheduler, "_is_printer_idle", return_value=False),
  381. ):
  382. mock_pm.get_status.return_value = _mock_state(dry_time=0)
  383. await scheduler._check_scheduled_dryings(db_session)
  384. await db_session.refresh(row)
  385. assert row.status == "pending"
  386. assert row.started_at is None
  387. assert row.waiting_reason == "interrupted"
  388. @pytest.mark.asyncio
  389. async def test_running_stopped_while_idle_cancels(scheduler, db_session, printer_factory):
  390. """A stop on an idle printer is deliberate; the row must not resurrect."""
  391. row = await _make_row(
  392. db_session,
  393. printer_factory,
  394. status="running",
  395. duration_hours=8,
  396. started_at=_utcnow_naive() - timedelta(minutes=30),
  397. )
  398. with (
  399. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  400. patch.object(scheduler, "_is_printer_idle", return_value=True),
  401. ):
  402. mock_pm.get_status.return_value = _mock_state(dry_time=0)
  403. await scheduler._check_scheduled_dryings(db_session)
  404. await db_session.refresh(row)
  405. assert row.status == "cancelled"
  406. assert row.completed_at is not None
  407. @pytest.mark.asyncio
  408. async def test_running_within_grace_untouched(scheduler, db_session, printer_factory):
  409. row = await _make_row(
  410. db_session,
  411. printer_factory,
  412. status="running",
  413. duration_hours=8,
  414. started_at=_utcnow_naive() - timedelta(seconds=30), # inside 120 s grace
  415. )
  416. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  417. mock_pm.get_status.return_value = _mock_state(dry_time=0)
  418. await scheduler._check_scheduled_dryings(db_session)
  419. await db_session.refresh(row)
  420. assert row.status == "running"
  421. @pytest.mark.asyncio
  422. async def test_scheduled_drying_survives_auto_drying_stop_all(scheduler, db_session, printer_factory):
  423. """Regression (#2638): a running scheduled drying must not be stopped or
  424. untracked by _check_auto_drying's stop-all branch, even in the default
  425. config where both auto-drying toggles are off. Before the fix, the two
  426. features co-owned _drying_in_progress and auto-drying would stop/pop any
  427. printer it didn't start drying on itself.
  428. """
  429. row = await _make_row(db_session, printer_factory, start_after=_utcnow_naive() - timedelta(minutes=1))
  430. with (
  431. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  432. patch.object(scheduler, "_is_printer_idle", return_value=True),
  433. ):
  434. mock_pm.get_status.return_value = _mock_state()
  435. mock_pm.send_drying_command.return_value = True
  436. await scheduler._check_scheduled_dryings(db_session)
  437. await db_session.refresh(row)
  438. assert row.status == "running"
  439. assert scheduler._drying_in_progress.get(row.printer_id)
  440. assert row.printer_id in scheduler._scheduled_drying_printer_ids
  441. mock_pm.reset_mock()
  442. with patch.object(scheduler, "_get_bool_setting", AsyncMock(return_value=False)):
  443. # Default config: queue_drying_enabled and ambient_drying_enabled both off.
  444. await scheduler._check_auto_drying(db_session, [], set())
  445. mock_pm.send_drying_command.assert_not_called()
  446. await db_session.refresh(row)
  447. assert row.status == "running"
  448. assert scheduler._drying_in_progress.get(row.printer_id)
  449. assert row.printer_id in scheduler._scheduled_drying_printer_ids
  450. @pytest.mark.asyncio
  451. async def test_second_pending_row_for_same_printer_does_not_dispatch(scheduler, db_session, printer_factory):
  452. """Regression (#2638): two pending rows for the same printer must not both
  453. dispatch in the same tick; the second should see the first's dispatch and
  454. stay pending.
  455. """
  456. printer = await printer_factory()
  457. past = _utcnow_naive() - timedelta(minutes=1)
  458. row1 = ScheduledDrying(printer_id=printer.id, ams_id=0, temp=65, duration_hours=8, start_after=past)
  459. row2 = ScheduledDrying(printer_id=printer.id, ams_id=0, temp=60, duration_hours=6, start_after=past)
  460. db_session.add_all([row1, row2])
  461. await db_session.commit()
  462. await db_session.refresh(row1)
  463. await db_session.refresh(row2)
  464. with (
  465. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  466. patch.object(scheduler, "_is_printer_idle", return_value=True),
  467. ):
  468. mock_pm.get_status.return_value = _mock_state()
  469. mock_pm.send_drying_command.return_value = True
  470. await scheduler._check_scheduled_dryings(db_session)
  471. mock_pm.send_drying_command.assert_called_once()
  472. await db_session.refresh(row1)
  473. await db_session.refresh(row2)
  474. # Ordered dispatch: same start_after, so the row created first wins.
  475. assert row1.status == "running"
  476. assert row2.status == "pending"
  477. assert row2.waiting_reason == "already_drying"
  478. @pytest.mark.asyncio
  479. async def test_earliest_start_after_dispatches_first(scheduler, db_session, printer_factory):
  480. """Two rows due on one printer: the earlier schedule starts, not an arbitrary one."""
  481. printer = await printer_factory()
  482. now = _utcnow_naive()
  483. later = ScheduledDrying(
  484. printer_id=printer.id, ams_id=0, temp=65, duration_hours=8, start_after=now - timedelta(minutes=1)
  485. )
  486. sooner = ScheduledDrying(
  487. printer_id=printer.id, ams_id=0, temp=60, duration_hours=6, start_after=now - timedelta(hours=3)
  488. )
  489. # Inserted later-first so row order alone cannot produce the right answer.
  490. db_session.add_all([later, sooner])
  491. await db_session.commit()
  492. await db_session.refresh(later)
  493. await db_session.refresh(sooner)
  494. with (
  495. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  496. patch.object(scheduler, "_is_printer_idle", return_value=True),
  497. ):
  498. mock_pm.get_status.return_value = _mock_state()
  499. mock_pm.send_drying_command.return_value = True
  500. await scheduler._check_scheduled_dryings(db_session)
  501. mock_pm.send_drying_command.assert_called_once_with(printer.id, 0, 60, 6, mode=1, filament="PLA", rotate_tray=False)
  502. await db_session.refresh(later)
  503. await db_session.refresh(sooner)
  504. assert sooner.status == "running"
  505. assert later.status == "pending"
  506. @pytest.mark.asyncio
  507. async def test_malformed_ams_id_does_not_throw_while_running(scheduler, db_session, printer_factory):
  508. """_update_running_scheduled_drying runs inside check_queue: a throw here
  509. would cost the whole pass, print dispatch included, on every tick.
  510. """
  511. row = await _make_row(
  512. db_session,
  513. printer_factory,
  514. status="running",
  515. started_at=_utcnow_naive() - timedelta(minutes=30),
  516. )
  517. state = MagicMock()
  518. state.firmware_version = DRYING_CAPABLE_FIRMWARE
  519. state.raw_data = {"ams": [{"id": "not-a-number", "dry_time": 120}]}
  520. with (
  521. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  522. patch.object(scheduler, "_is_printer_idle", return_value=False),
  523. ):
  524. mock_pm.get_status.return_value = state
  525. await scheduler._check_scheduled_dryings(db_session)
  526. # No matching unit means no dry_time; the printer is busy, so it re-queues.
  527. await db_session.refresh(row)
  528. assert row.status == "pending"
  529. assert row.waiting_reason == "interrupted"
  530. def _parked_state(ams_id=0, dry_time=720):
  531. """A unit whose countdown the MQTT layer has flagged as not running (#2896)."""
  532. state = _mock_state(ams_id=ams_id, dry_time=dry_time)
  533. state.raw_data["ams"][0]["dry_countdown_stalled"] = True
  534. return state
  535. @pytest.mark.asyncio
  536. async def test_running_with_a_ticking_countdown_stays_running(scheduler, db_session, printer_factory):
  537. row = await _make_row(
  538. db_session, printer_factory, status="running", started_at=_utcnow_naive() - timedelta(minutes=30)
  539. )
  540. with patch("backend.app.services.print_scheduler.printer_manager") as mock_pm:
  541. mock_pm.get_status.return_value = _mock_state(dry_time=450)
  542. await scheduler._check_scheduled_dryings(db_session)
  543. await db_session.refresh(row)
  544. assert row.status == "running"
  545. @pytest.mark.asyncio
  546. async def test_running_with_a_parked_countdown_during_a_print_requeues(scheduler, db_session, printer_factory):
  547. """#2896: a timer the printer took but never runs would keep the row
  548. "running" forever. Mid-print it is re-queued like any interruption."""
  549. row = await _make_row(
  550. db_session, printer_factory, status="running", started_at=_utcnow_naive() - timedelta(minutes=30)
  551. )
  552. with (
  553. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  554. patch.object(scheduler, "_is_printer_idle", return_value=False),
  555. ):
  556. mock_pm.get_status.return_value = _parked_state()
  557. await scheduler._check_scheduled_dryings(db_session)
  558. # Neither a stop nor a restart: the timer stays on the printer.
  559. mock_pm.send_drying_command.assert_not_called()
  560. await db_session.refresh(row)
  561. assert row.status == "pending"
  562. assert row.started_at is None
  563. assert row.waiting_reason == "interrupted"
  564. assert row.printer_id not in scheduler._scheduled_drying_printer_ids
  565. @pytest.mark.asyncio
  566. async def test_running_with_a_parked_countdown_on_an_idle_printer_fails(scheduler, db_session, printer_factory):
  567. """Parked with nothing else running is a refusal, not a user stop: the row
  568. fails with a reason instead of reading as cancelled or retrying forever."""
  569. row = await _make_row(
  570. db_session, printer_factory, status="running", started_at=_utcnow_naive() - timedelta(minutes=30)
  571. )
  572. with (
  573. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  574. patch.object(scheduler, "_is_printer_idle", return_value=True),
  575. ):
  576. mock_pm.get_status.return_value = _parked_state()
  577. await scheduler._check_scheduled_dryings(db_session)
  578. await db_session.refresh(row)
  579. assert row.status == "failed"
  580. assert "did not start drying" in row.error_message
  581. assert row.error_code == "did_not_start"
  582. assert row.completed_at is not None
  583. @pytest.mark.asyncio
  584. async def test_a_parked_timer_does_not_make_a_pending_run_wait(scheduler, db_session, printer_factory):
  585. """Auto-drying keeps tracking a parked unit so its stop paths still reach it,
  586. but a scheduled run must not wait "already_drying" on a timer that never ends."""
  587. row = await _make_row(db_session, printer_factory, start_after=None)
  588. scheduler._drying_in_progress[row.printer_id] = 1.0
  589. with (
  590. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  591. patch.object(scheduler, "_is_printer_idle", return_value=True),
  592. ):
  593. mock_pm.get_status.return_value = _parked_state()
  594. mock_pm.send_drying_command.return_value = True
  595. await scheduler._check_scheduled_dryings(db_session)
  596. mock_pm.send_drying_command.assert_called_once()
  597. await db_session.refresh(row)
  598. assert row.status == "running"
  599. @pytest.mark.asyncio
  600. async def test_real_drying_still_makes_a_pending_run_wait(scheduler, db_session, printer_factory):
  601. row = await _make_row(db_session, printer_factory, start_after=None)
  602. scheduler._drying_in_progress[row.printer_id] = 1.0
  603. with (
  604. patch("backend.app.services.print_scheduler.printer_manager") as mock_pm,
  605. patch.object(scheduler, "_is_printer_idle", return_value=True),
  606. ):
  607. mock_pm.get_status.return_value = _mock_state(dry_time=450)
  608. await scheduler._check_scheduled_dryings(db_session)
  609. mock_pm.send_drying_command.assert_not_called()
  610. await db_session.refresh(row)
  611. assert row.waiting_reason == "already_drying"
  612. class TestDryingIsOnlyParked:
  613. @patch("backend.app.services.print_scheduler.printer_manager")
  614. def test_every_timed_unit_parked(self, mock_pm):
  615. state = MagicMock()
  616. state.raw_data = {
  617. "ams": [
  618. {"id": 0, "dry_time": 720, "dry_countdown_stalled": True},
  619. {"id": 1, "dry_time": 0},
  620. ]
  621. }
  622. mock_pm.get_status.return_value = state
  623. assert PrintScheduler._drying_is_only_parked(1) is True
  624. @patch("backend.app.services.print_scheduler.printer_manager")
  625. def test_one_running_unit_is_enough_to_count_as_drying(self, mock_pm):
  626. state = MagicMock()
  627. state.raw_data = {
  628. "ams": [
  629. {"id": 0, "dry_time": 720, "dry_countdown_stalled": True},
  630. {"id": 1, "dry_time": 300},
  631. ]
  632. }
  633. mock_pm.get_status.return_value = state
  634. assert PrintScheduler._drying_is_only_parked(1) is False
  635. @patch("backend.app.services.print_scheduler.printer_manager")
  636. def test_no_timer_yet_is_not_parked(self, mock_pm):
  637. """A command just sent that the firmware has not reported back yet is
  638. real drying about to begin, not a parked one."""
  639. state = MagicMock()
  640. state.raw_data = {"ams": [{"id": 0, "dry_time": 0}]}
  641. mock_pm.get_status.return_value = state
  642. assert PrintScheduler._drying_is_only_parked(1) is False
  643. @patch("backend.app.services.print_scheduler.printer_manager")
  644. def test_offline_printer_is_not_parked(self, mock_pm):
  645. mock_pm.get_status.return_value = None
  646. assert PrintScheduler._drying_is_only_parked(1) is False
  647. def test_every_failure_detail_has_a_code():
  648. """Each English failure text the scheduler can store maps to a code the
  649. frontend translates (FAILED_REASON_KEYS in PrintersPage.tsx)."""
  650. from backend.app.services import drying_preflight
  651. assert drying_preflight.DETAIL_CODES == {
  652. drying_preflight.SCREEN_ONLY_DETAIL: "screen_only",
  653. drying_preflight.UNSUPPORTED_DETAIL: "unsupported",
  654. drying_preflight.DID_NOT_START_DETAIL: "did_not_start",
  655. }