From 20e06bcf0c7a97e433d33afe4c7f0aaa7266c2f8 Mon Sep 17 00:00:00 2001 From: maziggy Date: Tue, 17 Feb 2026 11:57:50 +0100 Subject: [PATCH] feat(virtual-printer): add port 3000 bind/detect server for slicer connectivity Recent BambuStudio/OrcaSlicer updates require a bind/detect handshake on port 3000 before connecting via MQTT/FTP. Without this, slicers cannot discover or connect to the virtual printer in any mode. - Add BindServer for server modes (immediate/review/print_queue) - Add TCPProxy for raw TCP forwarding (proxy mode) - Update Dockerfile (EXPOSE 3000) and docker-compose.yml (bridge port) - Add 10 new tests for BindServer protocol and integration --- CHANGELOG.md | 1 + Dockerfile | 1 + .../services/virtual_printer/bind_server.py | 190 +++++++++++++ .../app/services/virtual_printer/manager.py | 18 +- .../app/services/virtual_printer/tcp_proxy.py | 219 +++++++++++++++ .../unit/services/test_virtual_printer.py | 249 ++++++++++++++++++ docker-compose.yml | 1 + 7 files changed, 678 insertions(+), 1 deletion(-) create mode 100644 backend/app/services/virtual_printer/bind_server.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 2ebae57c2..dfb200e65 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -55,6 +55,7 @@ All notable changes to Bambuddy will be documented in this file. - **Spool Assignments Falsely Unlinked After Print Due to Color Variation** — The auto-unlink logic compared AMS tray colors against saved fingerprints using exact hex match. RFID sensors report slightly different color values across reads (e.g. `7CC4D5FF` vs `56B7E6FF` for the same spool, Euclidean distance ~43.6). Now uses a color similarity function with a tolerance threshold of 50, preventing false unlinks from minor RFID/firmware color variations while still detecting genuinely different spools. ### Improved +- **Virtual Printer: Port 3000 Bind/Detect Server** — Recent BambuStudio/OrcaSlicer updates require a bind/detect handshake on port 3000 before connecting via MQTT/FTP. Added a BindServer that responds to the slicer's detect protocol in all server modes (immediate, review, print_queue). Without this, slicers cannot discover or connect to the virtual printer. Docker users in bridge mode need to expose port 3000 (`-p 3000:3000`). Proxy mode already forwards port 3000 via TCPProxy. Wiki documentation updated with revised port tables, Docker examples, and platform setup instructions. - **Usage Tracking Diagnostic Logging** ([#364](https://github.com/maziggy/bambuddy/issues/364)) — Added INFO-level logging at print start and completion that dumps the printer's MQTT `mapping` field, `tray_now`, `last_loaded_tray`, all mapping-related raw data keys, and per-AMS-tray summaries (type, color, tray_now, tray_tar). Enables investigating the slot-to-tray mapping behavior across different printer models (X1E, H2D Pro, P1S, etc.) without requiring DEBUG mode. - **Skip Objects: Click-to-Enlarge Lightbox** ([#396](https://github.com/maziggy/bambuddy/issues/396)) — The skip objects modal's small 208px image panel made it difficult to distinguish object markers when parts are small or close together. Clicking the image now opens a fullscreen lightbox overlay with the same image and markers at a much larger size (up to 600px). The 24px marker circles are proportionally smaller relative to the enlarged image, solving the overlap problem. Close via X button, Escape key, or clicking the backdrop. Escape cascades correctly — closes lightbox first, then the modal. - **Phantom Print Investigation — Logging & Hardening** ([#374](https://github.com/maziggy/bambuddy/issues/374)) — Added targeted logging and hardening to help diagnose reports of prints starting automatically without user input. Debug log volume reduced ~90% by suppressing `sqlalchemy.engine` (changed from INFO to WARNING) and `aiosqlite` (new WARNING suppression) noise that previously filled 2.5MB in 16 minutes. Every `start_print()` call now logs a `PRINT COMMAND` trace with the caller's file, line, and function name. The print scheduler logs pending queue items when found. `on_print_complete` warns when multiple queue items are in "printing" status for the same printer, which signals a state inconsistency. diff --git a/Dockerfile b/Dockerfile index 2ebd7da6c..208577c0f 100644 --- a/Dockerfile +++ b/Dockerfile @@ -46,6 +46,7 @@ ENV DATA_DIR=/app/data ENV LOG_DIR=/app/logs ENV PORT=8000 +EXPOSE 3000 EXPOSE 8000 EXPOSE 8883 EXPOSE 9990 diff --git a/backend/app/services/virtual_printer/bind_server.py b/backend/app/services/virtual_printer/bind_server.py new file mode 100644 index 000000000..2ff08e3cf --- /dev/null +++ b/backend/app/services/virtual_printer/bind_server.py @@ -0,0 +1,190 @@ +"""Bind/detect server for virtual printer discovery (port 3000). + +Bambu slicers (BambuStudio, OrcaSlicer) connect to port 3000 on a printer +to perform the "bind with access code" handshake before using MQTT/FTP. + +Protocol: + - Framing: 0xA5A5 + uint16_le(total_msg_size) + JSON payload + 0xA7A7 + - Slicer sends: {"login":{"command":"detect","sequence_id":"20000"}} + - Printer replies: {"login":{"bind":"free","command":"detect","connect":"lan", + "dev_cap":1,"id":"","model":"","name":"", + "sequence_id":,"version":""}} + - Connection closes after one exchange. +""" + +import asyncio +import json +import logging +import struct + +logger = logging.getLogger(__name__) + +BIND_PORT = 3000 +FRAME_HEADER = b"\xa5\xa5" +FRAME_TRAILER = b"\xa7\xa7" +HEADER_SIZE = 4 # 2 bytes magic + 2 bytes length +TRAILER_SIZE = 2 + + +class BindServer: + """Responds to slicer bind/detect requests on port 3000. + + In server mode, Bambuddy IS the printer — it responds with its own + identity so the slicer can discover and bind to it. + """ + + def __init__( + self, + serial: str, + model: str, + name: str, + version: str = "01.00.00.00", + ): + self.serial = serial + self.model = model + self.name = name + self.version = version + + self._server: asyncio.Server | None = None + self._running = False + + async def start(self) -> None: + """Start the bind server on port 3000.""" + if self._running: + return + + logger.info("Starting bind server on port %s (serial=%s, model=%s)", BIND_PORT, self.serial, self.model) + + try: + self._running = True + self._server = await asyncio.start_server( + self._handle_client, + "0.0.0.0", # nosec B104 + BIND_PORT, + ) + + logger.info("Bind server listening on port %s", BIND_PORT) + + async with self._server: + await self._server.serve_forever() + + except OSError as e: + if e.errno == 98: + logger.error("Bind server port %s is already in use", BIND_PORT) + elif e.errno == 13: + logger.error("Bind server: cannot bind to port %s (permission denied)", BIND_PORT) + else: + logger.error("Bind server error: %s", e) + except asyncio.CancelledError: + logger.debug("Bind server task cancelled") + except Exception as e: + logger.error("Bind server error: %s", e) + finally: + await self.stop() + + async def stop(self) -> None: + """Stop the bind server.""" + logger.info("Stopping bind server") + self._running = False + + if self._server: + try: + self._server.close() + await self._server.wait_closed() + except OSError as e: + logger.debug("Error closing bind server: %s", e) + self._server = None + + async def _handle_client( + self, + reader: asyncio.StreamReader, + writer: asyncio.StreamWriter, + ) -> None: + """Handle a single bind/detect request from a slicer.""" + peername = writer.get_extra_info("peername") + client_id = f"{peername[0]}:{peername[1]}" if peername else "unknown" + logger.info("Bind server: client connected from %s", client_id) + + try: + # Read the framed message (timeout after 10s) + data = await asyncio.wait_for(reader.read(4096), timeout=10.0) + if not data: + return + + # Parse the request + request = self._parse_frame(data) + if request is None: + logger.warning("Bind server: invalid frame from %s", client_id) + return + + logger.info("Bind server: received from %s: %s", client_id, request) + + # Check if this is a detect command + login = request.get("login", {}) + if not isinstance(login, dict) or login.get("command") != "detect": + logger.warning("Bind server: unexpected command from %s: %s", client_id, request) + return + + # Build response + response = { + "login": { + "bind": "free", + "command": "detect", + "connect": "lan", + "dev_cap": 1, + "id": self.serial, + "model": self.model, + "name": self.name, + "sequence_id": 3021, + "version": self.version, + } + } + + frame = self._build_frame(response) + writer.write(frame) + await writer.drain() + + logger.info("Bind server: sent detect response to %s (serial=%s)", client_id, self.serial) + + except TimeoutError: + logger.debug("Bind server: timeout waiting for data from %s", client_id) + except Exception as e: + logger.error("Bind server: error handling %s: %s", client_id, e) + finally: + try: + writer.close() + await writer.wait_closed() + except OSError: + pass + logger.debug("Bind server: client %s disconnected", client_id) + + def _parse_frame(self, data: bytes) -> dict | None: + """Parse a framed message: 0xA5A5 + len(u16le) + JSON + 0xA7A7.""" + if len(data) < HEADER_SIZE + TRAILER_SIZE: + return None + + if data[:2] != FRAME_HEADER: + return None + + if data[-2:] != FRAME_TRAILER: + return None + + # Length field is total message size (header + json + trailer) + total_len = struct.unpack_from(" bytes: + """Build a framed message: 0xA5A5 + len(u16le) + JSON + 0xA7A7.""" + json_bytes = json.dumps(payload, separators=(",", ":")).encode("utf-8") + total_len = HEADER_SIZE + len(json_bytes) + TRAILER_SIZE + header = FRAME_HEADER + struct.pack(" None: @@ -429,6 +433,13 @@ class VirtualPrinterManager: on_print_command=self._on_print_command, ) + # Bind server responds to slicer detect/bind requests on port 3000 + self._bind = BindServer( + serial=self.printer_serial, + model=self._model, + name=self.PRINTER_NAME, + ) + # Start services as background tasks # Wrap each in error handler so one failure doesn't stop others async def run_with_logging(coro, name): @@ -441,6 +452,7 @@ class VirtualPrinterManager: asyncio.create_task(run_with_logging(self._ssdp.start(), "SSDP"), name="virtual_printer_ssdp"), asyncio.create_task(run_with_logging(self._ftp.start(), "FTP"), name="virtual_printer_ftp"), asyncio.create_task(run_with_logging(self._mqtt.start(), "MQTT"), name="virtual_printer_mqtt"), + asyncio.create_task(run_with_logging(self._bind.start(), "Bind"), name="virtual_printer_bind"), ] logger.info("Virtual printer '%s' started (serial: %s)", self.PRINTER_NAME, self.printer_serial) @@ -466,6 +478,10 @@ class VirtualPrinterManager: await self._ssdp.stop() self._ssdp = None + if self._bind: + await self._bind.stop() + self._bind = None + if self._ssdp_proxy: await self._ssdp_proxy.stop() self._ssdp_proxy = None diff --git a/backend/app/services/virtual_printer/tcp_proxy.py b/backend/app/services/virtual_printer/tcp_proxy.py index 17e81739f..6dc906ec3 100644 --- a/backend/app/services/virtual_printer/tcp_proxy.py +++ b/backend/app/services/virtual_printer/tcp_proxy.py @@ -340,6 +340,202 @@ class TLSProxy: logger.debug("%s proxy %s: total %s bytes", self.name, direction, total_bytes) +class TCPProxy: + """Raw TCP proxy that forwards data without TLS termination. + + Used for protocols where the printer doesn't use TLS (e.g., port 3000 + binding/authentication protocol). + """ + + def __init__( + self, + name: str, + listen_port: int, + target_host: str, + target_port: int, + on_connect: Callable[[str], None] | None = None, + on_disconnect: Callable[[str], None] | None = None, + ): + self.name = name + self.listen_port = listen_port + self.target_host = target_host + self.target_port = target_port + self.on_connect = on_connect + self.on_disconnect = on_disconnect + + self._server: asyncio.Server | None = None + self._running = False + self._active_connections: dict[str, tuple[asyncio.Task, asyncio.Task]] = {} + + async def start(self) -> None: + """Start the TCP proxy server.""" + if self._running: + return + + logger.info( + "Starting %s TCP proxy: 0.0.0.0:%s → %s:%s", + self.name, + self.listen_port, + self.target_host, + self.target_port, + ) + + try: + self._running = True + + self._server = await asyncio.start_server( + self._handle_client, + "0.0.0.0", # nosec B104 + self.listen_port, + ) + + logger.info("%s TCP proxy listening on port %s", self.name, self.listen_port) + + async with self._server: + await self._server.serve_forever() + + except OSError as e: + if e.errno == 98: # Address already in use + logger.error("%s proxy port %s is already in use", self.name, self.listen_port) + else: + logger.error("%s proxy error: %s", self.name, e) + except asyncio.CancelledError: + logger.debug("%s proxy task cancelled", self.name) + except Exception as e: + logger.error("%s proxy error: %s", self.name, e) + finally: + await self.stop() + + async def stop(self) -> None: + """Stop the TCP proxy server.""" + logger.info("Stopping %s proxy", self.name) + self._running = False + + for client_id, (task1, task2) in list(self._active_connections.items()): + task1.cancel() + task2.cancel() + if self.on_disconnect: + try: + self.on_disconnect(client_id) + except Exception: + pass + + self._active_connections.clear() + + if self._server: + try: + self._server.close() + await self._server.wait_closed() + except OSError as e: + logger.debug("Error closing %s proxy server: %s", self.name, e) + self._server = None + + async def _handle_client( + self, + client_reader: asyncio.StreamReader, + client_writer: asyncio.StreamWriter, + ) -> None: + """Handle a new client connection by proxying to target.""" + peername = client_writer.get_extra_info("peername") + client_id = f"{peername[0]}:{peername[1]}" if peername else "unknown" + + logger.info("%s proxy: client connected from %s", self.name, client_id) + + if self.on_connect: + try: + self.on_connect(client_id) + except Exception: + pass + + try: + printer_reader, printer_writer = await asyncio.wait_for( + asyncio.open_connection(self.target_host, self.target_port), + timeout=10.0, + ) + logger.info("%s proxy: connected to printer %s:%s", self.name, self.target_host, self.target_port) + except TimeoutError: + logger.error("%s proxy: timeout connecting to %s:%s", self.name, self.target_host, self.target_port) + client_writer.close() + await client_writer.wait_closed() + return + except OSError as e: + logger.error("%s proxy: failed to connect to %s:%s: %s", self.name, self.target_host, self.target_port, e) + client_writer.close() + await client_writer.wait_closed() + return + + client_to_printer = asyncio.create_task( + self._forward(client_reader, printer_writer, f"{client_id}→printer"), + name=f"{self.name}_c2p_{client_id}", + ) + printer_to_client = asyncio.create_task( + self._forward(printer_reader, client_writer, f"printer→{client_id}"), + name=f"{self.name}_p2c_{client_id}", + ) + + self._active_connections[client_id] = (client_to_printer, printer_to_client) + + try: + done, pending = await asyncio.wait( + [client_to_printer, printer_to_client], + return_when=asyncio.FIRST_COMPLETED, + ) + for task in pending: + task.cancel() + try: + await task + except asyncio.CancelledError: + pass + + except Exception as e: + logger.debug("%s proxy connection error: %s", self.name, e) + finally: + self._active_connections.pop(client_id, None) + + for writer in [client_writer, printer_writer]: + try: + writer.close() + await writer.wait_closed() + except OSError: + pass + + logger.info("%s proxy: client %s disconnected", self.name, client_id) + + if self.on_disconnect: + try: + self.on_disconnect(client_id) + except Exception: + pass + + async def _forward( + self, + reader: asyncio.StreamReader, + writer: asyncio.StreamWriter, + direction: str, + ) -> None: + """Forward data from reader to writer.""" + total_bytes = 0 + try: + while self._running: + data = await reader.read(65536) + if not data: + break + writer.write(data) + await writer.drain() + total_bytes += len(data) + logger.debug("%s proxy %s: %s bytes", self.name, direction, len(data)) + except asyncio.CancelledError: + pass + except ConnectionResetError: + logger.debug("%s proxy %s: connection reset", self.name, direction) + except BrokenPipeError: + logger.debug("%s proxy %s: broken pipe", self.name, direction) + except OSError as e: + logger.debug("%s proxy %s error: %s", self.name, direction, e) + + logger.debug("%s proxy %s: total %s bytes", self.name, direction, total_bytes) + + class FTPTLSProxy(TLSProxy): """FTP-aware TLS proxy that handles passive data connections. @@ -843,11 +1039,13 @@ class SlicerProxyManager: # Bambu printer ports PRINTER_FTP_PORT = 990 PRINTER_MQTT_PORT = 8883 + PRINTER_BIND_PORT = 3000 # Local listen ports - must match what Bambu Studio expects # Note: Port 990 requires root or CAP_NET_BIND_SERVICE capability LOCAL_FTP_PORT = 990 LOCAL_MQTT_PORT = 8883 + LOCAL_BIND_PORT = 3000 def __init__( self, @@ -871,6 +1069,7 @@ class SlicerProxyManager: self._ftp_proxy: TLSProxy | None = None self._mqtt_proxy: TLSProxy | None = None + self._bind_proxy: TCPProxy | None = None self._tasks: list[asyncio.Task] = [] async def start(self) -> None: @@ -914,6 +1113,16 @@ class SlicerProxyManager: on_disconnect=lambda cid: self._log_activity("MQTT", f"disconnected: {cid}"), ) + # Bind/auth proxy (port 3000) - raw TCP, no TLS + self._bind_proxy = TCPProxy( + name="Bind", + listen_port=self.LOCAL_BIND_PORT, + target_host=self.target_host, + target_port=self.PRINTER_BIND_PORT, + on_connect=lambda cid: self._log_activity("Bind", f"connected: {cid}"), + on_disconnect=lambda cid: self._log_activity("Bind", f"disconnected: {cid}"), + ) + # Start as background tasks async def run_with_logging(proxy: TLSProxy) -> None: try: @@ -930,6 +1139,10 @@ class SlicerProxyManager: run_with_logging(self._mqtt_proxy), name="slicer_proxy_mqtt", ), + asyncio.create_task( + run_with_logging(self._bind_proxy), + name="slicer_proxy_bind", + ), ] logger.info("Slicer TLS proxy started for %s", self.target_host) @@ -954,6 +1167,10 @@ class SlicerProxyManager: await self._mqtt_proxy.stop() self._mqtt_proxy = None + if self._bind_proxy: + await self._bind_proxy.stop() + self._bind_proxy = None + # Cancel tasks for task in self._tasks: task.cancel() @@ -990,6 +1207,8 @@ class SlicerProxyManager: "target_host": self.target_host, "ftp_port": self.LOCAL_FTP_PORT, "mqtt_port": self.LOCAL_MQTT_PORT, + "bind_port": self.LOCAL_BIND_PORT, "ftp_connections": (len(self._ftp_proxy._active_connections) if self._ftp_proxy else 0), "mqtt_connections": (len(self._mqtt_proxy._active_connections) if self._mqtt_proxy else 0), + "bind_connections": (len(self._bind_proxy._active_connections) if self._bind_proxy else 0), } diff --git a/backend/tests/unit/services/test_virtual_printer.py b/backend/tests/unit/services/test_virtual_printer.py index e7cd528a3..2f33b363d 100644 --- a/backend/tests/unit/services/test_virtual_printer.py +++ b/backend/tests/unit/services/test_virtual_printer.py @@ -509,6 +509,126 @@ class TestCertificateService: assert key_path.exists() +class TestBindServer: + """Tests for BindServer (port 3000 bind/detect protocol).""" + + @pytest.fixture + def bind_server(self): + """Create a BindServer instance.""" + from backend.app.services.virtual_printer.bind_server import BindServer + + return BindServer( + serial="09400A391800001", + model="O1D", + name="Bambuddy", + ) + + def test_build_frame(self, bind_server): + """Verify frame building produces correct format.""" + payload = {"login": {"command": "detect"}} + frame = bind_server._build_frame(payload) + + # Header: 0xA5A5 + assert frame[:2] == b"\xa5\xa5" + # Trailer: 0xA7A7 + assert frame[-2:] == b"\xa7\xa7" + # Length field is total message size (LE uint16) + import struct + + total_len = struct.unpack_from("