From 0f65fb948489b7f3651b0b3f397d7cc7947470c7 Mon Sep 17 00:00:00 2001 From: maziggy Date: Fri, 2 Jan 2026 13:21:57 +0100 Subject: [PATCH] - Bugfixes - AMS "Unexpected format" warnings fixed - P1S/P1P send partial updates without full tray list (per https://github.com/Doridian/OpenBambuAPI/blob/main/mqtt.md). Now handled correctly. - FTP improvements: - Added timeouts (60s download, 30s listing) - Better logging at INFO level - Shows what files exist in /cache - Fallback archive - When 3MF can't be downloaded, creates minimal archive so prints are tracked --- backend/app/main.py | 85 ++++++++++++++++++++++++++++-- backend/app/services/bambu_ftp.py | 62 +++++++++++++--------- backend/app/services/bambu_mqtt.py | 15 ++++-- 3 files changed, 129 insertions(+), 33 deletions(-) diff --git a/backend/app/main.py b/backend/app/main.py index ffb708250..0c2688153 100644 --- a/backend/app/main.py +++ b/backend/app/main.py @@ -604,13 +604,19 @@ async def on_print_start(printer_id: int, data: dict): # If still not found, try listing /cache to find matching file if not downloaded_filename and (filename or subtask_name): search_term = (subtask_name or filename).lower().replace(".gcode", "").replace(".3mf", "") + logger.info(f"Direct FTP download failed, listing /cache to find '{search_term}'") try: cache_files = await list_files_async(printer.ip_address, printer.access_code, "/cache") + threemf_files = [f.get("name") for f in cache_files if f.get("name", "").endswith(".3mf")] + logger.info( + f"Found {len(threemf_files)} 3MF files in /cache: {threemf_files[:5]}{'...' if len(threemf_files) > 5 else ''}" + ) for f in cache_files: if f.get("is_directory"): continue fname = f.get("name", "") if fname.endswith(".3mf") and search_term in fname.lower(): + logger.info(f"Found matching file: {fname}") temp_path = app_settings.archive_dir / "temp" / fname temp_path.parent.mkdir(parents=True, exist_ok=True) if await download_file_async( @@ -627,10 +633,81 @@ async def on_print_start(printer_id: int, data: dict): if not downloaded_filename or not temp_path: logger.warning(f"Could not find 3MF file for print: {filename or subtask_name}") - # Send notification without archive data (file not found) - if not notification_sent: - await _send_print_start_notification(printer_id, data, logger=logger) - return + # Create a fallback archive without 3MF data so the print is still tracked + # This commonly happens with P1S/A1 printers where FTP has file size limitations + try: + from backend.app.models.archive import PrintArchive + + # Derive print name from subtask_name or filename + print_name = subtask_name or filename + if print_name: + # Clean up the name (remove extensions, path parts) + print_name = print_name.split("/")[-1] + print_name = print_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "") + else: + print_name = "Unknown Print" + + # Create minimal archive entry + fallback_archive = PrintArchive( + printer_id=printer_id, + filename=filename or f"{print_name}.3mf", + file_path="", # Empty - no 3MF file available + file_size=0, + print_name=print_name, + status="printing", + started_at=datetime.now(), + extra_data={"no_3mf_available": True, "original_subtask": subtask_name, "_print_data": data}, + ) + + db.add(fallback_archive) + await db.commit() + await db.refresh(fallback_archive) + + logger.info(f"Created fallback archive {fallback_archive.id} for {print_name} (no 3MF available)") + + # Track as active print + _active_prints[(printer_id, fallback_archive.filename)] = fallback_archive.id + if filename: + _active_prints[(printer_id, filename)] = fallback_archive.id + if subtask_name: + _active_prints[(printer_id, f"{subtask_name}.3mf")] = fallback_archive.id + _active_prints[(printer_id, subtask_name)] = fallback_archive.id + + # Record starting energy if smart plug available + try: + 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[fallback_archive.id] = energy["total"] + logger.info( + f"[ENERGY] Recorded starting energy for fallback archive {fallback_archive.id}: {energy['total']} kWh" + ) + except Exception as e: + logger.warning(f"Failed to record starting energy for fallback: {e}") + + # Send WebSocket notification + await ws_manager.send_archive_created( + { + "id": fallback_archive.id, + "printer_id": fallback_archive.printer_id, + "filename": fallback_archive.filename, + "print_name": fallback_archive.print_name, + "status": fallback_archive.status, + } + ) + + # Send notification without archive data (file not found) + if not notification_sent: + await _send_print_start_notification(printer_id, data, logger=logger) + return + except Exception as e: + logger.error(f"Failed to create fallback archive: {e}") + # Send notification without archive data (file not found) + if not notification_sent: + await _send_print_start_notification(printer_id, data, logger=logger) + return try: # Archive the file with status "printing" diff --git a/backend/app/services/bambu_ftp.py b/backend/app/services/bambu_ftp.py index 163655a67..4c7138fc5 100644 --- a/backend/app/services/bambu_ftp.py +++ b/backend/app/services/bambu_ftp.py @@ -1,10 +1,10 @@ -import ssl -import socket import asyncio import logging -from ftplib import FTP_TLS, FTP -from pathlib import Path +import socket +import ssl +from ftplib import FTP, FTP_TLS from io import BytesIO +from pathlib import Path logger = logging.getLogger(__name__) @@ -19,7 +19,7 @@ class ImplicitFTP_TLS(FTP_TLS): self.ssl_context.check_hostname = False self.ssl_context.verify_mode = ssl.CERT_NONE - def connect(self, host='', port=990, timeout=-999, source_address=None): + def connect(self, host="", port=990, timeout=-999, source_address=None): """Connect to host, wrapping socket in TLS immediately (implicit FTPS).""" if host: self.host = host @@ -31,14 +31,10 @@ class ImplicitFTP_TLS(FTP_TLS): self.source_address = source_address # Create and wrap socket immediately (implicit TLS) - self.sock = socket.create_connection( - (self.host, self.port), - self.timeout, - source_address=self.source_address - ) + self.sock = socket.create_connection((self.host, self.port), self.timeout, source_address=self.source_address) self.sock = self.ssl_context.wrap_socket(self.sock, server_hostname=self.host) self.af = self.sock.family - self.file = self.sock.makefile('r', encoding=self.encoding) + self.file = self.sock.makefile("r", encoding=self.encoding) self.welcome = self.getresp() return self.welcome @@ -50,12 +46,11 @@ class ImplicitFTP_TLS(FTP_TLS): conn = self.ssl_context.wrap_socket( conn, server_hostname=self.host, - session=self.sock.session # Reuse session! + session=self.sock.session, # Reuse session! ) return conn, size - class BambuFTPClient: """FTP client for retrieving files from Bambu Lab printers.""" @@ -69,11 +64,15 @@ class BambuFTPClient: def connect(self) -> bool: """Connect to the printer FTP server (implicit FTPS on port 990).""" try: + logger.debug(f"FTP connecting to {self.ip_address}:{self.FTP_PORT}") self._ftp = ImplicitFTP_TLS() self._ftp.connect(self.ip_address, self.FTP_PORT, timeout=10) + logger.debug("FTP connected, logging in as bblp") self._ftp.login("bblp", self.access_code) + logger.debug("FTP logged in, setting prot_p and passive mode") self._ftp.prot_p() self._ftp.set_pasv(True) + logger.info(f"FTP connected successfully to {self.ip_address}") return True except Exception as e: logger.warning(f"FTP connection failed to {self.ip_address}: {e}") @@ -112,6 +111,7 @@ class BambuFTPClient: mtime = None try: from datetime import datetime + month = parts[5] day = parts[6] time_or_year = parts[7] @@ -141,8 +141,9 @@ class BambuFTPClient: if mtime: file_entry["mtime"] = mtime files.append(file_entry) - except Exception: - pass + logger.debug(f"Listed {len(files)} files in {path}") + except Exception as e: + logger.info(f"FTP list_files failed for {path}: {e}") return files @@ -168,10 +169,12 @@ class BambuFTPClient: local_path.parent.mkdir(parents=True, exist_ok=True) with open(local_path, "wb") as f: self._ftp.retrbinary(f"RETR {remote_path}", f.write) - logger.info(f"Successfully downloaded {remote_path} to {local_path}") + file_size = local_path.stat().st_size if local_path.exists() else 0 + logger.info(f"Successfully downloaded {remote_path} to {local_path} ({file_size} bytes)") return True except Exception as e: - logger.debug(f"Failed to download {remote_path}: {e}") + # Log at INFO level so we can see failures in normal logs + logger.info(f"FTP download failed for {remote_path}: {e}") # Clean up partial file if it exists if local_path.exists(): try: @@ -183,7 +186,7 @@ class BambuFTPClient: def upload_file(self, local_path: Path, remote_path: str) -> bool: """Upload a file to the printer.""" if not self._ftp: - logger.warning(f"upload_file: FTP not connected") + logger.warning("upload_file: FTP not connected") return False try: @@ -289,8 +292,9 @@ async def download_file_async( access_code: str, remote_path: str, local_path: Path, + timeout: float = 60.0, ) -> bool: - """Async wrapper for downloading a file.""" + """Async wrapper for downloading a file with timeout.""" loop = asyncio.get_event_loop() def _download(): @@ -302,7 +306,11 @@ async def download_file_async( client.disconnect() return False - return await loop.run_in_executor(None, _download) + try: + return await asyncio.wait_for(loop.run_in_executor(None, _download), timeout=timeout) + except TimeoutError: + logger.warning(f"FTP download timed out after {timeout}s for {remote_path}") + return False async def download_file_try_paths_async( @@ -320,10 +328,7 @@ async def download_file_try_paths_async( return False try: - for remote_path in remote_paths: - if client.download_to_file(remote_path, local_path): - return True - return False + return any(client.download_to_file(remote_path, local_path) for remote_path in remote_paths) finally: client.disconnect() @@ -358,8 +363,9 @@ async def list_files_async( ip_address: str, access_code: str, path: str = "/", + timeout: float = 30.0, ) -> list[dict]: - """Async wrapper for listing files.""" + """Async wrapper for listing files with timeout.""" loop = asyncio.get_event_loop() def _list(): @@ -371,7 +377,11 @@ async def list_files_async( client.disconnect() return [] - return await loop.run_in_executor(None, _list) + try: + return await asyncio.wait_for(loop.run_in_executor(None, _list), timeout=timeout) + except TimeoutError: + logger.warning(f"FTP list_files timed out after {timeout}s for {path}") + return [] async def delete_file_async( diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 378ee6cb6..3fda1177a 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -698,12 +698,15 @@ class BambuMQTTClient: import hashlib # Handle nested ams structure: {"ams": {"ams": [...]}} or {"ams": [...]} - if isinstance(ams_data, dict) and "ams" in ams_data: - ams_list = ams_data["ams"] + # Also handle P1S partial updates: {"tray_now": ..., "tray_tar": ...} without "ams" key + ams_list = None + if isinstance(ams_data, dict): + if "ams" in ams_data: + ams_list = ams_data["ams"] # Log all AMS dict fields to debug tray_now for H2D dual-nozzle non_list_fields = {k: v for k, v in ams_data.items() if k != "ams"} if non_list_fields: - logger.info(f"[{self.serial_number}] AMS dict fields: {non_list_fields}") + logger.debug(f"[{self.serial_number}] AMS dict fields: {non_list_fields}") # IMPORTANT: Parse ams_status FIRST before tray_now, so we have fresh status # when checking if we're in filament change mode for tray_now disambiguation @@ -813,6 +816,12 @@ class BambuMQTTClient: # NOTE: ams_status is parsed BEFORE tray_now (see above) to ensure correct # state when checking filament change mode for H2D disambiguation + + # P1S/P1P send partial updates without "ams" key - this is valid, not an error + # We've already processed the status fields above, so just return if no ams list + if ams_list is None: + logger.debug(f"[{self.serial_number}] AMS partial update (no tray data)") + return elif isinstance(ams_data, list): ams_list = ams_data else: