Browse Source

Fix P2S FTP upload failure - pass skip_session_reuse to ImplicitFTP_TLS (Issue #218)

The fix for A1/P1S FTP uploads (commit 82a6025) was accidentally broken in
commit 9969005 which removed the skip_session_reuse parameter from the
ImplicitFTP_TLS constructor. This caused P2S (and other models in
SKIP_SESSION_REUSE_MODELS) to still use SSL on the data channel, resulting
in "426 Failure reading network stream" errors.

The fix was implemented in commit b96ecfa on test/issue_174 branch but
never merged to main. This cherry-picks that fix.

Also includes:
- Storage diagnostics for debugging upload issues
- Better FTP error logging with specific error codes (553, 550, 552)
- Improved error messages in print scheduler

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
maziggy 3 months ago
parent
commit
4b2ea2d2c2

+ 19 - 2
backend/app/api/routes/archives.py

@@ -2538,14 +2538,22 @@ async def reprint_archive(
     # Get FTP retry settings
     ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
 
+    logger.info(
+        f"Reprint FTP upload starting: printer={printer.name} ({printer.model}), "
+        f"ip={printer.ip_address}, file={remote_filename}, local_path={file_path}, "
+        f"retry_enabled={ftp_retry_enabled}, retry_count={ftp_retry_count}, timeout={ftp_timeout}"
+    )
+
     # Delete existing file if present (avoids 553 error)
-    await delete_file_async(
+    logger.debug(f"Deleting existing file {remote_path} if present...")
+    delete_result = await delete_file_async(
         printer.ip_address,
         printer.access_code,
         remote_path,
         socket_timeout=ftp_timeout,
         printer_model=printer.model,
     )
+    logger.debug(f"Delete result: {delete_result}")
 
     if ftp_retry_enabled:
         uploaded = await with_ftp_retry(
@@ -2571,7 +2579,16 @@ async def reprint_archive(
         )
 
     if not uploaded:
-        raise HTTPException(500, "Failed to upload file to printer")
+        logger.error(
+            f"FTP upload failed for reprint: printer={printer.name}, model={printer.model}, "
+            f"ip={printer.ip_address}, file={remote_filename}. "
+            "Check logs above for storage diagnostics and specific error codes."
+        )
+        raise HTTPException(
+            500,
+            "Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT). "
+            "See server logs for detailed diagnostics.",
+        )
 
     # Register this as an expected print so we don't create a duplicate archive
     register_expected_print(printer_id, remote_filename, archive_id)

+ 19 - 2
backend/app/api/routes/library.py

@@ -1679,14 +1679,22 @@ async def print_library_file(
     # Get FTP retry settings
     ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
 
+    logger.info(
+        f"Library print FTP upload starting: printer={printer.name} ({printer.model}), "
+        f"ip={printer.ip_address}, file={remote_filename}, local_path={file_path}, "
+        f"retry_enabled={ftp_retry_enabled}, retry_count={ftp_retry_count}, timeout={ftp_timeout}"
+    )
+
     # Delete existing file if present (avoids 553 error)
-    await delete_file_async(
+    logger.debug(f"Deleting existing file {remote_path} if present...")
+    delete_result = await delete_file_async(
         printer.ip_address,
         printer.access_code,
         remote_path,
         socket_timeout=ftp_timeout,
         printer_model=printer.model,
     )
+    logger.debug(f"Delete result: {delete_result}")
 
     # Upload file to printer
     if ftp_retry_enabled:
@@ -1713,7 +1721,16 @@ async def print_library_file(
         )
 
     if not uploaded:
-        raise HTTPException(status_code=500, detail="Failed to upload file to printer")
+        logger.error(
+            f"FTP upload failed for library print: printer={printer.name}, model={printer.model}, "
+            f"ip={printer.ip_address}, file={remote_filename}. "
+            "Check logs above for storage diagnostics and specific error codes."
+        )
+        raise HTTPException(
+            status_code=500,
+            detail="Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT). "
+            "See server logs for detailed diagnostics.",
+        )
 
     # Register this as an expected print so we don't create a duplicate archive
     register_expected_print(printer_id, remote_filename, archive.id)

+ 102 - 4
backend/app/services/bambu_ftp.py

@@ -107,17 +107,32 @@ class BambuFTPClient:
                 f"FTP connecting to {self.ip_address}:{self.FTP_PORT} "
                 f"(timeout={self.timeout}s, model={self.printer_model}, skip_session_reuse={skip_reuse})"
             )
-            self._ftp = ImplicitFTP_TLS()
+            self._ftp = ImplicitFTP_TLS(skip_session_reuse=skip_reuse)
             self._ftp.connect(self.ip_address, self.FTP_PORT, timeout=self.timeout)
             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}")
+            # Log welcome message for debugging
+            if hasattr(self._ftp, "welcome") and self._ftp.welcome:
+                logger.debug(f"FTP server welcome: {self._ftp.welcome}")
+            logger.info(f"FTP connected successfully to {self.ip_address} (model={self.printer_model})")
             return True
+        except ftplib.error_perm as e:
+            logger.warning(f"FTP connection permission error to {self.ip_address}: {e}")
+            self._ftp = None
+            return False
+        except TimeoutError as e:
+            logger.warning(f"FTP connection timed out to {self.ip_address}: {e}")
+            self._ftp = None
+            return False
+        except ssl.SSLError as e:
+            logger.warning(f"FTP SSL error connecting to {self.ip_address}: {e}")
+            self._ftp = None
+            return False
         except Exception as e:
-            logger.warning(f"FTP connection failed to {self.ip_address}: {e}")
+            logger.warning(f"FTP connection failed to {self.ip_address}: {e} (type: {type(e).__name__})")
             self._ftp = None
             return False
 
@@ -227,6 +242,62 @@ class BambuFTPClient:
                     pass
             return False
 
+    def diagnose_storage(self) -> dict:
+        """Run storage diagnostics and return results. For debugging upload issues."""
+        results = {
+            "connected": self._ftp is not None,
+            "can_list_root": False,
+            "root_files": [],
+            "can_list_cache": False,
+            "storage_info": None,
+            "pwd": None,
+            "errors": [],
+        }
+
+        if not self._ftp:
+            results["errors"].append("FTP not connected")
+            return results
+
+        # Try to get current directory
+        try:
+            results["pwd"] = self._ftp.pwd()
+            logger.debug(f"FTP current directory: {results['pwd']}")
+        except Exception as e:
+            results["errors"].append(f"PWD failed: {e}")
+            logger.debug(f"FTP PWD failed: {e}")
+
+        # Try to list root directory
+        try:
+            self._ftp.cwd("/")
+            items = []
+            self._ftp.retrlines("LIST", items.append)
+            results["can_list_root"] = True
+            results["root_files"] = items[:10]  # First 10 entries
+            logger.debug(f"FTP root listing ({len(items)} items): {items[:5]}")
+        except Exception as e:
+            results["errors"].append(f"LIST / failed: {e}")
+            logger.debug(f"FTP LIST / failed: {e}")
+
+        # Try to list /cache (should exist on all printers)
+        try:
+            self._ftp.cwd("/cache")
+            items = []
+            self._ftp.retrlines("LIST", items.append)
+            results["can_list_cache"] = True
+            logger.debug(f"FTP /cache listing: {len(items)} items")
+        except Exception as e:
+            results["errors"].append(f"LIST /cache failed: {e}")
+            logger.debug(f"FTP LIST /cache failed: {e}")
+
+        # Try to get storage info
+        try:
+            results["storage_info"] = self.get_storage_info()
+            logger.debug(f"FTP storage info: {results['storage_info']}")
+        except Exception as e:
+            results["errors"].append(f"Storage info failed: {e}")
+
+        return results
+
     def upload_file(
         self,
         local_path: Path,
@@ -242,6 +313,17 @@ class BambuFTPClient:
             file_size = local_path.stat().st_size if local_path.exists() else 0
             logger.info(f"FTP uploading {local_path} ({file_size} bytes) to {remote_path}")
 
+            # Run storage diagnostics before upload (debug)
+            logger.debug("Running pre-upload storage diagnostics...")
+            diag = self.diagnose_storage()
+            logger.info(
+                f"FTP storage diagnostics: can_list_root={diag['can_list_root']}, "
+                f"can_list_cache={diag['can_list_cache']}, "
+                f"storage={diag['storage_info']}, errors={diag['errors']}"
+            )
+            if diag["root_files"]:
+                logger.debug(f"FTP root directory contents: {diag['root_files']}")
+
             uploaded = 0
 
             def on_block(block: bytes):
@@ -254,11 +336,27 @@ class BambuFTPClient:
                 if self._should_skip_session_reuse():
                     ftplib._SSLSocket = None
 
+                logger.debug(f"FTP STOR command starting for {remote_path}")
                 self._ftp.storbinary(f"STOR {remote_path}", f, callback=on_block)
             logger.info(f"FTP upload complete: {remote_path}")
             return True
+        except ftplib.error_perm as e:
+            # Permanent FTP error (4xx/5xx response)
+            error_code = str(e)[:3] if str(e) else "unknown"
+            logger.error(f"FTP upload failed for {remote_path}: {e} (error code: {error_code})")
+            if error_code == "553":
+                logger.error(
+                    "FTP 553 error - Could not create file. Possible causes: "
+                    "1) No SD card inserted, 2) SD card full, 3) SD card not formatted correctly (needs FAT32/exFAT), "
+                    "4) Printer busy/not ready, 5) File path issue"
+                )
+            elif error_code == "550":
+                logger.error("FTP 550 error - File/directory not found or permission denied")
+            elif error_code == "552":
+                logger.error("FTP 552 error - Storage quota exceeded (SD card full?)")
+            return False
         except Exception as e:
-            logger.error(f"FTP upload failed for {remote_path}: {e}")
+            logger.error(f"FTP upload failed for {remote_path}: {e} (type: {type(e).__name__})")
             return False
 
     def upload_bytes(self, data: bytes, remote_path: str) -> bool:

+ 21 - 7
backend/app/services/print_scheduler.py

@@ -857,17 +857,25 @@ class PrintScheduler:
         # Get FTP retry settings
         ftp_retry_enabled, ftp_retry_count, ftp_retry_delay, ftp_timeout = await get_ftp_retry_settings()
 
+        logger.info(
+            f"Queue item {item.id}: FTP upload starting - printer={printer.name} ({printer.model}), "
+            f"ip={printer.ip_address}, file={remote_filename}, local_path={file_path}, "
+            f"retry_enabled={ftp_retry_enabled}, retry_count={ftp_retry_count}, timeout={ftp_timeout}"
+        )
+
         # Delete existing file if present (avoids 553 error on overwrite)
         try:
-            await delete_file_async(
+            logger.debug(f"Queue item {item.id}: Deleting existing file {remote_path} if present...")
+            delete_result = await delete_file_async(
                 printer.ip_address,
                 printer.access_code,
                 remote_path,
                 socket_timeout=ftp_timeout,
                 printer_model=printer.model,
             )
-        except Exception:
-            pass  # File may not exist, that's fine
+            logger.debug(f"Queue item {item.id}: Delete result: {delete_result}")
+        except Exception as e:
+            logger.debug(f"Queue item {item.id}: Delete failed (may not exist): {e}")
 
         try:
             if ftp_retry_enabled:
@@ -894,14 +902,21 @@ class PrintScheduler:
                 )
         except Exception as e:
             uploaded = False
-            logger.error(f"Queue item {item.id}: FTP error: {e}")
+            logger.error(f"Queue item {item.id}: FTP error: {e} (type: {type(e).__name__})")
 
         if not uploaded:
+            error_msg = (
+                "Failed to upload file to printer. Check if SD card is inserted and properly formatted (FAT32/exFAT). "
+                "See server logs for detailed diagnostics."
+            )
             item.status = "failed"
-            item.error_message = "Failed to upload file to printer"
+            item.error_message = error_msg
             item.completed_at = datetime.utcnow()
             await db.commit()
-            logger.error(f"Queue item {item.id}: FTP upload failed")
+            logger.error(
+                f"Queue item {item.id}: FTP upload failed - printer={printer.name}, model={printer.model}, "
+                f"ip={printer.ip_address}. Check logs above for storage diagnostics and specific error codes."
+            )
 
             # Send failure notification
             await notification_service.on_queue_job_failed(
@@ -911,7 +926,6 @@ class PrintScheduler:
                 reason="Failed to upload file to printer",
                 db=db,
             )
-
             await self._power_off_if_needed(db, item)
             return