background_dispatch.py 49 KB

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073107410751076107710781079108010811082108310841085108610871088108910901091109210931094109510961097109810991100110111021103110411051106110711081109111011111112111311141115111611171118111911201121112211231124112511261127112811291130113111321133113411351136113711381139114011411142114311441145114611471148114911501151115211531154115511561157
  1. """Background dispatch for print/reprint jobs.
  2. This service is separate from the app's print queue feature. It exists only to
  3. decouple "send/start print" operations (FTP upload + start command) from API
  4. request latency so the UI can continue immediately after dispatch.
  5. """
  6. from __future__ import annotations
  7. import asyncio
  8. import logging
  9. import time
  10. import zipfile
  11. from collections import deque
  12. from dataclasses import dataclass, field
  13. from pathlib import Path
  14. from typing import Any, Literal
  15. from sqlalchemy import select
  16. from backend.app.core.config import settings
  17. from backend.app.core.database import async_session
  18. from backend.app.core.tasks import spawn_background_task
  19. from backend.app.core.websocket import ws_manager
  20. from backend.app.models.finance import BudgetReservation, CostCenter
  21. from backend.app.models.library import LibraryFile
  22. from backend.app.models.printer import Printer
  23. from backend.app.models.user import User
  24. from backend.app.services.archive import ArchiveService
  25. from backend.app.services.bambu_ftp import (
  26. cache_3mf_download,
  27. delete_file_async,
  28. get_ftp_retry_settings,
  29. upload_file_async,
  30. with_ftp_retry,
  31. )
  32. from backend.app.services.finance_budget import create_budget_reservation, release_budget_reservation
  33. from backend.app.services.printer_manager import printer_manager
  34. from backend.app.utils.filename import derive_remote_filename
  35. logger = logging.getLogger(__name__)
  36. # Bambu firmware states that mean the project_file has actually been accepted
  37. # and the printer is now processing / running / paused mid-print. Used by the
  38. # direct-dispatch verifier (#1370): a transition into one of these states means
  39. # the print landed, anything else (e.g. FINISH -> IDLE after the user dismisses
  40. # a post-print prompt) is NOT a valid "command landed" signal even though the
  41. # state value did change. Mirrors the same constant in print_scheduler.py —
  42. # kept duplicated rather than imported to avoid coupling the two services and
  43. # to keep the value at the point of use.
  44. _ACTIVE_PRINT_STATES: frozenset[str] = frozenset({"PREPARE", "SLICING", "RUNNING", "PAUSE"})
  45. class DispatchJobCancelled(Exception):
  46. """Raised when a dispatch job is cancelled by the user."""
  47. class DispatchEnqueueRejected(Exception):
  48. """Raised when a dispatch job should not be accepted."""
  49. @dataclass(slots=True)
  50. class PrintDispatchJob:
  51. id: int
  52. kind: Literal["reprint_archive", "print_library_file"]
  53. source_id: int
  54. source_name: str
  55. printer_id: int
  56. printer_name: str
  57. options: dict[str, Any] = field(default_factory=dict)
  58. requested_by_user_id: int | None = None
  59. requested_by_username: str | None = None
  60. project_id: int | None = None
  61. cleanup_library_after_dispatch: bool = False
  62. @dataclass(slots=True)
  63. class ActiveDispatchState:
  64. job: PrintDispatchJob
  65. message: str
  66. upload_bytes: int | None = None
  67. upload_total_bytes: int | None = None
  68. class BackgroundDispatchService:
  69. def __init__(self):
  70. self._queued_jobs: deque[PrintDispatchJob] = deque()
  71. self._dispatcher_task: asyncio.Task | None = None
  72. self._running_tasks: dict[int, asyncio.Task] = {}
  73. self._lock = asyncio.Lock()
  74. self._job_event = asyncio.Event()
  75. self._next_job_id = 1
  76. self._active_jobs: dict[int, ActiveDispatchState] = {}
  77. self._cancel_requested_job_ids: set[int] = set()
  78. # Progress for the current "batch" (since queue became non-empty)
  79. self._batch_total = 0
  80. self._batch_completed = 0
  81. self._batch_failed = 0
  82. @staticmethod
  83. def _printer_is_busy_printing(printer_id: int) -> bool:
  84. state = printer_manager.get_status(printer_id)
  85. if not state:
  86. return False
  87. return state.state in ("RUNNING", "PAUSE", "PAUSED") and bool(state.gcode_file)
  88. async def start(self):
  89. async with self._lock:
  90. if self._dispatcher_task and not self._dispatcher_task.done():
  91. return
  92. self._dispatcher_task = asyncio.create_task(self._dispatcher_loop(), name="background-dispatch-dispatcher")
  93. logger.info("Background dispatch dispatcher started")
  94. async def stop(self):
  95. dispatcher: asyncio.Task | None = None
  96. running_tasks: list[asyncio.Task] = []
  97. async with self._lock:
  98. dispatcher = self._dispatcher_task
  99. self._dispatcher_task = None
  100. running_tasks = list(self._running_tasks.values())
  101. jobs_to_release = [*self._queued_jobs, *(state.job for state in self._active_jobs.values())]
  102. self._running_tasks.clear()
  103. self._active_jobs.clear()
  104. self._queued_jobs.clear()
  105. self._cancel_requested_job_ids.clear()
  106. self._job_event.set()
  107. for job in jobs_to_release:
  108. await self._release_budget_reservation(job, status="released")
  109. if dispatcher:
  110. dispatcher.cancel()
  111. for task in running_tasks:
  112. task.cancel()
  113. if dispatcher:
  114. try:
  115. await dispatcher
  116. except asyncio.CancelledError:
  117. pass
  118. if running_tasks:
  119. await asyncio.gather(*running_tasks, return_exceptions=True)
  120. logger.info("Background dispatch dispatcher stopped")
  121. async def dispatch_reprint_archive(
  122. self,
  123. *,
  124. archive_id: int,
  125. archive_name: str,
  126. printer_id: int,
  127. printer_name: str,
  128. options: dict[str, Any],
  129. requested_by_user_id: int | None,
  130. requested_by_username: str | None,
  131. ) -> dict[str, Any]:
  132. return await self._dispatch(
  133. kind="reprint_archive",
  134. source_id=archive_id,
  135. source_name=archive_name,
  136. printer_id=printer_id,
  137. printer_name=printer_name,
  138. options=options,
  139. requested_by_user_id=requested_by_user_id,
  140. requested_by_username=requested_by_username,
  141. )
  142. async def get_state(self) -> dict[str, Any]:
  143. """Get current dispatch queue state snapshot for newly connected clients."""
  144. async with self._lock:
  145. return self._build_state_payload_unlocked()
  146. async def dispatch_print_library_file(
  147. self,
  148. *,
  149. file_id: int,
  150. filename: str,
  151. printer_id: int,
  152. printer_name: str,
  153. options: dict[str, Any],
  154. requested_by_user_id: int | None,
  155. requested_by_username: str | None,
  156. project_id: int | None = None,
  157. cleanup_library_after_dispatch: bool = False,
  158. ) -> dict[str, Any]:
  159. return await self._dispatch(
  160. kind="print_library_file",
  161. source_id=file_id,
  162. source_name=filename,
  163. printer_id=printer_id,
  164. printer_name=printer_name,
  165. options=options,
  166. requested_by_user_id=requested_by_user_id,
  167. requested_by_username=requested_by_username,
  168. project_id=project_id,
  169. cleanup_library_after_dispatch=cleanup_library_after_dispatch,
  170. )
  171. async def cancel_job(self, job_id: int) -> dict[str, Any]:
  172. """Cancel a queued dispatch job.
  173. Queued jobs are removed immediately. Active jobs are cancelled
  174. cooperatively and will stop at the next cancellation checkpoint.
  175. """
  176. async with self._lock:
  177. # Check active jobs first
  178. active_state = self._active_jobs.get(job_id)
  179. if active_state is not None:
  180. logger.info("Cancel requested for active dispatch job %s", job_id)
  181. self._cancel_requested_job_ids.add(job_id)
  182. active_job = active_state.job
  183. payload = self._build_state_payload_unlocked(
  184. recent_event={
  185. "status": "cancelling",
  186. "job_id": active_job.id,
  187. "source_name": active_job.source_name,
  188. "printer_id": active_job.printer_id,
  189. "printer_name": active_job.printer_name,
  190. "message": "Cancelling current dispatch...",
  191. }
  192. )
  193. result = {
  194. "cancelled": True,
  195. "pending": True,
  196. "job_id": active_job.id,
  197. "source_name": active_job.source_name,
  198. "printer_id": active_job.printer_id,
  199. "printer_name": active_job.printer_name,
  200. }
  201. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  202. return result
  203. # Check queued jobs
  204. cancelled_job: PrintDispatchJob | None = None
  205. for job in self._queued_jobs:
  206. if job.id == job_id:
  207. cancelled_job = job
  208. break
  209. if not cancelled_job:
  210. logger.info("Cancel requested for unknown dispatch job %s", job_id)
  211. return {"cancelled": False, "reason": "not_found"}
  212. self._queued_jobs.remove(cancelled_job)
  213. logger.info("Cancelled queued dispatch job %s", cancelled_job.id)
  214. self._batch_total = max(0, self._batch_total - 1)
  215. if self._batch_total == 0 and len(self._queued_jobs) == 0 and len(self._active_jobs) == 0:
  216. self._batch_completed = 0
  217. self._batch_failed = 0
  218. payload = self._build_state_payload_unlocked(
  219. recent_event={
  220. "status": "cancelled",
  221. "job_id": cancelled_job.id,
  222. "source_name": cancelled_job.source_name,
  223. "printer_id": cancelled_job.printer_id,
  224. "printer_name": cancelled_job.printer_name,
  225. "message": "Cancelled from queue",
  226. }
  227. )
  228. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  229. return {
  230. "cancelled": True,
  231. "pending": False,
  232. "job_id": cancelled_job.id,
  233. "source_name": cancelled_job.source_name,
  234. "printer_id": cancelled_job.printer_id,
  235. "printer_name": cancelled_job.printer_name,
  236. }
  237. async def _dispatch(
  238. self,
  239. *,
  240. kind: Literal["reprint_archive", "print_library_file"],
  241. source_id: int,
  242. source_name: str,
  243. printer_id: int,
  244. printer_name: str,
  245. options: dict[str, Any],
  246. requested_by_user_id: int | None,
  247. requested_by_username: str | None,
  248. project_id: int | None = None,
  249. cleanup_library_after_dispatch: bool = False,
  250. ) -> dict[str, Any]:
  251. async with self._lock:
  252. has_pending_for_printer = any(job.printer_id == printer_id for job in self._queued_jobs)
  253. has_active_for_printer = any(active.job.printer_id == printer_id for active in self._active_jobs.values())
  254. if has_pending_for_printer or has_active_for_printer:
  255. raise DispatchEnqueueRejected(f"Printer {printer_name} already has a background dispatch in progress")
  256. if self._printer_is_busy_printing(printer_id):
  257. raise DispatchEnqueueRejected(f"Printer {printer_name} is currently busy printing")
  258. dispatch_position = len(self._queued_jobs) + len(self._active_jobs) + 1
  259. job_id = self._next_job_id
  260. async with async_session() as db:
  261. requested_by = await db.get(User, requested_by_user_id) if requested_by_user_id is not None else None
  262. await create_budget_reservation(
  263. db,
  264. cost_center_id=options.get("cost_center_id"),
  265. estimated_cost=options.get("estimated_cost"),
  266. current_user=requested_by,
  267. source_type="background_dispatch",
  268. source_id=job_id,
  269. print_archive_id=source_id if kind == "reprint_archive" else None,
  270. )
  271. await db.commit()
  272. job = PrintDispatchJob(
  273. id=job_id,
  274. kind=kind,
  275. source_id=source_id,
  276. source_name=source_name,
  277. printer_id=printer_id,
  278. printer_name=printer_name,
  279. options=options,
  280. requested_by_user_id=requested_by_user_id,
  281. requested_by_username=requested_by_username,
  282. project_id=project_id,
  283. cleanup_library_after_dispatch=cleanup_library_after_dispatch,
  284. )
  285. self._next_job_id += 1
  286. self._batch_total += 1
  287. self._queued_jobs.append(job)
  288. self._job_event.set()
  289. payload = self._build_state_payload_unlocked(
  290. recent_event={
  291. "status": "dispatched",
  292. "job_id": job.id,
  293. "source_name": source_name,
  294. "printer_id": printer_id,
  295. "printer_name": printer_name,
  296. "message": f"Dispatched to {printer_name}",
  297. }
  298. )
  299. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  300. return {
  301. "dispatch_job_id": job.id,
  302. "dispatch_position": dispatch_position,
  303. "status": "dispatched",
  304. "printer_id": printer_id,
  305. "source_id": source_id,
  306. "source_name": source_name,
  307. }
  308. async def _dispatcher_loop(self):
  309. while True:
  310. await self._job_event.wait()
  311. self._job_event.clear()
  312. while True:
  313. payload: dict[str, Any] | None = None
  314. job_to_start: PrintDispatchJob | None = None
  315. async with self._lock:
  316. busy_printer_ids = {state.job.printer_id for state in self._active_jobs.values()}
  317. start_index = next(
  318. (
  319. idx
  320. for idx, queued_job in enumerate(self._queued_jobs)
  321. if queued_job.printer_id not in busy_printer_ids
  322. ),
  323. None,
  324. )
  325. if start_index is None:
  326. break
  327. job_to_start = self._queued_jobs[start_index]
  328. del self._queued_jobs[start_index]
  329. self._active_jobs[job_to_start.id] = ActiveDispatchState(
  330. job=job_to_start,
  331. message="Preparing background dispatch...",
  332. )
  333. task = asyncio.create_task(
  334. self._run_active_job(job_to_start), name=f"background-dispatch-job-{job_to_start.id}"
  335. )
  336. self._running_tasks[job_to_start.id] = task
  337. payload = self._build_state_payload_unlocked(
  338. recent_event={
  339. "status": "processing",
  340. "job_id": job_to_start.id,
  341. "source_name": job_to_start.source_name,
  342. "printer_id": job_to_start.printer_id,
  343. "printer_name": job_to_start.printer_name,
  344. "message": "Preparing background dispatch...",
  345. }
  346. )
  347. if payload:
  348. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  349. async def _run_active_job(self, job: PrintDispatchJob):
  350. try:
  351. await self._process_job(job)
  352. await self._mark_job_finished(job, failed=False, message="Background dispatch complete")
  353. except DispatchJobCancelled:
  354. await self._mark_job_cancelled(job)
  355. except asyncio.CancelledError:
  356. raise
  357. except Exception as e:
  358. logger.error("Background dispatch job %s failed: %s", job.id, e, exc_info=True)
  359. await self._mark_job_finished(job, failed=True, message=str(e))
  360. finally:
  361. self._job_event.set()
  362. async def _set_active_message(self, job: PrintDispatchJob, message: str):
  363. async with self._lock:
  364. active = self._active_jobs.get(job.id)
  365. if not active:
  366. return
  367. active.message = message
  368. payload = self._build_state_payload_unlocked(
  369. recent_event={
  370. "status": "processing",
  371. "job_id": active.job.id,
  372. "source_name": active.job.source_name,
  373. "printer_id": active.job.printer_id,
  374. "printer_name": active.job.printer_name,
  375. "message": message,
  376. }
  377. )
  378. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  379. async def _set_active_upload_progress(self, job: PrintDispatchJob, uploaded: int, total: int):
  380. async with self._lock:
  381. active = self._active_jobs.get(job.id)
  382. if not active:
  383. return
  384. active.upload_bytes = max(0, int(uploaded))
  385. active.upload_total_bytes = max(0, int(total))
  386. payload = self._build_state_payload_unlocked(
  387. recent_event={
  388. "status": "processing",
  389. "job_id": active.job.id,
  390. "source_name": active.job.source_name,
  391. "printer_id": active.job.printer_id,
  392. "printer_name": active.job.printer_name,
  393. "message": active.message,
  394. }
  395. )
  396. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  397. async def _mark_job_finished(self, job: PrintDispatchJob, *, failed: bool, message: str):
  398. if failed:
  399. await self._release_budget_reservation(job, status="released")
  400. async with self._lock:
  401. if failed:
  402. self._batch_failed += 1
  403. else:
  404. self._batch_completed += 1
  405. self._active_jobs.pop(job.id, None)
  406. self._running_tasks.pop(job.id, None)
  407. self._cancel_requested_job_ids.discard(job.id)
  408. payload = self._build_state_payload_unlocked(
  409. recent_event={
  410. "status": "failed" if failed else "completed",
  411. "job_id": job.id,
  412. "source_name": job.source_name,
  413. "printer_id": job.printer_id,
  414. "printer_name": job.printer_name,
  415. "message": message,
  416. }
  417. )
  418. should_reset_batch = len(self._queued_jobs) == 0 and len(self._active_jobs) == 0
  419. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  420. if should_reset_batch:
  421. async with self._lock:
  422. if len(self._queued_jobs) == 0 and len(self._active_jobs) == 0:
  423. self._batch_total = 0
  424. self._batch_completed = 0
  425. self._batch_failed = 0
  426. async def _mark_job_cancelled(self, job: PrintDispatchJob):
  427. await self._release_budget_reservation(job, status="released")
  428. async with self._lock:
  429. self._active_jobs.pop(job.id, None)
  430. self._running_tasks.pop(job.id, None)
  431. self._cancel_requested_job_ids.discard(job.id)
  432. self._batch_total = max(0, self._batch_total - 1)
  433. if self._batch_total == 0 and len(self._queued_jobs) == 0 and len(self._active_jobs) == 0:
  434. self._batch_completed = 0
  435. self._batch_failed = 0
  436. payload = self._build_state_payload_unlocked(
  437. recent_event={
  438. "status": "cancelled",
  439. "job_id": job.id,
  440. "source_name": job.source_name,
  441. "printer_id": job.printer_id,
  442. "printer_name": job.printer_name,
  443. "message": "Cancelled during dispatch",
  444. }
  445. )
  446. await ws_manager.broadcast({"type": "background_dispatch", "data": payload})
  447. def _is_cancel_requested(self, job_id: int) -> bool:
  448. return job_id in self._cancel_requested_job_ids
  449. def _raise_if_cancel_requested(self, job: PrintDispatchJob):
  450. if self._is_cancel_requested(job.id):
  451. raise DispatchJobCancelled(f"Dispatch job {job.id} cancelled")
  452. @staticmethod
  453. async def _release_budget_reservation(job: PrintDispatchJob, *, status: str):
  454. if job.options.get("cost_center_id") is None:
  455. return
  456. async with async_session() as db:
  457. await release_budget_reservation(
  458. db,
  459. source_type="background_dispatch",
  460. source_id=job.id,
  461. status=status,
  462. )
  463. await db.commit()
  464. def _build_state_payload_unlocked(self, recent_event: dict[str, Any] | None = None) -> dict[str, Any]:
  465. processing = len(self._active_jobs)
  466. dispatched = len(self._queued_jobs)
  467. dispatched_jobs = [
  468. {
  469. "job_id": job.id,
  470. "kind": job.kind,
  471. "source_id": job.source_id,
  472. "source_name": job.source_name,
  473. "printer_id": job.printer_id,
  474. "printer_name": job.printer_name,
  475. }
  476. for job in list(self._queued_jobs)
  477. ]
  478. active_jobs: list[dict[str, Any]] = []
  479. for active in self._active_jobs.values():
  480. upload_progress_pct = None
  481. if active.upload_total_bytes and active.upload_total_bytes > 0 and active.upload_bytes is not None:
  482. upload_progress_pct = round(
  483. max(0.0, min(100.0, (active.upload_bytes / active.upload_total_bytes) * 100.0)), 1
  484. )
  485. active_jobs.append(
  486. {
  487. "job_id": active.job.id,
  488. "kind": active.job.kind,
  489. "source_id": active.job.source_id,
  490. "source_name": active.job.source_name,
  491. "printer_id": active.job.printer_id,
  492. "printer_name": active.job.printer_name,
  493. "message": active.message,
  494. "upload_bytes": active.upload_bytes,
  495. "upload_total_bytes": active.upload_total_bytes,
  496. "upload_progress_pct": upload_progress_pct,
  497. }
  498. )
  499. active_jobs.sort(key=lambda item: int(item["job_id"]))
  500. active_job = active_jobs[0] if active_jobs else None
  501. return {
  502. "total": self._batch_total,
  503. "dispatched": dispatched,
  504. "processing": processing,
  505. "completed": self._batch_completed,
  506. "failed": self._batch_failed,
  507. "dispatched_jobs": dispatched_jobs,
  508. "active_jobs": active_jobs,
  509. "active_job": active_job,
  510. "recent_event": recent_event,
  511. }
  512. async def _process_job(self, job: PrintDispatchJob):
  513. if job.kind == "reprint_archive":
  514. await self._run_reprint_archive(job)
  515. return
  516. if job.kind == "print_library_file":
  517. await self._run_print_library_file(job)
  518. return
  519. raise RuntimeError(f"Unknown dispatch job kind: {job.kind}")
  520. async def _run_reprint_archive(self, job: PrintDispatchJob):
  521. from backend.app.main import register_expected_print
  522. async with async_session() as db:
  523. service = ArchiveService(db)
  524. archive = await service.get_archive(job.source_id)
  525. if not archive:
  526. raise RuntimeError("Archive not found")
  527. cost_center_id = job.options.get("cost_center_id")
  528. if cost_center_id is not None:
  529. cost_center = await db.scalar(select(CostCenter).where(CostCenter.id == cost_center_id))
  530. if not cost_center:
  531. raise RuntimeError("Cost center not found")
  532. printer = await db.scalar(select(Printer).where(Printer.id == job.printer_id))
  533. if not printer:
  534. raise RuntimeError("Printer not found")
  535. printer_name = printer.name
  536. printer_ip = printer.ip_address
  537. printer_access_code = printer.access_code
  538. printer_model = printer.model
  539. archive_filename = archive.filename
  540. if not printer_manager.is_connected(job.printer_id):
  541. raise RuntimeError("Printer is not connected")
  542. file_path = settings.base_dir / archive.file_path
  543. if not file_path.exists():
  544. raise RuntimeError("Archive file not found")
  545. remote_filename = derive_remote_filename(archive.filename)
  546. remote_path = f"/{remote_filename}"
  547. ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
  548. self._raise_if_cancel_requested(job)
  549. await self._set_active_message(job, f"Preparing upload to {printer_name}...")
  550. await delete_file_async(
  551. printer_ip,
  552. printer_access_code,
  553. remote_path,
  554. socket_timeout=ftp_timeout,
  555. printer_model=printer_model,
  556. )
  557. self._raise_if_cancel_requested(job)
  558. try:
  559. await self._set_active_message(job, f"Uploading {archive_filename} to {printer_name}...")
  560. loop = asyncio.get_running_loop()
  561. progress_state = {"last_emit": 0.0, "last_bytes": 0}
  562. def upload_progress_callback(uploaded: int, total: int):
  563. if self._is_cancel_requested(job.id):
  564. raise DispatchJobCancelled(f"Dispatch job {job.id} cancelled during upload")
  565. now = time.monotonic()
  566. should_emit = (
  567. uploaded >= total
  568. or now - progress_state["last_emit"] >= 0.2
  569. or uploaded - progress_state["last_bytes"] >= 256 * 1024
  570. )
  571. if should_emit:
  572. progress_state["last_emit"] = now
  573. progress_state["last_bytes"] = uploaded
  574. loop.call_soon_threadsafe(
  575. lambda u=uploaded, t=total: spawn_background_task(
  576. self._set_active_upload_progress(job, u, t),
  577. name=f"upload-progress-{job.id}",
  578. )
  579. )
  580. if ftp_retry_enabled:
  581. uploaded = await with_ftp_retry(
  582. upload_file_async,
  583. printer_ip,
  584. printer_access_code,
  585. file_path,
  586. remote_path,
  587. progress_callback=upload_progress_callback,
  588. socket_timeout=ftp_timeout,
  589. printer_model=printer_model,
  590. max_retries=ftp_retry_count,
  591. retry_delay=ftp_retry_delay,
  592. operation_name=f"Upload for reprint to {printer_name}",
  593. non_retry_exceptions=(DispatchJobCancelled,),
  594. )
  595. else:
  596. uploaded = await upload_file_async(
  597. printer_ip,
  598. printer_access_code,
  599. file_path,
  600. remote_path,
  601. progress_callback=upload_progress_callback,
  602. socket_timeout=ftp_timeout,
  603. printer_model=printer_model,
  604. )
  605. if uploaded:
  606. await self._set_active_upload_progress(job, 1, 1)
  607. if not uploaded:
  608. raise RuntimeError(
  609. "Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT)."
  610. )
  611. # Resolve plate_id before register so usage tracking can scope the
  612. # 3MF parse to the dispatched plate at print-start (#1697). Pure
  613. # transform of file_path + options, safe to reorder.
  614. plate_id = self._resolve_plate_id(file_path, job.options.get("plate_id"))
  615. register_expected_print(
  616. job.printer_id,
  617. remote_filename,
  618. job.source_id,
  619. ams_mapping=job.options.get("ams_mapping"),
  620. cost_center_id=job.options.get("cost_center_id"),
  621. plate_id=plate_id,
  622. )
  623. self._raise_if_cancel_requested(job)
  624. effective_timelapse = bool(job.options.get("timelapse", False))
  625. await self._set_active_message(job, f"Starting print on {printer_name}...")
  626. started = printer_manager.start_print(
  627. job.printer_id,
  628. remote_filename,
  629. plate_id,
  630. ams_mapping=job.options.get("ams_mapping"),
  631. timelapse=effective_timelapse,
  632. bed_levelling=job.options.get("bed_levelling", True),
  633. flow_cali=job.options.get("flow_cali", False),
  634. vibration_cali=job.options.get("vibration_cali", True),
  635. layer_inspect=job.options.get("layer_inspect", False),
  636. use_ams=job.options.get("use_ams", True),
  637. nozzle_offset_cali=job.options.get("nozzle_offset_cali", False),
  638. )
  639. if not started:
  640. await self._cleanup_sd_card_file(
  641. printer_ip,
  642. printer_access_code,
  643. remote_path,
  644. printer_model,
  645. )
  646. raise RuntimeError("Failed to start print")
  647. # Register the archive's local 3MF in the cover-cache so the
  648. # /cover endpoint can skip FTP — we already have the file on
  649. # disk, no need to refetch 36 MB from a printer whose FTP is
  650. # busy serving the active print (#1166 follow-up).
  651. cache_3mf_download(job.printer_id, remote_filename, file_path)
  652. # Wait for the printer to actually pick up the command before
  653. # marking the dispatch job complete (#1042). MQTT-publish success
  654. # only proves the command queued locally; the printer can still
  655. # reject it (HMS error pending, half-broken session, SD card
  656. # missing) and never transition. Until #1042 this watchdog was
  657. # fire-and-forget — the job was reported successful and the
  658. # user had no signal that the print never started. The uploaded
  659. # file is intentionally left on the printer's SD card on
  660. # timeout: the next dispatch will overwrite it via the existing
  661. # delete-then-upload step, and the printer may still be in the
  662. # middle of reading it if it picked up just past the timeout.
  663. pre_status = printer_manager.get_status(job.printer_id)
  664. pre_state = getattr(pre_status, "state", None) if pre_status else None
  665. pre_subtask_id = getattr(pre_status, "subtask_id", None) if pre_status else None
  666. pre_gcode_file = getattr(pre_status, "gcode_file", None) if pre_status else None
  667. if pre_state:
  668. await self._set_active_message(job, f"Waiting for {printer_name} to acknowledge print...")
  669. transitioned = await self._verify_print_response(
  670. job.printer_id,
  671. printer_name,
  672. pre_state,
  673. pre_subtask_id=pre_subtask_id,
  674. pre_gcode_file=pre_gcode_file,
  675. )
  676. if not transitioned:
  677. raise RuntimeError(
  678. f"Printer did not acknowledge print command — state still {pre_state}. "
  679. f"Check the printer for a pending error (HMS code, plate-clear prompt, "
  680. f"SD card) and try again."
  681. )
  682. if job.requested_by_user_id and job.requested_by_username:
  683. printer_manager.set_current_print_user(
  684. job.printer_id,
  685. job.requested_by_user_id,
  686. job.requested_by_username,
  687. )
  688. except DispatchJobCancelled:
  689. await self._set_active_message(job, f"Cancelled upload on {printer_name}.")
  690. raise
  691. async def _run_print_library_file(self, job: PrintDispatchJob):
  692. from backend.app.main import register_expected_print
  693. async with async_session() as db:
  694. lib_file = await db.scalar(LibraryFile.active().where(LibraryFile.id == job.source_id))
  695. if not lib_file:
  696. raise RuntimeError("File not found")
  697. if not self._is_sliced_file(lib_file.filename):
  698. raise RuntimeError("Not a sliced file. Only .gcode or .gcode.3mf files can be printed.")
  699. file_path = Path(settings.base_dir) / lib_file.file_path
  700. if not file_path.exists():
  701. raise RuntimeError("File not found on disk")
  702. printer = await db.scalar(select(Printer).where(Printer.id == job.printer_id))
  703. if not printer:
  704. raise RuntimeError("Printer not found")
  705. printer_name = printer.name
  706. printer_ip = printer.ip_address
  707. printer_access_code = printer.access_code
  708. printer_model = printer.model
  709. library_filename = lib_file.filename
  710. if not printer_manager.is_connected(job.printer_id):
  711. raise RuntimeError("Printer is not connected")
  712. await self._set_active_message(job, f"Creating archive for {lib_file.filename}...")
  713. archive_service = ArchiveService(db)
  714. archive = await archive_service.archive_print(
  715. printer_id=job.printer_id,
  716. source_file=file_path,
  717. original_filename=lib_file.filename,
  718. project_id=job.project_id,
  719. created_by_id=job.requested_by_user_id,
  720. cost_center_id=job.options.get("cost_center_id"),
  721. )
  722. if not archive:
  723. raise RuntimeError("Failed to create archive")
  724. if job.options.get("cost_center_id") is not None:
  725. reservation = await db.scalar(
  726. select(BudgetReservation).where(
  727. BudgetReservation.source_type == "background_dispatch",
  728. BudgetReservation.source_id == job.id,
  729. BudgetReservation.status == "active",
  730. )
  731. )
  732. if reservation:
  733. reservation.print_archive_id = archive.id
  734. await db.flush()
  735. remote_filename = derive_remote_filename(lib_file.filename)
  736. remote_path = f"/{remote_filename}"
  737. ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
  738. self._raise_if_cancel_requested(job)
  739. await self._set_active_message(job, f"Preparing upload to {printer_name}...")
  740. await delete_file_async(
  741. printer_ip,
  742. printer_access_code,
  743. remote_path,
  744. socket_timeout=ftp_timeout,
  745. printer_model=printer_model,
  746. )
  747. self._raise_if_cancel_requested(job)
  748. try:
  749. await self._set_active_message(job, f"Uploading {library_filename} to {printer_name}...")
  750. loop = asyncio.get_running_loop()
  751. progress_state = {"last_emit": 0.0, "last_bytes": 0}
  752. def upload_progress_callback(uploaded: int, total: int):
  753. if self._is_cancel_requested(job.id):
  754. raise DispatchJobCancelled(f"Dispatch job {job.id} cancelled during upload")
  755. now = time.monotonic()
  756. should_emit = (
  757. uploaded >= total
  758. or now - progress_state["last_emit"] >= 0.2
  759. or uploaded - progress_state["last_bytes"] >= 256 * 1024
  760. )
  761. if should_emit:
  762. progress_state["last_emit"] = now
  763. progress_state["last_bytes"] = uploaded
  764. loop.call_soon_threadsafe(
  765. lambda u=uploaded, t=total: spawn_background_task(
  766. self._set_active_upload_progress(job, u, t),
  767. name=f"upload-progress-{job.id}",
  768. )
  769. )
  770. if ftp_retry_enabled:
  771. uploaded = await with_ftp_retry(
  772. upload_file_async,
  773. printer_ip,
  774. printer_access_code,
  775. file_path,
  776. remote_path,
  777. progress_callback=upload_progress_callback,
  778. socket_timeout=ftp_timeout,
  779. printer_model=printer_model,
  780. max_retries=ftp_retry_count,
  781. retry_delay=ftp_retry_delay,
  782. operation_name=f"Upload for print to {printer_name}",
  783. non_retry_exceptions=(DispatchJobCancelled,),
  784. )
  785. else:
  786. uploaded = await upload_file_async(
  787. printer_ip,
  788. printer_access_code,
  789. file_path,
  790. remote_path,
  791. progress_callback=upload_progress_callback,
  792. socket_timeout=ftp_timeout,
  793. printer_model=printer_model,
  794. )
  795. if uploaded:
  796. await self._set_active_upload_progress(job, 1, 1)
  797. if not uploaded:
  798. await db.rollback()
  799. raise RuntimeError(
  800. "Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT)."
  801. )
  802. # Resolve plate_id before register so usage tracking can scope the
  803. # 3MF parse to the dispatched plate at print-start (#1697).
  804. plate_id = self._resolve_plate_id(file_path, job.options.get("plate_id"))
  805. register_expected_print(
  806. job.printer_id,
  807. remote_filename,
  808. archive.id,
  809. ams_mapping=job.options.get("ams_mapping"),
  810. cost_center_id=job.options.get("cost_center_id"),
  811. plate_id=plate_id,
  812. )
  813. self._raise_if_cancel_requested(job)
  814. effective_timelapse = bool(job.options.get("timelapse", False))
  815. await self._set_active_message(job, f"Starting print on {printer_name}...")
  816. started = printer_manager.start_print(
  817. job.printer_id,
  818. remote_filename,
  819. plate_id,
  820. ams_mapping=job.options.get("ams_mapping"),
  821. timelapse=effective_timelapse,
  822. bed_levelling=job.options.get("bed_levelling", True),
  823. flow_cali=job.options.get("flow_cali", False),
  824. vibration_cali=job.options.get("vibration_cali", True),
  825. layer_inspect=job.options.get("layer_inspect", False),
  826. use_ams=job.options.get("use_ams", True),
  827. nozzle_offset_cali=job.options.get("nozzle_offset_cali", False),
  828. )
  829. if not started:
  830. await self._cleanup_sd_card_file(
  831. printer_ip,
  832. printer_access_code,
  833. remote_path,
  834. printer_model,
  835. )
  836. await db.rollback()
  837. raise RuntimeError("Failed to start print")
  838. # Same as the archive path: register the library file's local
  839. # 3MF in the cover-cache so /cover skips FTP (#1166 follow-up).
  840. cache_3mf_download(job.printer_id, remote_filename, file_path)
  841. # See _run_reprint_archive for rationale (#1042). On timeout
  842. # also rolls back the freshly-created archive so the library
  843. # flow doesn't leave behind a phantom row for a print that
  844. # never started.
  845. pre_status = printer_manager.get_status(job.printer_id)
  846. pre_state = getattr(pre_status, "state", None) if pre_status else None
  847. pre_subtask_id = getattr(pre_status, "subtask_id", None) if pre_status else None
  848. pre_gcode_file = getattr(pre_status, "gcode_file", None) if pre_status else None
  849. if pre_state:
  850. await self._set_active_message(job, f"Waiting for {printer_name} to acknowledge print...")
  851. transitioned = await self._verify_print_response(
  852. job.printer_id,
  853. printer_name,
  854. pre_state,
  855. pre_subtask_id=pre_subtask_id,
  856. pre_gcode_file=pre_gcode_file,
  857. )
  858. if not transitioned:
  859. await db.rollback()
  860. raise RuntimeError(
  861. f"Printer did not acknowledge print command — state still {pre_state}. "
  862. f"Check the printer for a pending error (HMS code, plate-clear prompt, "
  863. f"SD card) and try again."
  864. )
  865. if job.requested_by_user_id and job.requested_by_username:
  866. printer_manager.set_current_print_user(
  867. job.printer_id,
  868. job.requested_by_user_id,
  869. job.requested_by_username,
  870. )
  871. # Direct-Print flow only: archive_print copies, so deleting the
  872. # transient library row + files here leaves archive intact. Disk
  873. # deletes run only after commit so a rollback leaves no orphan.
  874. cleanup_disk_paths: list[Path] = []
  875. if job.cleanup_library_after_dispatch and not lib_file.is_external:
  876. cleanup_disk_paths.append(file_path)
  877. if lib_file.thumbnail_path:
  878. thumb_path = Path(lib_file.thumbnail_path)
  879. if not thumb_path.is_absolute():
  880. thumb_path = Path(settings.base_dir) / lib_file.thumbnail_path
  881. cleanup_disk_paths.append(thumb_path)
  882. await db.delete(lib_file)
  883. await db.commit()
  884. for cleanup_path in cleanup_disk_paths:
  885. try:
  886. if cleanup_path.exists():
  887. cleanup_path.unlink()
  888. except OSError as cleanup_err:
  889. logger.warning("Failed to delete transient library file %s: %s", cleanup_path, cleanup_err)
  890. except DispatchJobCancelled:
  891. await db.rollback()
  892. await self._set_active_message(job, f"Cancelled upload on {printer_name}.")
  893. raise
  894. @staticmethod
  895. async def _verify_print_response(
  896. printer_id: int,
  897. printer_name: str,
  898. pre_state: str,
  899. pre_subtask_id: str | None = None,
  900. pre_gcode_file: str | None = None,
  901. timeout: float = 90.0,
  902. poll_interval: float = 3.0,
  903. ) -> bool:
  904. """Wait for the printer to acknowledge a print command.
  905. Returns True if the printer transitioned (state advanced past pre_state
  906. or subtask_id advanced past pre_subtask_id). Returns False on timeout —
  907. in that case logs a warning and forces an MQTT reconnect, mirroring the
  908. queue-side watchdog (`_watchdog_print_start`). Caller is responsible
  909. for surfacing the False result to the user (typically by raising so the
  910. dispatch job is marked failed).
  911. Both transition signals are checked because H2D can sit at FINISH for
  912. ~50 s after accepting `project_file` before flipping to PREPARE; the
  913. printer echoes our per-dispatch identity back as `subtask_id` on
  914. `push_status` first, so a subtask_id change is a definitive "command
  915. landed" signal even while state is still FINISH (#1078).
  916. """
  917. deadline = time.monotonic() + timeout
  918. last_status = None
  919. while time.monotonic() < deadline:
  920. await asyncio.sleep(poll_interval)
  921. state = printer_manager.get_status(printer_id)
  922. if not state:
  923. # Printer momentarily not reporting — could be a brief MQTT
  924. # disconnect mid-window. Keep polling rather than declaring
  925. # failure on the first missed tick; the printer may reconnect
  926. # within the remaining timeout and still surface a transition.
  927. continue
  928. last_status = state
  929. if state.state in _ACTIVE_PRINT_STATES:
  930. # Printer is actively processing the job. We do NOT accept
  931. # arbitrary state transitions: a printer going FINISH -> IDLE
  932. # (user dismissed the post-print prompt without accepting our
  933. # project_file) would otherwise look like "command landed"
  934. # and the dispatch job would be marked successful even though
  935. # no print is running (#1370).
  936. return True
  937. if pre_subtask_id is not None and state.subtask_id is not None and state.subtask_id != pre_subtask_id:
  938. # Printer picked up the job (subtask_id advanced). H2D can
  939. # sit at FINISH for ~50 s after accepting project_file before
  940. # transitioning to PREPARE, but the subtask_id flips to our
  941. # submission_id almost immediately (#1078).
  942. return True
  943. logger.warning(
  944. "Printer %s (%d) did not respond to print command within %.0fs "
  945. "(state still %s, subtask_id still %s) — printer may need restart",
  946. printer_name,
  947. printer_id,
  948. timeout,
  949. pre_state,
  950. pre_subtask_id,
  951. )
  952. # Distinguish #1150 (slow parse) from #887/#936 (half-broken session)
  953. # via gcode_file: if the printer is now showing a different file than
  954. # before dispatch, the project_file command landed and the printer is
  955. # parsing — a forced reconnect mid-parse causes 0500_4003. If
  956. # gcode_file is unchanged, the publish was silently swallowed and the
  957. # original #936 recovery (force_reconnect → fresh client_id) is what
  958. # we want. Caveat: in the rare retry-same-file-after-timeout case the
  959. # printer's gcode_file looks identical before and after the publish
  960. # lands, so a slow parse on retry-same-file still falls through to the
  961. # reconnect (and the original 0500_4003) — accepted to avoid breaking
  962. # the half-broken-session recovery path.
  963. client = printer_manager.get_client(printer_id)
  964. current_gcode_file = getattr(last_status, "gcode_file", None) if last_status else None
  965. publish_landed = current_gcode_file is not None and current_gcode_file != pre_gcode_file
  966. if publish_landed:
  967. logger.warning(
  968. "Printer %s (%d) gcode_file changed to %r (was %r) — printer "
  969. "received the command and is parsing slowly. Skipping forced "
  970. "MQTT reconnect to avoid 0500_4003 mid-parse (#1150).",
  971. printer_name,
  972. printer_id,
  973. current_gcode_file,
  974. pre_gcode_file,
  975. )
  976. elif client and hasattr(client, "force_reconnect_stale_session"):
  977. client.force_reconnect_stale_session(
  978. f"print command unacknowledged after {timeout:.0f}s "
  979. f"(state still {pre_state}, gcode_file {current_gcode_file!r})"
  980. )
  981. return False
  982. @staticmethod
  983. async def _cleanup_sd_card_file(
  984. printer_ip: str,
  985. access_code: str,
  986. remote_path: str,
  987. printer_model: str | None,
  988. ):
  989. """Best-effort delete of uploaded file from printer SD card."""
  990. try:
  991. await delete_file_async(printer_ip, access_code, remote_path, printer_model=printer_model)
  992. except Exception:
  993. pass # Best-effort — don't fail the error handler
  994. @staticmethod
  995. def _resolve_plate_id(file_path: Path, requested_plate_id: int | None) -> int:
  996. if requested_plate_id is not None:
  997. return requested_plate_id
  998. plate_id = 1
  999. try:
  1000. with zipfile.ZipFile(file_path, "r") as zf:
  1001. for name in zf.namelist():
  1002. if name.startswith("Metadata/plate_") and name.endswith(".gcode"):
  1003. plate_str = name[15:-6]
  1004. plate_id = int(plate_str)
  1005. break
  1006. except (ValueError, zipfile.BadZipFile, OSError):
  1007. pass
  1008. return plate_id
  1009. @staticmethod
  1010. def _is_sliced_file(filename: str) -> bool:
  1011. lower = filename.lower()
  1012. return lower.endswith(".gcode") or lower.endswith(".gcode.3mf")
  1013. background_dispatch = BackgroundDispatchService()