diff --git a/backend/app/main.py b/backend/app/main.py index 05f44289a..8a418e5fd 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -1,21 +1,19 @@ import asyncio import logging -import os -from datetime import datetime, timedelta from contextlib import asynccontextmanager -from pathlib import Path +from datetime import datetime, timedelta from logging.handlers import RotatingFileHandler from fastapi import FastAPI # Import settings first for logging configuration -from backend.app.core.config import settings as app_settings, APP_VERSION +from backend.app.core.config import APP_VERSION, settings as app_settings # Configure logging based on settings # DEBUG=true -> DEBUG level, else use LOG_LEVEL setting log_level_str = "DEBUG" if app_settings.debug else app_settings.log_level.upper() log_level = getattr(logging, log_level_str, logging.INFO) -log_format = '%(asctime)s %(levelname)s [%(name)s] %(message)s' +log_format = "%(asctime)s %(levelname)s [%(name)s] %(message)s" # Create root logger root_logger = logging.getLogger() @@ -32,9 +30,9 @@ if app_settings.log_to_file: log_file = app_settings.log_dir / "bambuddy.log" file_handler = RotatingFileHandler( log_file, - maxBytes=5*1024*1024, # 5MB + maxBytes=5 * 1024 * 1024, # 5MB backupCount=3, - encoding='utf-8' + encoding="utf-8", ) file_handler.setLevel(log_level) file_handler.setFormatter(logging.Formatter(log_format)) @@ -48,32 +46,52 @@ if not app_settings.debug: logging.getLogger("httpx").setLevel(logging.WARNING) logging.info(f"Bambuddy starting - debug={app_settings.debug}, log_level={log_level_str}") -from fastapi.staticfiles import StaticFiles from fastapi.responses import FileResponse +from fastapi.staticfiles import StaticFiles +from sqlalchemy import delete, or_, select -from backend.app.core.database import init_db, async_session -from sqlalchemy import select, or_, delete -from backend.app.core.websocket import ws_manager -from backend.app.api.routes import printers, archives, websocket, filaments, cloud, smart_plugs, print_queue, kprofiles, notifications, notification_templates, spoolman, updates, maintenance, camera, external_links, projects, api_keys, webhook, ams_history, system -from backend.app.api.routes import settings as settings_routes -from backend.app.services.notification_service import notification_service -from backend.app.services.printer_manager import ( - printer_manager, - printer_state_to_dict, - init_printer_connections, +from backend.app.api.routes import ( + ams_history, + api_keys, + archives, + camera, + cloud, + external_links, + filaments, + kprofiles, + maintenance, + notification_templates, + notifications, + print_queue, + printers, + projects, + settings as settings_routes, + smart_plugs, + spoolman, + system, + updates, + webhook, + websocket, ) -from backend.app.services.print_scheduler import scheduler as print_scheduler -from backend.app.services.bambu_mqtt import PrinterState +from backend.app.api.routes.maintenance import _get_printer_maintenance_internal, ensure_default_types +from backend.app.core.database import async_session, init_db +from backend.app.core.websocket import ws_manager +from backend.app.models.smart_plug import SmartPlug from backend.app.services.archive import ArchiveService from backend.app.services.bambu_ftp import download_file_async +from backend.app.services.bambu_mqtt import PrinterState +from backend.app.services.notification_service import notification_service +from backend.app.services.print_scheduler import scheduler as print_scheduler +from backend.app.services.printer_manager import ( + init_printer_connections, + printer_manager, + printer_state_to_dict, +) from backend.app.services.smart_plug_manager import smart_plug_manager +from backend.app.services.spoolman import close_spoolman_client, get_spoolman_client, init_spoolman_client from backend.app.services.tasmota import tasmota_service -from backend.app.models.smart_plug import SmartPlug -from backend.app.services.spoolman import get_spoolman_client, init_spoolman_client, close_spoolman_client -from backend.app.api.routes.maintenance import _get_printer_maintenance_internal, ensure_default_types from backend.app.services.telemetry import start_telemetry_loop - # Track active prints: {(printer_id, filename): archive_id} _active_prints: dict[tuple[int, str], int] = {} @@ -130,13 +148,11 @@ async def _report_spoolman_usage(printer_id: int, archive_id: int, logger): # Check if Spoolman is reachable if not await client.health_check(): - logger.warning(f"Spoolman not reachable for usage reporting") + logger.warning("Spoolman not reachable for usage reporting") return # Get archive to find filament usage - result = await db.execute( - select(PrintArchive).where(PrintArchive.id == archive_id) - ) + result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) archive = result.scalar_one_or_none() if not archive or not archive.filament_used_grams: logger.debug(f"No filament usage data for archive {archive_id}") @@ -148,12 +164,12 @@ async def _report_spoolman_usage(printer_id: int, archive_id: int, logger): # Get current AMS state from printer to find the active spool state = printer_manager.get_status(printer_id) if not state or not state.raw_data: - logger.debug(f"No printer state available for usage reporting") + logger.debug("No printer state available for usage reporting") return ams_data = state.raw_data.get("ams") if not ams_data: - logger.debug(f"No AMS data available for usage reporting") + logger.debug("No AMS data available for usage reporting") return # Find spools with RFID tags in Spoolman and report usage @@ -161,7 +177,6 @@ async def _report_spoolman_usage(printer_id: int, archive_id: int, logger): # TODO: In future, track which specific trays were used during the print spools_updated = 0 for ams_unit in ams_data: - ams_id = int(ams_unit.get("id", 0)) trays = ams_unit.get("tray", []) for tray_data in trays: @@ -176,8 +191,7 @@ async def _report_spoolman_usage(printer_id: int, archive_id: int, logger): result = await client.use_spool(spool["id"], filament_used) if result: logger.info( - f"[SPOOLMAN] Reported {filament_used}g usage to spool {spool['id']} " - f"(tag: {tag_uid})" + f"[SPOOLMAN] Reported {filament_used}g usage to spool {spool['id']} " f"(tag: {tag_uid})" ) spools_updated += 1 # Only report to one spool for single-material prints @@ -204,9 +218,8 @@ async def on_printer_status_change(printer_id: int, state: PrinterState): # Update nozzle_count in database async with async_session() as db: from backend.app.models.printer import Printer - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() if printer and printer.nozzle_count != 2: printer.nozzle_count = 2 @@ -233,6 +246,7 @@ async def on_printer_status_change(printer_id: int, state: PrinterState): async def on_ams_change(printer_id: int, ams_data: list): """Handle AMS data changes - sync to Spoolman if enabled and auto mode.""" import logging + logger = logging.getLogger(__name__) try: @@ -266,9 +280,7 @@ async def on_ams_change(printer_id: int, ams_data: list): return # Get printer name for location - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() printer_name = printer.name if printer else f"Printer {printer_id}" @@ -295,6 +307,7 @@ async def on_ams_change(printer_id: int, ams_data: list): except Exception as e: import logging + logging.getLogger(__name__).warning(f"Spoolman AMS sync failed: {e}") @@ -307,19 +320,17 @@ async def _send_print_start_notification( """Helper to send print start notification with optional archive data.""" if logger is None: import logging + logger = logging.getLogger(__name__) try: async with async_session() as db: from backend.app.models.printer import Printer - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() printer_name = printer.name if printer else f"Printer {printer_id}" - await notification_service.on_print_start( - printer_id, printer_name, data, db, archive_data=archive_data - ) + await notification_service.on_print_start(printer_id, printer_name, data, db, archive_data=archive_data) except Exception as e: logger.warning(f"Notification on_print_start failed: {e}") @@ -327,6 +338,7 @@ async def _send_print_start_notification( async def on_print_start(printer_id: int, data: dict): """Handle print start - archive the 3MF file immediately.""" import logging + logger = logging.getLogger(__name__) logger.info(f"[CALLBACK] on_print_start called for printer {printer_id}, data keys: {list(data.keys())}") @@ -347,14 +359,14 @@ async def on_print_start(printer_id: int, data: dict): from backend.app.models.printer import Printer from backend.app.services.bambu_ftp import list_files_async - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() if not printer or not printer.auto_archive: # Send notification without archive data (auto-archive disabled) - logger.info(f"[CALLBACK] Skipping archive - printer: {printer is not None}, auto_archive: {printer.auto_archive if printer else 'N/A'}") + logger.info( + f"[CALLBACK] Skipping archive - printer: {printer is not None}, auto_archive: {printer.auto_archive if printer else 'N/A'}" + ) if not notification_sent: await _send_print_start_notification(printer_id, data, logger=logger) return @@ -367,7 +379,7 @@ async def on_print_start(printer_id: int, data: dict): if not filename and not subtask_name: # Send notification without archive data (no filename) - logger.info(f"[CALLBACK] Skipping archive - no filename or subtask_name") + logger.info("[CALLBACK] Skipping archive - no filename or subtask_name") if not notification_sent: await _send_print_start_notification(printer_id, data, logger=logger) return @@ -399,12 +411,11 @@ async def on_print_start(printer_id: int, data: dict): if expected_archive_id: # This is a reprint/scheduled print - use existing archive, don't create new one logger.info(f"Using expected archive {expected_archive_id} for print (skipping duplicate)") - from backend.app.models.archive import PrintArchive from datetime import datetime - result = await db.execute( - select(PrintArchive).where(PrintArchive.id == expected_archive_id) - ) + from backend.app.models.archive import PrintArchive + + result = await db.execute(select(PrintArchive).where(PrintArchive.id == expected_archive_id)) archive = result.scalar_one_or_none() if archive: @@ -420,17 +431,19 @@ async def on_print_start(printer_id: int, data: dict): # Set up energy tracking try: - plug_result = await db.execute( - select(SmartPlug).where(SmartPlug.printer_id == printer_id) - ) + plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id)) plug = plug_result.scalar_one_or_none() - logger.info(f"[ENERGY] Print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}") + logger.info( + f"[ENERGY] Print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}" + ) if plug: energy = await tasmota_service.get_energy(plug) logger.info(f"[ENERGY] Energy response from plug: {energy}") if energy and energy.get("total") is not None: _print_energy_start[archive.id] = energy["total"] - logger.info(f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh") + logger.info( + f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh" + ) else: logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}") else: @@ -438,10 +451,12 @@ async def on_print_start(printer_id: int, data: dict): except Exception as e: logger.warning(f"Failed to record starting energy: {e}") - await ws_manager.send_archive_updated({ - "id": archive.id, - "status": "printing", - }) + await ws_manager.send_archive_updated( + { + "id": archive.id, + "status": "printing", + } + ) # Send notification with archive data (reprint/scheduled) if not notification_sent: @@ -453,6 +468,7 @@ async def on_print_start(printer_id: int, data: dict): # Check if there's already a "printing" archive for this printer/file # This prevents duplicates when backend restarts during an active print from backend.app.models.archive import PrintArchive + check_name = subtask_name or filename.split("/")[-1].replace(".gcode", "").replace(".3mf", "") existing = await db.execute( select(PrintArchive) @@ -470,15 +486,15 @@ async def on_print_start(printer_id: int, data: dict): # Also set up energy tracking if not already tracked if existing_archive.id not in _print_energy_start: try: - plug_result = await db.execute( - select(SmartPlug).where(SmartPlug.printer_id == printer_id) - ) + plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id)) plug = plug_result.scalar_one_or_none() if plug: energy = await tasmota_service.get_energy(plug) if energy and energy.get("total") is not None: _print_energy_start[existing_archive.id] = energy["total"] - logger.info(f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh") + logger.info( + f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh" + ) except Exception as e: logger.warning(f"Failed to record starting energy for existing archive: {e}") # Send notification with archive data (existing archive) @@ -604,17 +620,19 @@ async def on_print_start(printer_id: int, data: dict): # Record starting energy from smart plug if available try: - plug_result = await db.execute( - select(SmartPlug).where(SmartPlug.printer_id == printer_id) - ) + plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id)) plug = plug_result.scalar_one_or_none() - logger.info(f"[ENERGY] Auto-archive print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}") + logger.info( + f"[ENERGY] Auto-archive print start - archive {archive.id}, printer {printer_id}, plug found: {plug is not None}" + ) if plug: energy = await tasmota_service.get_energy(plug) logger.info(f"[ENERGY] Auto-archive energy response: {energy}") if energy and energy.get("total") is not None: _print_energy_start[archive.id] = energy["total"] - logger.info(f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh") + logger.info( + f"[ENERGY] Recorded starting energy for archive {archive.id}: {energy['total']} kWh" + ) else: logger.warning(f"[ENERGY] No 'total' in energy response for archive {archive.id}") else: @@ -622,13 +640,15 @@ async def on_print_start(printer_id: int, data: dict): except Exception as e: logger.warning(f"Failed to record starting energy: {e}") - await ws_manager.send_archive_created({ - "id": archive.id, - "printer_id": archive.printer_id, - "filename": archive.filename, - "print_name": archive.print_name, - "status": archive.status, - }) + await ws_manager.send_archive_created( + { + "id": archive.id, + "printer_id": archive.printer_id, + "filename": archive.filename, + "print_name": archive.print_name, + "status": archive.status, + } + ) # Send notification with archive data (new archive created) if not notification_sent: @@ -643,6 +663,7 @@ async def on_print_start(printer_id: int, data: dict): async def on_print_complete(printer_id: int, data: dict): """Handle print completion - update the archive status.""" import logging + logger = logging.getLogger(__name__) logger.info(f"[CALLBACK] on_print_complete started for printer {printer_id}") @@ -656,7 +677,7 @@ async def on_print_complete(printer_id: int, data: dict): subtask_name = data.get("subtask_name", "") if not filename and not subtask_name: - logger.warning(f"Print complete without filename or subtask_name") + logger.warning("Print complete without filename or subtask_name") return logger.info(f"Print complete - filename: {filename}, subtask: {subtask_name}, status: {data.get('status')}") @@ -723,10 +744,12 @@ async def on_print_complete(printer_id: int, data: dict): select(PrintArchive) .where(PrintArchive.printer_id == printer_id) .where(PrintArchive.status == "printing") - .where(or_( - PrintArchive.print_name.ilike(f"%{subtask_name}%"), - PrintArchive.filename.ilike(f"%{subtask_name}%"), - )) + .where( + or_( + PrintArchive.print_name.ilike(f"%{subtask_name}%"), + PrintArchive.filename.ilike(f"%{subtask_name}%"), + ) + ) .order_by(PrintArchive.created_at.desc()) .limit(1) ) @@ -759,17 +782,49 @@ async def on_print_complete(printer_id: int, data: dict): async with async_session() as db: service = ArchiveService(db) status = data.get("status", "completed") + + # Auto-detect failure reason + failure_reason = None + if status == "aborted": + failure_reason = "User cancelled" + logger.info("[ARCHIVE] Print was aborted by user, setting failure_reason='User cancelled'") + elif status == "failed": + # Try to determine failure reason from HMS errors + hms_errors = data.get("hms_errors", []) + if hms_errors: + logger.info(f"[ARCHIVE] HMS errors at failure: {hms_errors}") + # Map known HMS error modules to failure reasons + # Module 0x07 = Filament, 0x0C = MC (Motion Controller), etc. + for err in hms_errors: + module = err.get("module", 0) + if module == 0x07: # Filament module + failure_reason = "Filament runout" + break + elif module == 0x0C: # Motion controller + failure_reason = "Layer shift" + break + elif module == 0x05: # Nozzle/extruder + failure_reason = "Clogged nozzle" + break + if failure_reason: + logger.info(f"[ARCHIVE] Detected failure_reason from HMS: {failure_reason}") + else: + logger.info("[ARCHIVE] No HMS errors available to determine failure reason") + await service.update_archive_status( archive_id, status=status, completed_at=datetime.now() if status in ("completed", "failed", "aborted") else None, + failure_reason=failure_reason, ) - logger.info(f"[ARCHIVE] Archive {archive_id} status updated to {status}") + logger.info(f"[ARCHIVE] Archive {archive_id} status updated to {status}, failure_reason={failure_reason}") - await ws_manager.send_archive_updated({ - "id": archive_id, - "status": status, - }) + await ws_manager.send_archive_updated( + { + "id": archive_id, + "status": status, + } + ) logger.info(f"[ARCHIVE] WebSocket notification sent for archive {archive_id}") except Exception as e: logger.error(f"[ARCHIVE] Failed to update archive {archive_id} status: {e}", exc_info=True) @@ -789,9 +844,7 @@ async def on_print_complete(printer_id: int, data: dict): async with async_session() as db: # Get smart plug for this printer (SmartPlug is imported at module level) - plug_result = await db.execute( - select(SmartPlug).where(SmartPlug.printer_id == printer_id) - ) + plug_result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id)) plug = plug_result.scalar_one_or_none() if plug: @@ -804,24 +857,26 @@ async def on_print_complete(printer_id: int, data: dict): if starting_kwh is not None and energy and energy.get("total") is not None: ending_kwh = energy["total"] energy_used = round(ending_kwh - starting_kwh, 4) - logger.info(f"[ENERGY] Per-print energy: ending={ending_kwh}, starting={starting_kwh}, used={energy_used}") + logger.info( + f"[ENERGY] Per-print energy: ending={ending_kwh}, starting={starting_kwh}, used={energy_used}" + ) elif starting_kwh is None: - logger.info(f"[ENERGY] No starting energy recorded for this archive") + logger.info("[ENERGY] No starting energy recorded for this archive") else: - logger.warning(f"[ENERGY] No 'total' in ending energy response") + logger.warning("[ENERGY] No 'total' in ending energy response") if energy_used is not None and energy_used >= 0: # Get energy cost per kWh from settings (default to 0.15) from backend.app.api.routes.settings import get_setting + energy_cost_per_kwh = await get_setting(db, "energy_cost_per_kwh") cost_per_kwh = float(energy_cost_per_kwh) if energy_cost_per_kwh else 0.15 energy_cost = round(energy_used * cost_per_kwh, 2) # Update archive with energy data from backend.app.models.archive import PrintArchive - result = await db.execute( - select(PrintArchive).where(PrintArchive.id == archive_id) - ) + + result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) archive = result.scalar_one_or_none() if archive: archive.energy_kwh = energy_used @@ -834,6 +889,7 @@ async def on_print_complete(printer_id: int, data: dict): logger.info(f"[ENERGY] No smart plug found for printer {printer_id} at print complete") except Exception as e: import logging + logging.getLogger(__name__).warning(f"Failed to calculate energy: {e}") # Capture finish photo from printer camera @@ -842,28 +898,28 @@ async def on_print_complete(printer_id: int, data: dict): async with async_session() as db: # Check if finish photo capture is enabled from backend.app.api.routes.settings import get_setting + capture_enabled = await get_setting(db, "capture_finish_photo") logger.info(f"[PHOTO] capture_finish_photo setting: {capture_enabled}") if capture_enabled is None or capture_enabled.lower() == "true": # Get printer details from backend.app.models.printer import Printer - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() if printer and archive_id: # Get archive to find its directory from backend.app.models.archive import PrintArchive - result = await db.execute( - select(PrintArchive).where(PrintArchive.id == archive_id) - ) + + result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) archive = result.scalar_one_or_none() if archive: - from backend.app.services.camera import capture_finish_photo from pathlib import Path + from backend.app.services.camera import capture_finish_photo + archive_dir = app_settings.base_dir / Path(archive.file_path).parent photo_filename = await capture_finish_photo( printer_id=printer_id, @@ -882,6 +938,7 @@ async def on_print_complete(printer_id: int, data: dict): logger.info(f"Added finish photo to archive {archive_id}: {photo_filename}") except Exception as e: import logging + logging.getLogger(__name__).warning(f"Finish photo capture failed: {e}") # Smart plug automation: schedule turn off when print completes @@ -890,19 +947,19 @@ async def on_print_complete(printer_id: int, data: dict): async with async_session() as db: status = data.get("status", "completed") await smart_plug_manager.on_print_complete(printer_id, status, db) - logger.info(f"[AUTO-OFF] smart_plug_manager.on_print_complete completed") + logger.info("[AUTO-OFF] smart_plug_manager.on_print_complete completed") except Exception as e: import logging + logging.getLogger(__name__).warning(f"Smart plug on_print_complete failed: {e}") # Send print complete notifications try: async with async_session() as db: - from backend.app.models.printer import Printer from backend.app.models.archive import PrintArchive - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + from backend.app.models.printer import Printer + + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() printer_name = printer.name if printer else f"Printer {printer_id}" status = data.get("status", "completed") @@ -910,9 +967,7 @@ async def on_print_complete(printer_id: int, data: dict): # Fetch archive data for notification variables archive_data = None if archive_id: - archive_result = await db.execute( - select(PrintArchive).where(PrintArchive.id == archive_id) - ) + archive_result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) archive = archive_result.scalar_one_or_none() if archive: archive_data = { @@ -927,6 +982,7 @@ async def on_print_complete(printer_id: int, data: dict): ) except Exception as e: import logging + logging.getLogger(__name__).warning(f"Notification on_print_complete failed: {e}") # Check for maintenance due and send notifications (only for completed prints) @@ -936,9 +992,7 @@ async def on_print_complete(printer_id: int, data: dict): from backend.app.models.printer import Printer # Get printer name - result = await db.execute( - select(Printer).where(Printer.id == printer_id) - ) + result = await db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() printer_name = printer.name if printer else f"Printer {printer_id}" @@ -958,15 +1012,14 @@ async def on_print_complete(printer_id: int, data: dict): ] if items_needing_attention: - await notification_service.on_maintenance_due( - printer_id, printer_name, items_needing_attention, db - ) + await notification_service.on_maintenance_due(printer_id, printer_name, items_needing_attention, db) logger.info( f"Sent maintenance notification for printer {printer_id}: " f"{len(items_needing_attention)} items need attention" ) except Exception as e: import logging + logging.getLogger(__name__).warning(f"Maintenance notification check failed: {e}") # Auto-scan for timelapse if recording was active during the print @@ -977,15 +1030,16 @@ async def on_print_complete(printer_id: int, data: dict): await asyncio.sleep(5) async with async_session() as db: - from backend.app.models.printer import Printer + from datetime import timedelta + from pathlib import Path + from backend.app.models.archive import PrintArchive + from backend.app.models.printer import Printer + # NOTE: ArchiveService is imported at module level (line 67) # Do NOT import it here - it causes a Python scoping issue that breaks # the earlier usage of ArchiveService in this function - from backend.app.services.bambu_ftp import list_files_async, download_file_bytes_async - from pathlib import Path - import re - from datetime import timedelta + from backend.app.services.bambu_ftp import download_file_bytes_async, list_files_async # Get archive (ArchiveService from module-level import) service = ArchiveService(db) @@ -1013,7 +1067,9 @@ async def on_print_complete(printer_id: int, data: dict): continue if files: - mp4_files = [f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4")] + mp4_files = [ + f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4") + ] # Strategy: Find most recent timelapse by mtime # Since we know timelapse was active during this print, use the most recent file @@ -1029,8 +1085,10 @@ async def on_print_complete(printer_id: int, data: dict): archive_completed = archive.completed_at or datetime.now() if file_mtime and abs(file_mtime - archive_completed) < timedelta(minutes=30): # Download and attach - logger.info(f"[TIMELAPSE] Downloading timelapse {most_recent['name']} for archive {archive_id}") - remote_path = most_recent.get('path') or f"/timelapse/{most_recent['name']}" + logger.info( + f"[TIMELAPSE] Downloading timelapse {most_recent['name']} for archive {archive_id}" + ) + remote_path = most_recent.get("path") or f"/timelapse/{most_recent['name']}" timelapse_data = await download_file_bytes_async( printer.ip_address, printer.access_code, remote_path ) @@ -1040,25 +1098,34 @@ async def on_print_complete(printer_id: int, data: dict): archive_id, timelapse_data, most_recent["name"] ) if success: - logger.info(f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}") - await ws_manager.send_archive_updated({ - "id": archive_id, - "timelapse_attached": True, - }) + logger.info( + f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}" + ) + await ws_manager.send_archive_updated( + { + "id": archive_id, + "timelapse_attached": True, + } + ) else: - logger.warning(f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}") + logger.warning( + f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}" + ) else: - logger.warning(f"[TIMELAPSE] Failed to download timelapse file") + logger.warning("[TIMELAPSE] Failed to download timelapse file") else: - logger.info(f"[TIMELAPSE] Most recent timelapse mtime too far from print completion") + logger.info( + "[TIMELAPSE] Most recent timelapse mtime too far from print completion" + ) else: - logger.info(f"[TIMELAPSE] No timelapse files with mtime found") + logger.info("[TIMELAPSE] No timelapse files with mtime found") else: - logger.info(f"[TIMELAPSE] No timelapse files found on printer") + logger.info("[TIMELAPSE] No timelapse files found on printer") else: logger.warning(f"[TIMELAPSE] Printer not found for archive {archive_id}") except Exception as e: import logging + logging.getLogger(__name__).warning(f"Timelapse auto-scan failed: {e}") # Update queue item if this was a scheduled print @@ -1084,9 +1151,7 @@ async def on_print_complete(printer_id: int, data: dict): # Handle auto_off_after - power off printer if requested (after cooldown) if queue_item.auto_off_after: - result = await db.execute( - select(SmartPlug).where(SmartPlug.printer_id == printer_id) - ) + result = await db.execute(select(SmartPlug).where(SmartPlug.printer_id == printer_id)) plug = result.scalar_one_or_none() if plug and plug.enabled: logger.info(f"Auto-off requested for printer {printer_id}, waiting for cooldown...") @@ -1096,9 +1161,7 @@ async def on_print_complete(printer_id: int, data: dict): await printer_manager.wait_for_cooldown(pid, target_temp=50.0, timeout=600) # Re-fetch plug in new session async with async_session() as new_db: - result = await new_db.execute( - select(SmartPlug).where(SmartPlug.id == plug_id) - ) + result = await new_db.execute(select(SmartPlug).where(SmartPlug.id == plug_id)) p = result.scalar_one_or_none() if p and p.enabled: success = await tasmota_service.turn_off(p) @@ -1110,6 +1173,7 @@ async def on_print_complete(printer_id: int, data: dict): asyncio.create_task(cooldown_and_poweroff(printer_id, plug.id)) except Exception as e: import logging + logging.getLogger(__name__).warning(f"Queue item update failed: {e}") logger.info(f"[CALLBACK] on_print_complete finished for printer {printer_id}, archive {archive_id}") @@ -1127,6 +1191,7 @@ AMS_ALARM_COOLDOWN_MINUTES = 60 # Don't send same alarm more than once per hour async def record_ams_history(): """Background task to record AMS humidity and temperature data.""" import logging + logger = logging.getLogger(__name__) # Wait a short time for MQTT connections to establish on startup @@ -1140,9 +1205,7 @@ async def record_ams_history(): async with async_session() as db: # Get all active printers - result = await db.execute( - select(Printer).where(Printer.is_active == True) - ) + result = await db.execute(select(Printer).where(Printer.is_active.is_(True))) printers = result.scalars().all() # Get alarm thresholds from settings @@ -1229,9 +1292,14 @@ async def record_ams_history(): cooldown_key = f"{printer.id}:{ams_id}:humidity" last_alarm = _ams_alarm_cooldown.get(cooldown_key) now = datetime.now() - if last_alarm is None or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60: + if ( + last_alarm is None + or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60 + ): _ams_alarm_cooldown[cooldown_key] = now - logger.info(f"Sending humidity alarm for {printer.name} {ams_label}: {humidity}% > {humidity_threshold}%") + logger.info( + f"Sending humidity alarm for {printer.name} {ams_label}: {humidity}% > {humidity_threshold}%" + ) try: # Call different notification method based on AMS type if is_ams_ht: @@ -1250,9 +1318,14 @@ async def record_ams_history(): cooldown_key = f"{printer.id}:{ams_id}:temperature" last_alarm = _ams_alarm_cooldown.get(cooldown_key) now = datetime.now() - if last_alarm is None or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60: + if ( + last_alarm is None + or (now - last_alarm).total_seconds() >= AMS_ALARM_COOLDOWN_MINUTES * 60 + ): _ams_alarm_cooldown[cooldown_key] = now - logger.info(f"Sending temperature alarm for {printer.name} {ams_label}: {temperature}°C > {temp_threshold}°C") + logger.info( + f"Sending temperature alarm for {printer.name} {ams_label}: {temperature}°C > {temp_threshold}°C" + ) try: # Call different notification method based on AMS type if is_ams_ht: @@ -1277,19 +1350,18 @@ async def record_ams_history(): _ams_cleanup_counter = 0 # Get retention days from settings from backend.app.models.settings import Settings - result = await db.execute( - select(Settings).where(Settings.key == "ams_history_retention_days") - ) + + result = await db.execute(select(Settings).where(Settings.key == "ams_history_retention_days")) setting = result.scalar_one_or_none() retention_days = int(setting.value) if setting else AMS_HISTORY_RETENTION_DAYS cutoff = datetime.now() - timedelta(days=retention_days) - result = await db.execute( - delete(AMSSensorHistory).where(AMSSensorHistory.recorded_at < cutoff) - ) + result = await db.execute(delete(AMSSensorHistory).where(AMSSensorHistory.recorded_at < cutoff)) await db.commit() if result.rowcount > 0: - logger.info(f"Cleaned up {result.rowcount} old AMS sensor history entries (older than {retention_days} days)") + logger.info( + f"Cleaned up {result.rowcount} old AMS sensor history entries (older than {retention_days} days)" + ) # Wait until next recording interval await asyncio.sleep(AMS_HISTORY_INTERVAL) @@ -1338,6 +1410,7 @@ async def lifespan(app: FastAPI): # Auto-connect to Spoolman if enabled async with async_session() as db: from backend.app.api.routes.settings import get_setting + spoolman_enabled = await get_setting(db, "spoolman_enabled") spoolman_url = await get_setting(db, "spoolman_url") diff --git a/backend/app/services/archive.py b/backend/app/services/archive.py index 1e7993beb..e07149708 100644 --- a/backend/app/services/archive.py +++ b/backend/app/services/archive.py @@ -1,19 +1,19 @@ import hashlib import json import re -import zipfile import shutil +import zipfile from datetime import datetime from pathlib import Path from xml.etree import ElementTree as ET +from sqlalchemy import and_, or_, select from sqlalchemy.ext.asyncio import AsyncSession -from sqlalchemy import select, and_, or_ from backend.app.core.config import settings from backend.app.models.archive import PrintArchive -from backend.app.models.printer import Printer from backend.app.models.filament import Filament +from backend.app.models.printer import Printer class ThreeMFParser: @@ -116,19 +116,20 @@ class ThreeMFParser: def _parse_gcode_header(self, zf: zipfile.ZipFile): """Parse G-code file header for total layer count.""" import re + try: # Look for plate_1.gcode or similar - gcode_files = [f for f in zf.namelist() if f.endswith('.gcode')] + gcode_files = [f for f in zf.namelist() if f.endswith(".gcode")] if not gcode_files: return # Read first 2KB of G-code (header contains the layer count) gcode_path = gcode_files[0] with zf.open(gcode_path) as f: - header = f.read(2048).decode('utf-8', errors='ignore') + header = f.read(2048).decode("utf-8", errors="ignore") # Look for "; total layer number: XX" pattern - match = re.search(r';\s*total\s+layer\s+number[:\s]+(\d+)', header, re.IGNORECASE) + match = re.search(r";\s*total\s+layer\s+number[:\s]+(\d+)", header, re.IGNORECASE) if match: self.metadata["total_layers"] = int(match.group(1)) except Exception: @@ -149,8 +150,8 @@ class ThreeMFParser: non_support_colors = [] for i, ftype in enumerate(filament_types): - is_support = filament_is_support[i] if i < len(filament_is_support) else '0' - if is_support == '0': + is_support = filament_is_support[i] if i < len(filament_is_support) else "0" + if is_support == "0": if ftype and ftype not in non_support_types: non_support_types.append(ftype) if i < len(filament_colors) and filament_colors[i]: @@ -243,6 +244,7 @@ class ThreeMFParser: def _parse_3dmodel(self, zf: zipfile.ZipFile): """Parse 3D/3dmodel.model for MakerWorld metadata.""" import re + try: model_path = "3D/3dmodel.model" if model_path not in zf.namelist(): @@ -270,7 +272,7 @@ class ThreeMFParser: # Format: https://makerworld.bblmw.com/makerworld/model/DSM00000001275614/... # The numeric part (1275614) is the MakerWorld model ID if "makerworld_url" not in self.metadata: - dsm_pattern = r'DSM0+(\d+)' + dsm_pattern = r"DSM0+(\d+)" dsm_match = re.search(dsm_pattern, content) if dsm_match: model_id = dsm_match.group(1) @@ -298,11 +300,13 @@ class ThreeMFParser: thumbnail_paths.append(f"Metadata/plate_{self.plate_number}.png") # Fallback to default paths - thumbnail_paths.extend([ - "Metadata/plate_1.png", - "Metadata/thumbnail.png", - "Metadata/model_thumbnail.png", - ]) + thumbnail_paths.extend( + [ + "Metadata/plate_1.png", + "Metadata/thumbnail.png", + "Metadata/model_thumbnail.png", + ] + ) for thumb_path in thumbnail_paths: if thumb_path in zf.namelist(): @@ -386,36 +390,43 @@ class ProjectPageParser: prev = decoded decoded = html.unescape(decoded) # Normalize non-breaking spaces to regular spaces - decoded = decoded.replace('\xa0', ' ') + decoded = decoded.replace("\xa0", " ") result[field_mapping[name]] = decoded if decoded else None # List images in Auxiliaries folder from urllib.parse import quote + for name in zf.namelist(): if name.startswith("Auxiliaries/Model Pictures/"): filename = name.split("/")[-1] if filename: - result["model_pictures"].append({ - "name": filename, - "path": name, - "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", - }) + result["model_pictures"].append( + { + "name": filename, + "path": name, + "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", + } + ) elif name.startswith("Auxiliaries/Profile Pictures/"): filename = name.split("/")[-1] if filename: - result["profile_pictures"].append({ - "name": filename, - "path": name, - "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", - }) + result["profile_pictures"].append( + { + "name": filename, + "path": name, + "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", + } + ) elif name.startswith("Auxiliaries/.thumbnails/"): filename = name.split("/")[-1] if filename: - result["thumbnails"].append({ - "name": filename, - "path": name, - "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", - }) + result["thumbnails"].append( + { + "name": filename, + "path": name, + "url": f"/api/v1/archives/{archive_id}/project-image/{quote(name, safe='')}", + } + ) except Exception as e: result["_error"] = str(e) @@ -485,7 +496,7 @@ class ProjectPageParser: new_value = html.escape(updates[field]) # Replace existing metadata or we'd need to add it pattern = rf'(]*>)[^<]*()' - replacement = rf'\g<1>{new_value}\g<2>' + replacement = rf"\g<1>{new_value}\g<2>" content = re.sub(pattern, replacement, content) # Write to a temporary file first @@ -569,12 +580,14 @@ class ArchiveService: .limit(10) ) for archive in result.scalars().all(): - duplicates.append({ - "id": archive.id, - "print_name": archive.print_name, - "created_at": archive.created_at, - "match_type": "exact", - }) + duplicates.append( + { + "id": archive.id, + "print_name": archive.print_name, + "created_at": archive.created_at, + "match_type": "exact", + } + ) # Then, find similar matches by print name or MakerWorld ID if print_name or makerworld_model_id: @@ -587,29 +600,29 @@ class ArchiveService: if makerworld_model_id: # Match by MakerWorld model ID stored in extra_data # Use json_extract for SQLite compatibility (astext is PostgreSQL-only) - from sqlalchemy import func, cast, String + from sqlalchemy import func + name_conditions.append( - func.json_extract(PrintArchive.extra_data, '$.makerworld_model_id') == str(makerworld_model_id) + func.json_extract(PrintArchive.extra_data, "$.makerworld_model_id") == str(makerworld_model_id) ) if name_conditions: conditions.append(or_(*name_conditions)) result = await self.db.execute( - select(PrintArchive) - .where(and_(*conditions)) - .order_by(PrintArchive.created_at.desc()) - .limit(10) + select(PrintArchive).where(and_(*conditions)).order_by(PrintArchive.created_at.desc()).limit(10) ) for archive in result.scalars().all(): # Don't add if already in duplicates (exact match) if not any(d["id"] == archive.id for d in duplicates): - duplicates.append({ - "id": archive.id, - "print_name": archive.print_name, - "created_at": archive.created_at, - "match_type": "similar", - }) + duplicates.append( + { + "id": archive.id, + "print_name": archive.print_name, + "created_at": archive.created_at, + "match_type": "similar", + } + ) return duplicates @@ -622,9 +635,7 @@ class ArchiveService: """Archive a 3MF file with metadata.""" # Verify printer exists if specified if printer_id is not None: - result = await self.db.execute( - select(Printer).where(Printer.id == printer_id) - ) + result = await self.db.execute(select(Printer).where(Printer.id == printer_id)) printer = result.scalar_one_or_none() if not printer: return None @@ -648,7 +659,7 @@ class ArchiveService: plate_number = None if print_data: filename = print_data.get("filename", "") - match = re.search(r'plate_(\d+)', filename) + match = re.search(r"plate_(\d+)", filename) if match: plate_number = int(match.group(1)) @@ -682,9 +693,7 @@ class ArchiveService: # For multi-material prints, use the first filament type for cost calculation primary_type = filament_type.split(",")[0].strip() # Look up filament cost_per_kg from database - filament_result = await self.db.execute( - select(Filament).where(Filament.type == primary_type).limit(1) - ) + filament_result = await self.db.execute(select(Filament).where(Filament.type == primary_type).limit(1)) filament = filament_result.scalar_one_or_none() if filament: cost = round((filament_grams / 1000) * filament.cost_per_kg, 2) @@ -728,9 +737,7 @@ class ArchiveService: async def get_archive(self, archive_id: int) -> PrintArchive | None: """Get an archive by ID.""" - result = await self.db.execute( - select(PrintArchive).where(PrintArchive.id == archive_id) - ) + result = await self.db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) return result.scalar_one_or_none() async def update_archive_status( @@ -738,6 +745,7 @@ class ArchiveService: archive_id: int, status: str, completed_at: datetime | None = None, + failure_reason: str | None = None, ) -> bool: """Update the status of an archive.""" archive = await self.get_archive(archive_id) @@ -747,6 +755,8 @@ class ArchiveService: archive.status = status if completed_at: archive.completed_at = completed_at + if failure_reason: + archive.failure_reason = failure_reason await self.db.commit() return True @@ -762,9 +772,7 @@ class ArchiveService: from sqlalchemy.orm import selectinload query = ( - select(PrintArchive) - .options(selectinload(PrintArchive.project)) - .order_by(PrintArchive.created_at.desc()) + select(PrintArchive).options(selectinload(PrintArchive.project)).order_by(PrintArchive.created_at.desc()) ) if printer_id: diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 151075d43..bbad81216 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -7,15 +7,15 @@ This was discovered when K-profile requests with qos=0 took 20-30 seconds, but with qos=1 they respond instantly. """ -import json -import ssl import asyncio +import json import logging +import ssl import time from collections import deque -from datetime import datetime -from typing import Callable +from collections.abc import Callable from dataclasses import dataclass, field +from datetime import datetime import paho.mqtt.client as mqtt @@ -25,6 +25,7 @@ logger = logging.getLogger(__name__) @dataclass class MQTTLogEntry: """Log entry for MQTT message debugging.""" + timestamp: str topic: str direction: str # "in" or "out" @@ -34,6 +35,7 @@ class MQTTLogEntry: @dataclass class HMSError: """Health Management System error from printer.""" + code: str attr: int # Attribute value for constructing wiki URL module: int @@ -44,6 +46,7 @@ class HMSError: @dataclass class KProfile: """Pressure advance (K) calibration profile from printer.""" + slot_id: int extruder_id: int nozzle_id: str @@ -60,6 +63,7 @@ class KProfile: @dataclass class NozzleInfo: """Nozzle hardware configuration.""" + nozzle_type: str = "" # "stainless_steel" or "hardened_steel" nozzle_diameter: str = "" # e.g., "0.4" @@ -67,6 +71,7 @@ class NozzleInfo: @dataclass class PrintOptions: """AI detection and print options from xcam data.""" + # Core AI detectors spaghetti_detector: bool = False print_halt: bool = False @@ -131,7 +136,7 @@ class PrinterState: # Main status: 0=idle, 1=filament_change, 2=rfid_identifying, 3=assist, 4=calibration, etc. ams_status: int = 0 ams_status_main: int = 0 # (ams_status >> 8) & 0xFF - ams_status_sub: int = 0 # ams_status & 0xFF + ams_status_sub: int = 0 # ams_status & 0xFF # mc_print_sub_stage - filament change step indicator from print.mc_print_sub_stage # Used by OrcaSlicer/BambuStudio to track progress during filament load/unload mc_print_sub_stage: int = 0 @@ -338,17 +343,19 @@ class BambuMQTTClient: self._last_message_time = time.time() self.state.connected = True # TEMP: Dump full payload once to find extruder state field - if not hasattr(self, '_payload_dumped'): + if not hasattr(self, "_payload_dumped"): self._payload_dumped = True logger.info(f"[{self.serial_number}] FULL MQTT PAYLOAD DUMP:\n{json.dumps(payload, indent=2)}") # Log message if logging is enabled if self._logging_enabled: - self._message_log.append(MQTTLogEntry( - timestamp=datetime.now().isoformat(), - topic=msg.topic, - direction="in", - payload=payload, - )) + self._message_log.append( + MQTTLogEntry( + timestamp=datetime.now().isoformat(), + topic=msg.topic, + direction="in", + payload=payload, + ) + ) self._process_message(payload) except json.JSONDecodeError: pass @@ -416,7 +423,7 @@ class BambuMQTTClient: vt_tray = print_data["vt_tray"] self.state.raw_data["vt_tray"] = vt_tray # Log vt_tray to investigate per-extruder data for H2D - if not hasattr(self, '_vt_tray_logged') or not self._vt_tray_logged: + if not hasattr(self, "_vt_tray_logged") or not self._vt_tray_logged: logger.info(f"[{self.serial_number}] vt_tray data: {vt_tray}") self._vt_tray_logged = True @@ -492,9 +499,7 @@ class BambuMQTTClient: if elapsed > self._xcam_hold_time: # Hold timer expired - accept incoming and clear hold del self._xcam_hold_start[module_name] - logger.debug( - f"[{self.serial_number}] Hold expired for {module_name}, accepting {incoming_value}" - ) + logger.debug(f"[{self.serial_number}] Hold expired for {module_name}, accepting {incoming_value}") return True # Within hold period - ignore incoming data @@ -531,7 +536,9 @@ class BambuMQTTClient: if should_accept_value("spaghetti_detector", cfg_spaghetti): old_value = self.state.print_options.spaghetti_detector if cfg_spaghetti != old_value: - logger.info(f"[{self.serial_number}] spaghetti_detector changed (from cfg): {old_value} -> {cfg_spaghetti}") + logger.info( + f"[{self.serial_number}] spaghetti_detector changed (from cfg): {old_value} -> {cfg_spaghetti}" + ) self.state.print_options.spaghetti_detector = cfg_spaghetti # Check hold timer for sensitivity before accepting @@ -564,19 +571,25 @@ class BambuMQTTClient: cfg_pileup, cfg_pileup_sens = decode_detector(8) if should_accept_value("pileup_detector", cfg_pileup): if cfg_pileup != self.state.print_options.pileup_detector: - logger.info(f"[{self.serial_number}] pileup_detector changed (from cfg): {self.state.print_options.pileup_detector} -> {cfg_pileup}") + logger.info( + f"[{self.serial_number}] pileup_detector changed (from cfg): {self.state.print_options.pileup_detector} -> {cfg_pileup}" + ) self.state.print_options.pileup_detector = cfg_pileup # Pileup sensitivity with hold timer if "pileup_sensitivity" not in self._xcam_hold_start: if cfg_pileup_sens != self.state.print_options.pileup_sensitivity: - logger.info(f"[{self.serial_number}] pileup_sensitivity changed (from cfg): {self.state.print_options.pileup_sensitivity} -> {cfg_pileup_sens}") + logger.info( + f"[{self.serial_number}] pileup_sensitivity changed (from cfg): {self.state.print_options.pileup_sensitivity} -> {cfg_pileup_sens}" + ) self.state.print_options.pileup_sensitivity = cfg_pileup_sens else: hold_start = self._xcam_hold_start["pileup_sensitivity"] elapsed = current_time - hold_start if elapsed > self._xcam_hold_time: if cfg_pileup_sens != self.state.print_options.pileup_sensitivity: - logger.info(f"[{self.serial_number}] pileup_sensitivity synced (from cfg after hold): {self.state.print_options.pileup_sensitivity} -> {cfg_pileup_sens}") + logger.info( + f"[{self.serial_number}] pileup_sensitivity synced (from cfg after hold): {self.state.print_options.pileup_sensitivity} -> {cfg_pileup_sens}" + ) self.state.print_options.pileup_sensitivity = cfg_pileup_sens del self._xcam_hold_start["pileup_sensitivity"] @@ -584,19 +597,25 @@ class BambuMQTTClient: cfg_clump, cfg_clump_sens = decode_detector(11) if should_accept_value("clump_detector", cfg_clump): if cfg_clump != self.state.print_options.nozzle_clumping_detector: - logger.info(f"[{self.serial_number}] nozzle_clumping_detector changed (from cfg): {self.state.print_options.nozzle_clumping_detector} -> {cfg_clump}") + logger.info( + f"[{self.serial_number}] nozzle_clumping_detector changed (from cfg): {self.state.print_options.nozzle_clumping_detector} -> {cfg_clump}" + ) self.state.print_options.nozzle_clumping_detector = cfg_clump # Clump sensitivity with hold timer if "nozzle_clumping_sensitivity" not in self._xcam_hold_start: if cfg_clump_sens != self.state.print_options.nozzle_clumping_sensitivity: - logger.info(f"[{self.serial_number}] nozzle_clumping_sensitivity changed (from cfg): {self.state.print_options.nozzle_clumping_sensitivity} -> {cfg_clump_sens}") + logger.info( + f"[{self.serial_number}] nozzle_clumping_sensitivity changed (from cfg): {self.state.print_options.nozzle_clumping_sensitivity} -> {cfg_clump_sens}" + ) self.state.print_options.nozzle_clumping_sensitivity = cfg_clump_sens else: hold_start = self._xcam_hold_start["nozzle_clumping_sensitivity"] elapsed = current_time - hold_start if elapsed > self._xcam_hold_time: if cfg_clump_sens != self.state.print_options.nozzle_clumping_sensitivity: - logger.info(f"[{self.serial_number}] nozzle_clumping_sensitivity synced (from cfg after hold): {self.state.print_options.nozzle_clumping_sensitivity} -> {cfg_clump_sens}") + logger.info( + f"[{self.serial_number}] nozzle_clumping_sensitivity synced (from cfg after hold): {self.state.print_options.nozzle_clumping_sensitivity} -> {cfg_clump_sens}" + ) self.state.print_options.nozzle_clumping_sensitivity = cfg_clump_sens del self._xcam_hold_start["nozzle_clumping_sensitivity"] @@ -604,19 +623,25 @@ class BambuMQTTClient: cfg_airprint, cfg_airprint_sens = decode_detector(14) if should_accept_value("airprint_detector", cfg_airprint): if cfg_airprint != self.state.print_options.airprint_detector: - logger.info(f"[{self.serial_number}] airprint_detector changed (from cfg): {self.state.print_options.airprint_detector} -> {cfg_airprint}") + logger.info( + f"[{self.serial_number}] airprint_detector changed (from cfg): {self.state.print_options.airprint_detector} -> {cfg_airprint}" + ) self.state.print_options.airprint_detector = cfg_airprint # Airprint sensitivity with hold timer if "airprint_sensitivity" not in self._xcam_hold_start: if cfg_airprint_sens != self.state.print_options.airprint_sensitivity: - logger.info(f"[{self.serial_number}] airprint_sensitivity changed (from cfg): {self.state.print_options.airprint_sensitivity} -> {cfg_airprint_sens}") + logger.info( + f"[{self.serial_number}] airprint_sensitivity changed (from cfg): {self.state.print_options.airprint_sensitivity} -> {cfg_airprint_sens}" + ) self.state.print_options.airprint_sensitivity = cfg_airprint_sens else: hold_start = self._xcam_hold_start["airprint_sensitivity"] elapsed = current_time - hold_start if elapsed > self._xcam_hold_time: if cfg_airprint_sens != self.state.print_options.airprint_sensitivity: - logger.info(f"[{self.serial_number}] airprint_sensitivity synced (from cfg after hold): {self.state.print_options.airprint_sensitivity} -> {cfg_airprint_sens}") + logger.info( + f"[{self.serial_number}] airprint_sensitivity synced (from cfg after hold): {self.state.print_options.airprint_sensitivity} -> {cfg_airprint_sens}" + ) self.state.print_options.airprint_sensitivity = cfg_airprint_sens del self._xcam_hold_start["airprint_sensitivity"] @@ -782,7 +807,7 @@ class BambuMQTTClient: # Extract ams_extruder_map from each AMS unit's info field # According to OpenBambuAPI: info field bit 8 indicates which extruder (0=right, 1=left) # Log AMS unit fields once to discover available fields - if not hasattr(self, '_ams_fields_logged') and ams_list: + if not hasattr(self, "_ams_fields_logged") and ams_list: first_unit = ams_list[0] logger.info(f"[{self.serial_number}] AMS unit fields: {sorted(first_unit.keys())}") for ams_unit in ams_list: @@ -804,7 +829,9 @@ class BambuMQTTClient: bit8 = (info_val >> 8) & 0x1 extruder_id = 1 - bit8 # 0=right, 1=left ams_extruder_map[str(ams_id)] = extruder_id - logger.debug(f"[{self.serial_number}] AMS {ams_id} info={info_val} (bit8={bit8}) -> extruder {extruder_id}") + logger.debug( + f"[{self.serial_number}] AMS {ams_id} info={info_val} (bit8={bit8}) -> extruder {extruder_id}" + ) except (ValueError, TypeError): pass if ams_extruder_map: @@ -879,8 +906,8 @@ class BambuMQTTClient: # Temperature data temps = {} # Log all fields for debugging dual-nozzle temperature discovery (only once) - if "bed_temper" in data and not hasattr(self, '_temp_fields_logged'): - temp_fields = {k: v for k, v in data.items() if 'temp' in k.lower() or 'chamber' in k.lower()} + if "bed_temper" in data and not hasattr(self, "_temp_fields_logged"): + temp_fields = {k: v for k, v in data.items() if "temp" in k.lower() or "chamber" in k.lower()} logger.info(f"[{self.serial_number}] Temperature-related fields: {temp_fields}") # Log ALL keys in print data for H2D temperature discovery all_keys = sorted(data.keys()) @@ -888,13 +915,17 @@ class BambuMQTTClient: self._temp_fields_logged = True # Log vir_slot data (once) - this may contain per-extruder slot mapping for H2D - if "vir_slot" in data and not hasattr(self, '_vir_slot_logged'): + if "vir_slot" in data and not hasattr(self, "_vir_slot_logged"): logger.info(f"[{self.serial_number}] vir_slot data: {data['vir_slot']}") self._vir_slot_logged = True # Log nozzle hardware info fields (once) - nozzle_fields = {k: v for k, v in data.items() if 'nozzle' in k.lower() or 'hw' in k.lower() or 'extruder' in k.lower() or 'upgrade' in k.lower()} - if nozzle_fields and not hasattr(self, '_nozzle_fields_logged'): + nozzle_fields = { + k: v + for k, v in data.items() + if "nozzle" in k.lower() or "hw" in k.lower() or "extruder" in k.lower() or "upgrade" in k.lower() + } + if nozzle_fields and not hasattr(self, "_nozzle_fields_logged"): logger.info(f"[{self.serial_number}] Nozzle/hardware fields in MQTT data: {nozzle_fields}") self._nozzle_fields_logged = True # Parse active extruder from device.extruder.state bit 8 @@ -907,7 +938,9 @@ class BambuMQTTClient: # Extract bit 8 for extruder position new_extruder = (state_val >> 8) & 0x1 if new_extruder != self.state.active_extruder: - logger.info(f"[{self.serial_number}] ACTIVE EXTRUDER CHANGED (state bit 8): {self.state.active_extruder} -> {new_extruder} (0=right, 1=left) [state={state_val}]") + logger.info( + f"[{self.serial_number}] ACTIVE EXTRUDER CHANGED (state bit 8): {self.state.active_extruder} -> {new_extruder} (0=right, 1=left) [state={state_val}]" + ) self.state.active_extruder = new_extruder # Log device.extruder structure for active extruder @@ -920,7 +953,9 @@ class BambuMQTTClient: state_val = ext_data["state"] # Extract bits 12-14 (3 bits) for switch state switch_state = (state_val >> 12) & 0x7 - logger.info(f"[{self.serial_number}] device.extruder.state={state_val} (switch_state bits 12-14: {switch_state})") + logger.info( + f"[{self.serial_number}] device.extruder.state={state_val} (switch_state bits 12-14: {switch_state})" + ) # Log 'cur' field if present (might indicate current/active extruder) if "cur" in ext_data: logger.info(f"[{self.serial_number}] device.extruder.cur: {ext_data['cur']}") @@ -930,11 +965,11 @@ class BambuMQTTClient: temps["bed_target"] = float(data["bed_target_temper"]) # Check if this is H2D (has device.extruder.info with 2 extruders) has_h2d_extruder_info = ( - "device" in data and - isinstance(data.get("device"), dict) and - "extruder" in data["device"] and - isinstance(data["device"]["extruder"].get("info"), list) and - len(data["device"]["extruder"]["info"]) >= 2 + "device" in data + and isinstance(data.get("device"), dict) + and "extruder" in data["device"] + and isinstance(data["device"]["extruder"].get("info"), list) + and len(data["device"]["extruder"]["info"]) >= 2 ) # Standard nozzle fields: these are for the RIGHT/default nozzle on H2D @@ -1002,7 +1037,9 @@ class BambuMQTTClient: if chamber_val > 500: mqtt_target = int(chamber_val) // 65536 current = int(chamber_val) % 65536 - logger.debug(f"[{self.serial_number}] chamber_temper decoded: mqtt_target={mqtt_target}, current={current}, respect_local={respect_local}") + logger.debug( + f"[{self.serial_number}] chamber_temper decoded: mqtt_target={mqtt_target}, current={current}, respect_local={respect_local}" + ) if -50 < current < 100: temps["chamber"] = float(current) # Store decoded target for later use, but DON'T set chamber_heating here! @@ -1035,7 +1072,9 @@ class BambuMQTTClient: # Store decoded target as fallback (may be overridden by ctc.info.target) if "_chamber_decoded_target" not in temps: temps["_chamber_decoded_target"] = float(target) - logger.debug(f"[{self.serial_number}] info.temp encoded: {info_temp} -> current={current}, decoded_target={target}") + logger.debug( + f"[{self.serial_number}] info.temp encoded: {info_temp} -> current={current}, decoded_target={target}" + ) elif -50 < info_temp < 100: # Valid direct temperature - heater is OFF temps["chamber"] = float(info_temp) @@ -1118,7 +1157,9 @@ class BambuMQTTClient: if "modeCur" in airduct_data: new_mode = airduct_data["modeCur"] if new_mode != self.state.airduct_mode: - logger.info(f"[{self.serial_number}] airduct_mode changed: {self.state.airduct_mode} -> {new_mode}") + logger.info( + f"[{self.serial_number}] airduct_mode changed: {self.state.airduct_mode} -> {new_mode}" + ) self.state.airduct_mode = new_mode # Parse chamber temp - may be encoded as (target*65536+current) when > 500 # Check if we recently set the target locally (within 5 seconds) @@ -1134,12 +1175,16 @@ class BambuMQTTClient: explicit_target = None if "target" in ctc_info: target_val = ctc_info["target"] - logger.debug(f"[{self.serial_number}] ctc_info.target explicit value: {target_val}, respect_local={respect_local_target}") + logger.debug( + f"[{self.serial_number}] ctc_info.target explicit value: {target_val}, respect_local={respect_local_target}" + ) # Filter out invalid values (valid chamber target is 0-60°C) if 0 <= target_val <= 60 and not respect_local_target: explicit_target = float(target_val) temps["chamber_target"] = explicit_target # Override any previous value - logger.debug(f"[{self.serial_number}] Setting chamber_target from ctc_info.target: {explicit_target}") + logger.debug( + f"[{self.serial_number}] Setting chamber_target from ctc_info.target: {explicit_target}" + ) # Parse chamber temp from ctc.info.temp - may be encoded if "temp" in ctc_info and "chamber" not in temps: @@ -1150,7 +1195,9 @@ class BambuMQTTClient: decoded_target = temp_val // 65536 current = temp_val % 65536 temps["chamber"] = float(current) - logger.debug(f"[{self.serial_number}] ctc_info.temp decoded: target={decoded_target}, current={current}, explicit_target={explicit_target}") + logger.debug( + f"[{self.serial_number}] ctc_info.temp decoded: target={decoded_target}, current={current}, explicit_target={explicit_target}" + ) # Determine which target to use for heating state: # Priority: local target > explicit target > decoded target @@ -1198,11 +1245,15 @@ class BambuMQTTClient: target = self.state.temperatures.get("chamber_target", 0) self.state.temperatures["chamber_heating"] = target > 0 and current < target - logger.debug(f"[{self.serial_number}] Chamber heating calculated: target={target}, current={current}, heating={self.state.temperatures['chamber_heating']}, respect_local={respect_local}") + logger.debug( + f"[{self.serial_number}] Chamber heating calculated: target={target}, current={current}, heating={self.state.temperatures['chamber_heating']}, respect_local={respect_local}" + ) # Debug: log chamber value if it was updated if "chamber" in temps: - logger.debug(f"[{self.serial_number}] Chamber temp updated to: {self.state.temperatures.get('chamber')}, target: {self.state.temperatures.get('chamber_target')}, heating: {self.state.temperatures.get('chamber_heating')}") + logger.debug( + f"[{self.serial_number}] Chamber temp updated to: {self.state.temperatures.get('chamber')}, target: {self.state.temperatures.get('chamber_target')}, heating: {self.state.temperatures.get('chamber_heating')}" + ) # Parse HMS (Health Management System) errors if "hms" in data: @@ -1224,12 +1275,14 @@ class BambuMQTTClient: severity = (attr >> 8) & 0xF # Module is in attr byte 3 (bits 24-31) module = (attr >> 24) & 0xFF - self.state.hms_errors.append(HMSError( - code=f"0x{code:x}" if code else "0x0", - attr=attr, - module=module, - severity=severity if severity > 0 else 2, - )) + self.state.hms_errors.append( + HMSError( + code=f"0x{code:x}" if code else "0x0", + attr=attr, + module=module, + severity=severity if severity > 0 else 2, + ) + ) # Parse SD card status if "sdcard" in data: @@ -1244,7 +1297,9 @@ class BambuMQTTClient: home_flag = home_flag & 0xFFFFFFFF store_to_sdcard = bool((home_flag >> 11) & 1) if store_to_sdcard != self.state.store_to_sdcard: - logger.info(f"[{self.serial_number}] store_to_sdcard changed: {self.state.store_to_sdcard} -> {store_to_sdcard}") + logger.info( + f"[{self.serial_number}] store_to_sdcard changed: {self.state.store_to_sdcard} -> {store_to_sdcard}" + ) self.state.store_to_sdcard = store_to_sdcard # Parse timelapse status (recording active during print) @@ -1294,7 +1349,9 @@ class BambuMQTTClient: if isinstance(light, dict) and light.get("node") == "chamber_light": new_light_state = light.get("mode") == "on" if new_light_state != self.state.chamber_light: - logger.info(f"[{self.serial_number}] chamber_light changed: {self.state.chamber_light} -> {new_light_state}") + logger.info( + f"[{self.serial_number}] chamber_light changed: {self.state.chamber_light} -> {new_light_state}" + ) self.state.chamber_light = new_light_state break @@ -1403,12 +1460,16 @@ class BambuMQTTClient: f"[{self.serial_number}] PRINT START detected - file: {current_file}, " f"subtask: {self.state.subtask_name}, is_new: {is_new_print}, is_file_change: {is_file_change}" ) - self.on_print_start({ - "filename": current_file, - "subtask_name": self.state.subtask_name, - "remaining_time": self.state.remaining_time * 60 if self.state.remaining_time > 0 else None, # Convert minutes to seconds - "raw_data": data, - }) + self.on_print_start( + { + "filename": current_file, + "subtask_name": self.state.subtask_name, + "remaining_time": self.state.remaining_time * 60 + if self.state.remaining_time > 0 + else None, # Convert minutes to seconds + "raw_data": data, + } + ) # Detect print completion (FINISH = success, FAILED = error, IDLE = aborted) # Use _was_running flag in addition to _previous_gcode_state for more robust detection @@ -1448,13 +1509,25 @@ class BambuMQTTClient: self._completion_triggered = True self._was_running = False self._timelapse_during_print = False # Reset for next print - self.on_print_complete({ - "status": status, - "filename": self._previous_gcode_file or current_file, - "subtask_name": self.state.subtask_name, - "raw_data": data, - "timelapse_was_active": timelapse_was_active, - }) + # Include HMS errors for failure reason detection + hms_errors_data = ( + [ + {"code": e.code, "attr": e.attr, "module": e.module, "severity": e.severity} + for e in self.state.hms_errors + ] + if self.state.hms_errors + else [] + ) + self.on_print_complete( + { + "status": status, + "filename": self._previous_gcode_file or current_file, + "subtask_name": self.state.subtask_name, + "raw_data": data, + "timelapse_was_active": timelapse_was_active, + "hms_errors": hms_errors_data, + } + ) self._previous_gcode_state = self.state.state if current_file: @@ -1493,7 +1566,7 @@ class BambuMQTTClient: "system": { "sequence_id": str(self._sequence_id), "command": "get_accessories", - "accessory_type": "none" + "accessory_type": "none", } } logger.debug(f"[{self.serial_number}] Requesting accessories info") @@ -1579,23 +1652,14 @@ class BambuMQTTClient: def stop_print(self) -> bool: """Stop the current print job.""" if self._client and self.state.connected: - command = { - "print": { - "command": "stop", - "sequence_id": "0" - } - } + command = {"print": {"command": "stop", "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Sent stop print command") return True return False def set_xcam_option( - self, - module_name: str, - enabled: bool, - print_halt: bool = True, - sensitivity: str = "medium" + self, module_name: str, enabled: bool, print_halt: bool = True, sensitivity: str = "medium" ) -> bool: """Set an xcam (AI detection) option on the printer. @@ -1813,12 +1877,14 @@ class BambuMQTTClient: if self._client and self.state.connected: # Log outgoing message if logging is enabled if self._logging_enabled: - self._message_log.append(MQTTLogEntry( - timestamp=datetime.now().isoformat(), - topic=self.topic_publish, - direction="out", - payload=command, - )) + self._message_log.append( + MQTTLogEntry( + timestamp=datetime.now().isoformat(), + topic=self.topic_publish, + direction="out", + payload=command, + ) + ) self._client.publish(self.topic_publish, json.dumps(command), qos=1) def enable_logging(self, enabled: bool = True): @@ -1844,18 +1910,22 @@ class BambuMQTTClient: response_nozzle = data.get("nozzle_diameter") response_seq_id = data.get("sequence_id", "?") filaments = data.get("filaments", []) - expected_nozzle = getattr(self, '_expected_kprofile_nozzle', None) + expected_nozzle = getattr(self, "_expected_kprofile_nozzle", None) has_pending_request = self._pending_kprofile_response is not None # Log all incoming responses when we have a pending request (for debugging) if has_pending_request: - logger.info(f"[{self.serial_number}] K-profile response: nozzle={response_nozzle}, {len(filaments)} profiles, expected={expected_nozzle}") + logger.info( + f"[{self.serial_number}] K-profile response: nozzle={response_nozzle}, {len(filaments)} profiles, expected={expected_nozzle}" + ) # If we have a pending request, only accept responses with matching nozzle_diameter # The printer broadcasts 0.4mm profiles constantly - we need to wait for the actual response if has_pending_request and expected_nozzle and response_nozzle != expected_nozzle: # Ignore this broadcast, keep waiting for matching response - logger.debug(f"[{self.serial_number}] Ignoring broadcast: got nozzle={response_nozzle}, waiting for {expected_nozzle}") + logger.debug( + f"[{self.serial_number}] Ignoring broadcast: got nozzle={response_nozzle}, waiting for {expected_nozzle}" + ) return # If no pending request, this is just a broadcast - update state silently and return early @@ -1866,19 +1936,21 @@ class BambuMQTTClient: if isinstance(f, dict): try: cali_idx = f.get("cali_idx", 0) - profiles.append(KProfile( - slot_id=cali_idx, - extruder_id=int(f.get("extruder_id", 0)), - nozzle_id=str(f.get("nozzle_id", "")), - nozzle_diameter=str(f.get("nozzle_diameter", "0.4")), - filament_id=str(f.get("filament_id", "")), - name=str(f.get("name", "")), - k_value=str(f.get("k_value", "0.000000")), - n_coef=str(f.get("n_coef", "0.000000")), - ams_id=int(f.get("ams_id", 0)), - tray_id=int(f.get("tray_id", -1)), - setting_id=f.get("setting_id"), - )) + profiles.append( + KProfile( + slot_id=cali_idx, + extruder_id=int(f.get("extruder_id", 0)), + nozzle_id=str(f.get("nozzle_id", "")), + nozzle_diameter=str(f.get("nozzle_diameter", "0.4")), + filament_id=str(f.get("filament_id", "")), + name=str(f.get("name", "")), + k_value=str(f.get("k_value", "0.000000")), + n_coef=str(f.get("n_coef", "0.000000")), + ams_id=int(f.get("ams_id", 0)), + tray_id=int(f.get("tray_id", -1)), + setting_id=f.get("setting_id"), + ) + ) except (ValueError, TypeError): pass self.state.kprofiles = profiles @@ -1891,19 +1963,21 @@ class BambuMQTTClient: try: # cali_idx is the actual slot/calibration index from the printer cali_idx = f.get("cali_idx", i) - profiles.append(KProfile( - slot_id=cali_idx, - extruder_id=int(f.get("extruder_id", 0)), - nozzle_id=str(f.get("nozzle_id", "")), - nozzle_diameter=str(f.get("nozzle_diameter", "0.4")), - filament_id=str(f.get("filament_id", "")), - name=str(f.get("name", "")), - k_value=str(f.get("k_value", "0.000000")), - n_coef=str(f.get("n_coef", "0.000000")), - ams_id=int(f.get("ams_id", 0)), - tray_id=int(f.get("tray_id", -1)), - setting_id=f.get("setting_id"), - )) + profiles.append( + KProfile( + slot_id=cali_idx, + extruder_id=int(f.get("extruder_id", 0)), + nozzle_id=str(f.get("nozzle_id", "")), + nozzle_diameter=str(f.get("nozzle_diameter", "0.4")), + filament_id=str(f.get("filament_id", "")), + name=str(f.get("name", "")), + k_value=str(f.get("k_value", "0.000000")), + n_coef=str(f.get("n_coef", "0.000000")), + ams_id=int(f.get("ams_id", 0)), + tray_id=int(f.get("tray_id", -1)), + setting_id=f.get("setting_id"), + ) + ) except (ValueError, TypeError) as e: logger.warning(f"Failed to parse K-profile: {e}") @@ -1920,7 +1994,9 @@ class BambuMQTTClient: # Fallback for when loop is not available self._pending_kprofile_response.set() - async def get_kprofiles(self, nozzle_diameter: str = "0.4", timeout: float = 5.0, max_retries: int = 3) -> list[KProfile]: + async def get_kprofiles( + self, nozzle_diameter: str = "0.4", timeout: float = 5.0, max_retries: int = 3 + ) -> list[KProfile]: """Request K-profiles from the printer with retry logic. Bambu printers sometimes ignore the first K-profile request, so we @@ -1962,7 +2038,9 @@ class BambuMQTTClient: } } - logger.info(f"[{self.serial_number}] Requesting K-profiles for nozzle_diameter={nozzle_diameter} (attempt {attempt + 1}/{max_retries})") + logger.info( + f"[{self.serial_number}] Requesting K-profiles for nozzle_diameter={nozzle_diameter} (attempt {attempt + 1}/{max_retries})" + ) logger.debug(f"[{self.serial_number}] K-profile request JSON: {json.dumps(command)}") self._client.publish(self.topic_publish, json.dumps(command), qos=1) @@ -1970,10 +2048,14 @@ class BambuMQTTClient: try: await asyncio.wait_for(self._pending_kprofile_response.wait(), timeout=timeout) profiles = self._kprofile_response_data or [] - logger.info(f"[{self.serial_number}] Got {len(profiles)} K-profiles for nozzle={nozzle_diameter} on attempt {attempt + 1}") + logger.info( + f"[{self.serial_number}] Got {len(profiles)} K-profiles for nozzle={nozzle_diameter} on attempt {attempt + 1}" + ) return profiles - except asyncio.TimeoutError: - logger.warning(f"[{self.serial_number}] Timeout on K-profiles request attempt {attempt + 1}/{max_retries}") + except TimeoutError: + logger.warning( + f"[{self.serial_number}] Timeout on K-profiles request attempt {attempt + 1}/{max_retries}" + ) if attempt < max_retries - 1: # Brief delay before retry await asyncio.sleep(0.5) @@ -2029,6 +2111,7 @@ class BambuMQTTClient: # Generate a setting_id for new profiles (required by printer) # Format: "PF" + 17 random digits import random + if not setting_id and slot_id == 0: setting_id = f"PF{random.randint(10000000000000000, 99999999999999999)}" @@ -2056,7 +2139,9 @@ class BambuMQTTClient: } command_json = json.dumps(command) - logger.info(f"[{self.serial_number}] Setting K-profile: {name} = {k_value} (cali_idx={effective_cali_idx}, new={slot_id==0})") + logger.info( + f"[{self.serial_number}] Setting K-profile: {name} = {k_value} (cali_idx={effective_cali_idx}, new={slot_id==0})" + ) logger.info(f"[{self.serial_number}] K-profile SET command: {command_json}") self._client.publish(self.topic_publish, command_json, qos=1) return True @@ -2081,6 +2166,7 @@ class BambuMQTTClient: return False import random + self._sequence_id += 1 filament_entries = [] @@ -2097,19 +2183,21 @@ class BambuMQTTClient: if not setting_id and slot_id == 0: setting_id = f"PF{random.randint(10000000000000000, 99999999999999999)}" - filament_entries.append({ - "ams_id": 0, - "cali_idx": effective_cali_idx, - "extruder_id": p.get("extruder_id", 0), - "filament_id": p.get("filament_id", ""), - "k_value": p.get("k_value", "0.020000"), - "n_coef": "0.000000", - "name": p.get("name", ""), - "nozzle_diameter": nozzle_diameter, - "nozzle_id": p.get("nozzle_id", f"HS00-{nozzle_diameter}"), - "setting_id": setting_id if setting_id else "", - "tray_id": -1, - }) + filament_entries.append( + { + "ams_id": 0, + "cali_idx": effective_cali_idx, + "extruder_id": p.get("extruder_id", 0), + "filament_id": p.get("filament_id", ""), + "k_value": p.get("k_value", "0.020000"), + "n_coef": "0.000000", + "name": p.get("name", ""), + "nozzle_diameter": nozzle_diameter, + "nozzle_id": p.get("nozzle_id", f"HS00-{nozzle_diameter}"), + "setting_id": setting_id if setting_id else "", + "tray_id": -1, + } + ) command = { "print": { @@ -2188,7 +2276,9 @@ class BambuMQTTClient: } command_json = json.dumps(command) - logger.info(f"[{self.serial_number}] Deleting K-profile: cali_idx={cali_idx}, filament={filament_id}, setting_id={setting_id}, dual={is_dual_nozzle}") + logger.info( + f"[{self.serial_number}] Deleting K-profile: cali_idx={cali_idx}, filament={filament_id}, setting_id={setting_id}, dual={is_dual_nozzle}" + ) logger.info(f"[{self.serial_number}] K-profile DELETE command: {command_json}") # Use QoS 1 for reliable delivery (at least once) self._client.publish(self.topic_publish, command_json, qos=1) @@ -2204,12 +2294,7 @@ class BambuMQTTClient: logger.warning(f"[{self.serial_number}] Cannot pause print: not connected") return False - command = { - "print": { - "command": "pause", - "sequence_id": "0" - } - } + command = {"print": {"command": "pause", "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Sent pause print command") return True @@ -2220,12 +2305,7 @@ class BambuMQTTClient: logger.warning(f"[{self.serial_number}] Cannot resume print: not connected") return False - command = { - "print": { - "command": "resume", - "sequence_id": "0" - } - } + command = {"print": {"command": "resume", "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Sent resume print command") return True @@ -2246,13 +2326,7 @@ class BambuMQTTClient: return False self._sequence_id += 1 - command = { - "print": { - "command": "gcode_line", - "param": gcode, - "sequence_id": str(self._sequence_id) - } - } + command = {"print": {"command": "gcode_line", "param": gcode, "sequence_id": str(self._sequence_id)}} # Use QoS 1 for reliable delivery (at least once) self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.debug(f"[{self.serial_number}] Sent G-code: {gcode[:50]}...") @@ -2308,7 +2382,9 @@ class BambuMQTTClient: # Update heating state immediately based on new target current_temp = self.state.temperatures.get("chamber", 0) self.state.temperatures["chamber_heating"] = target > 0 and current_temp < target - logger.info(f"[{self.serial_number}] Tracking chamber target locally: {target}°C (heating={self.state.temperatures['chamber_heating']})") + logger.info( + f"[{self.serial_number}] Tracking chamber target locally: {target}°C (heating={self.state.temperatures['chamber_heating']})" + ) return result def set_print_speed(self, mode: int) -> bool: @@ -2328,13 +2404,7 @@ class BambuMQTTClient: logger.warning(f"[{self.serial_number}] Invalid speed mode: {mode}") return False - command = { - "print": { - "command": "print_speed", - "param": str(mode), - "sequence_id": "0" - } - } + command = {"print": {"command": "print_speed", "param": str(mode), "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Set print speed mode to {mode}") return True @@ -2387,12 +2457,7 @@ class BambuMQTTClient: self._sequence_id += 1 mode_id = 0 if mode == "cooling" else 1 command = { - "print": { - "command": "set_airduct", - "modeId": mode_id, - "sequence_id": str(self._sequence_id), - "submode": -1 - } + "print": {"command": "set_airduct", "modeId": mode_id, "sequence_id": str(self._sequence_id), "submode": -1} } # Use QoS 1 for reliable delivery self._client.publish(self.topic_publish, json.dumps(command), qos=1) @@ -2425,7 +2490,7 @@ class BambuMQTTClient: "led_off_time": 500, "loop_times": 0, "interval_time": 0, - "sequence_id": str(self._sequence_id) + "sequence_id": str(self._sequence_id), } } self._client.publish(self.topic_publish, json.dumps(command), qos=1) @@ -2455,11 +2520,7 @@ class BambuMQTTClient: # extruder_index: 0 = RIGHT, 1 = LEFT self._sequence_id += 1 command = { - "print": { - "command": "select_extruder", - "extruder_index": extruder, - "sequence_id": str(self._sequence_id) - } + "print": {"command": "select_extruder", "extruder_index": extruder, "sequence_id": str(self._sequence_id)} } self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Sent select_extruder command: extruder_index={extruder} (0=right, 1=left)") @@ -2551,7 +2612,7 @@ class BambuMQTTClient: "slot_id": slot_id, "target": tray_id, "curr_temp": -1, - "tar_temp": -1 + "tar_temp": -1, } } @@ -2604,9 +2665,9 @@ class BambuMQTTClient: "sequence_id": str(self._sequence_id), "ams_id": ams_id, "slot_id": 255, # 255 = unload marker - "target": 255, # 255 = unload destination + "target": 255, # 255 = unload destination "curr_temp": nozzle_temp, - "tar_temp": nozzle_temp + "tar_temp": nozzle_temp, } } @@ -2639,13 +2700,7 @@ class BambuMQTTClient: logger.warning(f"[{self.serial_number}] Invalid AMS action: {action}") return False - command = { - "print": { - "command": "ams_control", - "param": action, - "sequence_id": "0" - } - } + command = {"print": {"command": "ams_control", "param": action, "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] AMS control: {action}") return True @@ -2682,14 +2737,7 @@ class BambuMQTTClient: # Use ams_get_rfid command to trigger RFID re-read # This command is used by Bambu Studio to re-read the RFID tag - command = { - "print": { - "command": "ams_get_rfid", - "ams_id": ams_id, - "slot_id": tray_id, - "sequence_id": "0" - } - } + command = {"print": {"command": "ams_get_rfid", "ams_id": ams_id, "slot_id": tray_id, "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info(f"[{self.serial_number}] Triggering RFID re-read: AMS {ams_id}, slot {tray_id}") return True, f"Refreshing AMS {ams_id} tray {tray_id}" @@ -2738,7 +2786,7 @@ class BambuMQTTClient: "nozzle_temp_min": nozzle_temp_min, "nozzle_temp_max": nozzle_temp_max, "k": k, - "sequence_id": "0" + "sequence_id": "0", } } @@ -2761,19 +2809,10 @@ class BambuMQTTClient: logger.warning(f"[{self.serial_number}] Cannot set timelapse: not connected") return False - command = { - "pushing": { - "command": "pushall", - "sequence_id": "0" - } - } + command = {"pushing": {"command": "pushall", "sequence_id": "0"}} # First send the timelapse setting timelapse_cmd = { - "print": { - "command": "gcode_line", - "param": f"M981 S{1 if enable else 0} P20000", - "sequence_id": "0" - } + "print": {"command": "gcode_line", "param": f"M981 S{1 if enable else 0} P20000", "sequence_id": "0"} } self._client.publish(self.topic_publish, json.dumps(timelapse_cmd), qos=1) # Request status update @@ -2795,20 +2834,11 @@ class BambuMQTTClient: return False command = { - "xcam": { - "command": "ipcam_record_set", - "control": "enable" if enable else "disable", - "sequence_id": "0" - } + "xcam": {"command": "ipcam_record_set", "control": "enable" if enable else "disable", "sequence_id": "0"} } self._client.publish(self.topic_publish, json.dumps(command), qos=1) # Request status update - pushall = { - "pushing": { - "command": "pushall", - "sequence_id": "0" - } - } + pushall = {"pushing": {"command": "pushall", "sequence_id": "0"}} self._client.publish(self.topic_publish, json.dumps(pushall), qos=1) logger.info(f"[{self.serial_number}] Set liveview {'enabled' if enable else 'disabled'}") return True diff --git a/backend/tests/integration/test_print_lifecycle.py b/backend/tests/integration/test_print_lifecycle.py index 215a813f6..4892b418e 100644 --- a/backend/tests/integration/test_print_lifecycle.py +++ b/backend/tests/integration/test_print_lifecycle.py @@ -13,10 +13,10 @@ Full end-to-end tests require the actual database setup. """ import asyncio -import pytest from datetime import datetime from unittest.mock import AsyncMock, MagicMock, patch +import pytest from sqlalchemy import select @@ -26,11 +26,12 @@ class TestPrintStartLogic: @pytest.mark.asyncio async def test_print_start_calls_notification_service(self, capture_logs): """Verify on_print_start triggers notification service.""" - with patch('backend.app.main.async_session') as mock_session_maker, \ - patch('backend.app.main.notification_service') as mock_notif, \ - patch('backend.app.main.smart_plug_manager') as mock_plug, \ - patch('backend.app.main.ws_manager') as mock_ws: - + with ( + patch("backend.app.main.async_session") as mock_session_maker, + patch("backend.app.main.notification_service") as mock_notif, + patch("backend.app.main.smart_plug_manager") as mock_plug, + patch("backend.app.main.ws_manager") as mock_ws, + ): mock_notif.on_print_start = AsyncMock() mock_plug.on_print_start = AsyncMock() mock_ws.send_print_start = AsyncMock() @@ -44,17 +45,19 @@ class TestPrintStartLogic: from backend.app.main import on_print_start - await on_print_start(1, { - "filename": "/data/Metadata/test.gcode", - "subtask_name": "Test", - }) + await on_print_start( + 1, + { + "filename": "/data/Metadata/test.gcode", + "subtask_name": "Test", + }, + ) # Verify WebSocket notification was sent mock_ws.send_print_start.assert_called_once() # Verify no import shadowing errors - errors = [r for r in capture_logs.get_errors() - if "cannot access local variable" in str(r.message)] + errors = [r for r in capture_logs.get_errors() if "cannot access local variable" in str(r.message)] assert not errors, f"Import shadowing error: {capture_logs.format_errors()}" @@ -64,11 +67,12 @@ class TestPrintCompleteLogic: @pytest.mark.asyncio async def test_print_complete_no_import_errors(self, capture_logs): """Verify on_print_complete doesn't have import shadowing issues.""" - with patch('backend.app.main.async_session') as mock_session_maker, \ - patch('backend.app.main.notification_service') as mock_notif, \ - patch('backend.app.main.smart_plug_manager') as mock_plug, \ - patch('backend.app.main.ws_manager') as mock_ws: - + with ( + patch("backend.app.main.async_session") as mock_session_maker, + patch("backend.app.main.notification_service") as mock_notif, + patch("backend.app.main.smart_plug_manager") as mock_plug, + patch("backend.app.main.ws_manager") as mock_ws, + ): mock_notif.on_print_complete = AsyncMock() mock_plug.on_print_complete = AsyncMock() mock_ws.send_print_complete = AsyncMock() @@ -82,16 +86,18 @@ class TestPrintCompleteLogic: from backend.app.main import on_print_complete - await on_print_complete(1, { - "status": "completed", - "filename": "/data/Metadata/test.gcode", - "subtask_name": "Test", - "timelapse_was_active": False, - }) + await on_print_complete( + 1, + { + "status": "completed", + "filename": "/data/Metadata/test.gcode", + "subtask_name": "Test", + "timelapse_was_active": False, + }, + ) # Verify no import shadowing errors - this would have caught the ArchiveService bug - errors = [r for r in capture_logs.get_errors() - if "cannot access local variable" in str(r.message)] + errors = [r for r in capture_logs.get_errors() if "cannot access local variable" in str(r.message)] assert not errors, f"Import shadowing error: {capture_logs.format_errors()}" @@ -115,18 +121,21 @@ class TestTimelapseTracking: client._timelapse_during_print = False # Message with both state and timelapse - client._process_message({ - "print": { - "gcode_state": "RUNNING", - "gcode_file": "/data/Metadata/test.gcode", - "subtask_name": "Test", - "xcam": {"timelapse": "enable"}, + client._process_message( + { + "print": { + "gcode_state": "RUNNING", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + "xcam": {"timelapse": "enable"}, + } } - }) + ) assert client._was_running is True - assert client._timelapse_during_print is True, \ - "Timelapse should be detected even when xcam is parsed before state" + assert ( + client._timelapse_during_print is True + ), "Timelapse should be detected even when xcam is parsed before state" @pytest.mark.asyncio async def test_timelapse_flag_included_in_completion_callback(self): @@ -148,27 +157,131 @@ class TestTimelapseTracking: client.on_print_complete = on_complete # Start with timelapse - client._process_message({ - "print": { - "gcode_state": "RUNNING", - "gcode_file": "/data/Metadata/test.gcode", - "subtask_name": "Test", - "xcam": {"timelapse": "enable"}, + client._process_message( + { + "print": { + "gcode_state": "RUNNING", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + "xcam": {"timelapse": "enable"}, + } } - }) + ) # Complete print - client._process_message({ - "print": { - "gcode_state": "FINISH", - "gcode_file": "/data/Metadata/test.gcode", - "subtask_name": "Test", + client._process_message( + { + "print": { + "gcode_state": "FINISH", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + } } - }) + ) assert "timelapse_was_active" in completion_data assert completion_data["timelapse_was_active"] is True + @pytest.mark.asyncio + async def test_hms_errors_included_in_failed_completion_callback(self): + """Verify completion callback receives hms_errors for failed prints.""" + from backend.app.services.bambu_mqtt import BambuMQTTClient + + client = BambuMQTTClient( + ip_address="192.168.1.100", + serial_number="TEST123", + access_code="12345678", + ) + + completion_data = {} + + def on_complete(data): + completion_data.update(data) + + client.on_print_start = lambda data: None + client.on_print_complete = on_complete + + # Start print + client._process_message( + { + "print": { + "gcode_state": "RUNNING", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + } + } + ) + + # Add HMS error during print + client._process_message( + { + "print": { + "gcode_state": "RUNNING", + "hms": [{"attr": 0x07000002, "code": 0x1234}], # Filament module error + } + } + ) + + # Fail print + client._process_message( + { + "print": { + "gcode_state": "FAILED", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + } + } + ) + + assert "hms_errors" in completion_data + assert len(completion_data["hms_errors"]) == 1 + assert completion_data["hms_errors"][0]["module"] == 0x07 + assert completion_data["status"] == "failed" + + @pytest.mark.asyncio + async def test_aborted_status_when_cancelled(self): + """Verify completion callback receives 'aborted' status when print is cancelled.""" + from backend.app.services.bambu_mqtt import BambuMQTTClient + + client = BambuMQTTClient( + ip_address="192.168.1.100", + serial_number="TEST123", + access_code="12345678", + ) + + completion_data = {} + + def on_complete(data): + completion_data.update(data) + + client.on_print_start = lambda data: None + client.on_print_complete = on_complete + + # Start print + client._process_message( + { + "print": { + "gcode_state": "RUNNING", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + } + } + ) + + # User cancels (goes to IDLE) + client._process_message( + { + "print": { + "gcode_state": "IDLE", + "gcode_file": "/data/Metadata/test.gcode", + "subtask_name": "Test", + } + } + ) + + assert completion_data["status"] == "aborted" + assert "hms_errors" in completion_data + class TestCallbackErrorHandling: """Test that callback errors are properly logged.""" @@ -216,6 +329,7 @@ class TestNoImportShadowing: # Check logs for any import-related errors errors = capture_logs.get_errors() - import_errors = [e for e in errors if "import" in str(e.message).lower() - or "local variable" in str(e.message).lower()] + import_errors = [ + e for e in errors if "import" in str(e.message).lower() or "local variable" in str(e.message).lower() + ] assert not import_errors, f"Import errors found: {import_errors}" diff --git a/frontend/src/components/EditArchiveModal.tsx b/frontend/src/components/EditArchiveModal.tsx index fa36917c3..d2ba35bee 100644 --- a/frontend/src/components/EditArchiveModal.tsx +++ b/frontend/src/components/EditArchiveModal.tsx @@ -144,7 +144,7 @@ export function EditArchiveModal({ archive, onClose, existingTags = [] }: EditAr project_id: projectId, notes: notes || undefined, tags: tags || undefined, - failure_reason: archive.status === 'failed' ? (failureReason || undefined) : undefined, + failure_reason: (archive.status === 'failed' || archive.status === 'aborted') ? (failureReason || undefined) : undefined, }); }; @@ -297,8 +297,8 @@ export function EditArchiveModal({ archive, onClose, existingTags = [] }: EditAr - {/* Failure Reason - only show for failed prints */} - {archive.status === 'failed' && ( + {/* Failure Reason - only show for failed/aborted prints */} + {(archive.status === 'failed' || archive.status === 'aborted') && (