main.py 69 KB

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073107410751076107710781079108010811082108310841085108610871088108910901091109210931094109510961097109810991100110111021103110411051106110711081109111011111112111311141115111611171118111911201121112211231124112511261127112811291130113111321133113411351136113711381139114011411142114311441145114611471148114911501151115211531154115511561157115811591160116111621163116411651166116711681169117011711172117311741175117611771178117911801181118211831184118511861187118811891190119111921193119411951196119711981199120012011202120312041205120612071208120912101211121212131214121512161217121812191220122112221223122412251226122712281229123012311232123312341235123612371238123912401241124212431244124512461247124812491250125112521253125412551256125712581259126012611262126312641265126612671268126912701271127212731274127512761277127812791280128112821283128412851286128712881289129012911292129312941295129612971298129913001301130213031304130513061307130813091310131113121313131413151316131713181319132013211322132313241325132613271328132913301331133213331334133513361337133813391340134113421343134413451346134713481349135013511352135313541355135613571358135913601361136213631364136513661367136813691370137113721373137413751376137713781379138013811382138313841385138613871388138913901391139213931394139513961397139813991400140114021403140414051406140714081409141014111412141314141415141614171418141914201421142214231424142514261427142814291430143114321433143414351436143714381439144014411442144314441445144614471448144914501451145214531454145514561457145814591460146114621463146414651466146714681469147014711472147314741475147614771478147914801481148214831484148514861487148814891490149114921493149414951496149714981499150015011502150315041505150615071508150915101511151215131514151515161517151815191520152115221523152415251526152715281529153015311532153315341535153615371538153915401541154215431544154515461547154815491550155115521553155415551556155715581559156015611562156315641565156615671568156915701571157215731574157515761577157815791580
  1. import asyncio
  2. import logging
  3. from contextlib import asynccontextmanager
  4. from datetime import 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. external_links,
  51. filaments,
  52. kprofiles,
  53. maintenance,
  54. notification_templates,
  55. notifications,
  56. print_queue,
  57. printers,
  58. projects,
  59. settings as settings_routes,
  60. smart_plugs,
  61. spoolman,
  62. system,
  63. updates,
  64. webhook,
  65. websocket,
  66. )
  67. from backend.app.api.routes.maintenance import _get_printer_maintenance_internal, ensure_default_types
  68. from backend.app.core.database import async_session, init_db
  69. from backend.app.core.websocket import ws_manager
  70. from backend.app.models.smart_plug import SmartPlug
  71. from backend.app.services.archive import ArchiveService
  72. from backend.app.services.bambu_ftp import download_file_async
  73. from backend.app.services.bambu_mqtt import PrinterState
  74. from backend.app.services.notification_service import notification_service
  75. from backend.app.services.print_scheduler import scheduler as print_scheduler
  76. from backend.app.services.printer_manager import (
  77. init_printer_connections,
  78. printer_manager,
  79. printer_state_to_dict,
  80. )
  81. from backend.app.services.smart_plug_manager import smart_plug_manager
  82. from backend.app.services.spoolman import close_spoolman_client, get_spoolman_client, init_spoolman_client
  83. from backend.app.services.tasmota import tasmota_service
  84. from backend.app.services.telemetry import start_telemetry_loop
  85. # Track active prints: {(printer_id, filename): archive_id}
  86. _active_prints: dict[tuple[int, str], int] = {}
  87. # Track expected prints from reprint/scheduled (skip auto-archiving for these)
  88. # {(printer_id, filename): archive_id}
  89. _expected_prints: dict[tuple[int, str], int] = {}
  90. # Track starting energy for prints: {archive_id: starting_kwh}
  91. _print_energy_start: dict[int, float] = {}
  92. def register_expected_print(printer_id: int, filename: str, archive_id: int):
  93. """Register an expected print from reprint/scheduled so we don't create duplicate archives."""
  94. # Store with multiple filename variations to catch different naming patterns
  95. _expected_prints[(printer_id, filename)] = archive_id
  96. # Also store without .3mf extension if present
  97. if filename.endswith(".3mf"):
  98. base = filename[:-4]
  99. _expected_prints[(printer_id, base)] = archive_id
  100. _expected_prints[(printer_id, f"{base}.gcode")] = archive_id
  101. logging.getLogger(__name__).info(
  102. f"Registered expected print: printer={printer_id}, file={filename}, archive={archive_id}"
  103. )
  104. _last_status_broadcast: dict[int, str] = {}
  105. _nozzle_count_updated: set[int] = set() # Track printers where we've updated nozzle_count
  106. async def _report_spoolman_usage(printer_id: int, archive_id: int, logger):
  107. """Report filament usage to Spoolman after print completion.
  108. This finds the spool by RFID tag_uid from current AMS state and reports
  109. the filament_used_grams from the archive metadata.
  110. """
  111. async with async_session() as db:
  112. from backend.app.api.routes.settings import get_setting
  113. from backend.app.models.archive import PrintArchive
  114. # Check if Spoolman is enabled
  115. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  116. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  117. return
  118. # Get Spoolman URL
  119. spoolman_url = await get_setting(db, "spoolman_url")
  120. if not spoolman_url:
  121. return
  122. # Get or create Spoolman client
  123. client = await get_spoolman_client()
  124. if not client:
  125. client = await init_spoolman_client(spoolman_url)
  126. # Check if Spoolman is reachable
  127. if not await client.health_check():
  128. logger.warning("Spoolman not reachable for usage reporting")
  129. return
  130. # Get archive to find filament usage
  131. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  132. archive = result.scalar_one_or_none()
  133. if not archive or not archive.filament_used_grams:
  134. logger.debug(f"No filament usage data for archive {archive_id}")
  135. return
  136. filament_used = archive.filament_used_grams
  137. logger.info(f"[SPOOLMAN] Archive {archive_id} used {filament_used}g of filament")
  138. # Get current AMS state from printer to find the active spool
  139. state = printer_manager.get_status(printer_id)
  140. if not state or not state.raw_data:
  141. logger.debug("No printer state available for usage reporting")
  142. return
  143. ams_data = state.raw_data.get("ams")
  144. if not ams_data:
  145. logger.debug("No AMS data available for usage reporting")
  146. return
  147. # Find spools with RFID tags in Spoolman and report usage
  148. # For now, we report usage to the first spool found with a matching tag
  149. # TODO: In future, track which specific trays were used during the print
  150. spools_updated = 0
  151. for ams_unit in ams_data:
  152. trays = ams_unit.get("tray", [])
  153. for tray_data in trays:
  154. tag_uid = tray_data.get("tag_uid")
  155. if not tag_uid:
  156. continue
  157. # Find spool in Spoolman by tag
  158. spool = await client.find_spool_by_tag(tag_uid)
  159. if spool:
  160. # Report usage to Spoolman
  161. result = await client.use_spool(spool["id"], filament_used)
  162. if result:
  163. logger.info(
  164. f"[SPOOLMAN] Reported {filament_used}g usage to spool {spool['id']} (tag: {tag_uid})"
  165. )
  166. spools_updated += 1
  167. # Only report to one spool for single-material prints
  168. # Multi-material prints would need more sophisticated tracking
  169. return
  170. if spools_updated == 0:
  171. logger.debug(f"No matching Spoolman spools found for printer {printer_id}")
  172. async def on_printer_status_change(printer_id: int, state: PrinterState):
  173. """Handle printer status changes - broadcast via WebSocket."""
  174. # Only broadcast if something meaningful changed (reduce WebSocket spam)
  175. # Include rounded temperatures to detect meaningful temp changes (within 1 degree)
  176. temps = state.temperatures or {}
  177. nozzle_temp = round(temps.get("nozzle", 0))
  178. bed_temp = round(temps.get("bed", 0))
  179. nozzle_2_temp = round(temps.get("nozzle_2", 0)) if "nozzle_2" in temps else ""
  180. chamber_temp = round(temps.get("chamber", 0)) if "chamber" in temps else ""
  181. # Auto-detect dual-nozzle printers from MQTT temperature data
  182. if "nozzle_2" in temps and printer_id not in _nozzle_count_updated:
  183. _nozzle_count_updated.add(printer_id)
  184. # Update nozzle_count in database
  185. async with async_session() as db:
  186. from backend.app.models.printer import Printer
  187. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  188. printer = result.scalar_one_or_none()
  189. if printer and printer.nozzle_count != 2:
  190. printer.nozzle_count = 2
  191. await db.commit()
  192. logging.getLogger(__name__).info(
  193. f"Auto-detected dual-nozzle printer {printer_id}, updated nozzle_count=2"
  194. )
  195. status_key = (
  196. f"{state.connected}:{state.state}:{state.progress}:{state.layer_num}:"
  197. f"{nozzle_temp}:{bed_temp}:{nozzle_2_temp}:{chamber_temp}"
  198. )
  199. if _last_status_broadcast.get(printer_id) == status_key:
  200. return # No change, skip broadcast
  201. _last_status_broadcast[printer_id] = status_key
  202. await ws_manager.send_printer_status(
  203. printer_id,
  204. printer_state_to_dict(state, printer_id),
  205. )
  206. async def on_ams_change(printer_id: int, ams_data: list):
  207. """Handle AMS data changes - sync to Spoolman if enabled and auto mode."""
  208. import logging
  209. logger = logging.getLogger(__name__)
  210. try:
  211. async with async_session() as db:
  212. from backend.app.api.routes.settings import get_setting
  213. from backend.app.models.printer import Printer
  214. # Check if Spoolman is enabled
  215. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  216. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  217. return
  218. # Check sync mode
  219. sync_mode = await get_setting(db, "spoolman_sync_mode")
  220. if sync_mode and sync_mode != "auto":
  221. return # Only sync on auto mode
  222. # Get Spoolman URL
  223. spoolman_url = await get_setting(db, "spoolman_url")
  224. if not spoolman_url:
  225. return
  226. # Get or create Spoolman client
  227. client = await get_spoolman_client()
  228. if not client:
  229. client = await init_spoolman_client(spoolman_url)
  230. # Check if Spoolman is reachable
  231. if not await client.health_check():
  232. logger.warning(f"Spoolman not reachable at {spoolman_url}")
  233. return
  234. # Get printer name for location
  235. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  236. printer = result.scalar_one_or_none()
  237. printer_name = printer.name if printer else f"Printer {printer_id}"
  238. # Sync each AMS tray
  239. synced = 0
  240. for ams_unit in ams_data:
  241. ams_id = int(ams_unit.get("id", 0))
  242. trays = ams_unit.get("tray", [])
  243. for tray_data in trays:
  244. tray = client.parse_ams_tray(ams_id, tray_data)
  245. if not tray:
  246. continue # Empty tray
  247. try:
  248. result = await client.sync_ams_tray(tray, printer_name)
  249. if result:
  250. synced += 1
  251. except Exception as e:
  252. logger.error(f"Error syncing AMS {ams_id} tray {tray.tray_id}: {e}")
  253. if synced > 0:
  254. logger.info(f"Auto-synced {synced} AMS trays to Spoolman for printer {printer_id}")
  255. except Exception as e:
  256. import logging
  257. logging.getLogger(__name__).warning(f"Spoolman AMS sync failed: {e}")
  258. async def _send_print_start_notification(
  259. printer_id: int,
  260. data: dict,
  261. archive_data: dict | None = None,
  262. logger=None,
  263. ):
  264. """Helper to send print start notification with optional archive data."""
  265. if logger is None:
  266. import logging
  267. logger = logging.getLogger(__name__)
  268. try:
  269. async with async_session() as db:
  270. from backend.app.models.printer import Printer
  271. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  272. printer = result.scalar_one_or_none()
  273. printer_name = printer.name if printer else f"Printer {printer_id}"
  274. await notification_service.on_print_start(printer_id, printer_name, data, db, archive_data=archive_data)
  275. except Exception as e:
  276. logger.warning(f"Notification on_print_start failed: {e}")
  277. async def on_print_start(printer_id: int, data: dict):
  278. """Handle print start - archive the 3MF file immediately."""
  279. import logging
  280. logger = logging.getLogger(__name__)
  281. logger.info(f"[CALLBACK] on_print_start called for printer {printer_id}, data keys: {list(data.keys())}")
  282. await ws_manager.send_print_start(printer_id, data)
  283. # Track if notification was sent (to avoid sending twice)
  284. notification_sent = False
  285. # Smart plug automation: turn on plug when print starts
  286. try:
  287. async with async_session() as db:
  288. await smart_plug_manager.on_print_start(printer_id, db)
  289. except Exception as e:
  290. logger.warning(f"Smart plug on_print_start failed: {e}")
  291. async with async_session() as db:
  292. from backend.app.models.printer import Printer
  293. from backend.app.services.bambu_ftp import list_files_async
  294. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  295. printer = result.scalar_one_or_none()
  296. if not printer or not printer.auto_archive:
  297. # Send notification without archive data (auto-archive disabled)
  298. logger.info(
  299. f"[CALLBACK] Skipping archive - printer: {printer is not None}, auto_archive: {printer.auto_archive if printer else 'N/A'}"
  300. )
  301. if not notification_sent:
  302. await _send_print_start_notification(printer_id, data, logger=logger)
  303. return
  304. # Get the filename and subtask_name
  305. filename = data.get("filename", "")
  306. subtask_name = data.get("subtask_name", "")
  307. logger.info(f"[CALLBACK] Print start detected - filename: {filename}, subtask: {subtask_name}")
  308. if not filename and not subtask_name:
  309. # Send notification without archive data (no filename)
  310. logger.info("[CALLBACK] Skipping archive - no filename or subtask_name")
  311. if not notification_sent:
  312. await _send_print_start_notification(printer_id, data, logger=logger)
  313. return
  314. # Check if this is an expected print from reprint/scheduled
  315. # Build list of possible keys to check
  316. expected_keys = []
  317. if subtask_name:
  318. expected_keys.append((printer_id, subtask_name))
  319. expected_keys.append((printer_id, f"{subtask_name}.3mf"))
  320. expected_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  321. if filename:
  322. fname = filename.split("/")[-1] if "/" in filename else filename
  323. expected_keys.append((printer_id, fname))
  324. # Strip extensions to match
  325. base = fname.replace(".gcode", "").replace(".3mf", "")
  326. expected_keys.append((printer_id, base))
  327. expected_keys.append((printer_id, f"{base}.3mf"))
  328. expected_archive_id = None
  329. for key in expected_keys:
  330. expected_archive_id = _expected_prints.pop(key, None)
  331. if expected_archive_id:
  332. # Clean up other possible keys for this print
  333. for other_key in expected_keys:
  334. _expected_prints.pop(other_key, None)
  335. break
  336. if expected_archive_id:
  337. # This is a reprint/scheduled print - use existing archive, don't create new one
  338. logger.info(f"Using expected archive {expected_archive_id} for print (skipping duplicate)")
  339. from datetime import datetime
  340. from backend.app.models.archive import PrintArchive
  341. result = await db.execute(select(PrintArchive).where(PrintArchive.id == expected_archive_id))
  342. archive = result.scalar_one_or_none()
  343. if archive:
  344. # Update archive status to printing
  345. archive.status = "printing"
  346. archive.started_at = datetime.now()
  347. await db.commit()
  348. # Track as active print
  349. _active_prints[(printer_id, archive.filename)] = archive.id
  350. if subtask_name:
  351. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  352. # Set up energy tracking
  353. try:
  354. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  355. plug = plug_result.scalar_one_or_none()
  356. logger.info(
  357. f"[ENERGY] Print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  358. )
  359. if plug:
  360. energy = await tasmota_service.get_energy(plug)
  361. logger.info(f"[ENERGY] Energy response from plug: {energy}")
  362. if energy and energy.get("total") is not None:
  363. _print_energy_start[archive.id] = energy["total"]
  364. logger.info(
  365. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  366. )
  367. else:
  368. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  369. else:
  370. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  371. except Exception as e:
  372. logger.warning(f"Failed to record starting energy: {e}")
  373. await ws_manager.send_archive_updated(
  374. {
  375. "id": archive.id,
  376. "status": "printing",
  377. }
  378. )
  379. # Send notification with archive data (reprint/scheduled)
  380. if not notification_sent:
  381. archive_data = {"print_time_seconds": archive.print_time_seconds}
  382. await _send_print_start_notification(printer_id, data, archive_data, logger)
  383. return # Skip creating a new archive
  384. # Check if there's already a "printing" archive for this printer/file
  385. # This prevents duplicates when backend restarts during an active print
  386. from backend.app.models.archive import PrintArchive
  387. check_name = subtask_name or filename.split("/")[-1].replace(".gcode", "").replace(".3mf", "")
  388. existing = await db.execute(
  389. select(PrintArchive)
  390. .where(PrintArchive.printer_id == printer_id)
  391. .where(PrintArchive.status == "printing")
  392. .where(PrintArchive.print_name.ilike(f"%{check_name}%"))
  393. .order_by(PrintArchive.created_at.desc())
  394. .limit(1)
  395. )
  396. existing_archive = existing.scalar_one_or_none()
  397. if existing_archive:
  398. logger.info(f"Skipping duplicate - already have printing archive {existing_archive.id} for {check_name}")
  399. # Track this as the active print
  400. _active_prints[(printer_id, existing_archive.filename)] = existing_archive.id
  401. # Also set up energy tracking if not already tracked
  402. if existing_archive.id not in _print_energy_start:
  403. try:
  404. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  405. plug = plug_result.scalar_one_or_none()
  406. if plug:
  407. energy = await tasmota_service.get_energy(plug)
  408. if energy and energy.get("total") is not None:
  409. _print_energy_start[existing_archive.id] = energy["total"]
  410. logger.info(
  411. f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh"
  412. )
  413. except Exception as e:
  414. logger.warning(f"Failed to record starting energy for existing archive: {e}")
  415. # Send notification with archive data (existing archive)
  416. if not notification_sent:
  417. archive_data = {"print_time_seconds": existing_archive.print_time_seconds}
  418. await _send_print_start_notification(printer_id, data, archive_data, logger)
  419. return
  420. # Build list of possible 3MF filenames to try
  421. possible_names = []
  422. # Bambu printers typically store files as "Name.gcode.3mf"
  423. # The subtask_name is usually the best source for the filename
  424. if subtask_name:
  425. # Try common Bambu naming patterns
  426. possible_names.append(f"{subtask_name}.gcode.3mf")
  427. possible_names.append(f"{subtask_name}.3mf")
  428. # Try original filename with .3mf extension
  429. if filename:
  430. # Extract just the filename part, not the full path
  431. fname = filename.split("/")[-1] if "/" in filename else filename
  432. if fname.endswith(".3mf"):
  433. possible_names.append(fname)
  434. elif fname.endswith(".gcode"):
  435. base = fname.rsplit(".", 1)[0]
  436. possible_names.append(f"{base}.gcode.3mf")
  437. possible_names.append(f"{base}.3mf")
  438. else:
  439. possible_names.append(f"{fname}.gcode.3mf")
  440. possible_names.append(f"{fname}.3mf")
  441. # Remove duplicates while preserving order
  442. seen = set()
  443. possible_names = [x for x in possible_names if not (x in seen or seen.add(x))]
  444. logger.info(f"Trying filenames: {possible_names}")
  445. # Try to find and download the 3MF file
  446. temp_path = None
  447. downloaded_filename = None
  448. for try_filename in possible_names:
  449. if not try_filename.endswith(".3mf"):
  450. continue
  451. remote_paths = [
  452. f"/cache/{try_filename}",
  453. f"/model/{try_filename}",
  454. f"/{try_filename}",
  455. ]
  456. temp_path = app_settings.archive_dir / "temp" / try_filename
  457. temp_path.parent.mkdir(parents=True, exist_ok=True)
  458. for remote_path in remote_paths:
  459. logger.debug(f"Trying FTP download: {remote_path}")
  460. try:
  461. if await download_file_async(
  462. printer.ip_address,
  463. printer.access_code,
  464. remote_path,
  465. temp_path,
  466. ):
  467. downloaded_filename = try_filename
  468. logger.info(f"Downloaded: {remote_path}")
  469. break
  470. except Exception as e:
  471. logger.debug(f"FTP download failed for {remote_path}: {e}")
  472. if downloaded_filename:
  473. break
  474. # If still not found, try listing /cache to find matching file
  475. if not downloaded_filename and (filename or subtask_name):
  476. search_term = (subtask_name or filename).lower().replace(".gcode", "").replace(".3mf", "")
  477. try:
  478. cache_files = await list_files_async(printer.ip_address, printer.access_code, "/cache")
  479. for f in cache_files:
  480. if f.get("is_directory"):
  481. continue
  482. fname = f.get("name", "")
  483. if fname.endswith(".3mf") and search_term in fname.lower():
  484. temp_path = app_settings.archive_dir / "temp" / fname
  485. temp_path.parent.mkdir(parents=True, exist_ok=True)
  486. if await download_file_async(
  487. printer.ip_address,
  488. printer.access_code,
  489. f"/cache/{fname}",
  490. temp_path,
  491. ):
  492. downloaded_filename = fname
  493. logger.info(f"Found and downloaded from cache: {fname}")
  494. break
  495. except Exception as e:
  496. logger.warning(f"Failed to list cache: {e}")
  497. if not downloaded_filename or not temp_path:
  498. logger.warning(f"Could not find 3MF file for print: {filename or subtask_name}")
  499. # Send notification without archive data (file not found)
  500. if not notification_sent:
  501. await _send_print_start_notification(printer_id, data, logger=logger)
  502. return
  503. try:
  504. # Archive the file with status "printing"
  505. service = ArchiveService(db)
  506. archive = await service.archive_print(
  507. printer_id=printer_id,
  508. source_file=temp_path,
  509. print_data={**data, "status": "printing"},
  510. )
  511. if archive:
  512. # Track this active print (use both original filename and downloaded filename)
  513. _active_prints[(printer_id, downloaded_filename)] = archive.id
  514. if filename and filename != downloaded_filename:
  515. _active_prints[(printer_id, filename)] = archive.id
  516. if subtask_name:
  517. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  518. logger.info(f"Created archive {archive.id} for {downloaded_filename}")
  519. # Record starting energy from smart plug if available
  520. try:
  521. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  522. plug = plug_result.scalar_one_or_none()
  523. logger.info(
  524. f"[ENERGY] Auto-archive print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  525. )
  526. if plug:
  527. energy = await tasmota_service.get_energy(plug)
  528. logger.info(f"[ENERGY] Auto-archive energy response: {energy}")
  529. if energy and energy.get("total") is not None:
  530. _print_energy_start[archive.id] = energy["total"]
  531. logger.info(
  532. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  533. )
  534. else:
  535. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  536. else:
  537. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  538. except Exception as e:
  539. logger.warning(f"Failed to record starting energy: {e}")
  540. await ws_manager.send_archive_created(
  541. {
  542. "id": archive.id,
  543. "printer_id": archive.printer_id,
  544. "filename": archive.filename,
  545. "print_name": archive.print_name,
  546. "status": archive.status,
  547. }
  548. )
  549. # Send notification with archive data (new archive created)
  550. if not notification_sent:
  551. archive_data = {"print_time_seconds": archive.print_time_seconds}
  552. await _send_print_start_notification(printer_id, data, archive_data, logger)
  553. notification_sent = True
  554. finally:
  555. if temp_path and temp_path.exists():
  556. temp_path.unlink()
  557. async def _scan_for_timelapse_with_retries(archive_id: int):
  558. """
  559. Scan for timelapse with retries.
  560. The printer encodes the timelapse quickly after print completion.
  561. We just need a short delay then grab the most recent file.
  562. Since we KNOW timelapse was active (from MQTT ipcam data), the most recent
  563. file in /timelapse is our target. Retries handle FTP connection issues.
  564. """
  565. import logging
  566. logger = logging.getLogger(__name__)
  567. # Short delays - printer usually finishes encoding within seconds
  568. retry_delays = [5, 10, 20]
  569. for attempt, delay in enumerate(retry_delays, 1):
  570. logger.info(
  571. f"[TIMELAPSE] Attempt {attempt}/{len(retry_delays)}: waiting {delay}s before scanning for archive {archive_id}"
  572. )
  573. await asyncio.sleep(delay)
  574. try:
  575. async with async_session() as db:
  576. from backend.app.models.printer import Printer
  577. from backend.app.services.bambu_ftp import download_file_bytes_async, list_files_async
  578. # Get archive (ArchiveService from module-level import)
  579. service = ArchiveService(db)
  580. archive = await service.get_archive(archive_id)
  581. if not archive:
  582. logger.warning(f"[TIMELAPSE] Archive {archive_id} not found, stopping retries")
  583. return
  584. if archive.timelapse_path:
  585. logger.info(f"[TIMELAPSE] Archive {archive_id} already has timelapse attached, stopping retries")
  586. return
  587. if not archive.printer_id:
  588. logger.warning(f"[TIMELAPSE] Archive {archive_id} has no printer, stopping retries")
  589. return
  590. # Get printer
  591. result = await db.execute(select(Printer).where(Printer.id == archive.printer_id))
  592. printer = result.scalar_one_or_none()
  593. if not printer:
  594. logger.warning(f"[TIMELAPSE] Printer not found for archive {archive_id}, stopping retries")
  595. return
  596. # Scan timelapse directory on printer
  597. # H2D may store in different locations than X1C
  598. files = []
  599. found_path = None
  600. for timelapse_path in ["/timelapse", "/timelapse/video", "/record", "/recording"]:
  601. try:
  602. found_files = await list_files_async(printer.ip_address, printer.access_code, timelapse_path)
  603. if found_files:
  604. files = found_files
  605. found_path = timelapse_path
  606. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(files)} files in {timelapse_path}")
  607. break
  608. except Exception as e:
  609. logger.debug(f"[TIMELAPSE] Path {timelapse_path} failed: {e}")
  610. continue
  611. if not files:
  612. logger.info(f"[TIMELAPSE] Attempt {attempt}: No timelapse files found on printer, will retry")
  613. continue
  614. mp4_files = [f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4")]
  615. # Log ALL mp4 files found for debugging
  616. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(mp4_files)} MP4 files in {found_path}")
  617. for f in mp4_files[:5]: # Log first 5
  618. logger.info(f"[TIMELAPSE] - {f.get('name')}, mtime={f.get('mtime')}")
  619. if not mp4_files:
  620. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files found, will retry")
  621. continue
  622. # Sort by mtime descending to get most recent file
  623. mp4_files_with_mtime = [f for f in mp4_files if f.get("mtime")]
  624. if not mp4_files_with_mtime:
  625. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files with mtime found, will retry")
  626. continue
  627. mp4_files_with_mtime.sort(key=lambda x: x.get("mtime"), reverse=True)
  628. most_recent = mp4_files_with_mtime[0]
  629. file_name = most_recent.get("name")
  630. logger.info(f"[TIMELAPSE] Attempt {attempt}: Most recent file: {file_name}")
  631. # Since we KNOW timelapse was active (from MQTT), just grab the most recent file
  632. remote_path = most_recent.get("path") or f"/timelapse/{file_name}"
  633. logger.info(f"[TIMELAPSE] Downloading {file_name} for archive {archive_id}")
  634. timelapse_data = await download_file_bytes_async(printer.ip_address, printer.access_code, remote_path)
  635. if timelapse_data:
  636. success = await service.attach_timelapse(archive_id, timelapse_data, file_name)
  637. if success:
  638. logger.info(f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}")
  639. await ws_manager.send_archive_updated({"id": archive_id, "timelapse_attached": True})
  640. return # Success!
  641. else:
  642. logger.warning(f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}")
  643. else:
  644. logger.warning(f"[TIMELAPSE] Attempt {attempt}: Failed to download, will retry")
  645. except Exception as e:
  646. logger.warning(f"[TIMELAPSE] Attempt {attempt} failed with error: {e}")
  647. logger.warning(f"[TIMELAPSE] All {len(retry_delays)} attempts exhausted for archive {archive_id}, giving up")
  648. async def on_print_complete(printer_id: int, data: dict):
  649. """Handle print completion - update the archive status."""
  650. import logging
  651. logger = logging.getLogger(__name__)
  652. logger.info(f"[CALLBACK] on_print_complete started for printer {printer_id}")
  653. try:
  654. # Only send necessary fields to WebSocket (not raw_data which can be large)
  655. ws_data = {
  656. "status": data.get("status"),
  657. "filename": data.get("filename"),
  658. "subtask_name": data.get("subtask_name"),
  659. "timelapse_was_active": data.get("timelapse_was_active"),
  660. }
  661. await ws_manager.send_print_complete(printer_id, ws_data)
  662. except Exception as e:
  663. logger.warning(f"[CALLBACK] WebSocket send_print_complete failed: {e}")
  664. filename = data.get("filename", "")
  665. subtask_name = data.get("subtask_name", "")
  666. if not filename and not subtask_name:
  667. logger.warning("Print complete without filename or subtask_name")
  668. return
  669. logger.info(f"Print complete - filename: {filename}, subtask: {subtask_name}, status: {data.get('status')}")
  670. # Build list of possible keys to try (matching how they were registered in on_print_start)
  671. possible_keys = []
  672. # Try subtask_name variations first (most reliable for matching)
  673. if subtask_name:
  674. possible_keys.append((printer_id, f"{subtask_name}.3mf"))
  675. possible_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  676. possible_keys.append((printer_id, subtask_name))
  677. # Try filename variations
  678. if filename:
  679. # Extract just the filename if it's a path
  680. fname = filename.split("/")[-1] if "/" in filename else filename
  681. if fname.endswith(".3mf"):
  682. possible_keys.append((printer_id, fname))
  683. elif fname.endswith(".gcode"):
  684. base_name = fname.rsplit(".", 1)[0]
  685. possible_keys.append((printer_id, f"{base_name}.gcode.3mf"))
  686. possible_keys.append((printer_id, f"{base_name}.3mf"))
  687. possible_keys.append((printer_id, fname))
  688. else:
  689. possible_keys.append((printer_id, f"{fname}.gcode.3mf"))
  690. possible_keys.append((printer_id, f"{fname}.3mf"))
  691. possible_keys.append((printer_id, fname))
  692. # Also try full path versions
  693. if filename.endswith(".3mf"):
  694. possible_keys.append((printer_id, filename))
  695. elif filename.endswith(".gcode"):
  696. base_name = filename.rsplit(".", 1)[0]
  697. possible_keys.append((printer_id, f"{base_name}.3mf"))
  698. possible_keys.append((printer_id, filename))
  699. else:
  700. possible_keys.append((printer_id, f"{filename}.3mf"))
  701. possible_keys.append((printer_id, filename))
  702. # Find the archive for this print
  703. logger.info(f"Looking for archive in _active_prints, keys to try: {possible_keys[:5]}...")
  704. logger.info(f"Current _active_prints: {list(_active_prints.keys())}")
  705. archive_id = None
  706. for key in possible_keys:
  707. archive_id = _active_prints.pop(key, None)
  708. if archive_id:
  709. logger.info(f"Found archive {archive_id} with key {key}")
  710. # Also clean up any other keys pointing to this archive
  711. keys_to_remove = [k for k, v in _active_prints.items() if v == archive_id]
  712. for k in keys_to_remove:
  713. _active_prints.pop(k, None)
  714. break
  715. if not archive_id:
  716. # Try to find by filename or subtask_name if not tracked (for prints started before app)
  717. async with async_session() as db:
  718. from backend.app.models.archive import PrintArchive
  719. # Try matching by subtask_name (stored as print_name) first
  720. if subtask_name:
  721. result = await db.execute(
  722. select(PrintArchive)
  723. .where(PrintArchive.printer_id == printer_id)
  724. .where(PrintArchive.status == "printing")
  725. .where(
  726. or_(
  727. PrintArchive.print_name.ilike(f"%{subtask_name}%"),
  728. PrintArchive.filename.ilike(f"%{subtask_name}%"),
  729. )
  730. )
  731. .order_by(PrintArchive.created_at.desc())
  732. .limit(1)
  733. )
  734. archive = result.scalar_one_or_none()
  735. if archive:
  736. archive_id = archive.id
  737. logger.info(f"Found archive {archive_id} by subtask_name match: {subtask_name}")
  738. # Also try by filename
  739. if not archive_id and filename:
  740. result = await db.execute(
  741. select(PrintArchive)
  742. .where(PrintArchive.printer_id == printer_id)
  743. .where(PrintArchive.filename == filename)
  744. .where(PrintArchive.status == "printing")
  745. .order_by(PrintArchive.created_at.desc())
  746. .limit(1)
  747. )
  748. archive = result.scalar_one_or_none()
  749. if archive:
  750. archive_id = archive.id
  751. if not archive_id:
  752. logger.warning(f"Could not find archive for print complete: filename={filename}, subtask={subtask_name}")
  753. return
  754. # Update archive status
  755. logger.info(f"[ARCHIVE] Updating archive {archive_id} status...")
  756. try:
  757. async with async_session() as db:
  758. service = ArchiveService(db)
  759. status = data.get("status", "completed")
  760. # Auto-detect failure reason
  761. failure_reason = None
  762. if status == "aborted":
  763. failure_reason = "User cancelled"
  764. logger.info("[ARCHIVE] Print was aborted by user, setting failure_reason='User cancelled'")
  765. elif status == "failed":
  766. # Try to determine failure reason from HMS errors
  767. hms_errors = data.get("hms_errors", [])
  768. if hms_errors:
  769. logger.info(f"[ARCHIVE] HMS errors at failure: {hms_errors}")
  770. # Map known HMS error modules to failure reasons
  771. # Module 0x07 = Filament, 0x0C = MC (Motion Controller), etc.
  772. for err in hms_errors:
  773. module = err.get("module", 0)
  774. if module == 0x07: # Filament module
  775. failure_reason = "Filament runout"
  776. break
  777. elif module == 0x0C: # Motion controller
  778. failure_reason = "Layer shift"
  779. break
  780. elif module == 0x05: # Nozzle/extruder
  781. failure_reason = "Clogged nozzle"
  782. break
  783. if failure_reason:
  784. logger.info(f"[ARCHIVE] Detected failure_reason from HMS: {failure_reason}")
  785. else:
  786. logger.info("[ARCHIVE] No HMS errors available to determine failure reason")
  787. await service.update_archive_status(
  788. archive_id,
  789. status=status,
  790. completed_at=datetime.now() if status in ("completed", "failed", "aborted") else None,
  791. failure_reason=failure_reason,
  792. )
  793. logger.info(f"[ARCHIVE] Archive {archive_id} status updated to {status}, failure_reason={failure_reason}")
  794. await ws_manager.send_archive_updated(
  795. {
  796. "id": archive_id,
  797. "status": status,
  798. }
  799. )
  800. logger.info(f"[ARCHIVE] WebSocket notification sent for archive {archive_id}")
  801. except Exception as e:
  802. logger.error(f"[ARCHIVE] Failed to update archive {archive_id} status: {e}", exc_info=True)
  803. # Continue with other operations even if archive update fails
  804. # Report filament usage to Spoolman if print completed successfully
  805. if data.get("status") == "completed":
  806. try:
  807. await _report_spoolman_usage(printer_id, archive_id, logger)
  808. except Exception as e:
  809. logger.warning(f"Spoolman usage reporting failed: {e}")
  810. # Calculate energy used for this print (always per-print: end - start)
  811. try:
  812. starting_kwh = _print_energy_start.pop(archive_id, None)
  813. logger.info(f"[ENERGY] Print complete for archive {archive_id}, starting_kwh={starting_kwh}")
  814. async with async_session() as db:
  815. # Get smart plug for this printer (SmartPlug is imported at module level)
  816. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  817. plug = plug_result.scalar_one_or_none()
  818. if plug:
  819. energy = await tasmota_service.get_energy(plug)
  820. logger.info(f"[ENERGY] Print complete - energy response: {energy}")
  821. energy_used = None
  822. # Calculate per-print energy: end total - start total
  823. if starting_kwh is not None and energy and energy.get("total") is not None:
  824. ending_kwh = energy["total"]
  825. energy_used = round(ending_kwh - starting_kwh, 4)
  826. logger.info(
  827. f"[ENERGY] Per-print energy: ending={ending_kwh}, starting={starting_kwh}, used={energy_used}"
  828. )
  829. elif starting_kwh is None:
  830. logger.info("[ENERGY] No starting energy recorded for this archive")
  831. else:
  832. logger.warning("[ENERGY] No 'total' in ending energy response")
  833. if energy_used is not None and energy_used >= 0:
  834. # Get energy cost per kWh from settings (default to 0.15)
  835. from backend.app.api.routes.settings import get_setting
  836. energy_cost_per_kwh = await get_setting(db, "energy_cost_per_kwh")
  837. cost_per_kwh = float(energy_cost_per_kwh) if energy_cost_per_kwh else 0.15
  838. energy_cost = round(energy_used * cost_per_kwh, 2)
  839. # Update archive with energy data
  840. from backend.app.models.archive import PrintArchive
  841. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  842. archive = result.scalar_one_or_none()
  843. if archive:
  844. archive.energy_kwh = energy_used
  845. archive.energy_cost = energy_cost
  846. await db.commit()
  847. logger.info(f"[ENERGY] Saved to archive {archive_id}: {energy_used} kWh, cost={energy_cost}")
  848. else:
  849. logger.warning(f"[ENERGY] Archive {archive_id} not found when saving energy")
  850. else:
  851. logger.info(f"[ENERGY] No smart plug found for printer {printer_id} at print complete")
  852. except Exception as e:
  853. import logging
  854. logging.getLogger(__name__).warning(f"Failed to calculate energy: {e}")
  855. # Capture finish photo from printer camera
  856. logger.info(f"[PHOTO] Starting finish photo capture for archive {archive_id}")
  857. try:
  858. async with async_session() as db:
  859. # Check if finish photo capture is enabled
  860. from backend.app.api.routes.settings import get_setting
  861. capture_enabled = await get_setting(db, "capture_finish_photo")
  862. logger.info(f"[PHOTO] capture_finish_photo setting: {capture_enabled}")
  863. if capture_enabled is None or capture_enabled.lower() == "true":
  864. # Get printer details
  865. from backend.app.models.printer import Printer
  866. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  867. printer = result.scalar_one_or_none()
  868. if printer and archive_id:
  869. # Get archive to find its directory
  870. from backend.app.models.archive import PrintArchive
  871. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  872. archive = result.scalar_one_or_none()
  873. if archive:
  874. from pathlib import Path
  875. from backend.app.services.camera import capture_finish_photo
  876. archive_dir = app_settings.base_dir / Path(archive.file_path).parent
  877. photo_filename = await capture_finish_photo(
  878. printer_id=printer_id,
  879. ip_address=printer.ip_address,
  880. access_code=printer.access_code,
  881. model=printer.model,
  882. archive_dir=archive_dir,
  883. )
  884. if photo_filename:
  885. # Add photo to archive's photos list
  886. photos = archive.photos or []
  887. photos.append(photo_filename)
  888. archive.photos = photos
  889. await db.commit()
  890. logger.info(f"Added finish photo to archive {archive_id}: {photo_filename}")
  891. except Exception as e:
  892. import logging
  893. logging.getLogger(__name__).warning(f"Finish photo capture failed: {e}")
  894. # Smart plug automation: schedule turn off when print completes
  895. logger.info(f"[AUTO-OFF] Calling smart_plug_manager.on_print_complete for printer {printer_id}")
  896. try:
  897. async with async_session() as db:
  898. status = data.get("status", "completed")
  899. await smart_plug_manager.on_print_complete(printer_id, status, db)
  900. logger.info("[AUTO-OFF] smart_plug_manager.on_print_complete completed")
  901. except Exception as e:
  902. import logging
  903. logging.getLogger(__name__).warning(f"Smart plug on_print_complete failed: {e}")
  904. # Send print complete notifications
  905. try:
  906. async with async_session() as db:
  907. from backend.app.models.archive import PrintArchive
  908. from backend.app.models.printer import Printer
  909. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  910. printer = result.scalar_one_or_none()
  911. printer_name = printer.name if printer else f"Printer {printer_id}"
  912. status = data.get("status", "completed")
  913. # Fetch archive data for notification variables
  914. archive_data = None
  915. if archive_id:
  916. archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  917. archive = archive_result.scalar_one_or_none()
  918. if archive:
  919. archive_data = {
  920. "print_time_seconds": archive.print_time_seconds,
  921. "actual_filament_grams": archive.filament_used_grams,
  922. "failure_reason": archive.failure_reason,
  923. }
  924. # on_print_complete handles all status types: completed, failed, aborted, stopped
  925. await notification_service.on_print_complete(
  926. printer_id, printer_name, status, data, db, archive_data=archive_data
  927. )
  928. except Exception as e:
  929. import logging
  930. logging.getLogger(__name__).warning(f"Notification on_print_complete failed: {e}")
  931. # Check for maintenance due and send notifications (only for completed prints)
  932. if data.get("status") == "completed":
  933. try:
  934. async with async_session() as db:
  935. from backend.app.models.printer import Printer
  936. # Get printer name
  937. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  938. printer = result.scalar_one_or_none()
  939. printer_name = printer.name if printer else f"Printer {printer_id}"
  940. # Get maintenance overview for this printer
  941. await ensure_default_types(db)
  942. overview = await _get_printer_maintenance_internal(printer_id, db, commit=True)
  943. # Check for any items that are due or have warnings
  944. items_needing_attention = [
  945. {
  946. "name": item.maintenance_type_name,
  947. "is_due": item.is_due,
  948. "is_warning": item.is_warning,
  949. }
  950. for item in overview.maintenance_items
  951. if item.enabled and (item.is_due or item.is_warning)
  952. ]
  953. if items_needing_attention:
  954. await notification_service.on_maintenance_due(printer_id, printer_name, items_needing_attention, db)
  955. logger.info(
  956. f"Sent maintenance notification for printer {printer_id}: "
  957. f"{len(items_needing_attention)} items need attention"
  958. )
  959. except Exception as e:
  960. import logging
  961. logging.getLogger(__name__).warning(f"Maintenance notification check failed: {e}")
  962. # Auto-scan for timelapse if recording was active during the print
  963. if archive_id and data.get("timelapse_was_active") and data.get("status") == "completed":
  964. logger.info(f"[TIMELAPSE] Timelapse was active during print, scheduling auto-scan for archive {archive_id}")
  965. # Schedule timelapse scan as background task with retries
  966. # The printer needs time to encode the video after print completion
  967. asyncio.create_task(_scan_for_timelapse_with_retries(archive_id))
  968. # Update queue item if this was a scheduled print
  969. try:
  970. async with async_session() as db:
  971. from backend.app.models.print_queue import PrintQueueItem
  972. # Note: SmartPlug is already imported at module level (line 56)
  973. # Do NOT import it here as it would shadow the module-level import
  974. # and cause "cannot access local variable" errors earlier in this function
  975. result = await db.execute(
  976. select(PrintQueueItem)
  977. .where(PrintQueueItem.printer_id == printer_id)
  978. .where(PrintQueueItem.status == "printing")
  979. )
  980. queue_item = result.scalar_one_or_none()
  981. if queue_item:
  982. status = data.get("status", "completed")
  983. queue_item.status = status
  984. queue_item.completed_at = datetime.now()
  985. await db.commit()
  986. logger.info(f"Updated queue item {queue_item.id} status to {status}")
  987. # Handle auto_off_after - power off printer if requested (after cooldown)
  988. if queue_item.auto_off_after:
  989. result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  990. plug = result.scalar_one_or_none()
  991. if plug and plug.enabled:
  992. logger.info(f"Auto-off requested for printer {printer_id}, waiting for cooldown...")
  993. async def cooldown_and_poweroff(pid: int, plug_id: int):
  994. # Wait for nozzle to cool down
  995. await printer_manager.wait_for_cooldown(pid, target_temp=50.0, timeout=600)
  996. # Re-fetch plug in new session
  997. async with async_session() as new_db:
  998. result = await new_db.execute(select(SmartPlug).where(SmartPlug.id == plug_id))
  999. p = result.scalar_one_or_none()
  1000. if p and p.enabled:
  1001. success = await tasmota_service.turn_off(p)
  1002. if success:
  1003. logger.info(f"Powered off printer {pid} via smart plug '{p.name}'")
  1004. else:
  1005. logger.warning(f"Failed to power off printer {pid} via smart plug")
  1006. asyncio.create_task(cooldown_and_poweroff(printer_id, plug.id))
  1007. except Exception as e:
  1008. import logging
  1009. logging.getLogger(__name__).warning(f"Queue item update failed: {e}")
  1010. logger.info(f"[CALLBACK] on_print_complete finished for printer {printer_id}, archive {archive_id}")
  1011. # AMS sensor history recording
  1012. _ams_history_task: asyncio.Task | None = None
  1013. AMS_HISTORY_INTERVAL = 300 # Record every 5 minutes
  1014. AMS_HISTORY_RETENTION_DAYS = 30 # Keep data for 30 days
  1015. _ams_cleanup_counter = 0 # Track recordings to trigger periodic cleanup
  1016. _ams_alarm_cooldown: dict[str, datetime] = {} # Track alarm cooldowns (printer_id:ams_id:type -> last_alarm_time)
  1017. AMS_ALARM_COOLDOWN_MINUTES = 60 # Don't send same alarm more than once per hour
  1018. async def record_ams_history():
  1019. """Background task to record AMS humidity and temperature data."""
  1020. import logging
  1021. logger = logging.getLogger(__name__)
  1022. # Wait a short time for MQTT connections to establish on startup
  1023. await asyncio.sleep(10)
  1024. while True:
  1025. try:
  1026. from backend.app.models.ams_history import AMSSensorHistory
  1027. from backend.app.models.printer import Printer
  1028. from backend.app.models.settings import Settings
  1029. async with async_session() as db:
  1030. # Get all active printers
  1031. result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
  1032. printers = result.scalars().all()
  1033. # Get alarm thresholds from settings
  1034. humidity_threshold = 60.0 # Default: fair threshold
  1035. temp_threshold = 35.0 # Default: fair threshold
  1036. result = await db.execute(select(Settings).where(Settings.key == "ams_humidity_fair"))
  1037. setting = result.scalar_one_or_none()
  1038. if setting:
  1039. try:
  1040. humidity_threshold = float(setting.value)
  1041. except (ValueError, TypeError):
  1042. pass
  1043. result = await db.execute(select(Settings).where(Settings.key == "ams_temp_fair"))
  1044. setting = result.scalar_one_or_none()
  1045. if setting:
  1046. try:
  1047. temp_threshold = float(setting.value)
  1048. except (ValueError, TypeError):
  1049. pass
  1050. recorded_count = 0
  1051. for printer in printers:
  1052. # Get current state from printer manager
  1053. state = printer_manager.get_status(printer.id)
  1054. if not state or not state.raw_data:
  1055. continue
  1056. raw_data = state.raw_data
  1057. if "ams" not in raw_data or not isinstance(raw_data["ams"], list):
  1058. continue
  1059. # Record data for each AMS unit
  1060. for ams_data in raw_data["ams"]:
  1061. ams_id = int(ams_data.get("id", 0))
  1062. # Get humidity (prefer humidity_raw)
  1063. humidity_raw = ams_data.get("humidity_raw")
  1064. humidity_idx = ams_data.get("humidity")
  1065. humidity = None
  1066. if humidity_raw is not None:
  1067. try:
  1068. humidity = float(humidity_raw)
  1069. except (ValueError, TypeError):
  1070. pass
  1071. if humidity is None and humidity_idx is not None:
  1072. try:
  1073. humidity = float(humidity_idx)
  1074. except (ValueError, TypeError):
  1075. pass
  1076. # Get temperature
  1077. temperature = None
  1078. temp_str = ams_data.get("temp")
  1079. if temp_str is not None:
  1080. try:
  1081. temperature = float(temp_str)
  1082. except (ValueError, TypeError):
  1083. pass
  1084. # Skip if no data
  1085. if humidity is None and temperature is None:
  1086. continue
  1087. # Record the data point
  1088. history = AMSSensorHistory(
  1089. printer_id=printer.id,
  1090. ams_id=ams_id,
  1091. humidity=humidity,
  1092. humidity_raw=float(humidity_raw) if humidity_raw else None,
  1093. temperature=temperature,
  1094. )
  1095. db.add(history)
  1096. recorded_count += 1
  1097. # Generate AMS label and determine if it's AMS-HT (A, B, C, D or HT-A for AMS-Lite/Hub)
  1098. is_ams_ht = ams_id >= 128
  1099. if is_ams_ht:
  1100. ams_label = f"HT-{chr(65 + (ams_id - 128))}"
  1101. else:
  1102. ams_label = f"AMS-{chr(65 + ams_id)}"
  1103. # Check humidity alarm (only if above threshold)
  1104. if humidity is not None and humidity > humidity_threshold:
  1105. cooldown_key = f"{printer.id}:{ams_id}:humidity"
  1106. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1107. now = datetime.now()
  1108. if (
  1109. last_alarm is None
  1110. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1111. ):
  1112. _ams_alarm_cooldown[cooldown_key] = now
  1113. logger.info(
  1114. f"Sending humidity alarm for {printer.name} {ams_label}: {humidity}% > {humidity_threshold}%"
  1115. )
  1116. try:
  1117. # Call different notification method based on AMS type
  1118. if is_ams_ht:
  1119. await notification_service.on_ams_ht_humidity_high(
  1120. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1121. )
  1122. else:
  1123. await notification_service.on_ams_humidity_high(
  1124. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1125. )
  1126. except Exception as e:
  1127. logger.warning(f"Failed to send humidity alarm: {e}")
  1128. # Check temperature alarm (only if above threshold)
  1129. if temperature is not None and temperature > temp_threshold:
  1130. cooldown_key = f"{printer.id}:{ams_id}:temperature"
  1131. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1132. now = datetime.now()
  1133. if (
  1134. last_alarm is None
  1135. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1136. ):
  1137. _ams_alarm_cooldown[cooldown_key] = now
  1138. logger.info(
  1139. f"Sending temperature alarm for {printer.name} {ams_label}: {temperature}°C > {temp_threshold}°C"
  1140. )
  1141. try:
  1142. # Call different notification method based on AMS type
  1143. if is_ams_ht:
  1144. await notification_service.on_ams_ht_temperature_high(
  1145. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1146. )
  1147. else:
  1148. await notification_service.on_ams_temperature_high(
  1149. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1150. )
  1151. except Exception as e:
  1152. logger.warning(f"Failed to send temperature alarm: {e}")
  1153. await db.commit()
  1154. if recorded_count > 0:
  1155. logger.info(f"Recorded {recorded_count} AMS sensor history entries")
  1156. # Periodic cleanup of old data (every ~288 recordings = ~24 hours at 5min interval)
  1157. global _ams_cleanup_counter
  1158. _ams_cleanup_counter += 1
  1159. if _ams_cleanup_counter >= 288:
  1160. _ams_cleanup_counter = 0
  1161. # Get retention days from settings
  1162. from backend.app.models.settings import Settings
  1163. result = await db.execute(select(Settings).where(Settings.key == "ams_history_retention_days"))
  1164. setting = result.scalar_one_or_none()
  1165. retention_days = int(setting.value) if setting else AMS_HISTORY_RETENTION_DAYS
  1166. cutoff = datetime.now() - timedelta(days=retention_days)
  1167. result = await db.execute(delete(AMSSensorHistory).where(AMSSensorHistory.recorded_at < cutoff))
  1168. await db.commit()
  1169. if result.rowcount > 0:
  1170. logger.info(
  1171. f"Cleaned up {result.rowcount} old AMS sensor history entries (older than {retention_days} days)"
  1172. )
  1173. # Wait until next recording interval
  1174. await asyncio.sleep(AMS_HISTORY_INTERVAL)
  1175. except asyncio.CancelledError:
  1176. break
  1177. except Exception as e:
  1178. logger.warning(f"AMS history recording failed: {e}")
  1179. await asyncio.sleep(60) # Wait a bit before retrying
  1180. def start_ams_history_recording():
  1181. """Start the AMS history recording background task."""
  1182. global _ams_history_task
  1183. if _ams_history_task is None:
  1184. _ams_history_task = asyncio.create_task(record_ams_history())
  1185. logging.getLogger(__name__).info("AMS history recording started")
  1186. def stop_ams_history_recording():
  1187. """Stop the AMS history recording background task."""
  1188. global _ams_history_task
  1189. if _ams_history_task:
  1190. _ams_history_task.cancel()
  1191. _ams_history_task = None
  1192. logging.getLogger(__name__).info("AMS history recording stopped")
  1193. @asynccontextmanager
  1194. async def lifespan(app: FastAPI):
  1195. # Startup
  1196. await init_db()
  1197. # Set up printer manager callbacks
  1198. loop = asyncio.get_event_loop()
  1199. printer_manager.set_event_loop(loop)
  1200. printer_manager.set_status_change_callback(on_printer_status_change)
  1201. printer_manager.set_print_start_callback(on_print_start)
  1202. printer_manager.set_print_complete_callback(on_print_complete)
  1203. printer_manager.set_ams_change_callback(on_ams_change)
  1204. # Connect to all active printers
  1205. async with async_session() as db:
  1206. await init_printer_connections(db)
  1207. # Auto-connect to Spoolman if enabled
  1208. async with async_session() as db:
  1209. from backend.app.api.routes.settings import get_setting
  1210. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  1211. spoolman_url = await get_setting(db, "spoolman_url")
  1212. if spoolman_enabled and spoolman_enabled.lower() == "true" and spoolman_url:
  1213. try:
  1214. client = await init_spoolman_client(spoolman_url)
  1215. if await client.health_check():
  1216. logging.info(f"Auto-connected to Spoolman at {spoolman_url}")
  1217. else:
  1218. logging.warning(f"Spoolman at {spoolman_url} is not reachable")
  1219. except Exception as e:
  1220. logging.warning(f"Failed to auto-connect to Spoolman: {e}")
  1221. # Start the print scheduler
  1222. asyncio.create_task(print_scheduler.run())
  1223. # Start the smart plug scheduler for time-based on/off
  1224. smart_plug_manager.start_scheduler()
  1225. # Resume any pending auto-offs that were interrupted by restart
  1226. await smart_plug_manager.resume_pending_auto_offs()
  1227. # Start the notification digest scheduler
  1228. notification_service.start_digest_scheduler()
  1229. # Start AMS history recording
  1230. start_ams_history_recording()
  1231. # Start anonymous telemetry (opt-out via settings)
  1232. asyncio.create_task(start_telemetry_loop(async_session))
  1233. yield
  1234. # Shutdown
  1235. print_scheduler.stop()
  1236. smart_plug_manager.stop_scheduler()
  1237. notification_service.stop_digest_scheduler()
  1238. stop_ams_history_recording()
  1239. printer_manager.disconnect_all()
  1240. await close_spoolman_client()
  1241. app = FastAPI(
  1242. title=app_settings.app_name,
  1243. description="Archive and manage Bambu Lab 3MF files",
  1244. version=APP_VERSION,
  1245. lifespan=lifespan,
  1246. )
  1247. # API routes
  1248. app.include_router(printers.router, prefix=app_settings.api_prefix)
  1249. app.include_router(archives.router, prefix=app_settings.api_prefix)
  1250. app.include_router(filaments.router, prefix=app_settings.api_prefix)
  1251. app.include_router(settings_routes.router, prefix=app_settings.api_prefix)
  1252. app.include_router(cloud.router, prefix=app_settings.api_prefix)
  1253. app.include_router(smart_plugs.router, prefix=app_settings.api_prefix)
  1254. app.include_router(print_queue.router, prefix=app_settings.api_prefix)
  1255. app.include_router(kprofiles.router, prefix=app_settings.api_prefix)
  1256. app.include_router(notifications.router, prefix=app_settings.api_prefix)
  1257. app.include_router(notification_templates.router, prefix=app_settings.api_prefix)
  1258. app.include_router(spoolman.router, prefix=app_settings.api_prefix)
  1259. app.include_router(updates.router, prefix=app_settings.api_prefix)
  1260. app.include_router(maintenance.router, prefix=app_settings.api_prefix)
  1261. app.include_router(camera.router, prefix=app_settings.api_prefix)
  1262. app.include_router(external_links.router, prefix=app_settings.api_prefix)
  1263. app.include_router(projects.router, prefix=app_settings.api_prefix)
  1264. app.include_router(api_keys.router, prefix=app_settings.api_prefix)
  1265. app.include_router(webhook.router, prefix=app_settings.api_prefix)
  1266. app.include_router(ams_history.router, prefix=app_settings.api_prefix)
  1267. app.include_router(system.router, prefix=app_settings.api_prefix)
  1268. app.include_router(websocket.router, prefix=app_settings.api_prefix)
  1269. # Serve static files (React build)
  1270. if app_settings.static_dir.exists() and any(app_settings.static_dir.iterdir()):
  1271. app.mount(
  1272. "/assets",
  1273. StaticFiles(directory=app_settings.static_dir / "assets"),
  1274. name="assets",
  1275. )
  1276. if (app_settings.static_dir / "img").exists():
  1277. app.mount(
  1278. "/img",
  1279. StaticFiles(directory=app_settings.static_dir / "img"),
  1280. name="img",
  1281. )
  1282. if (app_settings.static_dir / "icons").exists():
  1283. app.mount(
  1284. "/icons",
  1285. StaticFiles(directory=app_settings.static_dir / "icons"),
  1286. name="icons",
  1287. )
  1288. @app.get("/")
  1289. async def serve_frontend():
  1290. """Serve the React frontend."""
  1291. index_file = app_settings.static_dir / "index.html"
  1292. if index_file.exists():
  1293. return FileResponse(index_file)
  1294. return {
  1295. "message": "Bambuddy API",
  1296. "docs": "/docs",
  1297. "frontend": "Build and place React app in /static directory",
  1298. }
  1299. @app.get("/health")
  1300. async def health_check():
  1301. """Health check endpoint."""
  1302. return {"status": "healthy"}
  1303. @app.get("/manifest.json")
  1304. async def serve_manifest():
  1305. """Serve PWA manifest."""
  1306. manifest_file = app_settings.static_dir / "manifest.json"
  1307. if manifest_file.exists():
  1308. return FileResponse(manifest_file, media_type="application/manifest+json")
  1309. return {"error": "Manifest not found"}
  1310. @app.get("/sw.js")
  1311. async def serve_service_worker():
  1312. """Serve service worker."""
  1313. sw_file = app_settings.static_dir / "sw.js"
  1314. if sw_file.exists():
  1315. return FileResponse(sw_file, media_type="application/javascript")
  1316. return {"error": "Service worker not found"}
  1317. # Catch-all route for React Router (must be last)
  1318. @app.get("/{full_path:path}")
  1319. async def serve_spa(full_path: str):
  1320. """Serve React app for client-side routing."""
  1321. # Don't intercept API routes
  1322. if full_path.startswith("api/"):
  1323. return {"error": "Not found"}
  1324. index_file = app_settings.static_dir / "index.html"
  1325. if index_file.exists():
  1326. return FileResponse(index_file)
  1327. return {"error": "Frontend not built"}