main.py 118 KB

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