main.py 93 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455145614571458145914601461146214631464146514661467146814691470147114721473147414751476147714781479148014811482148314841485148614871488148914901491149214931494149514961497149814991500150115021503150415051506150715081509151015111512151315141515151615171518151915201521152215231524152515261527152815291530153115321533153415351536153715381539154015411542154315441545154615471548154915501551155215531554155515561557155815591560156115621563156415651566156715681569157015711572157315741575157615771578157915801581158215831584158515861587158815891590159115921593159415951596159715981599160016011602160316041605160616071608160916101611161216131614161516161617161816191620162116221623162416251626162716281629163016311632163316341635163616371638163916401641164216431644164516461647164816491650165116521653165416551656165716581659166016611662166316641665166616671668166916701671167216731674167516761677167816791680168116821683168416851686168716881689169016911692169316941695169616971698169917001701170217031704170517061707170817091710171117121713171417151716171717181719172017211722172317241725172617271728172917301731173217331734173517361737173817391740174117421743174417451746174717481749175017511752175317541755175617571758175917601761176217631764176517661767176817691770177117721773177417751776177717781779178017811782178317841785178617871788178917901791179217931794179517961797179817991800180118021803180418051806180718081809181018111812181318141815181618171818181918201821182218231824182518261827182818291830183118321833183418351836183718381839184018411842184318441845184618471848184918501851185218531854185518561857185818591860186118621863186418651866186718681869187018711872187318741875187618771878187918801881188218831884188518861887188818891890189118921893189418951896189718981899190019011902190319041905190619071908190919101911191219131914191519161917191819191920192119221923192419251926192719281929193019311932193319341935193619371938193919401941194219431944194519461947194819491950195119521953195419551956195719581959196019611962196319641965196619671968196919701971197219731974197519761977197819791980198119821983198419851986198719881989199019911992199319941995199619971998199920002001200220032004200520062007200820092010201120122013201420152016201720182019202020212022202320242025202620272028202920302031203220332034203520362037203820392040204120422043204420452046204720482049205020512052205320542055205620572058205920602061206220632064
  1. import asyncio
  2. import logging
  3. from contextlib import asynccontextmanager
  4. from datetime import UTC, datetime, timedelta
  5. from logging.handlers import RotatingFileHandler
  6. from fastapi import FastAPI
  7. # Import settings first for logging configuration
  8. from backend.app.core.config import APP_VERSION, settings as app_settings
  9. # Configure logging based on settings
  10. # DEBUG=true -> DEBUG level, else use LOG_LEVEL setting
  11. log_level_str = "DEBUG" if app_settings.debug else app_settings.log_level.upper()
  12. log_level = getattr(logging, log_level_str, logging.INFO)
  13. log_format = "%(asctime)s %(levelname)s [%(name)s] %(message)s"
  14. # Create root logger
  15. root_logger = logging.getLogger()
  16. root_logger.setLevel(log_level)
  17. # Console handler - always enabled
  18. console_handler = logging.StreamHandler()
  19. console_handler.setLevel(log_level)
  20. console_handler.setFormatter(logging.Formatter(log_format))
  21. root_logger.addHandler(console_handler)
  22. # File handler - only in production or if explicitly enabled
  23. if app_settings.log_to_file:
  24. log_file = app_settings.log_dir / "bambuddy.log"
  25. file_handler = RotatingFileHandler(
  26. log_file,
  27. maxBytes=5 * 1024 * 1024, # 5MB
  28. backupCount=3,
  29. encoding="utf-8",
  30. )
  31. file_handler.setLevel(log_level)
  32. file_handler.setFormatter(logging.Formatter(log_format))
  33. root_logger.addHandler(file_handler)
  34. logging.info(f"Logging to file: {log_file}")
  35. # Reduce noise from third-party libraries in production
  36. if not app_settings.debug:
  37. logging.getLogger("sqlalchemy.engine").setLevel(logging.WARNING)
  38. logging.getLogger("httpcore").setLevel(logging.WARNING)
  39. logging.getLogger("httpx").setLevel(logging.WARNING)
  40. logging.info(f"Bambuddy starting - debug={app_settings.debug}, log_level={log_level_str}")
  41. from fastapi.responses import FileResponse
  42. from fastapi.staticfiles import StaticFiles
  43. from sqlalchemy import delete, or_, select
  44. from backend.app.api.routes import (
  45. ams_history,
  46. api_keys,
  47. archives,
  48. camera,
  49. cloud,
  50. discovery,
  51. external_links,
  52. filaments,
  53. firmware,
  54. kprofiles,
  55. library,
  56. maintenance,
  57. notification_templates,
  58. notifications,
  59. pending_uploads,
  60. print_queue,
  61. printers,
  62. projects,
  63. settings as settings_routes,
  64. smart_plugs,
  65. spoolman,
  66. support,
  67. system,
  68. updates,
  69. webhook,
  70. websocket,
  71. )
  72. from backend.app.api.routes.maintenance import _get_printer_maintenance_internal, ensure_default_types
  73. from backend.app.api.routes.support import init_debug_logging
  74. from backend.app.core.database import async_session, init_db
  75. from backend.app.core.websocket import ws_manager
  76. from backend.app.models.smart_plug import SmartPlug
  77. from backend.app.services.archive import ArchiveService
  78. from backend.app.services.bambu_ftp import download_file_async, get_ftp_retry_settings, with_ftp_retry
  79. from backend.app.services.bambu_mqtt import PrinterState
  80. from backend.app.services.mqtt_relay import mqtt_relay
  81. from backend.app.services.notification_service import notification_service
  82. from backend.app.services.print_scheduler import scheduler as print_scheduler
  83. from backend.app.services.printer_manager import (
  84. init_printer_connections,
  85. printer_manager,
  86. printer_state_to_dict,
  87. )
  88. from backend.app.services.smart_plug_manager import smart_plug_manager
  89. from backend.app.services.spoolman import close_spoolman_client, get_spoolman_client, init_spoolman_client
  90. from backend.app.services.tasmota import tasmota_service
  91. from backend.app.services.telemetry import start_telemetry_loop
  92. # Track active prints: {(printer_id, filename): archive_id}
  93. _active_prints: dict[tuple[int, str], int] = {}
  94. # Track expected prints from reprint/scheduled (skip auto-archiving for these)
  95. # {(printer_id, filename): archive_id}
  96. _expected_prints: dict[tuple[int, str], int] = {}
  97. # Track starting energy for prints: {archive_id: starting_kwh}
  98. _print_energy_start: dict[int, float] = {}
  99. def register_expected_print(printer_id: int, filename: str, archive_id: int):
  100. """Register an expected print from reprint/scheduled so we don't create duplicate archives."""
  101. # Store with multiple filename variations to catch different naming patterns
  102. _expected_prints[(printer_id, filename)] = archive_id
  103. # Also store without .3mf extension if present
  104. if filename.endswith(".3mf"):
  105. base = filename[:-4]
  106. _expected_prints[(printer_id, base)] = archive_id
  107. _expected_prints[(printer_id, f"{base}.gcode")] = archive_id
  108. logging.getLogger(__name__).info(
  109. f"Registered expected print: printer={printer_id}, file={filename}, archive={archive_id}"
  110. )
  111. _last_status_broadcast: dict[int, str] = {}
  112. _nozzle_count_updated: set[int] = set() # Track printers where we've updated nozzle_count
  113. async def _report_spoolman_usage(printer_id: int, archive_id: int, logger):
  114. """Report filament usage to Spoolman after print completion.
  115. This finds the spool by RFID tag_uid from current AMS state and reports
  116. the filament_used_grams from the archive metadata.
  117. """
  118. async with async_session() as db:
  119. from backend.app.api.routes.settings import get_setting
  120. from backend.app.models.archive import PrintArchive
  121. # Check if Spoolman is enabled
  122. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  123. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  124. return
  125. # Get Spoolman URL
  126. spoolman_url = await get_setting(db, "spoolman_url")
  127. if not spoolman_url:
  128. return
  129. # Get or create Spoolman client
  130. client = await get_spoolman_client()
  131. if not client:
  132. client = await init_spoolman_client(spoolman_url)
  133. # Check if Spoolman is reachable
  134. if not await client.health_check():
  135. logger.warning("Spoolman not reachable for usage reporting")
  136. return
  137. # Get archive to find filament usage
  138. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  139. archive = result.scalar_one_or_none()
  140. if not archive or not archive.filament_used_grams:
  141. logger.debug(f"No filament usage data for archive {archive_id}")
  142. return
  143. filament_used = archive.filament_used_grams
  144. logger.info(f"[SPOOLMAN] Archive {archive_id} used {filament_used}g of filament")
  145. # Get current AMS state from printer to find the active spool
  146. state = printer_manager.get_status(printer_id)
  147. if not state or not state.raw_data:
  148. logger.debug("No printer state available for usage reporting")
  149. return
  150. ams_data = state.raw_data.get("ams")
  151. if not ams_data:
  152. logger.debug("No AMS data available for usage reporting")
  153. return
  154. # Find spools with RFID tags in Spoolman and report usage
  155. # For now, we report usage to the first spool found with a matching tag
  156. # TODO: In future, track which specific trays were used during the print
  157. spools_updated = 0
  158. for ams_unit in ams_data:
  159. trays = ams_unit.get("tray", [])
  160. for tray_data in trays:
  161. tag_uid = tray_data.get("tag_uid")
  162. if not tag_uid:
  163. continue
  164. # Find spool in Spoolman by tag
  165. spool = await client.find_spool_by_tag(tag_uid)
  166. if spool:
  167. # Report usage to Spoolman
  168. result = await client.use_spool(spool["id"], filament_used)
  169. if result:
  170. logger.info(
  171. f"[SPOOLMAN] Reported {filament_used}g usage to spool {spool['id']} (tag: {tag_uid})"
  172. )
  173. spools_updated += 1
  174. # Only report to one spool for single-material prints
  175. # Multi-material prints would need more sophisticated tracking
  176. return
  177. if spools_updated == 0:
  178. logger.debug(f"No matching Spoolman spools found for printer {printer_id}")
  179. async def on_printer_status_change(printer_id: int, state: PrinterState):
  180. """Handle printer status changes - broadcast via WebSocket."""
  181. # Only broadcast if something meaningful changed (reduce WebSocket spam)
  182. # Include rounded temperatures to detect meaningful temp changes (within 1 degree)
  183. temps = state.temperatures or {}
  184. nozzle_temp = round(temps.get("nozzle", 0))
  185. bed_temp = round(temps.get("bed", 0))
  186. nozzle_2_temp = round(temps.get("nozzle_2", 0)) if "nozzle_2" in temps else ""
  187. chamber_temp = round(temps.get("chamber", 0)) if "chamber" in temps else ""
  188. # Auto-detect dual-nozzle printers from MQTT temperature data
  189. if "nozzle_2" in temps and printer_id not in _nozzle_count_updated:
  190. _nozzle_count_updated.add(printer_id)
  191. # Update nozzle_count in database
  192. async with async_session() as db:
  193. from backend.app.models.printer import Printer
  194. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  195. printer = result.scalar_one_or_none()
  196. if printer and printer.nozzle_count != 2:
  197. printer.nozzle_count = 2
  198. await db.commit()
  199. logging.getLogger(__name__).info(
  200. f"Auto-detected dual-nozzle printer {printer_id}, updated nozzle_count=2"
  201. )
  202. # Include target temps for heating phase detection
  203. bed_target = round(temps.get("bed_target", 0))
  204. nozzle_target = round(temps.get("nozzle_target", 0))
  205. status_key = (
  206. f"{state.connected}:{state.state}:{state.progress}:{state.layer_num}:"
  207. f"{nozzle_temp}:{bed_temp}:{nozzle_2_temp}:{chamber_temp}:"
  208. f"{state.stg_cur}:{bed_target}:{nozzle_target}:"
  209. f"{state.cooling_fan_speed}:{state.big_fan1_speed}:{state.big_fan2_speed}:"
  210. f"{state.chamber_light}:{state.active_extruder}"
  211. )
  212. # MQTT relay - publish status (before dedup check - always publish to MQTT)
  213. try:
  214. printer_info = printer_manager.get_printer(printer_id)
  215. if printer_info:
  216. await mqtt_relay.on_printer_status(printer_id, state, printer_info.name, printer_info.serial_number)
  217. except Exception:
  218. pass # Don't fail status callback if MQTT fails
  219. if _last_status_broadcast.get(printer_id) == status_key:
  220. return # No change, skip WebSocket broadcast
  221. _last_status_broadcast[printer_id] = status_key
  222. await ws_manager.send_printer_status(
  223. printer_id,
  224. printer_state_to_dict(state, printer_id, printer_manager.get_model(printer_id)),
  225. )
  226. async def on_ams_change(printer_id: int, ams_data: list):
  227. """Handle AMS data changes - sync to Spoolman if enabled and auto mode."""
  228. import logging
  229. logger = logging.getLogger(__name__)
  230. # MQTT relay - publish AMS change
  231. try:
  232. printer_info = printer_manager.get_printer(printer_id)
  233. if printer_info:
  234. await mqtt_relay.on_ams_change(printer_id, printer_info.name, printer_info.serial_number, ams_data)
  235. except Exception:
  236. pass # Don't fail AMS callback if MQTT fails
  237. # Broadcast AMS change via WebSocket (bypasses status_key deduplication)
  238. # This ensures frontend gets immediate updates when AMS slots are configured
  239. try:
  240. state = printer_manager.get_status(printer_id)
  241. if state:
  242. logger.info(f"[Printer {printer_id}] Broadcasting AMS change via WebSocket")
  243. await ws_manager.send_printer_status(
  244. printer_id,
  245. printer_state_to_dict(state, printer_id, printer_manager.get_model(printer_id)),
  246. )
  247. except Exception as e:
  248. logger.warning(f"Failed to broadcast AMS change for printer {printer_id}: {e}")
  249. try:
  250. async with async_session() as db:
  251. from backend.app.api.routes.settings import get_setting
  252. from backend.app.models.printer import Printer
  253. # Check if Spoolman is enabled
  254. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  255. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  256. return
  257. # Check sync mode
  258. sync_mode = await get_setting(db, "spoolman_sync_mode")
  259. if sync_mode and sync_mode != "auto":
  260. return # Only sync on auto mode
  261. # Get Spoolman URL
  262. spoolman_url = await get_setting(db, "spoolman_url")
  263. if not spoolman_url:
  264. return
  265. # Get or create Spoolman client
  266. client = await get_spoolman_client()
  267. if not client:
  268. client = await init_spoolman_client(spoolman_url)
  269. # Check if Spoolman is reachable
  270. if not await client.health_check():
  271. logger.warning(f"Spoolman not reachable at {spoolman_url}")
  272. return
  273. # Get printer name for location
  274. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  275. printer = result.scalar_one_or_none()
  276. printer_name = printer.name if printer else f"Printer {printer_id}"
  277. # Sync each AMS tray
  278. synced = 0
  279. for ams_unit in ams_data:
  280. ams_id = int(ams_unit.get("id", 0))
  281. trays = ams_unit.get("tray", [])
  282. for tray_data in trays:
  283. tray = client.parse_ams_tray(ams_id, tray_data)
  284. if not tray:
  285. continue # Empty tray
  286. try:
  287. result = await client.sync_ams_tray(tray, printer_name)
  288. if result:
  289. synced += 1
  290. except Exception as e:
  291. logger.error(f"Error syncing AMS {ams_id} tray {tray.tray_id}: {e}")
  292. if synced > 0:
  293. logger.info(f"Auto-synced {synced} AMS trays to Spoolman for printer {printer_id}")
  294. except Exception as e:
  295. import logging
  296. logging.getLogger(__name__).warning(f"Spoolman AMS sync failed: {e}")
  297. async def _send_print_start_notification(
  298. printer_id: int,
  299. data: dict,
  300. archive_data: dict | None = None,
  301. logger=None,
  302. ):
  303. """Helper to send print start notification with optional archive data."""
  304. if logger is None:
  305. import logging
  306. logger = logging.getLogger(__name__)
  307. try:
  308. async with async_session() as db:
  309. from backend.app.models.printer import Printer
  310. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  311. printer = result.scalar_one_or_none()
  312. printer_name = printer.name if printer else f"Printer {printer_id}"
  313. await notification_service.on_print_start(printer_id, printer_name, data, db, archive_data=archive_data)
  314. except Exception as e:
  315. logger.warning(f"Notification on_print_start failed: {e}")
  316. def _load_objects_from_archive(archive, printer_id: int, logger) -> None:
  317. """Extract printable objects from an archive's 3MF file and store in printer state."""
  318. try:
  319. from backend.app.services.archive import extract_printable_objects_from_3mf
  320. file_path = app_settings.base_dir / archive.file_path
  321. if file_path.exists() and str(file_path).endswith(".3mf"):
  322. with open(file_path, "rb") as f:
  323. threemf_data = f.read()
  324. # Extract with positions for UI overlay
  325. printable_objects, bbox_all = extract_printable_objects_from_3mf(threemf_data, include_positions=True)
  326. if printable_objects:
  327. client = printer_manager.get_client(printer_id)
  328. if client:
  329. client.state.printable_objects = printable_objects
  330. client.state.printable_objects_bbox_all = bbox_all
  331. client.state.skipped_objects = []
  332. logger.info(f"Loaded {len(printable_objects)} printable objects for printer {printer_id}")
  333. except Exception as e:
  334. logger.debug(f"Failed to extract printable objects from archive: {e}")
  335. async def on_print_start(printer_id: int, data: dict):
  336. """Handle print start - archive the 3MF file immediately."""
  337. import logging
  338. logger = logging.getLogger(__name__)
  339. logger.info(f"[CALLBACK] on_print_start called for printer {printer_id}, data keys: {list(data.keys())}")
  340. await ws_manager.send_print_start(printer_id, data)
  341. # MQTT relay - publish print start
  342. try:
  343. printer_info = printer_manager.get_printer(printer_id)
  344. if printer_info:
  345. await mqtt_relay.on_print_start(
  346. printer_id,
  347. printer_info.name,
  348. printer_info.serial_number,
  349. data.get("filename", ""),
  350. data.get("subtask_name", ""),
  351. )
  352. except Exception:
  353. pass # Don't fail print start callback if MQTT fails
  354. # Track if notification was sent (to avoid sending twice)
  355. notification_sent = False
  356. # Smart plug automation: turn on plug when print starts
  357. try:
  358. async with async_session() as db:
  359. await smart_plug_manager.on_print_start(printer_id, db)
  360. except Exception as e:
  361. logger.warning(f"Smart plug on_print_start failed: {e}")
  362. async with async_session() as db:
  363. from backend.app.models.printer import Printer
  364. from backend.app.services.bambu_ftp import list_files_async
  365. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  366. printer = result.scalar_one_or_none()
  367. if not printer or not printer.auto_archive:
  368. # Send notification without archive data (auto-archive disabled)
  369. logger.info(
  370. f"[CALLBACK] Skipping archive - printer: {printer is not None}, auto_archive: {printer.auto_archive if printer else 'N/A'}"
  371. )
  372. if not notification_sent:
  373. await _send_print_start_notification(printer_id, data, logger=logger)
  374. return
  375. # Get the filename and subtask_name
  376. filename = data.get("filename", "")
  377. subtask_name = data.get("subtask_name", "")
  378. logger.info(f"[CALLBACK] Print start detected - filename: {filename}, subtask: {subtask_name}")
  379. if not filename and not subtask_name:
  380. # Send notification without archive data (no filename)
  381. logger.info("[CALLBACK] Skipping archive - no filename or subtask_name")
  382. if not notification_sent:
  383. await _send_print_start_notification(printer_id, data, logger=logger)
  384. return
  385. # Check if this is an expected print from reprint/scheduled
  386. # Build list of possible keys to check
  387. expected_keys = []
  388. if subtask_name:
  389. expected_keys.append((printer_id, subtask_name))
  390. expected_keys.append((printer_id, f"{subtask_name}.3mf"))
  391. expected_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  392. if filename:
  393. fname = filename.split("/")[-1] if "/" in filename else filename
  394. expected_keys.append((printer_id, fname))
  395. # Strip extensions to match
  396. base = fname.replace(".gcode", "").replace(".3mf", "")
  397. expected_keys.append((printer_id, base))
  398. expected_keys.append((printer_id, f"{base}.3mf"))
  399. expected_archive_id = None
  400. for key in expected_keys:
  401. expected_archive_id = _expected_prints.pop(key, None)
  402. if expected_archive_id:
  403. # Clean up other possible keys for this print
  404. for other_key in expected_keys:
  405. _expected_prints.pop(other_key, None)
  406. break
  407. if expected_archive_id:
  408. # This is a reprint/scheduled print - use existing archive, don't create new one
  409. logger.info(f"Using expected archive {expected_archive_id} for print (skipping duplicate)")
  410. from backend.app.models.archive import PrintArchive
  411. result = await db.execute(select(PrintArchive).where(PrintArchive.id == expected_archive_id))
  412. archive = result.scalar_one_or_none()
  413. if archive:
  414. # Update archive status to printing
  415. archive.status = "printing"
  416. archive.started_at = datetime.now()
  417. await db.commit()
  418. # Track as active print
  419. _active_prints[(printer_id, archive.filename)] = archive.id
  420. if subtask_name:
  421. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  422. # Set up energy tracking
  423. try:
  424. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  425. plug = plug_result.scalar_one_or_none()
  426. logger.info(
  427. f"[ENERGY] Print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  428. )
  429. if plug:
  430. energy = await tasmota_service.get_energy(plug)
  431. logger.info(f"[ENERGY] Energy response from plug: {energy}")
  432. if energy and energy.get("total") is not None:
  433. _print_energy_start[archive.id] = energy["total"]
  434. logger.info(
  435. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  436. )
  437. else:
  438. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  439. else:
  440. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  441. except Exception as e:
  442. logger.warning(f"Failed to record starting energy: {e}")
  443. await ws_manager.send_archive_updated(
  444. {
  445. "id": archive.id,
  446. "status": "printing",
  447. }
  448. )
  449. # Send notification with archive data (reprint/scheduled)
  450. if not notification_sent:
  451. archive_data = {"print_time_seconds": archive.print_time_seconds}
  452. await _send_print_start_notification(printer_id, data, archive_data, logger)
  453. # Extract printable objects from the archived 3MF file
  454. _load_objects_from_archive(archive, printer_id, logger)
  455. return # Skip creating a new archive
  456. # Check if there's already a "printing" archive for this printer/file
  457. # This prevents duplicates when backend restarts during an active print
  458. from backend.app.models.archive import PrintArchive
  459. check_name = subtask_name or filename.split("/")[-1].replace(".gcode", "").replace(".3mf", "")
  460. existing = await db.execute(
  461. select(PrintArchive)
  462. .where(PrintArchive.printer_id == printer_id)
  463. .where(PrintArchive.status == "printing")
  464. .where(PrintArchive.print_name.ilike(f"%{check_name}%"))
  465. .order_by(PrintArchive.created_at.desc())
  466. .limit(1)
  467. )
  468. existing_archive = existing.scalar_one_or_none()
  469. if existing_archive:
  470. # Check if archive is stale (older than 4 hours) - likely a failed/cancelled print
  471. # that didn't get properly updated
  472. archive_age = datetime.now(UTC) - existing_archive.created_at.replace(tzinfo=UTC)
  473. if archive_age.total_seconds() > 4 * 60 * 60: # 4 hours
  474. logger.warning(
  475. f"Found stale 'printing' archive {existing_archive.id} (age: {archive_age}), "
  476. f"marking as cancelled and creating new archive"
  477. )
  478. existing_archive.status = "cancelled"
  479. existing_archive.failure_reason = "Stale - print likely cancelled or failed without status update"
  480. await db.commit()
  481. # Fall through to create new archive (don't return)
  482. existing_archive = None # Clear so we don't use stale archive
  483. else:
  484. logger.info(
  485. f"Skipping duplicate - already have printing archive {existing_archive.id} for {check_name}"
  486. )
  487. # Track this as the active print
  488. _active_prints[(printer_id, existing_archive.filename)] = existing_archive.id
  489. # Also set up energy tracking if not already tracked
  490. if existing_archive.id not in _print_energy_start:
  491. try:
  492. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  493. plug = plug_result.scalar_one_or_none()
  494. if plug:
  495. energy = await tasmota_service.get_energy(plug)
  496. if energy and energy.get("total") is not None:
  497. _print_energy_start[existing_archive.id] = energy["total"]
  498. logger.info(
  499. f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh"
  500. )
  501. except Exception as e:
  502. logger.warning(f"Failed to record starting energy for existing archive: {e}")
  503. # Send notification with archive data (existing archive)
  504. if not notification_sent:
  505. archive_data = {"print_time_seconds": existing_archive.print_time_seconds}
  506. await _send_print_start_notification(printer_id, data, archive_data, logger)
  507. # Extract printable objects from the archived 3MF file
  508. _load_objects_from_archive(existing_archive, printer_id, logger)
  509. return
  510. # Build list of possible 3MF filenames to try
  511. possible_names = []
  512. # Bambu printers typically store files as "Name.gcode.3mf"
  513. # The subtask_name is usually the best source for the filename
  514. if subtask_name:
  515. # Try common Bambu naming patterns
  516. possible_names.append(f"{subtask_name}.gcode.3mf")
  517. possible_names.append(f"{subtask_name}.3mf")
  518. # Try original filename with .3mf extension
  519. if filename:
  520. # Extract just the filename part, not the full path
  521. fname = filename.split("/")[-1] if "/" in filename else filename
  522. if fname.endswith(".3mf"):
  523. possible_names.append(fname)
  524. elif fname.endswith(".gcode"):
  525. base = fname.rsplit(".", 1)[0]
  526. possible_names.append(f"{base}.gcode.3mf")
  527. possible_names.append(f"{base}.3mf")
  528. else:
  529. possible_names.append(f"{fname}.gcode.3mf")
  530. possible_names.append(f"{fname}.3mf")
  531. # Remove duplicates while preserving order
  532. seen = set()
  533. possible_names = [x for x in possible_names if not (x in seen or seen.add(x))]
  534. logger.info(f"Trying filenames: {possible_names}")
  535. # Try to find and download the 3MF file
  536. temp_path = None
  537. downloaded_filename = None
  538. # Get FTP retry settings
  539. ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
  540. for try_filename in possible_names:
  541. if not try_filename.endswith(".3mf"):
  542. continue
  543. remote_paths = [
  544. f"/cache/{try_filename}",
  545. f"/model/{try_filename}",
  546. f"/{try_filename}",
  547. ]
  548. temp_path = app_settings.archive_dir / "temp" / try_filename
  549. temp_path.parent.mkdir(parents=True, exist_ok=True)
  550. for remote_path in remote_paths:
  551. logger.debug(f"Trying FTP download: {remote_path}")
  552. try:
  553. if ftp_retry_enabled:
  554. downloaded = await with_ftp_retry(
  555. download_file_async,
  556. printer.ip_address,
  557. printer.access_code,
  558. remote_path,
  559. temp_path,
  560. socket_timeout=ftp_timeout,
  561. printer_model=printer.model,
  562. max_retries=ftp_retry_count,
  563. retry_delay=ftp_retry_delay,
  564. operation_name=f"Download 3MF from {remote_path}",
  565. )
  566. else:
  567. downloaded = await download_file_async(
  568. printer.ip_address,
  569. printer.access_code,
  570. remote_path,
  571. temp_path,
  572. socket_timeout=ftp_timeout,
  573. printer_model=printer.model,
  574. )
  575. if downloaded:
  576. downloaded_filename = try_filename
  577. logger.info(f"Downloaded: {remote_path}")
  578. break
  579. except Exception as e:
  580. logger.debug(f"FTP download failed for {remote_path}: {e}")
  581. if downloaded_filename:
  582. break
  583. # If still not found, try listing /cache to find matching file
  584. if not downloaded_filename and (filename or subtask_name):
  585. search_term = (subtask_name or filename).lower().replace(".gcode", "").replace(".3mf", "")
  586. logger.info(f"Direct FTP download failed, listing /cache to find '{search_term}'")
  587. try:
  588. cache_files = await list_files_async(printer.ip_address, printer.access_code, "/cache")
  589. threemf_files = [f.get("name") for f in cache_files if f.get("name", "").endswith(".3mf")]
  590. logger.info(
  591. f"Found {len(threemf_files)} 3MF files in /cache: {threemf_files[:5]}{'...' if len(threemf_files) > 5 else ''}"
  592. )
  593. for f in cache_files:
  594. if f.get("is_directory"):
  595. continue
  596. fname = f.get("name", "")
  597. if fname.endswith(".3mf") and search_term in fname.lower():
  598. logger.info(f"Found matching file: {fname}")
  599. temp_path = app_settings.archive_dir / "temp" / fname
  600. temp_path.parent.mkdir(parents=True, exist_ok=True)
  601. if ftp_retry_enabled:
  602. downloaded = await with_ftp_retry(
  603. download_file_async,
  604. printer.ip_address,
  605. printer.access_code,
  606. f"/cache/{fname}",
  607. temp_path,
  608. max_retries=ftp_retry_count,
  609. retry_delay=ftp_retry_delay,
  610. operation_name=f"Download 3MF from /cache/{fname}",
  611. )
  612. else:
  613. downloaded = await download_file_async(
  614. printer.ip_address,
  615. printer.access_code,
  616. f"/cache/{fname}",
  617. temp_path,
  618. )
  619. if downloaded:
  620. downloaded_filename = fname
  621. logger.info(f"Found and downloaded from cache: {fname}")
  622. break
  623. except Exception as e:
  624. logger.warning(f"Failed to list cache: {e}")
  625. if not downloaded_filename or not temp_path:
  626. logger.warning(f"Could not find 3MF file for print: {filename or subtask_name}")
  627. # Create a fallback archive without 3MF data so the print is still tracked
  628. # This commonly happens with P1S/A1 printers where FTP has file size limitations
  629. try:
  630. from backend.app.models.archive import PrintArchive
  631. # Derive print name from subtask_name or filename
  632. print_name = subtask_name or filename
  633. if print_name:
  634. # Clean up the name (remove extensions, path parts)
  635. print_name = print_name.split("/")[-1]
  636. print_name = print_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  637. else:
  638. print_name = "Unknown Print"
  639. # Create minimal archive entry
  640. fallback_archive = PrintArchive(
  641. printer_id=printer_id,
  642. filename=filename or f"{print_name}.3mf",
  643. file_path="", # Empty - no 3MF file available
  644. file_size=0,
  645. print_name=print_name,
  646. status="printing",
  647. started_at=datetime.now(),
  648. extra_data={"no_3mf_available": True, "original_subtask": subtask_name, "_print_data": data},
  649. )
  650. db.add(fallback_archive)
  651. await db.commit()
  652. await db.refresh(fallback_archive)
  653. logger.info(f"Created fallback archive {fallback_archive.id} for {print_name} (no 3MF available)")
  654. # Track as active print
  655. _active_prints[(printer_id, fallback_archive.filename)] = fallback_archive.id
  656. if filename:
  657. _active_prints[(printer_id, filename)] = fallback_archive.id
  658. if subtask_name:
  659. _active_prints[(printer_id, f"{subtask_name}.3mf")] = fallback_archive.id
  660. _active_prints[(printer_id, subtask_name)] = fallback_archive.id
  661. # Record starting energy if smart plug available
  662. try:
  663. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  664. plug = plug_result.scalar_one_or_none()
  665. if plug:
  666. energy = await tasmota_service.get_energy(plug)
  667. if energy and energy.get("total") is not None:
  668. _print_energy_start[fallback_archive.id] = energy["total"]
  669. logger.info(
  670. f"[ENERGY] Recorded starting energy for fallback archive {fallback_archive.id}: {energy['total']} kWh"
  671. )
  672. except Exception as e:
  673. logger.warning(f"Failed to record starting energy for fallback: {e}")
  674. # Send WebSocket notification
  675. await ws_manager.send_archive_created(
  676. {
  677. "id": fallback_archive.id,
  678. "printer_id": fallback_archive.printer_id,
  679. "filename": fallback_archive.filename,
  680. "print_name": fallback_archive.print_name,
  681. "status": fallback_archive.status,
  682. }
  683. )
  684. # MQTT relay - publish archive created
  685. try:
  686. await mqtt_relay.on_archive_created(
  687. archive_id=fallback_archive.id,
  688. print_name=fallback_archive.print_name,
  689. printer_name=printer.name,
  690. status=fallback_archive.status,
  691. )
  692. except Exception:
  693. pass # Don't fail if MQTT fails
  694. # Send notification without archive data (file not found)
  695. if not notification_sent:
  696. await _send_print_start_notification(printer_id, data, logger=logger)
  697. return
  698. except Exception as e:
  699. logger.error(f"Failed to create fallback archive: {e}")
  700. # Send notification without archive data (file not found)
  701. if not notification_sent:
  702. await _send_print_start_notification(printer_id, data, logger=logger)
  703. return
  704. try:
  705. # Archive the file with status "printing"
  706. service = ArchiveService(db)
  707. archive = await service.archive_print(
  708. printer_id=printer_id,
  709. source_file=temp_path,
  710. print_data={**data, "status": "printing"},
  711. )
  712. if archive:
  713. # Track this active print (use both original filename and downloaded filename)
  714. _active_prints[(printer_id, downloaded_filename)] = archive.id
  715. if filename and filename != downloaded_filename:
  716. _active_prints[(printer_id, filename)] = archive.id
  717. if subtask_name:
  718. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  719. logger.info(f"Created archive {archive.id} for {downloaded_filename}")
  720. # Record starting energy from smart plug if available
  721. try:
  722. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  723. plug = plug_result.scalar_one_or_none()
  724. logger.info(
  725. f"[ENERGY] Auto-archive print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  726. )
  727. if plug:
  728. energy = await tasmota_service.get_energy(plug)
  729. logger.info(f"[ENERGY] Auto-archive energy response: {energy}")
  730. if energy and energy.get("total") is not None:
  731. _print_energy_start[archive.id] = energy["total"]
  732. logger.info(
  733. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  734. )
  735. else:
  736. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  737. else:
  738. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  739. except Exception as e:
  740. logger.warning(f"Failed to record starting energy: {e}")
  741. await ws_manager.send_archive_created(
  742. {
  743. "id": archive.id,
  744. "printer_id": archive.printer_id,
  745. "filename": archive.filename,
  746. "print_name": archive.print_name,
  747. "status": archive.status,
  748. }
  749. )
  750. # MQTT relay - publish archive created
  751. try:
  752. await mqtt_relay.on_archive_created(
  753. archive_id=archive.id,
  754. print_name=archive.print_name,
  755. printer_name=printer.name,
  756. status=archive.status,
  757. )
  758. except Exception:
  759. pass # Don't fail if MQTT fails
  760. # Send notification with archive data (new archive created)
  761. if not notification_sent:
  762. archive_data = {"print_time_seconds": archive.print_time_seconds}
  763. await _send_print_start_notification(printer_id, data, archive_data, logger)
  764. notification_sent = True
  765. # Extract printable objects for skip object functionality
  766. try:
  767. from backend.app.services.archive import extract_printable_objects_from_3mf
  768. with open(temp_path, "rb") as f:
  769. threemf_data = f.read()
  770. # Extract with positions for UI overlay
  771. printable_objects, bbox_all = extract_printable_objects_from_3mf(
  772. threemf_data, include_positions=True
  773. )
  774. if printable_objects:
  775. # Store objects in printer state
  776. client = printer_manager.get_client(printer_id)
  777. if client:
  778. client.state.printable_objects = printable_objects
  779. client.state.printable_objects_bbox_all = bbox_all
  780. client.state.skipped_objects = [] # Reset skipped objects for new print
  781. logger.info(f"Loaded {len(printable_objects)} printable objects for printer {printer_id}")
  782. except Exception as e:
  783. logger.debug(f"Failed to extract printable objects: {e}")
  784. finally:
  785. if temp_path and temp_path.exists():
  786. temp_path.unlink()
  787. async def _scan_for_timelapse_with_retries(archive_id: int):
  788. """
  789. Scan for timelapse with retries.
  790. The printer encodes the timelapse quickly after print completion.
  791. We just need a short delay then grab the most recent file.
  792. Since we KNOW timelapse was active (from MQTT ipcam data), the most recent
  793. file in /timelapse is our target. Retries handle FTP connection issues.
  794. """
  795. import logging
  796. logger = logging.getLogger(__name__)
  797. # Short delays - printer usually finishes encoding within seconds
  798. retry_delays = [5, 10, 20]
  799. for attempt, delay in enumerate(retry_delays, 1):
  800. logger.info(
  801. f"[TIMELAPSE] Attempt {attempt}/{len(retry_delays)}: waiting {delay}s before scanning for archive {archive_id}"
  802. )
  803. await asyncio.sleep(delay)
  804. try:
  805. async with async_session() as db:
  806. from backend.app.models.printer import Printer
  807. from backend.app.services.bambu_ftp import download_file_bytes_async, list_files_async
  808. # Get archive (ArchiveService from module-level import)
  809. service = ArchiveService(db)
  810. archive = await service.get_archive(archive_id)
  811. if not archive:
  812. logger.warning(f"[TIMELAPSE] Archive {archive_id} not found, stopping retries")
  813. return
  814. if archive.timelapse_path:
  815. logger.info(f"[TIMELAPSE] Archive {archive_id} already has timelapse attached, stopping retries")
  816. return
  817. if not archive.printer_id:
  818. logger.warning(f"[TIMELAPSE] Archive {archive_id} has no printer, stopping retries")
  819. return
  820. # Get printer
  821. result = await db.execute(select(Printer).where(Printer.id == archive.printer_id))
  822. printer = result.scalar_one_or_none()
  823. if not printer:
  824. logger.warning(f"[TIMELAPSE] Printer not found for archive {archive_id}, stopping retries")
  825. return
  826. # Scan timelapse directory on printer
  827. # H2D may store in different locations than X1C
  828. files = []
  829. found_path = None
  830. for timelapse_path in ["/timelapse", "/timelapse/video", "/record", "/recording"]:
  831. try:
  832. found_files = await list_files_async(printer.ip_address, printer.access_code, timelapse_path)
  833. if found_files:
  834. files = found_files
  835. found_path = timelapse_path
  836. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(files)} files in {timelapse_path}")
  837. break
  838. except Exception as e:
  839. logger.debug(f"[TIMELAPSE] Path {timelapse_path} failed: {e}")
  840. continue
  841. if not files:
  842. logger.info(f"[TIMELAPSE] Attempt {attempt}: No timelapse files found on printer, will retry")
  843. continue
  844. mp4_files = [f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4")]
  845. # Log ALL mp4 files found for debugging
  846. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(mp4_files)} MP4 files in {found_path}")
  847. for f in mp4_files[:5]: # Log first 5
  848. logger.info(f"[TIMELAPSE] - {f.get('name')}, mtime={f.get('mtime')}")
  849. if not mp4_files:
  850. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files found, will retry")
  851. continue
  852. # Sort by mtime descending to get most recent file
  853. mp4_files_with_mtime = [f for f in mp4_files if f.get("mtime")]
  854. if not mp4_files_with_mtime:
  855. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files with mtime found, will retry")
  856. continue
  857. mp4_files_with_mtime.sort(key=lambda x: x.get("mtime"), reverse=True)
  858. most_recent = mp4_files_with_mtime[0]
  859. file_name = most_recent.get("name")
  860. logger.info(f"[TIMELAPSE] Attempt {attempt}: Most recent file: {file_name}")
  861. # Since we KNOW timelapse was active (from MQTT), just grab the most recent file
  862. remote_path = most_recent.get("path") or f"/timelapse/{file_name}"
  863. logger.info(f"[TIMELAPSE] Downloading {file_name} for archive {archive_id}")
  864. timelapse_data = await download_file_bytes_async(printer.ip_address, printer.access_code, remote_path)
  865. if timelapse_data:
  866. success = await service.attach_timelapse(archive_id, timelapse_data, file_name)
  867. if success:
  868. logger.info(f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}")
  869. await ws_manager.send_archive_updated({"id": archive_id, "timelapse_attached": True})
  870. return # Success!
  871. else:
  872. logger.warning(f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}")
  873. else:
  874. logger.warning(f"[TIMELAPSE] Attempt {attempt}: Failed to download, will retry")
  875. except Exception as e:
  876. logger.warning(f"[TIMELAPSE] Attempt {attempt} failed with error: {e}")
  877. logger.warning(f"[TIMELAPSE] All {len(retry_delays)} attempts exhausted for archive {archive_id}, giving up")
  878. async def on_print_complete(printer_id: int, data: dict):
  879. """Handle print completion - update the archive status."""
  880. import logging
  881. import time
  882. logger = logging.getLogger(__name__)
  883. start_time = time.time()
  884. def log_timing(section: str):
  885. elapsed = time.time() - start_time
  886. logger.info(f"[TIMING] {section}: {elapsed:.3f}s elapsed")
  887. logger.info(f"[CALLBACK] on_print_complete started for printer {printer_id}")
  888. try:
  889. ws_data = {
  890. "status": data.get("status"),
  891. "filename": data.get("filename"),
  892. "subtask_name": data.get("subtask_name"),
  893. "timelapse_was_active": data.get("timelapse_was_active"),
  894. }
  895. await ws_manager.send_print_complete(printer_id, ws_data)
  896. log_timing("WebSocket send_print_complete")
  897. except Exception as e:
  898. logger.warning(f"[CALLBACK] WebSocket send_print_complete failed: {e}")
  899. # MQTT relay - publish print complete
  900. try:
  901. printer_info = printer_manager.get_printer(printer_id)
  902. if printer_info:
  903. await mqtt_relay.on_print_complete(
  904. printer_id,
  905. printer_info.name,
  906. printer_info.serial_number,
  907. data.get("filename", ""),
  908. data.get("subtask_name", ""),
  909. data.get("status", "completed"),
  910. )
  911. except Exception:
  912. pass # Don't fail print complete callback if MQTT fails
  913. filename = data.get("filename", "")
  914. subtask_name = data.get("subtask_name", "")
  915. if not filename and not subtask_name:
  916. logger.warning("Print complete without filename or subtask_name")
  917. return
  918. logger.info(f"Print complete - filename: {filename}, subtask: {subtask_name}, status: {data.get('status')}")
  919. # Build list of possible keys to try (matching how they were registered in on_print_start)
  920. possible_keys = []
  921. # Try subtask_name variations first (most reliable for matching)
  922. if subtask_name:
  923. possible_keys.append((printer_id, f"{subtask_name}.3mf"))
  924. possible_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  925. possible_keys.append((printer_id, subtask_name))
  926. # Try filename variations
  927. if filename:
  928. # Extract just the filename if it's a path
  929. fname = filename.split("/")[-1] if "/" in filename else filename
  930. if fname.endswith(".3mf"):
  931. possible_keys.append((printer_id, fname))
  932. elif fname.endswith(".gcode"):
  933. base_name = fname.rsplit(".", 1)[0]
  934. possible_keys.append((printer_id, f"{base_name}.gcode.3mf"))
  935. possible_keys.append((printer_id, f"{base_name}.3mf"))
  936. possible_keys.append((printer_id, fname))
  937. else:
  938. possible_keys.append((printer_id, f"{fname}.gcode.3mf"))
  939. possible_keys.append((printer_id, f"{fname}.3mf"))
  940. possible_keys.append((printer_id, fname))
  941. # Also try full path versions
  942. if filename.endswith(".3mf"):
  943. possible_keys.append((printer_id, filename))
  944. elif filename.endswith(".gcode"):
  945. base_name = filename.rsplit(".", 1)[0]
  946. possible_keys.append((printer_id, f"{base_name}.3mf"))
  947. possible_keys.append((printer_id, filename))
  948. else:
  949. possible_keys.append((printer_id, f"{filename}.3mf"))
  950. possible_keys.append((printer_id, filename))
  951. # Find the archive for this print
  952. logger.info(f"Looking for archive in _active_prints, keys to try: {possible_keys[:5]}...")
  953. logger.info(f"Current _active_prints: {list(_active_prints.keys())}")
  954. archive_id = None
  955. for key in possible_keys:
  956. archive_id = _active_prints.pop(key, None)
  957. if archive_id:
  958. logger.info(f"Found archive {archive_id} with key {key}")
  959. # Also clean up any other keys pointing to this archive
  960. keys_to_remove = [k for k, v in _active_prints.items() if v == archive_id]
  961. for k in keys_to_remove:
  962. _active_prints.pop(k, None)
  963. break
  964. if not archive_id:
  965. # Try to find by filename or subtask_name if not tracked (for prints started before app)
  966. async with async_session() as db:
  967. from backend.app.models.archive import PrintArchive
  968. # Try matching by subtask_name (stored as print_name) first
  969. if subtask_name:
  970. result = await db.execute(
  971. select(PrintArchive)
  972. .where(PrintArchive.printer_id == printer_id)
  973. .where(PrintArchive.status == "printing")
  974. .where(
  975. or_(
  976. PrintArchive.print_name.ilike(f"%{subtask_name}%"),
  977. PrintArchive.filename.ilike(f"%{subtask_name}%"),
  978. )
  979. )
  980. .order_by(PrintArchive.created_at.desc())
  981. .limit(1)
  982. )
  983. archive = result.scalar_one_or_none()
  984. if archive:
  985. archive_id = archive.id
  986. logger.info(f"Found archive {archive_id} by subtask_name match: {subtask_name}")
  987. # Also try by filename
  988. if not archive_id and filename:
  989. result = await db.execute(
  990. select(PrintArchive)
  991. .where(PrintArchive.printer_id == printer_id)
  992. .where(PrintArchive.filename == filename)
  993. .where(PrintArchive.status == "printing")
  994. .order_by(PrintArchive.created_at.desc())
  995. .limit(1)
  996. )
  997. archive = result.scalar_one_or_none()
  998. if archive:
  999. archive_id = archive.id
  1000. if not archive_id:
  1001. logger.warning(f"Could not find archive for print complete: filename={filename}, subtask={subtask_name}")
  1002. return
  1003. log_timing("Archive lookup")
  1004. # Update archive status
  1005. logger.info(f"[ARCHIVE] Updating archive {archive_id} status...")
  1006. try:
  1007. async with async_session() as db:
  1008. service = ArchiveService(db)
  1009. status = data.get("status", "completed")
  1010. # Auto-detect failure reason
  1011. failure_reason = None
  1012. if status == "aborted":
  1013. failure_reason = "User cancelled"
  1014. logger.info("[ARCHIVE] Print was aborted by user, setting failure_reason='User cancelled'")
  1015. elif status == "failed":
  1016. # Try to determine failure reason from HMS errors
  1017. hms_errors = data.get("hms_errors", [])
  1018. if hms_errors:
  1019. logger.info(f"[ARCHIVE] HMS errors at failure: {hms_errors}")
  1020. # Map known HMS error modules to failure reasons
  1021. # Module 0x07 = Filament, 0x0C = MC (Motion Controller), etc.
  1022. for err in hms_errors:
  1023. module = err.get("module", 0)
  1024. if module == 0x07: # Filament module
  1025. failure_reason = "Filament runout"
  1026. break
  1027. elif module == 0x0C: # Motion controller
  1028. failure_reason = "Layer shift"
  1029. break
  1030. elif module == 0x05: # Nozzle/extruder
  1031. failure_reason = "Clogged nozzle"
  1032. break
  1033. if failure_reason:
  1034. logger.info(f"[ARCHIVE] Detected failure_reason from HMS: {failure_reason}")
  1035. else:
  1036. logger.info("[ARCHIVE] No HMS errors available to determine failure reason")
  1037. await service.update_archive_status(
  1038. archive_id,
  1039. status=status,
  1040. completed_at=datetime.now() if status in ("completed", "failed", "aborted") else None,
  1041. failure_reason=failure_reason,
  1042. )
  1043. logger.info(f"[ARCHIVE] Archive {archive_id} status updated to {status}, failure_reason={failure_reason}")
  1044. await ws_manager.send_archive_updated(
  1045. {
  1046. "id": archive_id,
  1047. "status": status,
  1048. }
  1049. )
  1050. logger.info(f"[ARCHIVE] WebSocket notification sent for archive {archive_id}")
  1051. # MQTT relay - publish archive updated
  1052. try:
  1053. await mqtt_relay.on_archive_updated(
  1054. archive_id=archive_id,
  1055. print_name=filename or subtask_name,
  1056. status=status,
  1057. )
  1058. except Exception:
  1059. pass # Don't fail if MQTT fails
  1060. except Exception as e:
  1061. logger.error(f"[ARCHIVE] Failed to update archive {archive_id} status: {e}", exc_info=True)
  1062. # Continue with other operations even if archive update fails
  1063. log_timing("Archive status update")
  1064. # Report filament usage to Spoolman if print completed successfully
  1065. if data.get("status") == "completed":
  1066. try:
  1067. await _report_spoolman_usage(printer_id, archive_id, logger)
  1068. log_timing("Spoolman usage report")
  1069. except Exception as e:
  1070. logger.warning(f"Spoolman usage reporting failed: {e}")
  1071. # Run slow operations as background tasks to avoid blocking the event loop
  1072. # These operations can take 5-10+ seconds and would freeze the UI if awaited
  1073. starting_kwh = _print_energy_start.pop(archive_id, None)
  1074. async def _background_energy_calculation():
  1075. """Calculate and save energy usage in background."""
  1076. try:
  1077. logger.info(f"[ENERGY-BG] Starting energy calculation for archive {archive_id}")
  1078. async with async_session() as db:
  1079. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  1080. plug = plug_result.scalar_one_or_none()
  1081. if plug:
  1082. energy = await tasmota_service.get_energy(plug)
  1083. logger.info(f"[ENERGY-BG] Energy response: {energy}")
  1084. energy_used = None
  1085. if starting_kwh is not None and energy and energy.get("total") is not None:
  1086. ending_kwh = energy["total"]
  1087. energy_used = round(ending_kwh - starting_kwh, 4)
  1088. logger.info(f"[ENERGY-BG] Per-print energy: {energy_used} kWh")
  1089. if energy_used is not None and energy_used >= 0:
  1090. from backend.app.api.routes.settings import get_setting
  1091. energy_cost_per_kwh = await get_setting(db, "energy_cost_per_kwh")
  1092. cost_per_kwh = float(energy_cost_per_kwh) if energy_cost_per_kwh else 0.15
  1093. energy_cost = round(energy_used * cost_per_kwh, 2)
  1094. from backend.app.models.archive import PrintArchive
  1095. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1096. archive = result.scalar_one_or_none()
  1097. if archive:
  1098. archive.energy_kwh = energy_used
  1099. archive.energy_cost = energy_cost
  1100. await db.commit()
  1101. logger.info(f"[ENERGY-BG] Saved: {energy_used} kWh, cost={energy_cost}")
  1102. else:
  1103. logger.info(f"[ENERGY-BG] No smart plug for printer {printer_id}")
  1104. except Exception as e:
  1105. logger.warning(f"[ENERGY-BG] Failed: {e}")
  1106. async def _background_finish_photo():
  1107. """Capture finish photo in background."""
  1108. try:
  1109. logger.info(f"[PHOTO-BG] Starting finish photo capture for archive {archive_id}")
  1110. from backend.app.api.routes.camera import _active_chamber_streams, _active_streams, get_buffered_frame
  1111. async with async_session() as db:
  1112. from backend.app.api.routes.settings import get_setting
  1113. capture_enabled = await get_setting(db, "capture_finish_photo")
  1114. if capture_enabled is None or capture_enabled.lower() == "true":
  1115. from backend.app.models.printer import Printer
  1116. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1117. printer = result.scalar_one_or_none()
  1118. if printer and archive_id:
  1119. from backend.app.models.archive import PrintArchive
  1120. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1121. archive = result.scalar_one_or_none()
  1122. if archive:
  1123. import uuid
  1124. from datetime import datetime
  1125. from pathlib import Path
  1126. archive_dir = app_settings.base_dir / Path(archive.file_path).parent
  1127. photo_filename = None
  1128. # Check if camera stream is active - use buffered frame to avoid freeze
  1129. # Check both RTSP streams (_active_streams) and chamber image streams (_active_chamber_streams)
  1130. active_for_printer = [k for k in _active_streams if k.startswith(f"{printer_id}-")]
  1131. active_chamber_for_printer = [
  1132. k for k in _active_chamber_streams if k.startswith(f"{printer_id}-")
  1133. ]
  1134. buffered_frame = get_buffered_frame(printer_id)
  1135. if (active_for_printer or active_chamber_for_printer) and buffered_frame:
  1136. # Use frame from active stream
  1137. logger.info("[PHOTO-BG] Using buffered frame from active stream")
  1138. photos_dir = archive_dir / "photos"
  1139. photos_dir.mkdir(parents=True, exist_ok=True)
  1140. timestamp = datetime.now().strftime("%Y%m%d_%H%M%S")
  1141. photo_filename = f"finish_{timestamp}_{uuid.uuid4().hex[:8]}.jpg"
  1142. photo_path = photos_dir / photo_filename
  1143. await asyncio.to_thread(photo_path.write_bytes, buffered_frame)
  1144. logger.info(f"[PHOTO-BG] Saved buffered frame: {photo_filename}")
  1145. else:
  1146. # No active stream - capture new frame
  1147. from backend.app.services.camera import capture_finish_photo
  1148. photo_filename = await capture_finish_photo(
  1149. printer_id=printer_id,
  1150. ip_address=printer.ip_address,
  1151. access_code=printer.access_code,
  1152. model=printer.model,
  1153. archive_dir=archive_dir,
  1154. )
  1155. if photo_filename:
  1156. photos = archive.photos or []
  1157. photos.append(photo_filename)
  1158. archive.photos = photos
  1159. await db.commit()
  1160. logger.info(f"[PHOTO-BG] Saved: {photo_filename}")
  1161. except Exception as e:
  1162. logger.warning(f"[PHOTO-BG] Failed: {e}")
  1163. asyncio.create_task(_background_energy_calculation())
  1164. asyncio.create_task(_background_finish_photo()) # Skips if camera stream active
  1165. log_timing("Background tasks scheduled (energy, photo)")
  1166. # Also run smart plug, notifications, and maintenance as background tasks
  1167. print_status = data.get("status", "completed")
  1168. async def _background_smart_plug():
  1169. """Handle smart plug automation in background."""
  1170. try:
  1171. logger.info(f"[AUTO-OFF-BG] Starting smart plug automation for printer {printer_id}")
  1172. async with async_session() as db:
  1173. await smart_plug_manager.on_print_complete(printer_id, print_status, db)
  1174. logger.info("[AUTO-OFF-BG] Completed")
  1175. except Exception as e:
  1176. logger.warning(f"[AUTO-OFF-BG] Failed: {e}")
  1177. async def _background_notifications():
  1178. """Send print complete notifications in background."""
  1179. try:
  1180. logger.info(f"[NOTIFY-BG] Starting notifications for printer {printer_id}")
  1181. async with async_session() as db:
  1182. from backend.app.models.archive import PrintArchive
  1183. from backend.app.models.printer import Printer
  1184. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1185. printer = result.scalar_one_or_none()
  1186. printer_name = printer.name if printer else f"Printer {printer_id}"
  1187. archive_data = None
  1188. if archive_id:
  1189. archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1190. archive = archive_result.scalar_one_or_none()
  1191. if archive:
  1192. archive_data = {
  1193. "print_time_seconds": archive.print_time_seconds,
  1194. "actual_filament_grams": archive.filament_used_grams,
  1195. "failure_reason": archive.failure_reason,
  1196. }
  1197. await notification_service.on_print_complete(
  1198. printer_id, printer_name, print_status, data, db, archive_data=archive_data
  1199. )
  1200. logger.info("[NOTIFY-BG] Completed")
  1201. except Exception as e:
  1202. logger.warning(f"[NOTIFY-BG] Failed: {e}")
  1203. async def _background_maintenance_check():
  1204. """Check for maintenance due in background."""
  1205. if print_status != "completed":
  1206. return
  1207. try:
  1208. logger.info(f"[MAINT-BG] Starting maintenance check for printer {printer_id}")
  1209. async with async_session() as db:
  1210. from backend.app.models.printer import Printer
  1211. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1212. printer = result.scalar_one_or_none()
  1213. printer_name = printer.name if printer else f"Printer {printer_id}"
  1214. await ensure_default_types(db)
  1215. overview = await _get_printer_maintenance_internal(printer_id, db, commit=True)
  1216. items_needing_attention = [
  1217. {"name": item.maintenance_type_name, "is_due": item.is_due, "is_warning": item.is_warning}
  1218. for item in overview.maintenance_items
  1219. if item.enabled and (item.is_due or item.is_warning)
  1220. ]
  1221. if items_needing_attention:
  1222. await notification_service.on_maintenance_due(printer_id, printer_name, items_needing_attention, db)
  1223. logger.info(f"[MAINT-BG] Sent notification: {len(items_needing_attention)} items need attention")
  1224. # MQTT relay - publish maintenance alerts
  1225. for item in items_needing_attention:
  1226. try:
  1227. await mqtt_relay.on_maintenance_alert(
  1228. printer_id=printer_id,
  1229. printer_name=printer_name,
  1230. maintenance_type=item["name"],
  1231. current_value=0, # Not easily available here
  1232. threshold=0, # Not easily available here
  1233. )
  1234. except Exception:
  1235. pass # Don't fail if MQTT fails
  1236. else:
  1237. logger.info("[MAINT-BG] Completed (no items need attention)")
  1238. except Exception as e:
  1239. logger.warning(f"[MAINT-BG] Failed: {e}")
  1240. asyncio.create_task(_background_smart_plug())
  1241. asyncio.create_task(_background_notifications())
  1242. asyncio.create_task(_background_maintenance_check())
  1243. log_timing("All background tasks scheduled")
  1244. # Auto-scan for timelapse if recording was active during the print
  1245. if archive_id and data.get("timelapse_was_active") and data.get("status") == "completed":
  1246. logger.info(f"[TIMELAPSE] Timelapse was active during print, scheduling auto-scan for archive {archive_id}")
  1247. # Schedule timelapse scan as background task with retries
  1248. # The printer needs time to encode the video after print completion
  1249. asyncio.create_task(_scan_for_timelapse_with_retries(archive_id))
  1250. log_timing("Timelapse scan scheduled")
  1251. # Update queue item if this was a scheduled print
  1252. try:
  1253. async with async_session() as db:
  1254. from backend.app.models.print_queue import PrintQueueItem
  1255. # Note: SmartPlug is already imported at module level (line 56)
  1256. # Do NOT import it here as it would shadow the module-level import
  1257. # and cause "cannot access local variable" errors earlier in this function
  1258. result = await db.execute(
  1259. select(PrintQueueItem)
  1260. .where(PrintQueueItem.printer_id == printer_id)
  1261. .where(PrintQueueItem.status == "printing")
  1262. )
  1263. queue_item = result.scalar_one_or_none()
  1264. if queue_item:
  1265. status = data.get("status", "completed")
  1266. queue_item.status = status
  1267. queue_item.completed_at = datetime.now()
  1268. await db.commit()
  1269. logger.info(f"Updated queue item {queue_item.id} status to {status}")
  1270. # MQTT relay - publish queue job completed
  1271. try:
  1272. printer_info = printer_manager.get_printer(printer_id)
  1273. await mqtt_relay.on_queue_job_completed(
  1274. job_id=queue_item.id,
  1275. filename=filename or subtask_name,
  1276. printer_id=printer_id,
  1277. printer_name=printer_info.name if printer_info else "Unknown",
  1278. status=status,
  1279. )
  1280. except Exception:
  1281. pass # Don't fail if MQTT fails
  1282. # Handle auto_off_after - power off printer if requested (after cooldown)
  1283. if queue_item.auto_off_after:
  1284. result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  1285. plug = result.scalar_one_or_none()
  1286. if plug and plug.enabled:
  1287. logger.info(f"Auto-off requested for printer {printer_id}, waiting for cooldown...")
  1288. async def cooldown_and_poweroff(pid: int, plug_id: int):
  1289. # Wait for nozzle to cool down
  1290. await printer_manager.wait_for_cooldown(pid, target_temp=50.0, timeout=600)
  1291. # Re-fetch plug in new session
  1292. async with async_session() as new_db:
  1293. result = await new_db.execute(select(SmartPlug).where(SmartPlug.id == plug_id))
  1294. p = result.scalar_one_or_none()
  1295. if p and p.enabled:
  1296. success = await tasmota_service.turn_off(p)
  1297. if success:
  1298. logger.info(f"Powered off printer {pid} via smart plug '{p.name}'")
  1299. else:
  1300. logger.warning(f"Failed to power off printer {pid} via smart plug")
  1301. asyncio.create_task(cooldown_and_poweroff(printer_id, plug.id))
  1302. except Exception as e:
  1303. import logging
  1304. logging.getLogger(__name__).warning(f"Queue item update failed: {e}")
  1305. log_timing("Queue item update")
  1306. logger.info(f"[CALLBACK] on_print_complete finished for printer {printer_id}, archive {archive_id}")
  1307. # AMS sensor history recording
  1308. _ams_history_task: asyncio.Task | None = None
  1309. AMS_HISTORY_INTERVAL = 300 # Record every 5 minutes
  1310. AMS_HISTORY_RETENTION_DAYS = 30 # Keep data for 30 days
  1311. _ams_cleanup_counter = 0 # Track recordings to trigger periodic cleanup
  1312. _ams_alarm_cooldown: dict[str, datetime] = {} # Track alarm cooldowns (printer_id:ams_id:type -> last_alarm_time)
  1313. AMS_ALARM_COOLDOWN_MINUTES = 60 # Don't send same alarm more than once per hour
  1314. async def record_ams_history():
  1315. """Background task to record AMS humidity and temperature data."""
  1316. import logging
  1317. logger = logging.getLogger(__name__)
  1318. # Wait a short time for MQTT connections to establish on startup
  1319. await asyncio.sleep(10)
  1320. while True:
  1321. try:
  1322. from backend.app.models.ams_history import AMSSensorHistory
  1323. from backend.app.models.printer import Printer
  1324. from backend.app.models.settings import Settings
  1325. async with async_session() as db:
  1326. # Get all active printers
  1327. result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
  1328. printers = result.scalars().all()
  1329. # Get alarm thresholds from settings
  1330. humidity_threshold = 60.0 # Default: fair threshold
  1331. temp_threshold = 35.0 # Default: fair threshold
  1332. result = await db.execute(select(Settings).where(Settings.key == "ams_humidity_fair"))
  1333. setting = result.scalar_one_or_none()
  1334. if setting:
  1335. try:
  1336. humidity_threshold = float(setting.value)
  1337. except (ValueError, TypeError):
  1338. pass
  1339. result = await db.execute(select(Settings).where(Settings.key == "ams_temp_fair"))
  1340. setting = result.scalar_one_or_none()
  1341. if setting:
  1342. try:
  1343. temp_threshold = float(setting.value)
  1344. except (ValueError, TypeError):
  1345. pass
  1346. recorded_count = 0
  1347. for printer in printers:
  1348. # Get current state from printer manager
  1349. state = printer_manager.get_status(printer.id)
  1350. if not state or not state.connected or not state.raw_data:
  1351. continue # Skip disconnected printers - don't use stale data
  1352. raw_data = state.raw_data
  1353. if "ams" not in raw_data or not isinstance(raw_data["ams"], list):
  1354. continue
  1355. # Record data for each AMS unit
  1356. for ams_data in raw_data["ams"]:
  1357. ams_id = int(ams_data.get("id", 0))
  1358. # Get humidity (prefer humidity_raw)
  1359. humidity_raw = ams_data.get("humidity_raw")
  1360. humidity_idx = ams_data.get("humidity")
  1361. humidity = None
  1362. if humidity_raw is not None:
  1363. try:
  1364. humidity = float(humidity_raw)
  1365. except (ValueError, TypeError):
  1366. pass
  1367. if humidity is None and humidity_idx is not None:
  1368. try:
  1369. humidity = float(humidity_idx)
  1370. except (ValueError, TypeError):
  1371. pass
  1372. # Get temperature
  1373. temperature = None
  1374. temp_str = ams_data.get("temp")
  1375. if temp_str is not None:
  1376. try:
  1377. temperature = float(temp_str)
  1378. except (ValueError, TypeError):
  1379. pass
  1380. # Skip if no data
  1381. if humidity is None and temperature is None:
  1382. continue
  1383. # Record the data point
  1384. history = AMSSensorHistory(
  1385. printer_id=printer.id,
  1386. ams_id=ams_id,
  1387. humidity=humidity,
  1388. humidity_raw=float(humidity_raw) if humidity_raw else None,
  1389. temperature=temperature,
  1390. )
  1391. db.add(history)
  1392. recorded_count += 1
  1393. # Generate AMS label and determine if it's AMS-HT (A, B, C, D or HT-A for AMS-Lite/Hub)
  1394. is_ams_ht = ams_id >= 128
  1395. if is_ams_ht:
  1396. ams_label = f"HT-{chr(65 + (ams_id - 128))}"
  1397. else:
  1398. ams_label = f"AMS-{chr(65 + ams_id)}"
  1399. # Check humidity alarm (only if above threshold)
  1400. if humidity is not None and humidity > humidity_threshold:
  1401. cooldown_key = f"{printer.id}:{ams_id}:humidity"
  1402. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1403. now = datetime.now()
  1404. if (
  1405. last_alarm is None
  1406. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1407. ):
  1408. _ams_alarm_cooldown[cooldown_key] = now
  1409. logger.info(
  1410. f"Sending humidity alarm for {printer.name} {ams_label}: {humidity}% > {humidity_threshold}%"
  1411. )
  1412. try:
  1413. # Call different notification method based on AMS type
  1414. if is_ams_ht:
  1415. await notification_service.on_ams_ht_humidity_high(
  1416. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1417. )
  1418. else:
  1419. await notification_service.on_ams_humidity_high(
  1420. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1421. )
  1422. except Exception as e:
  1423. logger.warning(f"Failed to send humidity alarm: {e}")
  1424. # Check temperature alarm (only if above threshold)
  1425. if temperature is not None and temperature > temp_threshold:
  1426. cooldown_key = f"{printer.id}:{ams_id}:temperature"
  1427. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1428. now = datetime.now()
  1429. if (
  1430. last_alarm is None
  1431. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1432. ):
  1433. _ams_alarm_cooldown[cooldown_key] = now
  1434. logger.info(
  1435. f"Sending temperature alarm for {printer.name} {ams_label}: {temperature}°C > {temp_threshold}°C"
  1436. )
  1437. try:
  1438. # Call different notification method based on AMS type
  1439. if is_ams_ht:
  1440. await notification_service.on_ams_ht_temperature_high(
  1441. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1442. )
  1443. else:
  1444. await notification_service.on_ams_temperature_high(
  1445. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1446. )
  1447. except Exception as e:
  1448. logger.warning(f"Failed to send temperature alarm: {e}")
  1449. await db.commit()
  1450. if recorded_count > 0:
  1451. logger.info(f"Recorded {recorded_count} AMS sensor history entries")
  1452. # Periodic cleanup of old data (every ~288 recordings = ~24 hours at 5min interval)
  1453. global _ams_cleanup_counter
  1454. _ams_cleanup_counter += 1
  1455. if _ams_cleanup_counter >= 288:
  1456. _ams_cleanup_counter = 0
  1457. # Get retention days from settings
  1458. from backend.app.models.settings import Settings
  1459. result = await db.execute(select(Settings).where(Settings.key == "ams_history_retention_days"))
  1460. setting = result.scalar_one_or_none()
  1461. retention_days = int(setting.value) if setting else AMS_HISTORY_RETENTION_DAYS
  1462. cutoff = datetime.now() - timedelta(days=retention_days)
  1463. result = await db.execute(delete(AMSSensorHistory).where(AMSSensorHistory.recorded_at < cutoff))
  1464. await db.commit()
  1465. if result.rowcount > 0:
  1466. logger.info(
  1467. f"Cleaned up {result.rowcount} old AMS sensor history entries (older than {retention_days} days)"
  1468. )
  1469. # Wait until next recording interval
  1470. await asyncio.sleep(AMS_HISTORY_INTERVAL)
  1471. except asyncio.CancelledError:
  1472. break
  1473. except Exception as e:
  1474. logger.warning(f"AMS history recording failed: {e}")
  1475. await asyncio.sleep(60) # Wait a bit before retrying
  1476. def start_ams_history_recording():
  1477. """Start the AMS history recording background task."""
  1478. global _ams_history_task
  1479. if _ams_history_task is None:
  1480. _ams_history_task = asyncio.create_task(record_ams_history())
  1481. logging.getLogger(__name__).info("AMS history recording started")
  1482. def stop_ams_history_recording():
  1483. """Stop the AMS history recording background task."""
  1484. global _ams_history_task
  1485. if _ams_history_task:
  1486. _ams_history_task.cancel()
  1487. _ams_history_task = None
  1488. logging.getLogger(__name__).info("AMS history recording stopped")
  1489. # Printer runtime tracking
  1490. _runtime_tracking_task: asyncio.Task | None = None
  1491. RUNTIME_TRACKING_INTERVAL = 30 # Update every 30 seconds
  1492. async def track_printer_runtime():
  1493. """Background task to track printer active runtime (RUNNING/PAUSE states)."""
  1494. import logging
  1495. logger = logging.getLogger(__name__)
  1496. # Wait for MQTT connections to establish on startup
  1497. await asyncio.sleep(15)
  1498. while True:
  1499. try:
  1500. from backend.app.models.printer import Printer
  1501. async with async_session() as db:
  1502. # Get all active printers
  1503. result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
  1504. printers = result.scalars().all()
  1505. now = datetime.now()
  1506. updated_count = 0
  1507. needs_commit = False
  1508. for printer in printers:
  1509. # Get current state from printer manager
  1510. state = printer_manager.get_status(printer.id)
  1511. if not state:
  1512. logger.debug(f"[{printer.name}] Runtime tracking: no state available")
  1513. continue
  1514. if not state.connected:
  1515. logger.debug(f"[{printer.name}] Runtime tracking: not connected")
  1516. continue
  1517. # Check if printer is in an active state (RUNNING or PAUSE)
  1518. if state.state in ("RUNNING", "PAUSE"):
  1519. # Calculate time since last update
  1520. if printer.last_runtime_update:
  1521. elapsed = (now - printer.last_runtime_update).total_seconds()
  1522. if elapsed > 0:
  1523. printer.runtime_seconds += int(elapsed)
  1524. updated_count += 1
  1525. needs_commit = True
  1526. logger.debug(
  1527. f"[{printer.name}] Runtime tracking: added {int(elapsed)}s, "
  1528. f"total={printer.runtime_seconds}s ({printer.runtime_seconds / 3600:.2f}h)"
  1529. )
  1530. else:
  1531. # First time seeing printer active - need to commit to save timestamp
  1532. needs_commit = True
  1533. logger.debug(f"[{printer.name}] Runtime tracking: first active detection")
  1534. printer.last_runtime_update = now
  1535. else:
  1536. # Printer is idle/offline - clear last_runtime_update
  1537. if printer.last_runtime_update is not None:
  1538. logger.debug(
  1539. f"[{printer.name}] Runtime tracking: state={state.state}, clearing last_runtime_update"
  1540. )
  1541. printer.last_runtime_update = None
  1542. needs_commit = True
  1543. if needs_commit:
  1544. await db.commit()
  1545. if updated_count > 0:
  1546. logger.debug(f"Updated runtime for {updated_count} printer(s)")
  1547. except asyncio.CancelledError:
  1548. logger.info("Runtime tracking cancelled")
  1549. break
  1550. except Exception as e:
  1551. logger.warning(f"Runtime tracking failed: {e}")
  1552. await asyncio.sleep(RUNTIME_TRACKING_INTERVAL)
  1553. def start_runtime_tracking():
  1554. """Start the printer runtime tracking background task."""
  1555. global _runtime_tracking_task
  1556. if _runtime_tracking_task is None:
  1557. _runtime_tracking_task = asyncio.create_task(track_printer_runtime())
  1558. logging.getLogger(__name__).info("Printer runtime tracking started")
  1559. def stop_runtime_tracking():
  1560. """Stop the printer runtime tracking background task."""
  1561. global _runtime_tracking_task
  1562. if _runtime_tracking_task:
  1563. _runtime_tracking_task.cancel()
  1564. _runtime_tracking_task = None
  1565. logging.getLogger(__name__).info("Printer runtime tracking stopped")
  1566. @asynccontextmanager
  1567. async def lifespan(app: FastAPI):
  1568. # Startup
  1569. await init_db()
  1570. # Restore debug logging state from previous session
  1571. await init_debug_logging()
  1572. # Set up printer manager callbacks
  1573. loop = asyncio.get_event_loop()
  1574. printer_manager.set_event_loop(loop)
  1575. printer_manager.set_status_change_callback(on_printer_status_change)
  1576. printer_manager.set_print_start_callback(on_print_start)
  1577. printer_manager.set_print_complete_callback(on_print_complete)
  1578. printer_manager.set_ams_change_callback(on_ams_change)
  1579. # Initialize MQTT relay from settings
  1580. async with async_session() as db:
  1581. from backend.app.api.routes.settings import get_setting
  1582. mqtt_settings = {
  1583. "mqtt_enabled": (await get_setting(db, "mqtt_enabled") or "false") == "true",
  1584. "mqtt_broker": await get_setting(db, "mqtt_broker") or "",
  1585. "mqtt_port": int(await get_setting(db, "mqtt_port") or "1883"),
  1586. "mqtt_username": await get_setting(db, "mqtt_username") or "",
  1587. "mqtt_password": await get_setting(db, "mqtt_password") or "",
  1588. "mqtt_topic_prefix": await get_setting(db, "mqtt_topic_prefix") or "bambuddy",
  1589. "mqtt_use_tls": (await get_setting(db, "mqtt_use_tls") or "false") == "true",
  1590. }
  1591. await mqtt_relay.configure(mqtt_settings)
  1592. # Connect to all active printers
  1593. async with async_session() as db:
  1594. await init_printer_connections(db)
  1595. # Auto-connect to Spoolman if enabled
  1596. async with async_session() as db:
  1597. from backend.app.api.routes.settings import get_setting
  1598. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  1599. spoolman_url = await get_setting(db, "spoolman_url")
  1600. if spoolman_enabled and spoolman_enabled.lower() == "true" and spoolman_url:
  1601. try:
  1602. client = await init_spoolman_client(spoolman_url)
  1603. if await client.health_check():
  1604. logging.info(f"Auto-connected to Spoolman at {spoolman_url}")
  1605. else:
  1606. logging.warning(f"Spoolman at {spoolman_url} is not reachable")
  1607. except Exception as e:
  1608. logging.warning(f"Failed to auto-connect to Spoolman: {e}")
  1609. # Start the print scheduler
  1610. asyncio.create_task(print_scheduler.run())
  1611. # Start the smart plug scheduler for time-based on/off
  1612. smart_plug_manager.start_scheduler()
  1613. # Resume any pending auto-offs that were interrupted by restart
  1614. await smart_plug_manager.resume_pending_auto_offs()
  1615. # Start the notification digest scheduler
  1616. notification_service.start_digest_scheduler()
  1617. # Start AMS history recording
  1618. start_ams_history_recording()
  1619. # Start printer runtime tracking
  1620. start_runtime_tracking()
  1621. # Start anonymous telemetry (opt-out via settings)
  1622. asyncio.create_task(start_telemetry_loop(async_session))
  1623. # Initialize virtual printer manager
  1624. from backend.app.services.virtual_printer import virtual_printer_manager
  1625. virtual_printer_manager.set_session_factory(async_session)
  1626. # Auto-start virtual printer if enabled
  1627. async with async_session() as db:
  1628. from backend.app.api.routes.settings import get_setting
  1629. vp_enabled = await get_setting(db, "virtual_printer_enabled")
  1630. if vp_enabled and vp_enabled.lower() == "true":
  1631. vp_access_code = await get_setting(db, "virtual_printer_access_code") or ""
  1632. vp_mode = await get_setting(db, "virtual_printer_mode") or "immediate"
  1633. vp_model = await get_setting(db, "virtual_printer_model") or ""
  1634. if vp_access_code:
  1635. try:
  1636. await virtual_printer_manager.configure(
  1637. enabled=True,
  1638. access_code=vp_access_code,
  1639. mode=vp_mode,
  1640. model=vp_model,
  1641. )
  1642. logging.info(f"Virtual printer started (model={vp_model or 'default'})")
  1643. except Exception as e:
  1644. logging.warning(f"Failed to start virtual printer: {e}")
  1645. yield
  1646. # Shutdown
  1647. print_scheduler.stop()
  1648. smart_plug_manager.stop_scheduler()
  1649. notification_service.stop_digest_scheduler()
  1650. stop_ams_history_recording()
  1651. stop_runtime_tracking()
  1652. printer_manager.disconnect_all()
  1653. await close_spoolman_client()
  1654. # Stop virtual printer if running
  1655. if virtual_printer_manager.is_enabled:
  1656. await virtual_printer_manager.configure(enabled=False)
  1657. app = FastAPI(
  1658. title=app_settings.app_name,
  1659. description="Archive and manage Bambu Lab 3MF files",
  1660. version=APP_VERSION,
  1661. lifespan=lifespan,
  1662. )
  1663. # API routes
  1664. app.include_router(printers.router, prefix=app_settings.api_prefix)
  1665. app.include_router(archives.router, prefix=app_settings.api_prefix)
  1666. app.include_router(filaments.router, prefix=app_settings.api_prefix)
  1667. app.include_router(settings_routes.router, prefix=app_settings.api_prefix)
  1668. app.include_router(cloud.router, prefix=app_settings.api_prefix)
  1669. app.include_router(smart_plugs.router, prefix=app_settings.api_prefix)
  1670. app.include_router(print_queue.router, prefix=app_settings.api_prefix)
  1671. app.include_router(kprofiles.router, prefix=app_settings.api_prefix)
  1672. app.include_router(notifications.router, prefix=app_settings.api_prefix)
  1673. app.include_router(notification_templates.router, prefix=app_settings.api_prefix)
  1674. app.include_router(spoolman.router, prefix=app_settings.api_prefix)
  1675. app.include_router(updates.router, prefix=app_settings.api_prefix)
  1676. app.include_router(maintenance.router, prefix=app_settings.api_prefix)
  1677. app.include_router(camera.router, prefix=app_settings.api_prefix)
  1678. app.include_router(external_links.router, prefix=app_settings.api_prefix)
  1679. app.include_router(projects.router, prefix=app_settings.api_prefix)
  1680. app.include_router(library.router, prefix=app_settings.api_prefix)
  1681. app.include_router(api_keys.router, prefix=app_settings.api_prefix)
  1682. app.include_router(webhook.router, prefix=app_settings.api_prefix)
  1683. app.include_router(ams_history.router, prefix=app_settings.api_prefix)
  1684. app.include_router(system.router, prefix=app_settings.api_prefix)
  1685. app.include_router(support.router, prefix=app_settings.api_prefix)
  1686. app.include_router(websocket.router, prefix=app_settings.api_prefix)
  1687. app.include_router(discovery.router, prefix=app_settings.api_prefix)
  1688. app.include_router(pending_uploads.router, prefix=app_settings.api_prefix)
  1689. app.include_router(firmware.router, prefix=app_settings.api_prefix)
  1690. # Serve static files (React build)
  1691. if app_settings.static_dir.exists() and any(app_settings.static_dir.iterdir()):
  1692. app.mount(
  1693. "/assets",
  1694. StaticFiles(directory=app_settings.static_dir / "assets"),
  1695. name="assets",
  1696. )
  1697. if (app_settings.static_dir / "img").exists():
  1698. app.mount(
  1699. "/img",
  1700. StaticFiles(directory=app_settings.static_dir / "img"),
  1701. name="img",
  1702. )
  1703. if (app_settings.static_dir / "icons").exists():
  1704. app.mount(
  1705. "/icons",
  1706. StaticFiles(directory=app_settings.static_dir / "icons"),
  1707. name="icons",
  1708. )
  1709. @app.get("/")
  1710. async def serve_frontend():
  1711. """Serve the React frontend."""
  1712. index_file = app_settings.static_dir / "index.html"
  1713. if index_file.exists():
  1714. return FileResponse(index_file)
  1715. return {
  1716. "message": "Bambuddy API",
  1717. "docs": "/docs",
  1718. "frontend": "Build and place React app in /static directory",
  1719. }
  1720. @app.get("/health")
  1721. async def health_check():
  1722. """Health check endpoint."""
  1723. return {"status": "healthy"}
  1724. @app.get("/manifest.json")
  1725. async def serve_manifest():
  1726. """Serve PWA manifest."""
  1727. manifest_file = app_settings.static_dir / "manifest.json"
  1728. if manifest_file.exists():
  1729. return FileResponse(manifest_file, media_type="application/manifest+json")
  1730. return {"error": "Manifest not found"}
  1731. @app.get("/sw.js")
  1732. async def serve_service_worker():
  1733. """Serve service worker."""
  1734. sw_file = app_settings.static_dir / "sw.js"
  1735. if sw_file.exists():
  1736. return FileResponse(sw_file, media_type="application/javascript")
  1737. return {"error": "Service worker not found"}
  1738. # Catch-all route for React Router (must be last)
  1739. @app.get("/{full_path:path}")
  1740. async def serve_spa(full_path: str):
  1741. """Serve React app for client-side routing."""
  1742. # Don't intercept API routes - raise proper 404 so FastAPI can handle redirects
  1743. if full_path.startswith("api/"):
  1744. from fastapi import HTTPException
  1745. raise HTTPException(status_code=404, detail="Not found")
  1746. index_file = app_settings.static_dir / "index.html"
  1747. if index_file.exists():
  1748. return FileResponse(index_file)
  1749. return {"error": "Frontend not built"}