Browse Source

Added VP name prefix (e.g. [Virtual - X1C]) to all FTP and MQTT
log lines so issues can be traced to a specific virtual printer, and
demoted FTP protocol chatter from info to debug.

maziggy 2 months ago
parent
commit
b2335a2592

+ 1 - 1
CHANGELOG.md

@@ -24,7 +24,7 @@ All notable changes to Bambuddy will be documented in this file.
 - **Reformatted AMS Drying Presets Table** ([#732](https://github.com/maziggy/bambuddy/issues/732)) — The drying presets table in Settings now groups columns by AMS type (AMS 2 Pro, AMS-HT) with inline °C and h unit labels next to each input, replacing the previous flat column layout. Requested by @cadtoolbox.
 
 ### Security
-- **Fixed Virtual Printer FTP server logging passwords in plaintext — now redacted**
+- **VP FTP Server Logged Passwords in Plaintext** — The Virtual Printer FTP server logged the full `PASS` command including the access code in plaintext. Since logs are included in support packages shared on GitHub, this could expose user credentials. The password is now always redacted as `PASS ********`. Also added VP name prefix to all FTP/MQTT log lines for easier diagnostics, and demoted FTP protocol chatter from `info` to `debug`.
 
 ## [0.2.2] - 2026-03-16
 

+ 19 - 11
backend/app/services/virtual_printer/ftp_server.py

@@ -35,6 +35,7 @@ class FTPSession:
         passive_port_range: tuple[int, int] = (50000, 50100),
         pasv_address: str = "",
         bind_address: str = "0.0.0.0",  # nosec B104
+        vp_name: str = "",
     ):
         self.reader = reader
         self.writer = writer
@@ -45,6 +46,8 @@ class FTPSession:
         self.passive_port_range = passive_port_range
         self.pasv_address = pasv_address
         self.bind_address = bind_address
+        self.vp_name = vp_name
+        self._log_prefix = f"[{vp_name}] " if vp_name else ""
 
         self.authenticated = False
         self.username: str | None = None
@@ -65,7 +68,7 @@ class FTPSession:
     async def send(self, code: int, message: str) -> None:
         """Send an FTP response."""
         response = f"{code} {message}\r\n"
-        logger.info("FTP -> %s: %s", self.remote_ip, response.strip())
+        logger.debug("%sFTP -> %s: %s", self._log_prefix, self.remote_ip, response.strip())
         self.writer.write(response.encode("utf-8"))
         await self.writer.drain()
 
@@ -82,7 +85,7 @@ class FTPSession:
                         timeout=300,  # 5 minute timeout
                     )
                 except TimeoutError:
-                    logger.debug("FTP session timeout from %s", self.remote_ip)
+                    logger.debug("%sFTP session timeout from %s", self._log_prefix, self.remote_ip)
                     break
 
                 if not line:
@@ -98,9 +101,9 @@ class FTPSession:
 
                 # Never log passwords
                 if command_line.upper().startswith("PASS"):
-                    logger.info("FTP <- %s: PASS ********", self.remote_ip)
+                    logger.debug("%sFTP <- %s: PASS ********", self._log_prefix, self.remote_ip)
                 else:
-                    logger.info("FTP <- %s: %s", self.remote_ip, command_line)
+                    logger.debug("%sFTP <- %s: %s", self._log_prefix, self.remote_ip, command_line)
 
                 # Parse command and argument
                 parts = command_line.split(" ", 1)
@@ -112,15 +115,15 @@ class FTPSession:
                 if handler:
                     await handler(arg)
                 else:
-                    logger.warning("FTP command not implemented: %s", cmd)
+                    logger.debug("%sFTP command not implemented: %s", self._log_prefix, cmd)
                     await self.send(502, f"Command {cmd} not implemented")
 
         except asyncio.CancelledError:
-            logger.info("FTP session cancelled from %s", self.remote_ip)
+            logger.info("%sFTP session cancelled from %s", self._log_prefix, self.remote_ip)
         except Exception as e:
-            logger.error("FTP session error from %s: %s", self.remote_ip, e)
+            logger.error("%sFTP session error from %s: %s", self._log_prefix, self.remote_ip, e)
         finally:
-            logger.info("FTP session ended from %s", self.remote_ip)
+            logger.info("%sFTP session ended from %s", self._log_prefix, self.remote_ip)
             await self._cleanup()
 
     async def _cleanup(self) -> None:
@@ -158,10 +161,10 @@ class FTPSession:
             if arg == self.access_code:
                 self.authenticated = True
                 await self.send(230, "Login successful")
-                logger.info("FTP login from %s", self.remote_ip)
+                logger.info("%sFTP login from %s", self._log_prefix, self.remote_ip)
             else:
                 await self.send(530, "Login incorrect")
-                logger.warning("FTP failed login from %s", self.remote_ip)
+                logger.warning("%sFTP failed login from %s (access code mismatch)", self._log_prefix, self.remote_ip)
         else:
             await self.send(503, "Login with USER first")
 
@@ -531,6 +534,7 @@ class VirtualPrinterFTPServer:
         port: int = FTP_PORT,
         on_file_received: Callable[[Path, str], None] | None = None,
         bind_address: str = "0.0.0.0",  # nosec B104
