main.py 93 KB

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