Browse Source

- 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

maziggy 4 tháng trước cách đây
mục cha
commit
0f65fb9484
3 tập tin đã thay đổi với 129 bổ sung33 xóa
  1. 81 4
      backend/app/main.py
  2. 36 26
      backend/app/services/bambu_ftp.py
  3. 12 3
      backend/app/services/bambu_mqtt.py

+ 81 - 4
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"

+ 36 - 26
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(

+ 12 - 3
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: