main.py 115 KB

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798991001011021031041051061071081091101111121131141151161171181191201211221231241251261271281291301311321331341351361371381391401411421431441451461471481491501511521531541551561571581591601611621631641651661671681691701711721731741751761771781791801811821831841851861871881891901911921931941951961971981992002012022032042052062072082092102112122132142152162172182192202212222232242252262272282292302312322332342352362372382392402412422432442452462472482492502512522532542552562572582592602612622632642652662672682692702712722732742752762772782792802812822832842852862872882892902912922932942952962972982993003013023033043053063073083093103113123133143153163173183193203213223233243253263273283293303313323333343353363373383393403413423433443453463473483493503513523533543553563573583593603613623633643653663673683693703713723733743753763773783793803813823833843853863873883893903913923933943953963973983994004014024034044054064074084094104114124134144154164174184194204214224234244254264274284294304314324334344354364374384394404414424434444454464474484494504514524534544554564574584594604614624634644654664674684694704714724734744754764774784794804814824834844854864874884894904914924934944954964974984995005015025035045055065075085095105115125135145155165175185195205215225235245255265275285295305315325335345355365375385395405415425435445455465475485495505515525535545555565575585595605615625635645655665675685695705715725735745755765775785795805815825835845855865875885895905915925935945955965975985996006016026036046056066076086096106116126136146156166176186196206216226236246256266276286296306316326336346356366376386396406416426436446456466476486496506516526536546556566576586596606616626636646656666676686696706716726736746756766776786796806816826836846856866876886896906916926936946956966976986997007017027037047057067077087097107117127137147157167177187197207217227237247257267277287297307317327337347357367377387397407417427437447457467477487497507517527537547557567577587597607617627637647657667677687697707717727737747757767777787797807817827837847857867877887897907917927937947957967977987998008018028038048058068078088098108118128138148158168178188198208218228238248258268278288298308318328338348358368378388398408418428438448458468478488498508518528538548558568578588598608618628638648658668678688698708718728738748758768778788798808818828838848858868878888898908918928938948958968978988999009019029039049059069079089099109119129139149159169179189199209219229239249259269279289299309319329339349359369379389399409419429439449459469479489499509519529539549559569579589599609619629639649659669679689699709719729739749759769779789799809819829839849859869879889899909919929939949959969979989991000100110021003100410051006100710081009101010111012101310141015101610171018101910201021102210231024102510261027102810291030103110321033103410351036103710381039104010411042104310441045104610471048104910501051105210531054105510561057105810591060106110621063106410651066106710681069107010711072107310741075107610771078107910801081108210831084108510861087108810891090109110921093109410951096109710981099110011011102110311041105110611071108110911101111111211131114111511161117111811191120112111221123112411251126112711281129113011311132113311341135113611371138113911401141114211431144114511461147114811491150115111521153115411551156115711581159116011611162116311641165116611671168116911701171117211731174117511761177117811791180118111821183118411851186118711881189119011911192119311941195119611971198119912001201120212031204120512061207120812091210121112121213121412151216121712181219122012211222122312241225122612271228122912301231123212331234123512361237123812391240124112421243124412451246124712481249125012511252125312541255125612571258125912601261126212631264126512661267126812691270127112721273127412751276127712781279128012811282128312841285128612871288128912901291129212931294129512961297129812991300130113021303130413051306130713081309131013111312131313141315131613171318131913201321132213231324132513261327132813291330133113321333133413351336133713381339134013411342134313441345134613471348134913501351135213531354135513561357135813591360136113621363136413651366136713681369137013711372137313741375137613771378137913801381138213831384138513861387138813891390139113921393139413951396139713981399140014011402140314041405140614071408140914101411141214131414141514161417141814191420142114221423142414251426142714281429143014311432143314341435143614371438143914401441144214431444144514461447144814491450145114521453145414551456145714581459146014611462146314641465146614671468146914701471147214731474147514761477147814791480148114821483148414851486148714881489149014911492149314941495149614971498149915001501150215031504150515061507150815091510151115121513151415151516151715181519152015211522152315241525152615271528152915301531153215331534153515361537153815391540154115421543154415451546154715481549155015511552155315541555155615571558155915601561156215631564156515661567156815691570157115721573157415751576157715781579158015811582158315841585158615871588158915901591159215931594159515961597159815991600160116021603160416051606160716081609161016111612161316141615161616171618161916201621162216231624162516261627162816291630163116321633163416351636163716381639164016411642164316441645164616471648164916501651165216531654165516561657165816591660166116621663166416651666166716681669167016711672167316741675167616771678167916801681168216831684168516861687168816891690169116921693169416951696169716981699170017011702170317041705170617071708170917101711171217131714171517161717171817191720172117221723172417251726172717281729173017311732173317341735173617371738173917401741174217431744174517461747174817491750175117521753175417551756175717581759176017611762176317641765176617671768176917701771177217731774177517761777177817791780178117821783178417851786178717881789179017911792179317941795179617971798179918001801180218031804180518061807180818091810181118121813181418151816181718181819182018211822182318241825182618271828182918301831183218331834183518361837183818391840184118421843184418451846184718481849185018511852185318541855185618571858185918601861186218631864186518661867186818691870187118721873187418751876187718781879188018811882188318841885188618871888188918901891189218931894189518961897189818991900190119021903190419051906190719081909191019111912191319141915191619171918191919201921192219231924192519261927192819291930193119321933193419351936193719381939194019411942194319441945194619471948194919501951195219531954195519561957195819591960196119621963196419651966196719681969197019711972197319741975197619771978197919801981198219831984198519861987198819891990199119921993199419951996199719981999200020012002200320042005200620072008200920102011201220132014201520162017201820192020202120222023202420252026202720282029203020312032203320342035203620372038203920402041204220432044204520462047204820492050205120522053205420552056205720582059206020612062206320642065206620672068206920702071207220732074207520762077207820792080208120822083208420852086208720882089209020912092209320942095209620972098209921002101210221032104210521062107210821092110211121122113211421152116211721182119212021212122212321242125212621272128212921302131213221332134213521362137213821392140214121422143214421452146214721482149215021512152215321542155215621572158215921602161216221632164216521662167216821692170217121722173217421752176217721782179218021812182218321842185218621872188218921902191219221932194219521962197219821992200220122022203220422052206220722082209221022112212221322142215221622172218221922202221222222232224222522262227222822292230223122322233223422352236223722382239224022412242224322442245224622472248224922502251225222532254225522562257225822592260226122622263226422652266226722682269227022712272227322742275227622772278227922802281228222832284228522862287228822892290229122922293229422952296229722982299230023012302230323042305230623072308230923102311231223132314231523162317231823192320232123222323232423252326232723282329233023312332233323342335233623372338233923402341234223432344234523462347234823492350235123522353235423552356235723582359236023612362236323642365236623672368236923702371237223732374237523762377237823792380238123822383238423852386238723882389239023912392239323942395239623972398239924002401240224032404240524062407240824092410241124122413241424152416241724182419242024212422242324242425242624272428242924302431243224332434243524362437243824392440244124422443244424452446244724482449245024512452245324542455245624572458245924602461246224632464246524662467246824692470247124722473247424752476247724782479248024812482248324842485248624872488248924902491249224932494249524962497249824992500250125022503250425052506250725082509251025112512251325142515251625172518251925202521252225232524252525262527252825292530253125322533253425352536253725382539254025412542254325442545
  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. # =============================================================================
  7. # Dependency Check - runs before other imports to give helpful error messages
  8. # =============================================================================
  9. def _start_error_server(missing_packages: list):
  10. """Start a minimal HTTP server to display dependency errors in browser."""
  11. import os
  12. import signal
  13. from http.server import BaseHTTPRequestHandler, HTTPServer
  14. packages_html = "".join(f"<li><code>{p}</code></li>" for p in missing_packages)
  15. html = f"""<!DOCTYPE html>
  16. <html>
  17. <head>
  18. <title>Bambuddy - Setup Required</title>
  19. <style>
  20. body {{
  21. font-family: -apple-system, BlinkMacSystemFont, 'Segoe UI', Roboto, sans-serif;
  22. background: #0f172a; color: #e2e8f0;
  23. display: flex; justify-content: center; align-items: center;
  24. min-height: 100vh; margin: 0; padding: 20px; box-sizing: border-box;
  25. }}
  26. .container {{
  27. background: #1e293b; border-radius: 12px; padding: 40px;
  28. max-width: 600px; text-align: center; box-shadow: 0 4px 20px rgba(0,0,0,0.3);
  29. }}
  30. h1 {{ color: #f87171; margin-bottom: 10px; }}
  31. h2 {{ color: #94a3b8; font-weight: normal; margin-top: 0; }}
  32. .packages {{
  33. background: #0f172a; border-radius: 8px; padding: 20px;
  34. margin: 20px 0; text-align: left;
  35. }}
  36. .packages ul {{ margin: 0; padding-left: 20px; }}
  37. .packages li {{ color: #fbbf24; margin: 8px 0; }}
  38. .command {{
  39. background: #0f172a; border-radius: 8px; padding: 15px 20px;
  40. margin: 15px 0; font-family: monospace; color: #4ade80;
  41. text-align: left; overflow-x: auto;
  42. }}
  43. .note {{ color: #94a3b8; font-size: 14px; margin-top: 20px; }}
  44. </style>
  45. </head>
  46. <body>
  47. <div class="container">
  48. <h1>Setup Required</h1>
  49. <h2>Missing Python packages</h2>
  50. <div class="packages"><ul>{packages_html}</ul></div>
  51. <p>To fix, run this command on your server:</p>
  52. <div class="command">pip install -r requirements.txt</div>
  53. <p>Or if using a virtual environment:</p>
  54. <div class="command">./venv/bin/pip install -r requirements.txt</div>
  55. <p class="note">After installing, restart Bambuddy:<br>
  56. <code>sudo systemctl restart bambuddy</code></p>
  57. </div>
  58. </body>
  59. </html>"""
  60. class ErrorHandler(BaseHTTPRequestHandler):
  61. def do_GET(self):
  62. self.send_response(503)
  63. self.send_header("Content-type", "text/html")
  64. self.end_headers()
  65. self.wfile.write(html.encode())
  66. def log_message(self, format, *args):
  67. print(f"[Error Server] {args[0]}")
  68. port = int(os.environ.get("PORT", 8000))
  69. print(f"\nStarting error server on http://0.0.0.0:{port}")
  70. print("Visit this URL in your browser to see the error details.\n")
  71. server = HTTPServer(("0.0.0.0", port), ErrorHandler)
  72. def shutdown(signum, frame):
  73. print("\nShutting down error server...")
  74. raise SystemExit(0)
  75. signal.signal(signal.SIGTERM, shutdown)
  76. signal.signal(signal.SIGINT, shutdown)
  77. server.serve_forever()
  78. def check_dependencies():
  79. """Check that all required packages are installed."""
  80. missing = []
  81. # Map of import name -> package name (for pip install)
  82. required = {
  83. "jwt": "PyJWT",
  84. "fastapi": "fastapi",
  85. "uvicorn": "uvicorn",
  86. "sqlalchemy": "sqlalchemy",
  87. "aiosqlite": "aiosqlite",
  88. "pydantic": "pydantic",
  89. "paho.mqtt": "paho-mqtt",
  90. }
  91. for module, package in required.items():
  92. try:
  93. __import__(module)
  94. except ImportError:
  95. missing.append(package)
  96. if missing:
  97. print("\n" + "=" * 60)
  98. print("ERROR: Missing required Python packages!")
  99. print("=" * 60)
  100. print(f"\nMissing packages: {', '.join(missing)}")
  101. print("\nTo fix, run:")
  102. print(" pip install -r requirements.txt")
  103. print("\nOr if using a virtual environment:")
  104. print(" ./venv/bin/pip install -r requirements.txt")
  105. print("=" * 60 + "\n")
  106. _start_error_server(missing)
  107. check_dependencies()
  108. # =============================================================================
  109. from fastapi import FastAPI
  110. # Import settings first for logging configuration
  111. from backend.app.core.config import APP_VERSION, settings as app_settings
  112. # Configure logging based on settings
  113. # DEBUG=true -> DEBUG level, else use LOG_LEVEL setting
  114. log_level_str = "DEBUG" if app_settings.debug else app_settings.log_level.upper()
  115. log_level = getattr(logging, log_level_str, logging.INFO)
  116. log_format = "%(asctime)s %(levelname)s [%(name)s] %(message)s"
  117. # Create root logger
  118. root_logger = logging.getLogger()
  119. root_logger.setLevel(log_level)
  120. # Console handler - always enabled
  121. console_handler = logging.StreamHandler()
  122. console_handler.setLevel(log_level)
  123. console_handler.setFormatter(logging.Formatter(log_format))
  124. root_logger.addHandler(console_handler)
  125. # File handler - only in production or if explicitly enabled
  126. if app_settings.log_to_file:
  127. log_file = app_settings.log_dir / "bambuddy.log"
  128. file_handler = RotatingFileHandler(
  129. log_file,
  130. maxBytes=5 * 1024 * 1024, # 5MB
  131. backupCount=3,
  132. encoding="utf-8",
  133. )
  134. file_handler.setLevel(log_level)
  135. file_handler.setFormatter(logging.Formatter(log_format))
  136. root_logger.addHandler(file_handler)
  137. logging.info(f"Logging to file: {log_file}")
  138. # Reduce noise from third-party libraries in production
  139. if not app_settings.debug:
  140. logging.getLogger("sqlalchemy.engine").setLevel(logging.WARNING)
  141. logging.getLogger("httpcore").setLevel(logging.WARNING)
  142. logging.getLogger("httpx").setLevel(logging.WARNING)
  143. logging.info(f"Bambuddy starting - debug={app_settings.debug}, log_level={log_level_str}")
  144. from fastapi.responses import FileResponse
  145. from fastapi.staticfiles import StaticFiles
  146. from sqlalchemy import delete, or_, select
  147. from backend.app.api.routes import (
  148. ams_history,
  149. api_keys,
  150. archives,
  151. auth,
  152. camera,
  153. cloud,
  154. discovery,
  155. external_links,
  156. filaments,
  157. firmware,
  158. kprofiles,
  159. library,
  160. maintenance,
  161. notification_templates,
  162. notifications,
  163. pending_uploads,
  164. print_queue,
  165. printers,
  166. projects,
  167. settings as settings_routes,
  168. smart_plugs,
  169. spoolman,
  170. support,
  171. system,
  172. updates,
  173. users,
  174. webhook,
  175. websocket,
  176. )
  177. from backend.app.api.routes.maintenance import _get_printer_maintenance_internal, ensure_default_types
  178. from backend.app.api.routes.support import init_debug_logging
  179. from backend.app.core.database import async_session, init_db
  180. from backend.app.core.websocket import ws_manager
  181. from backend.app.models.smart_plug import SmartPlug
  182. from backend.app.services.archive import ArchiveService
  183. from backend.app.services.bambu_ftp import download_file_async, get_ftp_retry_settings, with_ftp_retry
  184. from backend.app.services.bambu_mqtt import PrinterState
  185. from backend.app.services.homeassistant import homeassistant_service
  186. from backend.app.services.mqtt_relay import mqtt_relay
  187. from backend.app.services.notification_service import notification_service
  188. from backend.app.services.print_scheduler import scheduler as print_scheduler
  189. from backend.app.services.printer_manager import (
  190. init_printer_connections,
  191. printer_manager,
  192. printer_state_to_dict,
  193. )
  194. from backend.app.services.smart_plug_manager import smart_plug_manager
  195. from backend.app.services.spoolman import close_spoolman_client, get_spoolman_client, init_spoolman_client
  196. from backend.app.services.tasmota import tasmota_service
  197. # Track active prints: {(printer_id, filename): archive_id}
  198. _active_prints: dict[tuple[int, str], int] = {}
  199. # Track expected prints from reprint/scheduled (skip auto-archiving for these)
  200. # {(printer_id, filename): archive_id}
  201. _expected_prints: dict[tuple[int, str], int] = {}
  202. # Track starting energy for prints: {archive_id: starting_kwh}
  203. _print_energy_start: dict[int, float] = {}
  204. # Track reprints to add costs on completion: {archive_id}
  205. _reprint_archives: set[int] = set()
  206. # Track progress milestones for notifications: {printer_id: last_milestone_notified}
  207. # Milestones are 25, 50, 75. Value of 0 means no milestone notified yet for current print.
  208. _last_progress_milestone: dict[int, int] = {}
  209. # Track HMS errors that have been notified: {printer_id: set of error codes}
  210. # This prevents sending duplicate notifications for the same error
  211. _notified_hms_errors: dict[int, set[str]] = {}
  212. async def _get_plug_energy(plug, db) -> dict | None:
  213. """Get energy from plug regardless of type (Tasmota or Home Assistant).
  214. For HA plugs, configures the service with current settings from DB.
  215. """
  216. if plug.plug_type == "homeassistant":
  217. from backend.app.api.routes.settings import get_setting
  218. ha_url = await get_setting(db, "ha_url") or ""
  219. ha_token = await get_setting(db, "ha_token") or ""
  220. homeassistant_service.configure(ha_url, ha_token)
  221. return await homeassistant_service.get_energy(plug)
  222. else:
  223. return await tasmota_service.get_energy(plug)
  224. def register_expected_print(printer_id: int, filename: str, archive_id: int):
  225. """Register an expected print from reprint/scheduled so we don't create duplicate archives."""
  226. # Store with multiple filename variations to catch different naming patterns
  227. _expected_prints[(printer_id, filename)] = archive_id
  228. # Also store without .3mf extension if present
  229. if filename.endswith(".3mf"):
  230. base = filename[:-4]
  231. _expected_prints[(printer_id, base)] = archive_id
  232. _expected_prints[(printer_id, f"{base}.gcode")] = archive_id
  233. logging.getLogger(__name__).info(
  234. f"Registered expected print: printer={printer_id}, file={filename}, archive={archive_id}"
  235. )
  236. _last_status_broadcast: dict[int, str] = {}
  237. _nozzle_count_updated: set[int] = set() # Track printers where we've updated nozzle_count
  238. async def _report_spoolman_usage(printer_id: int, archive_id: int, logger):
  239. """Report filament usage to Spoolman after print completion.
  240. This finds the spool by RFID tag_uid from current AMS state and reports
  241. the filament_used_grams from the archive metadata.
  242. """
  243. async with async_session() as db:
  244. from backend.app.api.routes.settings import get_setting
  245. from backend.app.models.archive import PrintArchive
  246. # Check if Spoolman is enabled
  247. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  248. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  249. return
  250. # Get Spoolman URL
  251. spoolman_url = await get_setting(db, "spoolman_url")
  252. if not spoolman_url:
  253. return
  254. # Get or create Spoolman client
  255. client = await get_spoolman_client()
  256. if not client:
  257. client = await init_spoolman_client(spoolman_url)
  258. # Check if Spoolman is reachable
  259. if not await client.health_check():
  260. logger.warning("Spoolman not reachable for usage reporting")
  261. return
  262. # Get archive to find filament usage
  263. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  264. archive = result.scalar_one_or_none()
  265. if not archive or not archive.filament_used_grams:
  266. logger.debug(f"No filament usage data for archive {archive_id}")
  267. return
  268. filament_used = archive.filament_used_grams
  269. logger.info(f"[SPOOLMAN] Archive {archive_id} used {filament_used}g of filament")
  270. # Get current AMS state from printer to find the active spool
  271. state = printer_manager.get_status(printer_id)
  272. if not state or not state.raw_data:
  273. logger.debug("No printer state available for usage reporting")
  274. return
  275. ams_data = state.raw_data.get("ams")
  276. if not ams_data:
  277. logger.debug("No AMS data available for usage reporting")
  278. return
  279. # Find spools with RFID tags in Spoolman and report usage
  280. # For now, we report usage to the first spool found with a matching tag
  281. # TODO: In future, track which specific trays were used during the print
  282. spools_updated = 0
  283. for ams_unit in ams_data:
  284. trays = ams_unit.get("tray", [])
  285. for tray_data in trays:
  286. tag_uid = tray_data.get("tag_uid")
  287. if not tag_uid:
  288. continue
  289. # Find spool in Spoolman by tag
  290. spool = await client.find_spool_by_tag(tag_uid)
  291. if spool:
  292. # Report usage to Spoolman
  293. result = await client.use_spool(spool["id"], filament_used)
  294. if result:
  295. logger.info(
  296. f"[SPOOLMAN] Reported {filament_used}g usage to spool {spool['id']} (tag: {tag_uid})"
  297. )
  298. spools_updated += 1
  299. # Only report to one spool for single-material prints
  300. # Multi-material prints would need more sophisticated tracking
  301. return
  302. if spools_updated == 0:
  303. logger.debug(f"No matching Spoolman spools found for printer {printer_id}")
  304. async def on_printer_status_change(printer_id: int, state: PrinterState):
  305. """Handle printer status changes - broadcast via WebSocket."""
  306. # Only broadcast if something meaningful changed (reduce WebSocket spam)
  307. # Include rounded temperatures to detect meaningful temp changes (within 1 degree)
  308. temps = state.temperatures or {}
  309. nozzle_temp = round(temps.get("nozzle", 0))
  310. bed_temp = round(temps.get("bed", 0))
  311. nozzle_2_temp = round(temps.get("nozzle_2", 0)) if "nozzle_2" in temps else ""
  312. chamber_temp = round(temps.get("chamber", 0)) if "chamber" in temps else ""
  313. # Auto-detect dual-nozzle printers from MQTT temperature data
  314. if "nozzle_2" in temps and printer_id not in _nozzle_count_updated:
  315. _nozzle_count_updated.add(printer_id)
  316. # Update nozzle_count in database
  317. async with async_session() as db:
  318. from backend.app.models.printer import Printer
  319. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  320. printer = result.scalar_one_or_none()
  321. if printer and printer.nozzle_count != 2:
  322. printer.nozzle_count = 2
  323. await db.commit()
  324. logging.getLogger(__name__).info(
  325. f"Auto-detected dual-nozzle printer {printer_id}, updated nozzle_count=2"
  326. )
  327. # Include target temps for heating phase detection
  328. bed_target = round(temps.get("bed_target", 0))
  329. nozzle_target = round(temps.get("nozzle_target", 0))
  330. status_key = (
  331. f"{state.connected}:{state.state}:{state.progress}:{state.layer_num}:"
  332. f"{nozzle_temp}:{bed_temp}:{nozzle_2_temp}:{chamber_temp}:"
  333. f"{state.stg_cur}:{bed_target}:{nozzle_target}:"
  334. f"{state.cooling_fan_speed}:{state.big_fan1_speed}:{state.big_fan2_speed}:"
  335. f"{state.chamber_light}:{state.active_extruder}"
  336. )
  337. # MQTT relay - publish status (before dedup check - always publish to MQTT)
  338. try:
  339. printer_info = printer_manager.get_printer(printer_id)
  340. if printer_info:
  341. await mqtt_relay.on_printer_status(printer_id, state, printer_info.name, printer_info.serial_number)
  342. except Exception:
  343. pass # Don't fail status callback if MQTT fails
  344. if _last_status_broadcast.get(printer_id) == status_key:
  345. return # No change, skip WebSocket broadcast
  346. _last_status_broadcast[printer_id] = status_key
  347. # Check for progress milestone notifications (25%, 50%, 75%)
  348. progress = state.progress or 0
  349. is_printing = state.state in ("RUNNING", "PRINTING")
  350. if is_printing and progress > 0:
  351. # Determine which milestone we've reached
  352. current_milestone = 0
  353. if progress >= 75:
  354. current_milestone = 75
  355. elif progress >= 50:
  356. current_milestone = 50
  357. elif progress >= 25:
  358. current_milestone = 25
  359. last_milestone = _last_progress_milestone.get(printer_id, 0)
  360. # If we've crossed a new milestone, send notification
  361. if current_milestone > last_milestone:
  362. _last_progress_milestone[printer_id] = current_milestone
  363. try:
  364. async with async_session() as db:
  365. from backend.app.models.printer import Printer
  366. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  367. printer = result.scalar_one_or_none()
  368. printer_name = printer.name if printer else f"Printer {printer_id}"
  369. filename = state.subtask_name or state.gcode_file or "Unknown"
  370. # remaining_time is in minutes, convert to seconds for notification
  371. remaining_time_seconds = state.remaining_time * 60 if state.remaining_time else None
  372. await notification_service.on_print_progress(
  373. printer_id, printer_name, filename, current_milestone, db, remaining_time_seconds
  374. )
  375. except Exception as e:
  376. logging.getLogger(__name__).warning(f"Progress milestone notification failed: {e}")
  377. elif progress < 5:
  378. # Reset milestone tracking when print restarts or new print begins
  379. _last_progress_milestone[printer_id] = 0
  380. # Check for new HMS errors and send notifications
  381. current_hms_errors = getattr(state, "hms_errors", []) or []
  382. if current_hms_errors:
  383. # Build set of current error codes (using attr for uniqueness)
  384. current_error_codes = {f"{e.attr:08x}" for e in current_hms_errors}
  385. previously_notified = _notified_hms_errors.get(printer_id, set())
  386. # Find new errors that haven't been notified yet
  387. new_error_codes = current_error_codes - previously_notified
  388. if new_error_codes:
  389. # Get the actual new errors for the notification
  390. new_errors = [e for e in current_hms_errors if f"{e.attr:08x}" in new_error_codes]
  391. try:
  392. async with async_session() as db:
  393. from backend.app.models.printer import Printer
  394. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  395. printer = result.scalar_one_or_none()
  396. printer_name = printer.name if printer else f"Printer {printer_id}"
  397. # Format error details for notification
  398. # Module 0x07 = AMS/Filament, 0x05 = Nozzle, 0x0C = Motion Controller, etc.
  399. module_names = {
  400. 0x03: "Print/Task",
  401. 0x05: "Nozzle/Extruder",
  402. 0x07: "AMS/Filament",
  403. 0x0C: "Motion Controller",
  404. 0x12: "Chamber",
  405. }
  406. from backend.app.services.hms_errors import get_error_description
  407. for error in new_errors:
  408. module_name = module_names.get(error.module, f"Module 0x{error.module:02X}")
  409. # Build short code like "0700_8010"
  410. error_code_int = int(error.code.replace("0x", ""), 16) if error.code else 0
  411. short_code = f"{(error.attr >> 16) & 0xFFFF:04X}_{error_code_int:04X}"
  412. error_type = f"{module_name} Error"
  413. # Look up human-readable description
  414. description = get_error_description(short_code)
  415. error_detail = description if description else f"Error code: {short_code}"
  416. await notification_service.on_printer_error(
  417. printer_id, printer_name, error_type, db, error_detail
  418. )
  419. logging.getLogger(__name__).info(
  420. f"[HMS] Sent notification for {len(new_errors)} new error(s) on printer {printer_id}"
  421. )
  422. # Also publish to MQTT relay
  423. printer_info = printer_manager.get_printer(printer_id)
  424. if printer_info:
  425. errors_data = [
  426. {
  427. "code": e.code,
  428. "attr": e.attr,
  429. "module": e.module,
  430. "severity": e.severity,
  431. }
  432. for e in new_errors
  433. ]
  434. await mqtt_relay.on_printer_error(
  435. printer_id, printer_info.name, printer_info.serial_number, errors_data
  436. )
  437. except Exception as e:
  438. logging.getLogger(__name__).warning(f"HMS error notification failed: {e}")
  439. # Update tracking with all current errors
  440. _notified_hms_errors[printer_id] = current_error_codes
  441. else:
  442. # No HMS errors - clear tracking so future errors get notified
  443. if printer_id in _notified_hms_errors:
  444. _notified_hms_errors.pop(printer_id, None)
  445. await ws_manager.send_printer_status(
  446. printer_id,
  447. printer_state_to_dict(state, printer_id, printer_manager.get_model(printer_id)),
  448. )
  449. async def on_ams_change(printer_id: int, ams_data: list):
  450. """Handle AMS data changes - sync to Spoolman if enabled and auto mode."""
  451. import logging
  452. logger = logging.getLogger(__name__)
  453. # MQTT relay - publish AMS change
  454. try:
  455. printer_info = printer_manager.get_printer(printer_id)
  456. if printer_info:
  457. await mqtt_relay.on_ams_change(printer_id, printer_info.name, printer_info.serial_number, ams_data)
  458. except Exception:
  459. pass # Don't fail AMS callback if MQTT fails
  460. # Broadcast AMS change via WebSocket (bypasses status_key deduplication)
  461. # This ensures frontend gets immediate updates when AMS slots are configured
  462. try:
  463. state = printer_manager.get_status(printer_id)
  464. if state:
  465. logger.info(f"[Printer {printer_id}] Broadcasting AMS change via WebSocket")
  466. await ws_manager.send_printer_status(
  467. printer_id,
  468. printer_state_to_dict(state, printer_id, printer_manager.get_model(printer_id)),
  469. )
  470. except Exception as e:
  471. logger.warning(f"Failed to broadcast AMS change for printer {printer_id}: {e}")
  472. try:
  473. async with async_session() as db:
  474. from backend.app.api.routes.settings import get_setting
  475. from backend.app.models.printer import Printer
  476. # Check if Spoolman is enabled
  477. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  478. if not spoolman_enabled or spoolman_enabled.lower() != "true":
  479. return
  480. # Check sync mode
  481. sync_mode = await get_setting(db, "spoolman_sync_mode")
  482. if sync_mode and sync_mode != "auto":
  483. return # Only sync on auto mode
  484. # Get Spoolman URL
  485. spoolman_url = await get_setting(db, "spoolman_url")
  486. if not spoolman_url:
  487. return
  488. # Get or create Spoolman client
  489. client = await get_spoolman_client()
  490. if not client:
  491. client = await init_spoolman_client(spoolman_url)
  492. # Check if Spoolman is reachable
  493. if not await client.health_check():
  494. logger.warning(f"Spoolman not reachable at {spoolman_url}")
  495. return
  496. # Get printer name for location
  497. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  498. printer = result.scalar_one_or_none()
  499. printer_name = printer.name if printer else f"Printer {printer_id}"
  500. # Sync each AMS tray
  501. synced = 0
  502. for ams_unit in ams_data:
  503. ams_id = int(ams_unit.get("id", 0))
  504. trays = ams_unit.get("tray", [])
  505. for tray_data in trays:
  506. tray = client.parse_ams_tray(ams_id, tray_data)
  507. if not tray:
  508. continue # Empty tray
  509. try:
  510. result = await client.sync_ams_tray(tray, printer_name)
  511. if result:
  512. synced += 1
  513. except Exception as e:
  514. logger.error(f"Error syncing AMS {ams_id} tray {tray.tray_id}: {e}")
  515. if synced > 0:
  516. logger.info(f"Auto-synced {synced} AMS trays to Spoolman for printer {printer_id}")
  517. except Exception as e:
  518. import logging
  519. logging.getLogger(__name__).warning(f"Spoolman AMS sync failed: {e}")
  520. async def _send_print_start_notification(
  521. printer_id: int,
  522. data: dict,
  523. archive_data: dict | None = None,
  524. logger=None,
  525. ):
  526. """Helper to send print start notification with optional archive data."""
  527. if logger is None:
  528. import logging
  529. logger = logging.getLogger(__name__)
  530. try:
  531. async with async_session() as db:
  532. from backend.app.models.printer import Printer
  533. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  534. printer = result.scalar_one_or_none()
  535. printer_name = printer.name if printer else f"Printer {printer_id}"
  536. await notification_service.on_print_start(printer_id, printer_name, data, db, archive_data=archive_data)
  537. except Exception as e:
  538. logger.warning(f"Notification on_print_start failed: {e}")
  539. def _load_objects_from_archive(archive, printer_id: int, logger) -> None:
  540. """Extract printable objects from an archive's 3MF file and store in printer state."""
  541. try:
  542. from backend.app.services.archive import extract_printable_objects_from_3mf
  543. file_path = app_settings.base_dir / archive.file_path
  544. if file_path.exists() and str(file_path).endswith(".3mf"):
  545. with open(file_path, "rb") as f:
  546. threemf_data = f.read()
  547. # Extract with positions for UI overlay
  548. printable_objects, bbox_all = extract_printable_objects_from_3mf(threemf_data, include_positions=True)
  549. if printable_objects:
  550. client = printer_manager.get_client(printer_id)
  551. if client:
  552. client.state.printable_objects = printable_objects
  553. client.state.printable_objects_bbox_all = bbox_all
  554. client.state.skipped_objects = []
  555. logger.info(f"Loaded {len(printable_objects)} printable objects for printer {printer_id}")
  556. except Exception as e:
  557. logger.debug(f"Failed to extract printable objects from archive: {e}")
  558. async def on_print_start(printer_id: int, data: dict):
  559. """Handle print start - archive the 3MF file immediately."""
  560. import logging
  561. logger = logging.getLogger(__name__)
  562. logger.info(f"[CALLBACK] on_print_start called for printer {printer_id}, data keys: {list(data.keys())}")
  563. await ws_manager.send_print_start(printer_id, data)
  564. # MQTT relay - publish print start
  565. try:
  566. printer_info = printer_manager.get_printer(printer_id)
  567. if printer_info:
  568. await mqtt_relay.on_print_start(
  569. printer_id,
  570. printer_info.name,
  571. printer_info.serial_number,
  572. data.get("filename", ""),
  573. data.get("subtask_name", ""),
  574. )
  575. except Exception:
  576. pass # Don't fail print start callback if MQTT fails
  577. # Track if notification was sent (to avoid sending twice)
  578. notification_sent = False
  579. # Smart plug automation: turn on plug when print starts
  580. try:
  581. async with async_session() as db:
  582. await smart_plug_manager.on_print_start(printer_id, db)
  583. except Exception as e:
  584. logger.warning(f"Smart plug on_print_start failed: {e}")
  585. async with async_session() as db:
  586. from backend.app.models.printer import Printer
  587. from backend.app.services.bambu_ftp import list_files_async
  588. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  589. printer = result.scalar_one_or_none()
  590. # Plate detection check - pause if objects detected on build plate
  591. if printer and printer.plate_detection_enabled:
  592. try:
  593. from backend.app.services.plate_detection import check_plate_empty
  594. # Build ROI tuple from printer settings if available
  595. roi = None
  596. if all(
  597. [
  598. printer.plate_detection_roi_x is not None,
  599. printer.plate_detection_roi_y is not None,
  600. printer.plate_detection_roi_w is not None,
  601. printer.plate_detection_roi_h is not None,
  602. ]
  603. ):
  604. roi = (
  605. printer.plate_detection_roi_x,
  606. printer.plate_detection_roi_y,
  607. printer.plate_detection_roi_w,
  608. printer.plate_detection_roi_h,
  609. )
  610. logger.info(f"[PLATE CHECK] Running plate detection for printer {printer_id}")
  611. plate_result = await check_plate_empty(
  612. printer_id=printer_id,
  613. ip_address=printer.ip_address,
  614. access_code=printer.access_code,
  615. model=printer.model,
  616. include_debug_image=False,
  617. external_camera_url=printer.external_camera_url,
  618. external_camera_type=printer.external_camera_type,
  619. use_external=printer.external_camera_enabled,
  620. roi=roi,
  621. )
  622. if not plate_result.needs_calibration and not plate_result.is_empty:
  623. # Objects detected - pause the print!
  624. logger.warning(
  625. f"[PLATE CHECK] Objects detected on plate for printer {printer_id}! "
  626. f"Confidence: {plate_result.confidence:.0%}, Diff: {plate_result.difference_percent:.1f}%"
  627. )
  628. client = printer_manager.get_client(printer_id)
  629. if client:
  630. client.pause_print()
  631. logger.info(f"[PLATE CHECK] Print paused for printer {printer_id}")
  632. # Send notification about plate not empty
  633. await ws_manager.broadcast(
  634. {
  635. "type": "plate_not_empty",
  636. "printer_id": printer_id,
  637. "printer_name": printer.name,
  638. "message": f"Objects detected on build plate! Print paused. (Diff: {plate_result.difference_percent:.1f}%)",
  639. }
  640. )
  641. # Also send push notification
  642. try:
  643. await notification_service.on_plate_not_empty(
  644. printer_id=printer_id,
  645. printer_name=printer.name,
  646. db=db,
  647. difference_percent=plate_result.difference_percent,
  648. )
  649. except Exception as notif_err:
  650. logger.warning(f"[PLATE CHECK] Failed to send notification: {notif_err}")
  651. else:
  652. logger.info(f"[PLATE CHECK] Plate is empty for printer {printer_id}, proceeding with print")
  653. except Exception as plate_err:
  654. # Don't block print on plate detection errors
  655. logger.warning(f"[PLATE CHECK] Plate detection failed for printer {printer_id}: {plate_err}")
  656. if not printer or not printer.auto_archive:
  657. # Send notification without archive data (auto-archive disabled)
  658. logger.info(
  659. f"[CALLBACK] Skipping archive - printer: {printer is not None}, auto_archive: {printer.auto_archive if printer else 'N/A'}"
  660. )
  661. if not notification_sent:
  662. await _send_print_start_notification(printer_id, data, logger=logger)
  663. return
  664. # Get the filename and subtask_name
  665. filename = data.get("filename", "")
  666. subtask_name = data.get("subtask_name", "")
  667. logger.info(f"[CALLBACK] Print start detected - filename: {filename}, subtask: {subtask_name}")
  668. if not filename and not subtask_name:
  669. # Send notification without archive data (no filename)
  670. logger.info("[CALLBACK] Skipping archive - no filename or subtask_name")
  671. if not notification_sent:
  672. await _send_print_start_notification(printer_id, data, logger=logger)
  673. return
  674. # Check if this is an expected print from reprint/scheduled
  675. # Build list of possible keys to check
  676. expected_keys = []
  677. if subtask_name:
  678. expected_keys.append((printer_id, subtask_name))
  679. expected_keys.append((printer_id, f"{subtask_name}.3mf"))
  680. expected_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  681. if filename:
  682. fname = filename.split("/")[-1] if "/" in filename else filename
  683. expected_keys.append((printer_id, fname))
  684. # Strip extensions to match
  685. base = fname.replace(".gcode", "").replace(".3mf", "")
  686. expected_keys.append((printer_id, base))
  687. expected_keys.append((printer_id, f"{base}.3mf"))
  688. expected_archive_id = None
  689. for key in expected_keys:
  690. expected_archive_id = _expected_prints.pop(key, None)
  691. if expected_archive_id:
  692. # Clean up other possible keys for this print
  693. for other_key in expected_keys:
  694. _expected_prints.pop(other_key, None)
  695. break
  696. if expected_archive_id:
  697. # This is a reprint/scheduled print - use existing archive, don't create new one
  698. logger.info(f"Using expected archive {expected_archive_id} for print (skipping duplicate)")
  699. from backend.app.models.archive import PrintArchive
  700. result = await db.execute(select(PrintArchive).where(PrintArchive.id == expected_archive_id))
  701. archive = result.scalar_one_or_none()
  702. if archive:
  703. # Update archive status to printing
  704. archive.status = "printing"
  705. archive.started_at = datetime.now()
  706. await db.commit()
  707. # Track as active print
  708. _active_prints[(printer_id, archive.filename)] = archive.id
  709. if subtask_name:
  710. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  711. # Mark as reprint so we add cost on completion
  712. _reprint_archives.add(archive.id)
  713. logger.info(f"Marked archive {archive.id} as reprint for cost addition on completion")
  714. # Set up energy tracking
  715. try:
  716. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  717. plug = plug_result.scalar_one_or_none()
  718. logger.info(
  719. f"[ENERGY] Print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  720. )
  721. if plug:
  722. energy = await _get_plug_energy(plug, db)
  723. logger.info(f"[ENERGY] Energy response from plug: {energy}")
  724. if energy and energy.get("total") is not None:
  725. _print_energy_start[archive.id] = energy["total"]
  726. logger.info(
  727. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  728. )
  729. else:
  730. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  731. else:
  732. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  733. except Exception as e:
  734. logger.warning(f"Failed to record starting energy: {e}")
  735. await ws_manager.send_archive_updated(
  736. {
  737. "id": archive.id,
  738. "status": "printing",
  739. }
  740. )
  741. # Send notification with archive data (reprint/scheduled)
  742. if not notification_sent:
  743. archive_data = {"print_time_seconds": archive.print_time_seconds}
  744. await _send_print_start_notification(printer_id, data, archive_data, logger)
  745. # Extract printable objects from the archived 3MF file
  746. _load_objects_from_archive(archive, printer_id, logger)
  747. return # Skip creating a new archive
  748. # Check if there's already a "printing" archive for this printer/file
  749. # This prevents duplicates when backend restarts during an active print
  750. from backend.app.models.archive import PrintArchive
  751. check_name = subtask_name or filename.split("/")[-1].replace(".gcode", "").replace(".3mf", "")
  752. existing = await db.execute(
  753. select(PrintArchive)
  754. .where(PrintArchive.printer_id == printer_id)
  755. .where(PrintArchive.status == "printing")
  756. .where(PrintArchive.print_name.ilike(f"%{check_name}%"))
  757. .order_by(PrintArchive.created_at.desc())
  758. .limit(1)
  759. )
  760. existing_archive = existing.scalar_one_or_none()
  761. if existing_archive:
  762. # Check if archive is stale (older than 4 hours) - likely a failed/cancelled print
  763. # that didn't get properly updated
  764. archive_age = datetime.now(UTC) - existing_archive.created_at.replace(tzinfo=UTC)
  765. if archive_age.total_seconds() > 4 * 60 * 60: # 4 hours
  766. logger.warning(
  767. f"Found stale 'printing' archive {existing_archive.id} (age: {archive_age}), "
  768. f"marking as cancelled and creating new archive"
  769. )
  770. existing_archive.status = "cancelled"
  771. existing_archive.failure_reason = "Stale - print likely cancelled or failed without status update"
  772. await db.commit()
  773. # Fall through to create new archive (don't return)
  774. existing_archive = None # Clear so we don't use stale archive
  775. else:
  776. logger.info(
  777. f"Skipping duplicate - already have printing archive {existing_archive.id} for {check_name}"
  778. )
  779. # Track this as the active print
  780. _active_prints[(printer_id, existing_archive.filename)] = existing_archive.id
  781. # Also set up energy tracking if not already tracked
  782. if existing_archive.id not in _print_energy_start:
  783. try:
  784. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  785. plug = plug_result.scalar_one_or_none()
  786. if plug:
  787. energy = await _get_plug_energy(plug, db)
  788. if energy and energy.get("total") is not None:
  789. _print_energy_start[existing_archive.id] = energy["total"]
  790. logger.info(
  791. f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh"
  792. )
  793. except Exception as e:
  794. logger.warning(f"Failed to record starting energy for existing archive: {e}")
  795. # Send notification with archive data (existing archive)
  796. if not notification_sent:
  797. archive_data = {"print_time_seconds": existing_archive.print_time_seconds}
  798. await _send_print_start_notification(printer_id, data, archive_data, logger)
  799. # Extract printable objects from the archived 3MF file
  800. _load_objects_from_archive(existing_archive, printer_id, logger)
  801. return
  802. # Build list of possible 3MF filenames to try
  803. possible_names = []
  804. # Bambu printers typically store files as "Name.gcode.3mf"
  805. # The subtask_name is usually the best source for the filename
  806. if subtask_name:
  807. # Try common Bambu naming patterns
  808. possible_names.append(f"{subtask_name}.gcode.3mf")
  809. possible_names.append(f"{subtask_name}.3mf")
  810. # Try original filename with .3mf extension
  811. if filename:
  812. # Extract just the filename part, not the full path
  813. fname = filename.split("/")[-1] if "/" in filename else filename
  814. if fname.endswith(".3mf"):
  815. possible_names.append(fname)
  816. elif fname.endswith(".gcode"):
  817. base = fname.rsplit(".", 1)[0]
  818. possible_names.append(f"{base}.gcode.3mf")
  819. possible_names.append(f"{base}.3mf")
  820. else:
  821. possible_names.append(f"{fname}.gcode.3mf")
  822. possible_names.append(f"{fname}.3mf")
  823. # Remove duplicates while preserving order
  824. seen = set()
  825. possible_names = [x for x in possible_names if not (x in seen or seen.add(x))]
  826. logger.info(f"Trying filenames: {possible_names}")
  827. # Try to find and download the 3MF file
  828. temp_path = None
  829. downloaded_filename = None
  830. # Get FTP retry settings
  831. ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
  832. for try_filename in possible_names:
  833. if not try_filename.endswith(".3mf"):
  834. continue
  835. remote_paths = [
  836. f"/cache/{try_filename}",
  837. f"/model/{try_filename}",
  838. f"/data/{try_filename}",
  839. f"/data/Metadata/{try_filename}",
  840. f"/{try_filename}",
  841. ]
  842. temp_path = app_settings.archive_dir / "temp" / try_filename
  843. temp_path.parent.mkdir(parents=True, exist_ok=True)
  844. for remote_path in remote_paths:
  845. logger.debug(f"Trying FTP download: {remote_path}")
  846. try:
  847. if ftp_retry_enabled:
  848. downloaded = await with_ftp_retry(
  849. download_file_async,
  850. printer.ip_address,
  851. printer.access_code,
  852. remote_path,
  853. temp_path,
  854. socket_timeout=ftp_timeout,
  855. printer_model=printer.model,
  856. max_retries=ftp_retry_count,
  857. retry_delay=ftp_retry_delay,
  858. operation_name=f"Download 3MF from {remote_path}",
  859. )
  860. else:
  861. downloaded = await download_file_async(
  862. printer.ip_address,
  863. printer.access_code,
  864. remote_path,
  865. temp_path,
  866. socket_timeout=ftp_timeout,
  867. printer_model=printer.model,
  868. )
  869. if downloaded:
  870. downloaded_filename = try_filename
  871. logger.info(f"Downloaded: {remote_path}")
  872. break
  873. except Exception as e:
  874. logger.debug(f"FTP download failed for {remote_path}: {e}")
  875. if downloaded_filename:
  876. break
  877. # If still not found, try listing directories to find matching file
  878. # Different printer models use different directory structures
  879. if not downloaded_filename and (filename or subtask_name):
  880. search_term = (subtask_name or filename).lower().replace(".gcode", "").replace(".3mf", "")
  881. logger.info(f"Direct FTP download failed, searching directories for '{search_term}'")
  882. search_dirs = ["/cache", "/model", "/data", "/data/Metadata", "/"]
  883. for search_dir in search_dirs:
  884. if downloaded_filename:
  885. break
  886. try:
  887. dir_files = await list_files_async(printer.ip_address, printer.access_code, search_dir)
  888. threemf_files = [f.get("name") for f in dir_files if f.get("name", "").endswith(".3mf")]
  889. if threemf_files:
  890. logger.info(
  891. f"Found {len(threemf_files)} 3MF files in {search_dir}: {threemf_files[:5]}{'...' if len(threemf_files) > 5 else ''}"
  892. )
  893. for f in dir_files:
  894. if f.get("is_directory"):
  895. continue
  896. fname = f.get("name", "")
  897. if fname.endswith(".3mf") and search_term in fname.lower():
  898. logger.info(f"Found matching file in {search_dir}: {fname}")
  899. temp_path = app_settings.archive_dir / "temp" / fname
  900. temp_path.parent.mkdir(parents=True, exist_ok=True)
  901. if ftp_retry_enabled:
  902. downloaded = await with_ftp_retry(
  903. download_file_async,
  904. printer.ip_address,
  905. printer.access_code,
  906. f"{search_dir}/{fname}",
  907. temp_path,
  908. max_retries=ftp_retry_count,
  909. retry_delay=ftp_retry_delay,
  910. operation_name=f"Download 3MF from {search_dir}/{fname}",
  911. )
  912. else:
  913. downloaded = await download_file_async(
  914. printer.ip_address,
  915. printer.access_code,
  916. f"{search_dir}/{fname}",
  917. temp_path,
  918. )
  919. if downloaded:
  920. downloaded_filename = fname
  921. logger.info(f"Found and downloaded from {search_dir}: {fname}")
  922. break
  923. except Exception as e:
  924. logger.debug(f"Failed to list {search_dir}: {e}")
  925. if not downloaded_filename or not temp_path:
  926. logger.warning(f"Could not find 3MF file for print: {filename or subtask_name}")
  927. # Create a fallback archive without 3MF data so the print is still tracked
  928. # This commonly happens with P1S/A1 printers where FTP has file size limitations
  929. try:
  930. from backend.app.models.archive import PrintArchive
  931. # Derive print name from subtask_name or filename
  932. print_name = subtask_name or filename
  933. if print_name:
  934. # Clean up the name (remove extensions, path parts)
  935. print_name = print_name.split("/")[-1]
  936. print_name = print_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "")
  937. else:
  938. print_name = "Unknown Print"
  939. # Create minimal archive entry
  940. fallback_archive = PrintArchive(
  941. printer_id=printer_id,
  942. filename=filename or f"{print_name}.3mf",
  943. file_path="", # Empty - no 3MF file available
  944. file_size=0,
  945. print_name=print_name,
  946. status="printing",
  947. started_at=datetime.now(),
  948. extra_data={"no_3mf_available": True, "original_subtask": subtask_name, "_print_data": data},
  949. )
  950. db.add(fallback_archive)
  951. await db.commit()
  952. await db.refresh(fallback_archive)
  953. logger.info(f"Created fallback archive {fallback_archive.id} for {print_name} (no 3MF available)")
  954. # Start timelapse session if external camera is enabled
  955. if printer.external_camera_enabled and printer.external_camera_url:
  956. from backend.app.services.layer_timelapse import start_session
  957. start_session(
  958. printer_id,
  959. fallback_archive.id,
  960. printer.external_camera_url,
  961. printer.external_camera_type or "mjpeg",
  962. )
  963. logger.info(f"Started layer timelapse for printer {printer_id}, archive {fallback_archive.id}")
  964. # Track as active print
  965. _active_prints[(printer_id, fallback_archive.filename)] = fallback_archive.id
  966. if filename:
  967. _active_prints[(printer_id, filename)] = fallback_archive.id
  968. if subtask_name:
  969. _active_prints[(printer_id, f"{subtask_name}.3mf")] = fallback_archive.id
  970. _active_prints[(printer_id, subtask_name)] = fallback_archive.id
  971. # Record starting energy if smart plug available
  972. try:
  973. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  974. plug = plug_result.scalar_one_or_none()
  975. if plug:
  976. energy = await _get_plug_energy(plug, db)
  977. if energy and energy.get("total") is not None:
  978. _print_energy_start[fallback_archive.id] = energy["total"]
  979. logger.info(
  980. f"[ENERGY] Recorded starting energy for fallback archive {fallback_archive.id}: {energy['total']} kWh"
  981. )
  982. except Exception as e:
  983. logger.warning(f"Failed to record starting energy for fallback: {e}")
  984. # Send WebSocket notification
  985. await ws_manager.send_archive_created(
  986. {
  987. "id": fallback_archive.id,
  988. "printer_id": fallback_archive.printer_id,
  989. "filename": fallback_archive.filename,
  990. "print_name": fallback_archive.print_name,
  991. "status": fallback_archive.status,
  992. }
  993. )
  994. # MQTT relay - publish archive created
  995. try:
  996. await mqtt_relay.on_archive_created(
  997. archive_id=fallback_archive.id,
  998. print_name=fallback_archive.print_name,
  999. printer_name=printer.name,
  1000. status=fallback_archive.status,
  1001. )
  1002. except Exception:
  1003. pass # Don't fail if MQTT fails
  1004. # Send notification without archive data (file not found)
  1005. if not notification_sent:
  1006. await _send_print_start_notification(printer_id, data, logger=logger)
  1007. return
  1008. except Exception as e:
  1009. logger.error(f"Failed to create fallback archive: {e}")
  1010. # Send notification without archive data (file not found)
  1011. if not notification_sent:
  1012. await _send_print_start_notification(printer_id, data, logger=logger)
  1013. return
  1014. try:
  1015. # Archive the file with status "printing"
  1016. service = ArchiveService(db)
  1017. archive = await service.archive_print(
  1018. printer_id=printer_id,
  1019. source_file=temp_path,
  1020. print_data={**data, "status": "printing"},
  1021. )
  1022. if archive:
  1023. # Track this active print (use both original filename and downloaded filename)
  1024. _active_prints[(printer_id, downloaded_filename)] = archive.id
  1025. if filename and filename != downloaded_filename:
  1026. _active_prints[(printer_id, filename)] = archive.id
  1027. if subtask_name:
  1028. _active_prints[(printer_id, f"{subtask_name}.3mf")] = archive.id
  1029. logger.info(f"Created archive {archive.id} for {downloaded_filename}")
  1030. # Start timelapse session if external camera is enabled
  1031. if printer.external_camera_enabled and printer.external_camera_url:
  1032. from backend.app.services.layer_timelapse import start_session
  1033. start_session(
  1034. printer_id,
  1035. archive.id,
  1036. printer.external_camera_url,
  1037. printer.external_camera_type or "mjpeg",
  1038. )
  1039. logger.info(f"Started layer timelapse for printer {printer_id}, archive {archive.id}")
  1040. # Record starting energy from smart plug if available
  1041. try:
  1042. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  1043. plug = plug_result.scalar_one_or_none()
  1044. logger.info(
  1045. f"[ENERGY] Auto-archive print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}"
  1046. )
  1047. if plug:
  1048. energy = await _get_plug_energy(plug, db)
  1049. logger.info(f"[ENERGY] Auto-archive energy response: {energy}")
  1050. if energy and energy.get("total") is not None:
  1051. _print_energy_start[archive.id] = energy["total"]
  1052. logger.info(
  1053. f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh"
  1054. )
  1055. else:
  1056. logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}")
  1057. else:
  1058. logger.info(f"[ENERGY] No smart plug found for printer {printer_id}")
  1059. except Exception as e:
  1060. logger.warning(f"Failed to record starting energy: {e}")
  1061. await ws_manager.send_archive_created(
  1062. {
  1063. "id": archive.id,
  1064. "printer_id": archive.printer_id,
  1065. "filename": archive.filename,
  1066. "print_name": archive.print_name,
  1067. "status": archive.status,
  1068. }
  1069. )
  1070. # MQTT relay - publish archive created
  1071. try:
  1072. await mqtt_relay.on_archive_created(
  1073. archive_id=archive.id,
  1074. print_name=archive.print_name,
  1075. printer_name=printer.name,
  1076. status=archive.status,
  1077. )
  1078. except Exception:
  1079. pass # Don't fail if MQTT fails
  1080. # Send notification with archive data (new archive created)
  1081. if not notification_sent:
  1082. archive_data = {"print_time_seconds": archive.print_time_seconds}
  1083. await _send_print_start_notification(printer_id, data, archive_data, logger)
  1084. notification_sent = True
  1085. # Extract printable objects for skip object functionality
  1086. try:
  1087. from backend.app.services.archive import extract_printable_objects_from_3mf
  1088. with open(temp_path, "rb") as f:
  1089. threemf_data = f.read()
  1090. # Extract with positions for UI overlay
  1091. printable_objects, bbox_all = extract_printable_objects_from_3mf(
  1092. threemf_data, include_positions=True
  1093. )
  1094. if printable_objects:
  1095. # Store objects in printer state
  1096. client = printer_manager.get_client(printer_id)
  1097. if client:
  1098. client.state.printable_objects = printable_objects
  1099. client.state.printable_objects_bbox_all = bbox_all
  1100. client.state.skipped_objects = [] # Reset skipped objects for new print
  1101. logger.info(f"Loaded {len(printable_objects)} printable objects for printer {printer_id}")
  1102. except Exception as e:
  1103. logger.debug(f"Failed to extract printable objects: {e}")
  1104. finally:
  1105. if temp_path and temp_path.exists():
  1106. temp_path.unlink()
  1107. async def _scan_for_timelapse_with_retries(archive_id: int):
  1108. """
  1109. Scan for timelapse with retries.
  1110. The printer encodes the timelapse quickly after print completion.
  1111. We just need a short delay then grab the most recent file.
  1112. Since we KNOW timelapse was active (from MQTT ipcam data), the most recent
  1113. file in /timelapse is our target. Retries handle FTP connection issues.
  1114. """
  1115. import logging
  1116. logger = logging.getLogger(__name__)
  1117. # Short delays - printer usually finishes encoding within seconds
  1118. retry_delays = [5, 10, 20]
  1119. for attempt, delay in enumerate(retry_delays, 1):
  1120. logger.info(
  1121. f"[TIMELAPSE] Attempt {attempt}/{len(retry_delays)}: waiting {delay}s before scanning for archive {archive_id}"
  1122. )
  1123. await asyncio.sleep(delay)
  1124. try:
  1125. async with async_session() as db:
  1126. from backend.app.models.printer import Printer
  1127. from backend.app.services.bambu_ftp import download_file_bytes_async, list_files_async
  1128. # Get archive (ArchiveService from module-level import)
  1129. service = ArchiveService(db)
  1130. archive = await service.get_archive(archive_id)
  1131. if not archive:
  1132. logger.warning(f"[TIMELAPSE] Archive {archive_id} not found, stopping retries")
  1133. return
  1134. if archive.timelapse_path:
  1135. logger.info(f"[TIMELAPSE] Archive {archive_id} already has timelapse attached, stopping retries")
  1136. return
  1137. if not archive.printer_id:
  1138. logger.warning(f"[TIMELAPSE] Archive {archive_id} has no printer, stopping retries")
  1139. return
  1140. # Get printer
  1141. result = await db.execute(select(Printer).where(Printer.id == archive.printer_id))
  1142. printer = result.scalar_one_or_none()
  1143. if not printer:
  1144. logger.warning(f"[TIMELAPSE] Printer not found for archive {archive_id}, stopping retries")
  1145. return
  1146. # Scan timelapse directory on printer
  1147. # H2D may store in different locations than X1C
  1148. files = []
  1149. found_path = None
  1150. for timelapse_path in ["/timelapse", "/timelapse/video", "/record", "/recording"]:
  1151. try:
  1152. found_files = await list_files_async(printer.ip_address, printer.access_code, timelapse_path)
  1153. if found_files:
  1154. files = found_files
  1155. found_path = timelapse_path
  1156. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(files)} files in {timelapse_path}")
  1157. break
  1158. except Exception as e:
  1159. logger.debug(f"[TIMELAPSE] Path {timelapse_path} failed: {e}")
  1160. continue
  1161. if not files:
  1162. logger.info(f"[TIMELAPSE] Attempt {attempt}: No timelapse files found on printer, will retry")
  1163. continue
  1164. mp4_files = [f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4")]
  1165. # Log ALL mp4 files found for debugging
  1166. logger.info(f"[TIMELAPSE] Attempt {attempt}: Found {len(mp4_files)} MP4 files in {found_path}")
  1167. for f in mp4_files[:5]: # Log first 5
  1168. logger.info(f"[TIMELAPSE] - {f.get('name')}, mtime={f.get('mtime')}")
  1169. if not mp4_files:
  1170. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files found, will retry")
  1171. continue
  1172. # Sort by mtime descending to get most recent file
  1173. mp4_files_with_mtime = [f for f in mp4_files if f.get("mtime")]
  1174. if not mp4_files_with_mtime:
  1175. logger.info(f"[TIMELAPSE] Attempt {attempt}: No MP4 files with mtime found, will retry")
  1176. continue
  1177. mp4_files_with_mtime.sort(key=lambda x: x.get("mtime"), reverse=True)
  1178. most_recent = mp4_files_with_mtime[0]
  1179. file_name = most_recent.get("name")
  1180. logger.info(f"[TIMELAPSE] Attempt {attempt}: Most recent file: {file_name}")
  1181. # Since we KNOW timelapse was active (from MQTT), just grab the most recent file
  1182. remote_path = most_recent.get("path") or f"/timelapse/{file_name}"
  1183. logger.info(f"[TIMELAPSE] Downloading {file_name} for archive {archive_id}")
  1184. timelapse_data = await download_file_bytes_async(printer.ip_address, printer.access_code, remote_path)
  1185. if timelapse_data:
  1186. success = await service.attach_timelapse(archive_id, timelapse_data, file_name)
  1187. if success:
  1188. logger.info(f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}")
  1189. await ws_manager.send_archive_updated({"id": archive_id, "timelapse_attached": True})
  1190. return # Success!
  1191. else:
  1192. logger.warning(f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}")
  1193. else:
  1194. logger.warning(f"[TIMELAPSE] Attempt {attempt}: Failed to download, will retry")
  1195. except Exception as e:
  1196. logger.warning(f"[TIMELAPSE] Attempt {attempt} failed with error: {e}")
  1197. logger.warning(f"[TIMELAPSE] All {len(retry_delays)} attempts exhausted for archive {archive_id}, giving up")
  1198. async def on_print_complete(printer_id: int, data: dict):
  1199. """Handle print completion - update the archive status."""
  1200. import logging
  1201. import time
  1202. logger = logging.getLogger(__name__)
  1203. start_time = time.time()
  1204. def log_timing(section: str):
  1205. elapsed = time.time() - start_time
  1206. logger.info(f"[TIMING] {section}: {elapsed:.3f}s elapsed")
  1207. logger.info(f"[CALLBACK] on_print_complete started for printer {printer_id}")
  1208. try:
  1209. ws_data = {
  1210. "status": data.get("status"),
  1211. "filename": data.get("filename"),
  1212. "subtask_name": data.get("subtask_name"),
  1213. "timelapse_was_active": data.get("timelapse_was_active"),
  1214. }
  1215. await ws_manager.send_print_complete(printer_id, ws_data)
  1216. log_timing("WebSocket send_print_complete")
  1217. except Exception as e:
  1218. logger.warning(f"[CALLBACK] WebSocket send_print_complete failed: {e}")
  1219. # MQTT relay - publish print complete
  1220. try:
  1221. printer_info = printer_manager.get_printer(printer_id)
  1222. if printer_info:
  1223. await mqtt_relay.on_print_complete(
  1224. printer_id,
  1225. printer_info.name,
  1226. printer_info.serial_number,
  1227. data.get("filename", ""),
  1228. data.get("subtask_name", ""),
  1229. data.get("status", "completed"),
  1230. )
  1231. except Exception:
  1232. pass # Don't fail print complete callback if MQTT fails
  1233. filename = data.get("filename", "")
  1234. subtask_name = data.get("subtask_name", "")
  1235. if not filename and not subtask_name:
  1236. logger.warning("Print complete without filename or subtask_name")
  1237. return
  1238. logger.info(f"Print complete - filename: {filename}, subtask: {subtask_name}, status: {data.get('status')}")
  1239. # Build list of possible keys to try (matching how they were registered in on_print_start)
  1240. possible_keys = []
  1241. # Try subtask_name variations first (most reliable for matching)
  1242. if subtask_name:
  1243. possible_keys.append((printer_id, f"{subtask_name}.3mf"))
  1244. possible_keys.append((printer_id, f"{subtask_name}.gcode.3mf"))
  1245. possible_keys.append((printer_id, subtask_name))
  1246. # Try filename variations
  1247. if filename:
  1248. # Extract just the filename if it's a path
  1249. fname = filename.split("/")[-1] if "/" in filename else filename
  1250. if fname.endswith(".3mf"):
  1251. possible_keys.append((printer_id, fname))
  1252. elif fname.endswith(".gcode"):
  1253. base_name = fname.rsplit(".", 1)[0]
  1254. possible_keys.append((printer_id, f"{base_name}.gcode.3mf"))
  1255. possible_keys.append((printer_id, f"{base_name}.3mf"))
  1256. possible_keys.append((printer_id, fname))
  1257. else:
  1258. possible_keys.append((printer_id, f"{fname}.gcode.3mf"))
  1259. possible_keys.append((printer_id, f"{fname}.3mf"))
  1260. possible_keys.append((printer_id, fname))
  1261. # Also try full path versions
  1262. if filename.endswith(".3mf"):
  1263. possible_keys.append((printer_id, filename))
  1264. elif filename.endswith(".gcode"):
  1265. base_name = filename.rsplit(".", 1)[0]
  1266. possible_keys.append((printer_id, f"{base_name}.3mf"))
  1267. possible_keys.append((printer_id, filename))
  1268. else:
  1269. possible_keys.append((printer_id, f"{filename}.3mf"))
  1270. possible_keys.append((printer_id, filename))
  1271. # Find the archive for this print
  1272. logger.info(f"Looking for archive in _active_prints, keys to try: {possible_keys[:5]}...")
  1273. logger.info(f"Current _active_prints: {list(_active_prints.keys())}")
  1274. archive_id = None
  1275. for key in possible_keys:
  1276. archive_id = _active_prints.pop(key, None)
  1277. if archive_id:
  1278. logger.info(f"Found archive {archive_id} with key {key}")
  1279. # Also clean up any other keys pointing to this archive
  1280. keys_to_remove = [k for k, v in _active_prints.items() if v == archive_id]
  1281. for k in keys_to_remove:
  1282. _active_prints.pop(k, None)
  1283. break
  1284. if not archive_id:
  1285. # Try to find by filename or subtask_name if not tracked (for prints started before app)
  1286. async with async_session() as db:
  1287. from backend.app.models.archive import PrintArchive
  1288. # Try matching by subtask_name (stored as print_name) first
  1289. if subtask_name:
  1290. result = await db.execute(
  1291. select(PrintArchive)
  1292. .where(PrintArchive.printer_id == printer_id)
  1293. .where(PrintArchive.status == "printing")
  1294. .where(
  1295. or_(
  1296. PrintArchive.print_name.ilike(f"%{subtask_name}%"),
  1297. PrintArchive.filename.ilike(f"%{subtask_name}%"),
  1298. )
  1299. )
  1300. .order_by(PrintArchive.created_at.desc())
  1301. .limit(1)
  1302. )
  1303. archive = result.scalar_one_or_none()
  1304. if archive:
  1305. archive_id = archive.id
  1306. logger.info(f"Found archive {archive_id} by subtask_name match: {subtask_name}")
  1307. # Also try by filename
  1308. if not archive_id and filename:
  1309. result = await db.execute(
  1310. select(PrintArchive)
  1311. .where(PrintArchive.printer_id == printer_id)
  1312. .where(PrintArchive.filename == filename)
  1313. .where(PrintArchive.status == "printing")
  1314. .order_by(PrintArchive.created_at.desc())
  1315. .limit(1)
  1316. )
  1317. archive = result.scalar_one_or_none()
  1318. if archive:
  1319. archive_id = archive.id
  1320. if not archive_id:
  1321. logger.warning(f"Could not find archive for print complete: filename={filename}, subtask={subtask_name}")
  1322. return
  1323. log_timing("Archive lookup")
  1324. # Update archive status
  1325. logger.info(f"[ARCHIVE] Updating archive {archive_id} status...")
  1326. try:
  1327. async with async_session() as db:
  1328. service = ArchiveService(db)
  1329. status = data.get("status", "completed")
  1330. # Auto-detect failure reason
  1331. failure_reason = None
  1332. if status == "aborted":
  1333. failure_reason = "User cancelled"
  1334. logger.info("[ARCHIVE] Print was aborted by user, setting failure_reason='User cancelled'")
  1335. elif status == "failed":
  1336. # Try to determine failure reason from HMS errors
  1337. hms_errors = data.get("hms_errors", [])
  1338. if hms_errors:
  1339. logger.info(f"[ARCHIVE] HMS errors at failure: {hms_errors}")
  1340. # Map known HMS error modules to failure reasons
  1341. # Module 0x07 = Filament, 0x0C = MC (Motion Controller), etc.
  1342. for err in hms_errors:
  1343. module = err.get("module", 0)
  1344. if module == 0x07: # Filament module
  1345. failure_reason = "Filament runout"
  1346. break
  1347. elif module == 0x0C: # Motion controller
  1348. failure_reason = "Layer shift"
  1349. break
  1350. elif module == 0x05: # Nozzle/extruder
  1351. failure_reason = "Clogged nozzle"
  1352. break
  1353. if failure_reason:
  1354. logger.info(f"[ARCHIVE] Detected failure_reason from HMS: {failure_reason}")
  1355. else:
  1356. logger.info("[ARCHIVE] No HMS errors available to determine failure reason")
  1357. await service.update_archive_status(
  1358. archive_id,
  1359. status=status,
  1360. completed_at=datetime.now() if status in ("completed", "failed", "aborted") else None,
  1361. failure_reason=failure_reason,
  1362. )
  1363. logger.info(f"[ARCHIVE] Archive {archive_id} status updated to {status}, failure_reason={failure_reason}")
  1364. # Add cost for reprints (first prints have cost set in archive_print())
  1365. if status == "completed" and archive_id in _reprint_archives:
  1366. _reprint_archives.discard(archive_id)
  1367. try:
  1368. await service.add_reprint_cost(archive_id)
  1369. logger.info(f"[ARCHIVE] Added reprint cost for archive {archive_id}")
  1370. except Exception as e:
  1371. logger.warning(f"[ARCHIVE] Failed to add reprint cost for archive {archive_id}: {e}")
  1372. await ws_manager.send_archive_updated(
  1373. {
  1374. "id": archive_id,
  1375. "status": status,
  1376. }
  1377. )
  1378. logger.info(f"[ARCHIVE] WebSocket notification sent for archive {archive_id}")
  1379. # MQTT relay - publish archive updated
  1380. try:
  1381. await mqtt_relay.on_archive_updated(
  1382. archive_id=archive_id,
  1383. print_name=filename or subtask_name,
  1384. status=status,
  1385. )
  1386. except Exception:
  1387. pass # Don't fail if MQTT fails
  1388. except Exception as e:
  1389. logger.error(f"[ARCHIVE] Failed to update archive {archive_id} status: {e}", exc_info=True)
  1390. # Continue with other operations even if archive update fails
  1391. log_timing("Archive status update")
  1392. # Report filament usage to Spoolman if print completed successfully
  1393. if data.get("status") == "completed":
  1394. try:
  1395. await _report_spoolman_usage(printer_id, archive_id, logger)
  1396. log_timing("Spoolman usage report")
  1397. except Exception as e:
  1398. logger.warning(f"Spoolman usage reporting failed: {e}")
  1399. # Run slow operations as background tasks to avoid blocking the event loop
  1400. # These operations can take 5-10+ seconds and would freeze the UI if awaited
  1401. starting_kwh = _print_energy_start.pop(archive_id, None)
  1402. async def _background_energy_calculation():
  1403. """Calculate and save energy usage in background."""
  1404. try:
  1405. logger.info(f"[ENERGY-BG] Starting energy calculation for archive {archive_id}")
  1406. async with async_session() as db:
  1407. plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  1408. plug = plug_result.scalar_one_or_none()
  1409. if plug:
  1410. energy = await _get_plug_energy(plug, db)
  1411. logger.info(f"[ENERGY-BG] Energy response: {energy}")
  1412. energy_used = None
  1413. if starting_kwh is not None and energy and energy.get("total") is not None:
  1414. ending_kwh = energy["total"]
  1415. energy_used = round(ending_kwh - starting_kwh, 4)
  1416. logger.info(f"[ENERGY-BG] Per-print energy: {energy_used} kWh")
  1417. if energy_used is not None and energy_used >= 0:
  1418. from backend.app.api.routes.settings import get_setting
  1419. energy_cost_per_kwh = await get_setting(db, "energy_cost_per_kwh")
  1420. cost_per_kwh = float(energy_cost_per_kwh) if energy_cost_per_kwh else 0.15
  1421. energy_cost = round(energy_used * cost_per_kwh, 2)
  1422. from backend.app.models.archive import PrintArchive
  1423. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1424. archive = result.scalar_one_or_none()
  1425. if archive:
  1426. archive.energy_kwh = energy_used
  1427. archive.energy_cost = energy_cost
  1428. await db.commit()
  1429. logger.info(f"[ENERGY-BG] Saved: {energy_used} kWh, cost={energy_cost}")
  1430. else:
  1431. logger.info(f"[ENERGY-BG] No smart plug for printer {printer_id}")
  1432. except Exception as e:
  1433. logger.warning(f"[ENERGY-BG] Failed: {e}")
  1434. async def _background_finish_photo() -> str | None:
  1435. """Capture finish photo in background. Returns photo filename if captured."""
  1436. try:
  1437. logger.info(f"[PHOTO-BG] Starting finish photo capture for archive {archive_id}")
  1438. from backend.app.api.routes.camera import _active_chamber_streams, _active_streams, get_buffered_frame
  1439. async with async_session() as db:
  1440. from backend.app.api.routes.settings import get_setting
  1441. capture_enabled = await get_setting(db, "capture_finish_photo")
  1442. if capture_enabled is None or capture_enabled.lower() == "true":
  1443. from backend.app.models.printer import Printer
  1444. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1445. printer = result.scalar_one_or_none()
  1446. if printer and archive_id:
  1447. from backend.app.models.archive import PrintArchive
  1448. result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1449. archive = result.scalar_one_or_none()
  1450. if archive:
  1451. import uuid
  1452. from datetime import datetime
  1453. from pathlib import Path
  1454. archive_dir = app_settings.base_dir / Path(archive.file_path).parent
  1455. photo_filename = None
  1456. # Check for external camera first
  1457. if printer.external_camera_enabled and printer.external_camera_url:
  1458. logger.info("[PHOTO-BG] Using external camera")
  1459. from backend.app.services.external_camera import capture_frame
  1460. frame_data = await capture_frame(
  1461. printer.external_camera_url, printer.external_camera_type or "mjpeg"
  1462. )
  1463. if frame_data:
  1464. photos_dir = archive_dir / "photos"
  1465. photos_dir.mkdir(parents=True, exist_ok=True)
  1466. timestamp = datetime.now().strftime("%Y%m%d_%H%M%S")
  1467. photo_filename = f"finish_{timestamp}_{uuid.uuid4().hex[:8]}.jpg"
  1468. photo_path = photos_dir / photo_filename
  1469. await asyncio.to_thread(photo_path.write_bytes, frame_data)
  1470. logger.info(f"[PHOTO-BG] Saved external camera frame: {photo_filename}")
  1471. else:
  1472. # Check if camera stream is active - use buffered frame to avoid freeze
  1473. # Check both RTSP streams (_active_streams) and chamber image streams (_active_chamber_streams)
  1474. active_for_printer = [k for k in _active_streams if k.startswith(f"{printer_id}-")]
  1475. active_chamber_for_printer = [
  1476. k for k in _active_chamber_streams if k.startswith(f"{printer_id}-")
  1477. ]
  1478. buffered_frame = get_buffered_frame(printer_id)
  1479. if (active_for_printer or active_chamber_for_printer) and buffered_frame:
  1480. # Use frame from active stream
  1481. logger.info("[PHOTO-BG] Using buffered frame from active stream")
  1482. photos_dir = archive_dir / "photos"
  1483. photos_dir.mkdir(parents=True, exist_ok=True)
  1484. timestamp = datetime.now().strftime("%Y%m%d_%H%M%S")
  1485. photo_filename = f"finish_{timestamp}_{uuid.uuid4().hex[:8]}.jpg"
  1486. photo_path = photos_dir / photo_filename
  1487. await asyncio.to_thread(photo_path.write_bytes, buffered_frame)
  1488. logger.info(f"[PHOTO-BG] Saved buffered frame: {photo_filename}")
  1489. else:
  1490. # No active stream - capture new frame
  1491. from backend.app.services.camera import capture_finish_photo
  1492. photo_filename = await capture_finish_photo(
  1493. printer_id=printer_id,
  1494. ip_address=printer.ip_address,
  1495. access_code=printer.access_code,
  1496. model=printer.model,
  1497. archive_dir=archive_dir,
  1498. )
  1499. if photo_filename:
  1500. photos = archive.photos or []
  1501. photos.append(photo_filename)
  1502. archive.photos = photos
  1503. await db.commit()
  1504. logger.info(f"[PHOTO-BG] Saved: {photo_filename}")
  1505. return photo_filename
  1506. return None
  1507. except Exception as e:
  1508. logger.warning(f"[PHOTO-BG] Failed: {e}")
  1509. return None
  1510. asyncio.create_task(_background_energy_calculation())
  1511. # Photo capture task - result will be used by notifications
  1512. photo_task = asyncio.create_task(_background_finish_photo())
  1513. log_timing("Background tasks scheduled (energy, photo)")
  1514. # Also run smart plug, notifications, and maintenance as background tasks
  1515. print_status = data.get("status", "completed")
  1516. async def _background_smart_plug():
  1517. """Handle smart plug automation in background."""
  1518. try:
  1519. logger.info(f"[AUTO-OFF-BG] Starting smart plug automation for printer {printer_id}")
  1520. async with async_session() as db:
  1521. await smart_plug_manager.on_print_complete(printer_id, print_status, db)
  1522. logger.info("[AUTO-OFF-BG] Completed")
  1523. except Exception as e:
  1524. logger.warning(f"[AUTO-OFF-BG] Failed: {e}")
  1525. async def _background_notifications(finish_photo_filename: str | None = None):
  1526. """Send print complete notifications in background."""
  1527. try:
  1528. logger.info(f"[NOTIFY-BG] Starting notifications for printer {printer_id}, photo={finish_photo_filename}")
  1529. async with async_session() as db:
  1530. from backend.app.models.archive import PrintArchive
  1531. from backend.app.models.printer import Printer
  1532. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1533. printer = result.scalar_one_or_none()
  1534. printer_name = printer.name if printer else f"Printer {printer_id}"
  1535. archive_data = None
  1536. if archive_id:
  1537. archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id))
  1538. archive = archive_result.scalar_one_or_none()
  1539. if archive:
  1540. archive_data = {
  1541. "print_time_seconds": archive.print_time_seconds,
  1542. "actual_filament_grams": archive.filament_used_grams,
  1543. "failure_reason": archive.failure_reason,
  1544. }
  1545. # Add finish photo URL if available
  1546. if finish_photo_filename:
  1547. from backend.app.api.routes.settings import get_setting
  1548. external_url = await get_setting(db, "external_url")
  1549. if external_url:
  1550. external_url = external_url.rstrip("/")
  1551. archive_data["finish_photo_url"] = (
  1552. f"{external_url}/api/v1/archives/{archive_id}/photos/{finish_photo_filename}"
  1553. )
  1554. else:
  1555. # Fallback to relative URL (won't work for external services)
  1556. archive_data["finish_photo_url"] = (
  1557. f"/api/v1/archives/{archive_id}/photos/{finish_photo_filename}"
  1558. )
  1559. await notification_service.on_print_complete(
  1560. printer_id, printer_name, print_status, data, db, archive_data=archive_data
  1561. )
  1562. logger.info("[NOTIFY-BG] Completed")
  1563. except Exception as e:
  1564. logger.warning(f"[NOTIFY-BG] Failed: {e}")
  1565. async def _background_maintenance_check():
  1566. """Check for maintenance due in background."""
  1567. if print_status != "completed":
  1568. return
  1569. try:
  1570. logger.info(f"[MAINT-BG] Starting maintenance check for printer {printer_id}")
  1571. async with async_session() as db:
  1572. from backend.app.models.printer import Printer
  1573. result = await db.execute(select(Printer).where(Printer.id == printer_id))
  1574. printer = result.scalar_one_or_none()
  1575. printer_name = printer.name if printer else f"Printer {printer_id}"
  1576. await ensure_default_types(db)
  1577. overview = await _get_printer_maintenance_internal(printer_id, db, commit=True)
  1578. items_needing_attention = [
  1579. {"name": item.maintenance_type_name, "is_due": item.is_due, "is_warning": item.is_warning}
  1580. for item in overview.maintenance_items
  1581. if item.enabled and (item.is_due or item.is_warning)
  1582. ]
  1583. if items_needing_attention:
  1584. await notification_service.on_maintenance_due(printer_id, printer_name, items_needing_attention, db)
  1585. logger.info(f"[MAINT-BG] Sent notification: {len(items_needing_attention)} items need attention")
  1586. # MQTT relay - publish maintenance alerts
  1587. for item in items_needing_attention:
  1588. try:
  1589. await mqtt_relay.on_maintenance_alert(
  1590. printer_id=printer_id,
  1591. printer_name=printer_name,
  1592. maintenance_type=item["name"],
  1593. current_value=0, # Not easily available here
  1594. threshold=0, # Not easily available here
  1595. )
  1596. except Exception:
  1597. pass # Don't fail if MQTT fails
  1598. else:
  1599. logger.info("[MAINT-BG] Completed (no items need attention)")
  1600. except Exception as e:
  1601. logger.warning(f"[MAINT-BG] Failed: {e}")
  1602. asyncio.create_task(_background_smart_plug())
  1603. asyncio.create_task(_background_maintenance_check())
  1604. # Notification task waits for photo capture to complete first
  1605. async def _photo_then_notify():
  1606. """Wait for photo capture, then send notification with photo URL."""
  1607. try:
  1608. finish_photo = await photo_task
  1609. logger.info(f"[PHOTO-NOTIFY] Photo task returned: {finish_photo}")
  1610. await _background_notifications(finish_photo)
  1611. except Exception as e:
  1612. logger.warning(f"[PHOTO-NOTIFY] Failed: {e}")
  1613. # Still try to send notification without photo
  1614. await _background_notifications(None)
  1615. asyncio.create_task(_photo_then_notify())
  1616. # Stitch external camera layer timelapse if session was active
  1617. print_status = data.get("status", "completed")
  1618. async def _background_layer_timelapse():
  1619. """Stitch layer timelapse and attach to archive."""
  1620. from backend.app.services.layer_timelapse import cancel_session, on_print_complete as tl_complete
  1621. try:
  1622. if print_status == "completed":
  1623. logger.info(f"[LAYER-TL] Stitching layer timelapse for printer {printer_id}")
  1624. timelapse_path = await tl_complete(printer_id)
  1625. if timelapse_path and archive_id:
  1626. logger.info(f"[LAYER-TL] Attaching timelapse {timelapse_path} to archive {archive_id}")
  1627. async with async_session() as db:
  1628. service = ArchiveService(db)
  1629. timelapse_data = await asyncio.to_thread(timelapse_path.read_bytes)
  1630. await service.attach_timelapse(archive_id, timelapse_data, "layer_timelapse.mp4")
  1631. # Clean up the temp file
  1632. await asyncio.to_thread(timelapse_path.unlink, missing_ok=True)
  1633. logger.info("[LAYER-TL] Layer timelapse attached successfully")
  1634. elif timelapse_path:
  1635. # Timelapse created but no archive - just clean up
  1636. await asyncio.to_thread(timelapse_path.unlink, missing_ok=True)
  1637. else:
  1638. # Print failed or cancelled - cancel timelapse session
  1639. cancel_session(printer_id)
  1640. logger.info(f"[LAYER-TL] Cancelled layer timelapse for printer {printer_id} (status: {print_status})")
  1641. except Exception as e:
  1642. logger.warning(f"[LAYER-TL] Failed: {e}")
  1643. # Try to cancel session on error
  1644. try:
  1645. cancel_session(printer_id)
  1646. except Exception:
  1647. pass
  1648. asyncio.create_task(_background_layer_timelapse())
  1649. log_timing("All background tasks scheduled")
  1650. # Auto-scan for timelapse if recording was active during the print
  1651. if archive_id and data.get("timelapse_was_active") and data.get("status") == "completed":
  1652. logger.info(f"[TIMELAPSE] Timelapse was active during print, scheduling auto-scan for archive {archive_id}")
  1653. # Schedule timelapse scan as background task with retries
  1654. # The printer needs time to encode the video after print completion
  1655. asyncio.create_task(_scan_for_timelapse_with_retries(archive_id))
  1656. log_timing("Timelapse scan scheduled")
  1657. # Update queue item if this was a scheduled print
  1658. try:
  1659. async with async_session() as db:
  1660. from backend.app.models.print_queue import PrintQueueItem
  1661. # Note: SmartPlug is already imported at module level (line 56)
  1662. # Do NOT import it here as it would shadow the module-level import
  1663. # and cause "cannot access local variable" errors earlier in this function
  1664. result = await db.execute(
  1665. select(PrintQueueItem)
  1666. .where(PrintQueueItem.printer_id == printer_id)
  1667. .where(PrintQueueItem.status == "printing")
  1668. )
  1669. queue_item = result.scalar_one_or_none()
  1670. if queue_item:
  1671. status = data.get("status", "completed")
  1672. queue_item.status = status
  1673. queue_item.completed_at = datetime.now()
  1674. await db.commit()
  1675. logger.info(f"Updated queue item {queue_item.id} status to {status}")
  1676. # MQTT relay - publish queue job completed
  1677. try:
  1678. printer_info = printer_manager.get_printer(printer_id)
  1679. await mqtt_relay.on_queue_job_completed(
  1680. job_id=queue_item.id,
  1681. filename=filename or subtask_name,
  1682. printer_id=printer_id,
  1683. printer_name=printer_info.name if printer_info else "Unknown",
  1684. status=status,
  1685. )
  1686. except Exception:
  1687. pass # Don't fail if MQTT fails
  1688. # Handle auto_off_after - power off printer if requested (after cooldown)
  1689. if queue_item.auto_off_after:
  1690. result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id))
  1691. plug = result.scalar_one_or_none()
  1692. if plug and plug.enabled:
  1693. logger.info(f"Auto-off requested for printer {printer_id}, waiting for cooldown...")
  1694. async def cooldown_and_poweroff(pid: int, plug_id: int):
  1695. # Wait for nozzle to cool down
  1696. await printer_manager.wait_for_cooldown(pid, target_temp=50.0, timeout=600)
  1697. # Re-fetch plug in new session
  1698. async with async_session() as new_db:
  1699. result = await new_db.execute(select(SmartPlug).where(SmartPlug.id == plug_id))
  1700. p = result.scalar_one_or_none()
  1701. if p and p.enabled:
  1702. success = await tasmota_service.turn_off(p)
  1703. if success:
  1704. logger.info(f"Powered off printer {pid} via smart plug '{p.name}'")
  1705. else:
  1706. logger.warning(f"Failed to power off printer {pid} via smart plug")
  1707. asyncio.create_task(cooldown_and_poweroff(printer_id, plug.id))
  1708. except Exception as e:
  1709. import logging
  1710. logging.getLogger(__name__).warning(f"Queue item update failed: {e}")
  1711. log_timing("Queue item update")
  1712. logger.info(f"[CALLBACK] on_print_complete finished for printer {printer_id}, archive {archive_id}")
  1713. # AMS sensor history recording
  1714. _ams_history_task: asyncio.Task | None = None
  1715. AMS_HISTORY_INTERVAL = 300 # Record every 5 minutes
  1716. AMS_HISTORY_RETENTION_DAYS = 30 # Keep data for 30 days
  1717. _ams_cleanup_counter = 0 # Track recordings to trigger periodic cleanup
  1718. _ams_alarm_cooldown: dict[str, datetime] = {} # Track alarm cooldowns (printer_id:ams_id:type -> last_alarm_time)
  1719. AMS_ALARM_COOLDOWN_MINUTES = 60 # Don't send same alarm more than once per hour
  1720. async def record_ams_history():
  1721. """Background task to record AMS humidity and temperature data."""
  1722. import logging
  1723. logger = logging.getLogger(__name__)
  1724. # Wait a short time for MQTT connections to establish on startup
  1725. await asyncio.sleep(10)
  1726. while True:
  1727. try:
  1728. from backend.app.models.ams_history import AMSSensorHistory
  1729. from backend.app.models.printer import Printer
  1730. from backend.app.models.settings import Settings
  1731. async with async_session() as db:
  1732. # Get all active printers
  1733. result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
  1734. printers = result.scalars().all()
  1735. # Get alarm thresholds from settings
  1736. humidity_threshold = 60.0 # Default: fair threshold
  1737. temp_threshold = 35.0 # Default: fair threshold
  1738. result = await db.execute(select(Settings).where(Settings.key == "ams_humidity_fair"))
  1739. setting = result.scalar_one_or_none()
  1740. if setting:
  1741. try:
  1742. humidity_threshold = float(setting.value)
  1743. except (ValueError, TypeError):
  1744. pass
  1745. result = await db.execute(select(Settings).where(Settings.key == "ams_temp_fair"))
  1746. setting = result.scalar_one_or_none()
  1747. if setting:
  1748. try:
  1749. temp_threshold = float(setting.value)
  1750. except (ValueError, TypeError):
  1751. pass
  1752. recorded_count = 0
  1753. for printer in printers:
  1754. # Get current state from printer manager
  1755. state = printer_manager.get_status(printer.id)
  1756. if not state or not state.connected or not state.raw_data:
  1757. continue # Skip disconnected printers - don't use stale data
  1758. raw_data = state.raw_data
  1759. if "ams" not in raw_data or not isinstance(raw_data["ams"], list):
  1760. continue
  1761. # Record data for each AMS unit
  1762. for ams_data in raw_data["ams"]:
  1763. ams_id = int(ams_data.get("id", 0))
  1764. # Get humidity (prefer humidity_raw)
  1765. humidity_raw = ams_data.get("humidity_raw")
  1766. humidity_idx = ams_data.get("humidity")
  1767. humidity = None
  1768. if humidity_raw is not None:
  1769. try:
  1770. humidity = float(humidity_raw)
  1771. except (ValueError, TypeError):
  1772. pass
  1773. if humidity is None and humidity_idx is not None:
  1774. try:
  1775. humidity = float(humidity_idx)
  1776. except (ValueError, TypeError):
  1777. pass
  1778. # Get temperature
  1779. temperature = None
  1780. temp_str = ams_data.get("temp")
  1781. if temp_str is not None:
  1782. try:
  1783. temperature = float(temp_str)
  1784. except (ValueError, TypeError):
  1785. pass
  1786. # Skip if no data
  1787. if humidity is None and temperature is None:
  1788. continue
  1789. # Record the data point
  1790. history = AMSSensorHistory(
  1791. printer_id=printer.id,
  1792. ams_id=ams_id,
  1793. humidity=humidity,
  1794. humidity_raw=float(humidity_raw) if humidity_raw else None,
  1795. temperature=temperature,
  1796. )
  1797. db.add(history)
  1798. recorded_count += 1
  1799. # Generate AMS label and determine if it's AMS-HT (A, B, C, D or HT-A for AMS-Lite/Hub)
  1800. is_ams_ht = ams_id >= 128
  1801. if is_ams_ht:
  1802. ams_label = f"HT-{chr(65 + (ams_id - 128))}"
  1803. else:
  1804. ams_label = f"AMS-{chr(65 + ams_id)}"
  1805. # Check humidity alarm (only if above threshold)
  1806. if humidity is not None and humidity > humidity_threshold:
  1807. cooldown_key = f"{printer.id}:{ams_id}:humidity"
  1808. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1809. now = datetime.now()
  1810. if (
  1811. last_alarm is None
  1812. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1813. ):
  1814. _ams_alarm_cooldown[cooldown_key] = now
  1815. logger.info(
  1816. f"Sending humidity alarm for {printer.name} {ams_label}: {humidity}% > {humidity_threshold}%"
  1817. )
  1818. try:
  1819. # Call different notification method based on AMS type
  1820. if is_ams_ht:
  1821. await notification_service.on_ams_ht_humidity_high(
  1822. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1823. )
  1824. else:
  1825. await notification_service.on_ams_humidity_high(
  1826. printer.id, printer.name, ams_label, humidity, humidity_threshold, db
  1827. )
  1828. except Exception as e:
  1829. logger.warning(f"Failed to send humidity alarm: {e}")
  1830. # Check temperature alarm (only if above threshold)
  1831. if temperature is not None and temperature > temp_threshold:
  1832. cooldown_key = f"{printer.id}:{ams_id}:temperature"
  1833. last_alarm = _ams_alarm_cooldown.get(cooldown_key)
  1834. now = datetime.now()
  1835. if (
  1836. last_alarm is None
  1837. or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60
  1838. ):
  1839. _ams_alarm_cooldown[cooldown_key] = now
  1840. logger.info(
  1841. f"Sending temperature alarm for {printer.name} {ams_label}: {temperature}°C > {temp_threshold}°C"
  1842. )
  1843. try:
  1844. # Call different notification method based on AMS type
  1845. if is_ams_ht:
  1846. await notification_service.on_ams_ht_temperature_high(
  1847. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1848. )
  1849. else:
  1850. await notification_service.on_ams_temperature_high(
  1851. printer.id, printer.name, ams_label, temperature, temp_threshold, db
  1852. )
  1853. except Exception as e:
  1854. logger.warning(f"Failed to send temperature alarm: {e}")
  1855. await db.commit()
  1856. if recorded_count > 0:
  1857. logger.info(f"Recorded {recorded_count} AMS sensor history entries")
  1858. # Periodic cleanup of old data (every ~288 recordings = ~24 hours at 5min interval)
  1859. global _ams_cleanup_counter
  1860. _ams_cleanup_counter += 1
  1861. if _ams_cleanup_counter >= 288:
  1862. _ams_cleanup_counter = 0
  1863. # Get retention days from settings
  1864. from backend.app.models.settings import Settings
  1865. result = await db.execute(select(Settings).where(Settings.key == "ams_history_retention_days"))
  1866. setting = result.scalar_one_or_none()
  1867. retention_days = int(setting.value) if setting else AMS_HISTORY_RETENTION_DAYS
  1868. cutoff = datetime.now() - timedelta(days=retention_days)
  1869. result = await db.execute(delete(AMSSensorHistory).where(AMSSensorHistory.recorded_at < cutoff))
  1870. await db.commit()
  1871. if result.rowcount > 0:
  1872. logger.info(
  1873. f"Cleaned up {result.rowcount} old AMS sensor history entries (older than {retention_days} days)"
  1874. )
  1875. # Wait until next recording interval
  1876. await asyncio.sleep(AMS_HISTORY_INTERVAL)
  1877. except asyncio.CancelledError:
  1878. break
  1879. except Exception as e:
  1880. logger.warning(f"AMS history recording failed: {e}")
  1881. await asyncio.sleep(60) # Wait a bit before retrying
  1882. def start_ams_history_recording():
  1883. """Start the AMS history recording background task."""
  1884. global _ams_history_task
  1885. if _ams_history_task is None:
  1886. _ams_history_task = asyncio.create_task(record_ams_history())
  1887. logging.getLogger(__name__).info("AMS history recording started")
  1888. def stop_ams_history_recording():
  1889. """Stop the AMS history recording background task."""
  1890. global _ams_history_task
  1891. if _ams_history_task:
  1892. _ams_history_task.cancel()
  1893. _ams_history_task = None
  1894. logging.getLogger(__name__).info("AMS history recording stopped")
  1895. # Printer runtime tracking
  1896. _runtime_tracking_task: asyncio.Task | None = None
  1897. RUNTIME_TRACKING_INTERVAL = 30 # Update every 30 seconds
  1898. async def track_printer_runtime():
  1899. """Background task to track printer active runtime (RUNNING/PAUSE states)."""
  1900. import logging
  1901. logger = logging.getLogger(__name__)
  1902. # Wait for MQTT connections to establish on startup
  1903. await asyncio.sleep(15)
  1904. while True:
  1905. try:
  1906. from backend.app.models.printer import Printer
  1907. async with async_session() as db:
  1908. # Get all active printers
  1909. result = await db.execute(select(Printer).where(Printer.is_active.is_(True)))
  1910. printers = result.scalars().all()
  1911. now = datetime.now()
  1912. updated_count = 0
  1913. needs_commit = False
  1914. for printer in printers:
  1915. # Get current state from printer manager
  1916. state = printer_manager.get_status(printer.id)
  1917. if not state:
  1918. logger.debug(f"[{printer.name}] Runtime tracking: no state available")
  1919. continue
  1920. if not state.connected:
  1921. logger.debug(f"[{printer.name}] Runtime tracking: not connected")
  1922. continue
  1923. # Check if printer is in an active state (RUNNING or PAUSE)
  1924. if state.state in ("RUNNING", "PAUSE"):
  1925. # Calculate time since last update
  1926. if printer.last_runtime_update:
  1927. elapsed = (now - printer.last_runtime_update).total_seconds()
  1928. if elapsed > 0:
  1929. printer.runtime_seconds += int(elapsed)
  1930. updated_count += 1
  1931. needs_commit = True
  1932. logger.debug(
  1933. f"[{printer.name}] Runtime tracking: added {int(elapsed)}s, "
  1934. f"total={printer.runtime_seconds}s ({printer.runtime_seconds / 3600:.2f}h)"
  1935. )
  1936. else:
  1937. # First time seeing printer active - need to commit to save timestamp
  1938. needs_commit = True
  1939. logger.debug(f"[{printer.name}] Runtime tracking: first active detection")
  1940. printer.last_runtime_update = now
  1941. else:
  1942. # Printer is idle/offline - clear last_runtime_update
  1943. if printer.last_runtime_update is not None:
  1944. logger.debug(
  1945. f"[{printer.name}] Runtime tracking: state={state.state}, clearing last_runtime_update"
  1946. )
  1947. printer.last_runtime_update = None
  1948. needs_commit = True
  1949. if needs_commit:
  1950. await db.commit()
  1951. if updated_count > 0:
  1952. logger.debug(f"Updated runtime for {updated_count} printer(s)")
  1953. except asyncio.CancelledError:
  1954. logger.info("Runtime tracking cancelled")
  1955. break
  1956. except Exception as e:
  1957. logger.warning(f"Runtime tracking failed: {e}")
  1958. await asyncio.sleep(RUNTIME_TRACKING_INTERVAL)
  1959. def start_runtime_tracking():
  1960. """Start the printer runtime tracking background task."""
  1961. global _runtime_tracking_task
  1962. if _runtime_tracking_task is None:
  1963. _runtime_tracking_task = asyncio.create_task(track_printer_runtime())
  1964. logging.getLogger(__name__).info("Printer runtime tracking started")
  1965. def stop_runtime_tracking():
  1966. """Stop the printer runtime tracking background task."""
  1967. global _runtime_tracking_task
  1968. if _runtime_tracking_task:
  1969. _runtime_tracking_task.cancel()
  1970. _runtime_tracking_task = None
  1971. logging.getLogger(__name__).info("Printer runtime tracking stopped")
  1972. @asynccontextmanager
  1973. async def lifespan(app: FastAPI):
  1974. # Startup
  1975. await init_db()
  1976. # Restore debug logging state from previous session
  1977. await init_debug_logging()
  1978. # Set up printer manager callbacks
  1979. loop = asyncio.get_event_loop()
  1980. printer_manager.set_event_loop(loop)
  1981. printer_manager.set_status_change_callback(on_printer_status_change)
  1982. printer_manager.set_print_start_callback(on_print_start)
  1983. printer_manager.set_print_complete_callback(on_print_complete)
  1984. printer_manager.set_ams_change_callback(on_ams_change)
  1985. # Layer change callback for external camera timelapse
  1986. async def on_layer_change(printer_id: int, layer_num: int):
  1987. """Capture timelapse frame on layer change."""
  1988. from backend.app.services.layer_timelapse import on_layer_change as tl_layer_change
  1989. await tl_layer_change(printer_id, layer_num)
  1990. printer_manager.set_layer_change_callback(on_layer_change)
  1991. # Initialize MQTT relay from settings
  1992. async with async_session() as db:
  1993. from backend.app.api.routes.settings import get_setting
  1994. mqtt_settings = {
  1995. "mqtt_enabled": (await get_setting(db, "mqtt_enabled") or "false") == "true",
  1996. "mqtt_broker": await get_setting(db, "mqtt_broker") or "",
  1997. "mqtt_port": int(await get_setting(db, "mqtt_port") or "1883"),
  1998. "mqtt_username": await get_setting(db, "mqtt_username") or "",
  1999. "mqtt_password": await get_setting(db, "mqtt_password") or "",
  2000. "mqtt_topic_prefix": await get_setting(db, "mqtt_topic_prefix") or "bambuddy",
  2001. "mqtt_use_tls": (await get_setting(db, "mqtt_use_tls") or "false") == "true",
  2002. }
  2003. await mqtt_relay.configure(mqtt_settings)
  2004. # Connect to all active printers
  2005. async with async_session() as db:
  2006. await init_printer_connections(db)
  2007. # Auto-connect to Spoolman if enabled
  2008. async with async_session() as db:
  2009. from backend.app.api.routes.settings import get_setting
  2010. spoolman_enabled = await get_setting(db, "spoolman_enabled")
  2011. spoolman_url = await get_setting(db, "spoolman_url")
  2012. if spoolman_enabled and spoolman_enabled.lower() == "true" and spoolman_url:
  2013. try:
  2014. client = await init_spoolman_client(spoolman_url)
  2015. if await client.health_check():
  2016. logging.info(f"Auto-connected to Spoolman at {spoolman_url}")
  2017. # Ensure the 'tag' extra field exists for RFID/UUID storage
  2018. await client.ensure_tag_extra_field()
  2019. else:
  2020. logging.warning(f"Spoolman at {spoolman_url} is not reachable")
  2021. except Exception as e:
  2022. logging.warning(f"Failed to auto-connect to Spoolman: {e}")
  2023. # Start the print scheduler
  2024. asyncio.create_task(print_scheduler.run())
  2025. # Start the smart plug scheduler for time-based on/off
  2026. smart_plug_manager.start_scheduler()
  2027. # Resume any pending auto-offs that were interrupted by restart
  2028. await smart_plug_manager.resume_pending_auto_offs()
  2029. # Start the notification digest scheduler
  2030. notification_service.start_digest_scheduler()
  2031. # Start AMS history recording
  2032. start_ams_history_recording()
  2033. # Start printer runtime tracking
  2034. start_runtime_tracking()
  2035. # Initialize virtual printer manager
  2036. from backend.app.services.virtual_printer import virtual_printer_manager
  2037. virtual_printer_manager.set_session_factory(async_session)
  2038. # Auto-start virtual printer if enabled
  2039. async with async_session() as db:
  2040. from backend.app.api.routes.settings import get_setting
  2041. vp_enabled = await get_setting(db, "virtual_printer_enabled")
  2042. if vp_enabled and vp_enabled.lower() == "true":
  2043. vp_access_code = await get_setting(db, "virtual_printer_access_code") or ""
  2044. vp_mode = await get_setting(db, "virtual_printer_mode") or "immediate"
  2045. vp_model = await get_setting(db, "virtual_printer_model") or ""
  2046. if vp_access_code:
  2047. try:
  2048. await virtual_printer_manager.configure(
  2049. enabled=True,
  2050. access_code=vp_access_code,
  2051. mode=vp_mode,
  2052. model=vp_model,
  2053. )
  2054. logging.info(f"Virtual printer started (model={vp_model or 'default'})")
  2055. except Exception as e:
  2056. logging.warning(f"Failed to start virtual printer: {e}")
  2057. yield
  2058. # Shutdown
  2059. print_scheduler.stop()
  2060. smart_plug_manager.stop_scheduler()
  2061. notification_service.stop_digest_scheduler()
  2062. stop_ams_history_recording()
  2063. stop_runtime_tracking()
  2064. printer_manager.disconnect_all()
  2065. await close_spoolman_client()
  2066. # Stop virtual printer if running
  2067. if virtual_printer_manager.is_enabled:
  2068. await virtual_printer_manager.configure(enabled=False)
  2069. app = FastAPI(
  2070. title=app_settings.app_name,
  2071. description="Archive and manage Bambu Lab 3MF files",
  2072. version=APP_VERSION,
  2073. lifespan=lifespan,
  2074. )
  2075. # API routes
  2076. app.include_router(auth.router, prefix=app_settings.api_prefix)
  2077. app.include_router(users.router, prefix=app_settings.api_prefix)
  2078. app.include_router(printers.router, prefix=app_settings.api_prefix)
  2079. app.include_router(archives.router, prefix=app_settings.api_prefix)
  2080. app.include_router(filaments.router, prefix=app_settings.api_prefix)
  2081. app.include_router(settings_routes.router, prefix=app_settings.api_prefix)
  2082. app.include_router(cloud.router, prefix=app_settings.api_prefix)
  2083. app.include_router(smart_plugs.router, prefix=app_settings.api_prefix)
  2084. app.include_router(print_queue.router, prefix=app_settings.api_prefix)
  2085. app.include_router(kprofiles.router, prefix=app_settings.api_prefix)
  2086. app.include_router(notifications.router, prefix=app_settings.api_prefix)
  2087. app.include_router(notification_templates.router, prefix=app_settings.api_prefix)
  2088. app.include_router(spoolman.router, prefix=app_settings.api_prefix)
  2089. app.include_router(updates.router, prefix=app_settings.api_prefix)
  2090. app.include_router(maintenance.router, prefix=app_settings.api_prefix)
  2091. app.include_router(camera.router, prefix=app_settings.api_prefix)
  2092. app.include_router(external_links.router, prefix=app_settings.api_prefix)
  2093. app.include_router(projects.router, prefix=app_settings.api_prefix)
  2094. app.include_router(library.router, prefix=app_settings.api_prefix)
  2095. app.include_router(api_keys.router, prefix=app_settings.api_prefix)
  2096. app.include_router(webhook.router, prefix=app_settings.api_prefix)
  2097. app.include_router(ams_history.router, prefix=app_settings.api_prefix)
  2098. app.include_router(system.router, prefix=app_settings.api_prefix)
  2099. app.include_router(support.router, prefix=app_settings.api_prefix)
  2100. app.include_router(websocket.router, prefix=app_settings.api_prefix)
  2101. app.include_router(discovery.router, prefix=app_settings.api_prefix)
  2102. app.include_router(pending_uploads.router, prefix=app_settings.api_prefix)
  2103. app.include_router(firmware.router, prefix=app_settings.api_prefix)
  2104. # Serve static files (React build)
  2105. if app_settings.static_dir.exists() and any(app_settings.static_dir.iterdir()):
  2106. app.mount(
  2107. "/assets",
  2108. StaticFiles(directory=app_settings.static_dir / "assets"),
  2109. name="assets",
  2110. )
  2111. if (app_settings.static_dir / "img").exists():
  2112. app.mount(
  2113. "/img",
  2114. StaticFiles(directory=app_settings.static_dir / "img"),
  2115. name="img",
  2116. )
  2117. if (app_settings.static_dir / "icons").exists():
  2118. app.mount(
  2119. "/icons",
  2120. StaticFiles(directory=app_settings.static_dir / "icons"),
  2121. name="icons",
  2122. )
  2123. @app.get("/")
  2124. async def serve_frontend():
  2125. """Serve the React frontend."""
  2126. index_file = app_settings.static_dir / "index.html"
  2127. if index_file.exists():
  2128. return FileResponse(index_file)
  2129. return {
  2130. "message": "Bambuddy API",
  2131. "docs": "/docs",
  2132. "frontend": "Build and place React app in /static directory",
  2133. }
  2134. @app.get("/health")
  2135. async def health_check():
  2136. """Health check endpoint."""
  2137. return {"status": "healthy"}
  2138. @app.get("/manifest.json")
  2139. async def serve_manifest():
  2140. """Serve PWA manifest."""
  2141. manifest_file = app_settings.static_dir / "manifest.json"
  2142. if manifest_file.exists():
  2143. return FileResponse(manifest_file, media_type="application/manifest+json")
  2144. return {"error": "Manifest not found"}
  2145. @app.get("/sw.js")
  2146. async def serve_service_worker():
  2147. """Serve service worker."""
  2148. sw_file = app_settings.static_dir / "sw.js"
  2149. if sw_file.exists():
  2150. return FileResponse(sw_file, media_type="application/javascript")
  2151. return {"error": "Service worker not found"}
  2152. # Catch-all route for React Router (must be last)
  2153. @app.get("/{full_path:path}")
  2154. async def serve_spa(full_path: str):
  2155. """Serve React app for client-side routing."""
  2156. # Don't intercept API routes - raise proper 404 so FastAPI can handle redirects
  2157. if full_path.startswith("api/"):
  2158. from fastapi import HTTPException
  2159. raise HTTPException(status_code=404, detail="Not found")
  2160. index_file = app_settings.static_dir / "index.html"
  2161. if index_file.exists():
  2162. return FileResponse(index_file)
  2163. return {"error": "Frontend not built"}