test_run_lifecycle.py 12 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295
  1. """Every print of an archive keeps its own record, start to end (archive redesign P0).
  2. The archive redesign moves what describes one print -- status, times, plate,
  3. failure reason, charge -- from the archive onto the run. These tests drive
  4. real print starts and completions against the database and pin what each run
  5. records today, so every step of the move is checked against the same outcome.
  6. They assert on the print log first; what the archive row shows is pinned
  7. where the archive page reads it today, and changes there are meant to be
  8. made here on purpose.
  9. """
  10. from __future__ import annotations
  11. import asyncio
  12. from types import SimpleNamespace
  13. import pytest
  14. from sqlalchemy import func, select
  15. from backend.app import main as main_module
  16. from backend.app.main import register_expected_print
  17. from backend.app.models.archive import PrintArchive
  18. from backend.app.models.finance import CostCenter, WalletTransaction
  19. from backend.app.models.print_log import PrintLogEntry
  20. from backend.app.models.print_queue import PrintQueueItem
  21. from backend.app.models.settings import Settings
  22. from backend.app.models.user import User
  23. from backend.tests.integration.test_external_print_confirmation_1898 import ( # noqa: F401
  24. SUBTASK,
  25. _clear_print_state,
  26. _drive_print_start,
  27. )
  28. from backend.tests.integration.test_print_complete_end_to_end import _complete as _complete_concurrently
  29. pytestmark = [pytest.mark.asyncio, pytest.mark.integration]
  30. FILE = f"{SUBTASK}.gcode.3mf"
  31. async def _complete(test_engine, printer_id: int, status: str, name: str):
  32. """``on_print_complete`` with its background work run one task at a time.
  33. The SQLite test database is one shared connection, so tasks writing at
  34. the same time fail each other ("cannot commit transaction - SQL
  35. statements in progress"), which a real database does not. The finish
  36. photo is left out of the turn-taking: the notification task waits for it.
  37. """
  38. from unittest.mock import patch
  39. from backend.app.core.tasks import spawn_background_task
  40. turn = asyncio.Lock()
  41. async def in_turn(coro):
  42. async with turn:
  43. return await coro
  44. def spawn(coro, name=None, **kwargs):
  45. if name != "background-finish-photo":
  46. coro = in_turn(coro)
  47. return spawn_background_task(coro, name=name, **kwargs)
  48. with patch("backend.app.main.spawn_background_task", side_effect=spawn):
  49. return await _complete_concurrently(test_engine, printer_id, status, name=name)
  50. @pytest.fixture(autouse=True)
  51. def _clean():
  52. from backend.app.services.printer_manager import printer_manager
  53. main_module._print_plate_ids.clear()
  54. main_module._archive_runs_finishing.clear()
  55. yield
  56. main_module._print_plate_ids.clear()
  57. main_module._archive_runs_finishing.clear()
  58. printer_manager._awaiting_plate_clear.clear()
  59. @pytest.fixture
  60. async def farm(db_session, printer_factory):
  61. """A printer, a user paying from a cost centre, and an archive of a
  62. multi-plate file printed before."""
  63. db_session.add_all(
  64. [Settings(key="capture_finish_photo", value="false"), Settings(key="billing_enabled", value="true")]
  65. )
  66. printer = await printer_factory(name="P")
  67. user = User(username="payer", password_hash="x", is_active=True)
  68. center = CostCenter(name="Lab", is_active=True, is_private=False)
  69. db_session.add_all([user, center])
  70. await db_session.flush()
  71. archive = PrintArchive(
  72. printer_id=printer.id,
  73. filename=FILE,
  74. file_path=f"archives/test/{FILE}",
  75. file_size=1,
  76. print_name=SUBTASK,
  77. status="completed",
  78. cost=5.0,
  79. created_by_id=user.id,
  80. )
  81. db_session.add(archive)
  82. await db_session.commit()
  83. return SimpleNamespace(printer=printer.id, user=user.id, center=center.id, archive=archive.id)
  84. async def _run(test_engine, db_session, farm, *, plate: int, status: str, run_id: str) -> int:
  85. """One queued print of the archive's plate, from dispatch to its end.
  86. Returns the queue item's id."""
  87. item = PrintQueueItem(
  88. printer_id=farm.printer,
  89. archive_id=farm.archive,
  90. status="printing",
  91. position=1,
  92. plate_id=plate,
  93. created_by_id=farm.user,
  94. cost_center_id=farm.center,
  95. estimated_cost=5.0,
  96. billing_run_id=run_id,
  97. )
  98. db_session.add(item)
  99. # As the scheduler's dispatch writes it (_start_print).
  100. (await db_session.get(PrintArchive, farm.archive)).plate_id = plate
  101. await db_session.commit()
  102. item_id = item.id
  103. register_expected_print(farm.printer, FILE, farm.archive, plate_id=plate, cost_center_id=farm.center)
  104. await _drive_print_start(test_engine, SimpleNamespace(id=farm.printer), download_ok=False)
  105. await _complete(test_engine, farm.printer, status, name=SUBTASK)
  106. return item_id
  107. async def _runs(db_session, archive_id: int) -> list[PrintLogEntry]:
  108. db_session.expire_all()
  109. return list(
  110. (
  111. await db_session.scalars(
  112. select(PrintLogEntry).where(PrintLogEntry.archive_id == archive_id).order_by(PrintLogEntry.id)
  113. )
  114. ).all()
  115. )
  116. async def test_a_queued_print_of_an_archive_is_one_run_on_it(test_engine, db_session, farm):
  117. item = await _run(test_engine, db_session, farm, plate=1, status="completed", run_id="run-1")
  118. runs = await _runs(db_session, farm.archive)
  119. assert [(r.status, r.plate_id, r.queue_item_id, r.printer_id) for r in runs] == [
  120. ("completed", 1, item, farm.printer)
  121. ]
  122. assert runs[0].started_at is not None and runs[0].completed_at is not None
  123. assert runs[0].completed_at >= runs[0].started_at
  124. archive = await db_session.get(PrintArchive, farm.archive)
  125. assert (archive.status, archive.plate_id) == ("completed", 1)
  126. assert await db_session.scalar(select(func.count()).select_from(PrintArchive)) == 1
  127. async def test_each_run_keeps_its_own_plate_outcome_and_times(test_engine, db_session, farm):
  128. """Plate 1 fails, then plate 2 prints: neither run takes the other's."""
  129. first = await _run(test_engine, db_session, farm, plate=1, status="failed", run_id="run-1")
  130. second = await _run(test_engine, db_session, farm, plate=2, status="completed", run_id="run-2")
  131. runs = await _runs(db_session, farm.archive)
  132. assert [(r.status, r.plate_id, r.queue_item_id) for r in runs] == [
  133. ("failed", 1, first),
  134. ("completed", 2, second),
  135. ]
  136. assert runs[1].started_at >= runs[0].completed_at, "the second run's start is its own"
  137. assert runs[1].failure_reason is None, "a completed run carries no reason of the failed one"
  138. # The archive page shows the latest run.
  139. archive = await db_session.get(PrintArchive, farm.archive)
  140. assert (archive.status, archive.plate_id, archive.failure_reason) == ("completed", 2, None)
  141. async def test_each_run_is_charged_once_under_its_own_run_id(test_engine, db_session, farm):
  142. await _run(test_engine, db_session, farm, plate=1, status="completed", run_id="run-1")
  143. await _run(test_engine, db_session, farm, plate=2, status="completed", run_id="run-2")
  144. charges = (
  145. await db_session.scalars(
  146. select(WalletTransaction)
  147. .where(WalletTransaction.transaction_type == "print_charge")
  148. .order_by(WalletTransaction.id)
  149. )
  150. ).all()
  151. assert [(c.print_run_id, c.print_archive_id, c.cost_center_id) for c in charges] == [
  152. ("run-1", farm.archive, farm.center),
  153. ("run-2", farm.archive, farm.center),
  154. ]
  155. async def test_a_print_started_on_the_printer_is_an_archive_with_one_run(test_engine, db_session, printer_factory):
  156. db_session.add(Settings(key="capture_finish_photo", value="false"))
  157. await db_session.commit()
  158. printer_id = (await printer_factory(name="P")).id
  159. await _drive_print_start(test_engine, SimpleNamespace(id=printer_id), download_ok=False)
  160. await _complete(test_engine, printer_id, "completed", name=SUBTASK)
  161. archives = (await db_session.scalars(select(PrintArchive))).all()
  162. assert len(archives) == 1
  163. runs = await _runs(db_session, archives[0].id)
  164. assert [(r.status, r.queue_item_id, r.printer_id) for r in runs] == [("completed", None, printer_id)]
  165. async def test_a_reported_end_after_an_offline_stop_replaces_the_run(test_engine, db_session, farm, async_client):
  166. """The stop could not reach the printer and logged the run as cancelled;
  167. the printer then reports how it really ended. Still one run."""
  168. from unittest.mock import AsyncMock, patch
  169. item = PrintQueueItem(
  170. printer_id=farm.printer,
  171. archive_id=farm.archive,
  172. status="printing",
  173. position=1,
  174. plate_id=2,
  175. created_by_id=farm.user,
  176. billing_run_id="run-1",
  177. )
  178. db_session.add(item)
  179. await db_session.commit()
  180. register_expected_print(farm.printer, FILE, farm.archive, plate_id=2)
  181. await _drive_print_start(test_engine, SimpleNamespace(id=farm.printer), download_ok=False)
  182. with (
  183. patch("backend.app.services.print_control.stop_print_by_user", return_value=False),
  184. patch("backend.app.api.routes.print_queue.ws_manager") as ws,
  185. ):
  186. ws.send_archive_updated = AsyncMock()
  187. assert (await async_client.post(f"/api/v1/queue/{item.id}/stop")).status_code == 200
  188. assert [(r.status, r.plate_id) for r in await _runs(db_session, farm.archive)] == [("cancelled", 2)]
  189. main_module._active_prints[(farm.printer, FILE)] = farm.archive
  190. await _complete(test_engine, farm.printer, "completed", name=SUBTASK)
  191. assert [(r.status, r.plate_id) for r in await _runs(db_session, farm.archive)] == [("completed", 2)]
  192. async def test_each_run_gets_its_own_energy(test_engine, db_session, farm):
  193. """The plug's counter at each start and end: the archive card shows the
  194. first run's, each run its own."""
  195. from unittest.mock import AsyncMock, MagicMock, patch
  196. plug = MagicMock(id=1)
  197. plug.name = "Plug"
  198. counters = iter([10.5, 20.3])
  199. async def reading(candidates, read, db):
  200. return plug, {"total": next(counters)}
  201. async def started_at(kwh):
  202. archive = await db_session.get(PrintArchive, farm.archive)
  203. archive.energy_start_kwh = kwh
  204. await db_session.commit()
  205. with (
  206. patch("backend.app.main.energy_plug_candidates", AsyncMock(return_value=[plug])),
  207. patch("backend.app.main.select_energy_reading", side_effect=reading),
  208. patch("backend.app.services.energy_price.print_energy_cost", AsyncMock(return_value=0.1)),
  209. patch("backend.app.services.energy_price.current_price", AsyncMock(return_value=0.3)),
  210. ):
  211. for plate, kwh in ((1, 10.0), (2, 20.0)):
  212. item = PrintQueueItem(
  213. printer_id=farm.printer, archive_id=farm.archive, status="printing", position=1, plate_id=plate
  214. )
  215. db_session.add(item)
  216. await db_session.commit()
  217. register_expected_print(farm.printer, FILE, farm.archive, plate_id=plate)
  218. await _drive_print_start(test_engine, SimpleNamespace(id=farm.printer), download_ok=False)
  219. await started_at(kwh)
  220. await _complete(test_engine, farm.printer, "completed", name=SUBTASK)
  221. runs = await _runs(db_session, farm.archive)
  222. assert [(r.plate_id, r.energy_kwh) for r in runs] == [(1, 0.5), (2, pytest.approx(0.3))]
  223. archive = await db_session.get(PrintArchive, farm.archive)
  224. assert archive.energy_kwh == 0.5
  225. async def test_each_run_keeps_its_own_verdict(test_engine, db_session, farm):
  226. """An answered outcome prompt belongs to its run; the next run asks again."""
  227. from backend.app.services.print_confirmation import apply_outcome_verdict
  228. archive = await db_session.get(PrintArchive, farm.archive)
  229. archive.confirm_requested = True
  230. await db_session.commit()
  231. await _run(test_engine, db_session, farm, plate=1, status="completed", run_id="run-1")
  232. archive = await db_session.get(PrintArchive, farm.archive)
  233. assert await apply_outcome_verdict(db_session, archive, "reject", source="dialog")
  234. await db_session.commit()
  235. await _run(test_engine, db_session, farm, plate=2, status="completed", run_id="run-2")
  236. runs = await _runs(db_session, farm.archive)
  237. assert [(r.plate_id, r.user_verdict) for r in runs] == [(1, "reject"), (2, None)]
  238. archive = await db_session.get(PrintArchive, farm.archive)
  239. assert archive.user_verdict is None, "the latest run is not judged yet"