+        vp_name: str = "",
     ):
         """Initialize the FTPS server.
 
@@ -542,6 +546,7 @@ class VirtualPrinterFTPServer:
             port: Port to listen on (default 990)
             on_file_received: Callback when file upload completes (path, source_ip)
             bind_address: IP address to bind to (default 0.0.0.0)
+            vp_name: Virtual printer name for log identification
         """
         self.upload_dir = upload_dir
         self.access_code = access_code
@@ -550,6 +555,7 @@ class VirtualPrinterFTPServer:
         self.port = port
         self.on_file_received = on_file_received
         self.bind_address = bind_address
+        self.vp_name = vp_name
         self._server: asyncio.Server | None = None
         self._running = False
         self._ssl_context: ssl.SSLContext | None = None
@@ -617,7 +623,8 @@ class VirtualPrinterFTPServer:
     async def _handle_client(self, reader: asyncio.StreamReader, writer: asyncio.StreamWriter) -> None:
         """Handle a new FTP client connection."""
         peername = writer.get_extra_info("peername")
-        logger.info("FTP connection from %s", peername)
+        log_prefix = f"[{self.vp_name}] " if self.vp_name else ""
+        logger.info("%sFTP connection from %s", log_prefix, peername)
 
         session = FTPSession(
             reader=reader,
@@ -629,6 +636,7 @@ class VirtualPrinterFTPServer:
             passive_port_range=(self.PASSIVE_PORT_MIN, self.PASSIVE_PORT_MAX),
             pasv_address=self._pasv_address,
             bind_address=self.bind_address,
+            vp_name=self.vp_name,
         )
 
         # Track the session task so we can cancel it on stop

+ 2 - 0
backend/app/services/virtual_printer/manager.py

@@ -385,6 +385,7 @@ class VirtualPrinterInstance:
             key_path=key_path,
             on_file_received=self.on_file_received,
             bind_address=bind_addr,
+            vp_name=self.name,
         )
         self._tasks.append(
             asyncio.create_task(
@@ -402,6 +403,7 @@ class VirtualPrinterInstance:
             on_print_command=self.on_print_command,
             model=self.model or DEFAULT_VIRTUAL_PRINTER_MODEL,
             bind_address=bind_addr,
+            vp_name=self.name,
         )
         self._tasks.append(
             asyncio.create_task(

+ 9 - 6
backend/app/services/virtual_printer/mqtt_server.py

@@ -186,6 +186,7 @@ class SimpleMQTTServer:
         on_print_command: Callable[[str, dict], None] | None = None,
         model: str = "",
         bind_address: str = "0.0.0.0",  # nosec B104
+        vp_name: str = "",
     ):
         self.serial = serial
         self.access_code = access_code
@@ -195,6 +196,8 @@ class SimpleMQTTServer:
         self.port = port
         self.on_print_command = on_print_command
         self.bind_address = bind_address
+        self.vp_name = vp_name
+        self._log_prefix = f"[{vp_name}] " if vp_name else ""
         self._running = False
         self._server = None
         self._clients: dict[str, asyncio.StreamWriter] = {}
@@ -249,10 +252,10 @@ class SimpleMQTTServer:
                     ssl_obj = writer.get_extra_info("ssl_object")
                     if ssl_obj:
                         logger.info(
-                            f"MQTT TLS connection from {addr} - cipher={ssl_obj.cipher()}, version={ssl_obj.version()}"
+                            f"{self._log_prefix}MQTT TLS connection from {addr} - cipher={ssl_obj.cipher()}, version={ssl_obj.version()}"
                         )
                     else:
-                        logger.info("MQTT connection from %s (no TLS?)", addr)
+                        logger.info("%sMQTT connection from %s (no TLS?)", self._log_prefix, addr)
                     await self._handle_client(reader, writer)
                 except ssl.SSLError as e:
                     logger.error("MQTT SSL error: %s", e)
@@ -365,7 +368,7 @@ class SimpleMQTTServer:
         """Handle an MQTT client connection."""
         addr = writer.get_extra_info("peername")
         client_id = f"{addr[0]}:{addr[1]}" if addr else "unknown"
-        logger.info("MQTT client connected: %s", client_id)
+        logger.info("%sMQTT client connected: %s", self._log_prefix, client_id)
 
         authenticated = False
 
@@ -485,7 +488,7 @@ class SimpleMQTTServer:
                 # Send CONNACK with success
                 writer.write(bytes([0x20, 0x02, 0x00, 0x00]))
                 await writer.drain()
-                logger.info("MQTT client authenticated successfully")
+                logger.info("%sMQTT client authenticated successfully", self._log_prefix)
 
                 # Send immediate status report after auth - slicer expects this
                 await self._send_status_report(writer)
@@ -494,7 +497,7 @@ class SimpleMQTTServer:
                 # Send CONNACK with auth failure
                 writer.write(bytes([0x20, 0x02, 0x00, 0x05]))  # Not authorized
                 await writer.drain()
-                logger.warning("MQTT auth failed for user '%s'", username)
+                logger.warning("%sMQTT auth failed for user '%s' (access code mismatch)", self._log_prefix, username)
                 return False
 
         except (IndexError, ValueError) as e:
@@ -521,7 +524,7 @@ class SimpleMQTTServer:
                 requested_qos = payload[idx]
                 idx += 1
 
-                logger.info("MQTT subscribe: %s QoS=%s", topic, requested_qos)
+                logger.info("%sMQTT subscribe: %s QoS=%s", self._log_prefix, topic, requested_qos)
                 granted_qos.append(min(requested_qos, 1))  # Grant up to QoS 1
 
             # Send SUBACK