mqtt_server.py 56 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287
  1. """MQTT broker for virtual printer.
  2. Implements an MQTT broker that accepts connections from slicers,
  3. authenticates with the configured access code, and logs print commands.
  4. """
  5. import asyncio
  6. import copy
  7. import hmac
  8. import json
  9. import logging
  10. import socket
  11. import ssl
  12. from collections.abc import Callable
  13. from pathlib import Path
  14. from typing import TYPE_CHECKING
  15. from backend.app.services.virtual_printer._debug import dump_wire
  16. if TYPE_CHECKING:
  17. from backend.app.services.virtual_printer.mqtt_bridge import MQTTBridge
  18. logger = logging.getLogger(__name__)
  19. # Default MQTT port for Bambu printers (MQTT over TLS)
  20. MQTT_PORT = 8883
  21. # Per-IP MQTT auth rate-limit. 5 failures within 60 s blocks further attempts
  22. # for the remainder of the window. Bambu printers themselves don't rate-limit,
  23. # but they're not exposed past the LAN edge; Bambuddy's VPs sometimes are
  24. # (Tailscale, port-forwarded), so an 8-char access code without any
  25. # brute-force friction is too weak. The window auto-recovers — no manual
  26. # unblock — so a legitimate user who fat-fingered their access code 5 times
  27. # only waits up to 60 s.
  28. _AUTH_RATE_LIMIT_MAX_ATTEMPTS = 5
  29. _AUTH_RATE_LIMIT_WINDOW_SECONDS = 60.0
  30. # Pending-request map bound. Each entry maps a slicer command's
  31. # sequence_id to its originating client_id so the bridge response can be
  32. # routed back to just that client. Bounded so a slicer that issues
  33. # commands without ever consuming responses can't leak memory.
  34. _PENDING_REQUEST_MAX_ENTRIES = 256
  35. # Model code → product_name for version response (must match what slicer expects)
  36. MODEL_PRODUCT_NAMES = {
  37. "BL-P001": "X1 Carbon",
  38. "BL-P002": "X1",
  39. "C13": "X1E",
  40. "N6": "X2D",
  41. "N9": "A2L",
  42. "C11": "P1P",
  43. "C12": "P1S",
  44. "N7": "P2S",
  45. "N2S": "A1",
  46. "N1": "A1 mini",
  47. "O1D": "H2D",
  48. "O1C": "H2C",
  49. "O1C2": "H2C",
  50. "O1S": "H2S",
  51. }
  52. class VirtualPrinterMQTTServer:
  53. """MQTT broker that accepts connections from slicers.
  54. This is a minimal MQTT broker implementation that:
  55. - Accepts TLS connections on port 8883
  56. - Authenticates with username 'bblp' and the configured access code
  57. - Receives print commands on device/{serial}/request
  58. - Can publish status on device/{serial}/report
  59. """
  60. def __init__(
  61. self,
  62. serial: str,
  63. access_code: str,
  64. cert_path: Path,
  65. key_path: Path,
  66. port: int = MQTT_PORT,
  67. on_print_command: Callable[[str, dict], None] | None = None,
  68. ):
  69. """Initialize the MQTT server.
  70. Args:
  71. serial: Virtual printer serial number
  72. access_code: Password for authentication
  73. cert_path: Path to TLS certificate
  74. key_path: Path to TLS private key
  75. port: Port to listen on (default 8883)
  76. on_print_command: Callback when print command received (filename, data)
  77. """
  78. self.serial = serial
  79. self.access_code = access_code
  80. self.cert_path = cert_path
  81. self.key_path = key_path
  82. self.port = port
  83. self.on_print_command = on_print_command
  84. self._running = False
  85. self._broker = None
  86. self._broker_task = None
  87. async def start(self) -> None:
  88. """Start the MQTT broker."""
  89. if self._running:
  90. return
  91. # Try to import amqtt
  92. try:
  93. from amqtt.broker import Broker
  94. except ImportError:
  95. logger.error("amqtt not installed. Run: pip install amqtt")
  96. return
  97. logger.info("Starting virtual printer MQTT broker on port %s", self.port)
  98. # Build broker configuration
  99. config = {
  100. "listeners": {
  101. "default": {
  102. "type": "tcp",
  103. "bind": f"0.0.0.0:{self.port}",
  104. "ssl": "on",
  105. "certfile": str(self.cert_path),
  106. "keyfile": str(self.key_path),
  107. },
  108. },
  109. "auth": {
  110. "allow-anonymous": False,
  111. "plugins": ["auth_custom"],
  112. },
  113. "topic-check": {
  114. "enabled": False, # Allow any topic
  115. },
  116. }
  117. try:
  118. self._running = True
  119. # Create and start broker
  120. self._broker = Broker(config)
  121. # Register custom auth plugin
  122. self._broker.plugins_manager.plugins_handlers["auth_custom"] = self._authenticate
  123. # Start the broker
  124. await self._broker.start()
  125. logger.info("MQTT broker started on port %s", self.port)
  126. # Keep running
  127. while self._running:
  128. await asyncio.sleep(1)
  129. except OSError as e:
  130. if e.errno == 98: # Address already in use
  131. logger.error("MQTT port %s is already in use", self.port)
  132. else:
  133. logger.error("MQTT broker error: %s", e)
  134. except asyncio.CancelledError:
  135. logger.debug("MQTT broker task cancelled")
  136. except Exception as e:
  137. logger.error("MQTT broker error: %s", e)
  138. finally:
  139. await self.stop()
  140. async def _authenticate(self, session) -> bool:
  141. """Authenticate MQTT connection.
  142. Args:
  143. session: MQTT session with username/password
  144. Returns:
  145. True if authentication successful
  146. """
  147. username = getattr(session, "username", None)
  148. password = getattr(session, "password", None)
  149. # Bambu slicers use 'bblp' as username and access code as password
  150. if username == "bblp" and password == self.access_code:
  151. logger.debug("MQTT client authenticated from %s", session.remote_address)
  152. return True
  153. logger.warning("MQTT auth failed for user '%s' from %s", username, session.remote_address)
  154. return False
  155. async def stop(self) -> None:
  156. """Stop the MQTT broker."""
  157. logger.info("Stopping MQTT broker")
  158. self._running = False
  159. if self._broker:
  160. try:
  161. await self._broker.shutdown()
  162. except OSError as e:
  163. logger.debug("Error shutting down MQTT broker: %s", e)
  164. self._broker = None
  165. class SimpleMQTTServer:
  166. """Simplified MQTT server using raw sockets.
  167. This is a fallback implementation that handles basic MQTT protocol
  168. without requiring the amqtt library. It's less feature-complete but
  169. more lightweight.
  170. """
  171. def __init__(
  172. self,
  173. serial: str,
  174. access_code: str,
  175. cert_path: Path,
  176. key_path: Path,
  177. port: int = MQTT_PORT,
  178. on_print_command: Callable[[str, dict], None] | None = None,
  179. model: str = "",
  180. bind_address: str = "0.0.0.0", # nosec B104
  181. vp_name: str = "",
  182. ):
  183. self.serial = serial
  184. self.access_code = access_code
  185. self.model = model
  186. self.cert_path = cert_path
  187. self.key_path = key_path
  188. self.port = port
  189. self.on_print_command = on_print_command
  190. self.bind_address = bind_address
  191. self.vp_name = vp_name
  192. self._log_prefix = f"[{vp_name}] " if vp_name else ""
  193. self._running = False
  194. # Set after the socket is bound — see ftp_server.py for rationale.
  195. self.ready = asyncio.Event()
  196. self._server = None
  197. self._clients: dict[str, asyncio.StreamWriter] = {}
  198. # Per-client "effective serial" — the serial the slicer actually uses in
  199. # device/{serial}/report|request topics. Populated from the first
  200. # SUBSCRIBE/PUBLISH we see on a connection. This lets the VP respond on
  201. # the topic the slicer is listening on even when it disagrees with
  202. # self.serial (e.g. a stale Orca config that was bound to an older VP
  203. # serial, or a printer entry that was re-pointed at the VP IP without
  204. # updating the serial).
  205. self._client_serials: dict[str, str] = {}
  206. self._status_push_task: asyncio.Task | None = None
  207. self._sequence_id = 0
  208. # Dynamic state for status reports
  209. self._gcode_state = "IDLE"
  210. self._current_file = ""
  211. self._prepare_percent = "0"
  212. # MQTT bridge for non-proxy modes — set by VirtualPrinterInstance after start().
  213. # When the bridge is_active, real printer pushes are fanned out to slicers and
  214. # the synthetic 1s push is suspended. When the target printer goes offline the
  215. # synthetic fallback resumes automatically.
  216. self._bridge: MQTTBridge | None = None
  217. # Per-source-IP failed-auth tracker for rate-limiting / lockout.
  218. # Maps IP → list[monotonic timestamp] of recent failures within the
  219. # window. Pruned on every check so it doesn't grow unbounded.
  220. self._auth_failures: dict[str, list[float]] = {}
  221. # Maps sequence_id → originating client_id for slicer-initiated
  222. # commands forwarded to the real printer. Used in
  223. # ``push_raw_to_clients`` to route the printer's response only
  224. # back to the requesting slicer instead of fanning out to all
  225. # connected clients (which leaks slicer A's responses to slicer
  226. # B in multi-slicer setups). FIFO-bounded; if a response never
  227. # arrives the entry ages out instead of leaking.
  228. self._pending_requests: dict[str, str] = {}
  229. async def start(self) -> None:
  230. """Start the MQTT server."""
  231. if self._running:
  232. return
  233. logger.info("Starting simple MQTT server on port %s", self.port)
  234. # Create SSL context with Bambu-compatible settings
  235. ssl_context = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER)
  236. ssl_context.load_cert_chain(str(self.cert_path), str(self.key_path))
  237. # Match Bambu printer behavior - accept any client
  238. ssl_context.verify_mode = ssl.CERT_NONE
  239. # Allow TLS 1.2 for broader compatibility (some slicers may not support 1.3)
  240. ssl_context.minimum_version = ssl.TLSVersion.TLSv1_2
  241. # Match real Bambu printer cipher behaviour: include the plain-RSA
  242. # AES-GCM suites the slicer expects. On hardened distros
  243. # (Fedora / RHEL with `update-crypto-policies`, hardened Alpine builds)
  244. # OpenSSL's `DEFAULT` list strips these suites, leaving no overlap
  245. # with the slicer's MQTT-over-TLS ClientHello — handshake fails
  246. # immediately and the slicer reports a connect error before any MQTT
  247. # CONNECT can be sent (#1610 audit). Same shape as the #620 fix.
  248. ssl_context.set_ciphers("DEFAULT:AES256-GCM-SHA384:AES128-GCM-SHA256")
  249. # Disable hostname checking
  250. ssl_context.check_hostname = False
  251. # Log certificate info
  252. import subprocess
  253. try:
  254. result = subprocess.run(
  255. ["openssl", "x509", "-in", str(self.cert_path), "-noout", "-subject", "-issuer"],
  256. capture_output=True,
  257. text=True,
  258. timeout=5,
  259. )
  260. logger.info("MQTT SSL cert info: %s", result.stdout.strip())
  261. except (OSError, subprocess.SubprocessError):
  262. pass # Certificate info is for debug logging only; not critical
  263. logger.info("MQTT SSL context: TLS 1.2+, cert=%s", self.cert_path)
  264. try:
  265. self._running = True
  266. # Wrapper to log ALL connection attempts including SSL errors
  267. async def connection_handler(reader, writer):
  268. try:
  269. addr = writer.get_extra_info("peername")
  270. ssl_obj = writer.get_extra_info("ssl_object")
  271. if ssl_obj:
  272. logger.info(
  273. f"{self._log_prefix}MQTT TLS connection from {addr} - cipher={ssl_obj.cipher()}, version={ssl_obj.version()}"
  274. )
  275. else:
  276. logger.info("%sMQTT connection from %s (no TLS?)", self._log_prefix, addr)
  277. await self._handle_client(reader, writer)
  278. except ssl.SSLError as e:
  279. logger.error("MQTT SSL error: %s", e)
  280. except Exception as e:
  281. logger.error("MQTT connection handler error: %s", e)
  282. self._server = await asyncio.start_server(
  283. connection_handler,
  284. self.bind_address,
  285. self.port,
  286. ssl=ssl_context,
  287. )
  288. self.ready.set()
  289. logger.info("Simple MQTT server listening on port %s", self.port)
  290. # Start periodic status push task
  291. self._status_push_task = asyncio.create_task(self._periodic_status_push())
  292. async with self._server:
  293. await self._server.serve_forever()
  294. except OSError as e:
  295. if e.errno == 98: # Address already in use
  296. logger.error("MQTT port %s is already in use", self.port)
  297. else:
  298. logger.error("MQTT server error: %s", e)
  299. except asyncio.CancelledError:
  300. logger.debug("MQTT server task cancelled")
  301. except Exception as e:
  302. logger.error("MQTT server error: %s", e)
  303. finally:
  304. await self.stop()
  305. async def stop(self) -> None:
  306. """Stop the MQTT server."""
  307. logger.info("Stopping simple MQTT server")
  308. self._running = False
  309. self.ready.clear()
  310. # Stop periodic status push
  311. if self._status_push_task:
  312. self._status_push_task.cancel()
  313. try:
  314. await self._status_push_task
  315. except asyncio.CancelledError:
  316. pass # Expected when stopping the periodic status push task
  317. self._status_push_task = None
  318. # Close all client connections (iterate over copy to avoid modification during iteration)
  319. for _client_id, writer in list(self._clients.items()):
  320. try:
  321. writer.close()
  322. await writer.wait_closed()
  323. except OSError:
  324. pass # Best-effort client connection cleanup; client may have disconnected
  325. self._clients.clear()
  326. self._client_serials.clear()
  327. if self._server:
  328. try:
  329. self._server.close()
  330. await self._server.wait_closed()
  331. except OSError:
  332. pass # Best-effort server shutdown; port may already be released
  333. self._server = None
  334. @staticmethod
  335. def _extract_serial_from_topic(topic: str) -> str | None:
  336. """Pull the serial out of a `device/{serial}/report|request` topic.
  337. Returns None if the topic doesn't match that shape — callers fall back
  338. to self.serial in that case.
  339. """
  340. if not topic.startswith("device/"):
  341. return None
  342. rest = topic[len("device/") :]
  343. # Expect "{serial}/report" or "{serial}/request" (possibly with suffixes).
  344. slash = rest.find("/")
  345. if slash <= 0:
  346. return None
  347. return rest[:slash]
  348. def set_bridge(self, bridge: "MQTTBridge | None") -> None:
  349. """Attach (or detach) the MQTT bridge that mirrors the target printer."""
  350. self._bridge = bridge
  351. async def _periodic_status_push(self) -> None:
  352. """Send periodic status updates to all connected clients (1 Hz, exact pre-bridge behaviour)."""
  353. logger.info("Starting periodic status push task")
  354. # Per-client push counters reset every 60 ticks. Lets us confirm from
  355. # logs whether the 1Hz push is actually reaching a specific slicer
  356. # connection (#1548 keepalive follow-up: keepalive parser shipped but
  357. # OrcaSlicer still disconnects on idle, and the periodic push is
  358. # otherwise silent at INFO level so it can't be observed in the
  359. # support bundle). One log line per minute per active connection —
  360. # nothing when no slicer is attached.
  361. push_counts: dict[str, int] = {}
  362. ticks_since_summary = 0
  363. while self._running:
  364. try:
  365. await asyncio.sleep(1) # Push every 1 second like real printers
  366. ticks_since_summary += 1
  367. disconnected = []
  368. for client_id, writer in list(self._clients.items()):
  369. try:
  370. if writer.is_closing():
  371. disconnected.append(client_id)
  372. continue
  373. serial = self._client_serials.get(client_id, self.serial)
  374. await self._send_status_report(writer, serial=serial)
  375. push_counts[client_id] = push_counts.get(client_id, 0) + 1
  376. except OSError as e:
  377. logger.debug("Failed to push status to %s: %s", client_id, e)
  378. disconnected.append(client_id)
  379. # Remove disconnected clients
  380. for client_id in disconnected:
  381. self._clients.pop(client_id, None)
  382. self._client_serials.pop(client_id, None)
  383. push_counts.pop(client_id, None)
  384. if ticks_since_summary >= 60:
  385. for cid, count in push_counts.items():
  386. logger.info(
  387. "%s1Hz status push: %d pushes/min to %s",
  388. self._log_prefix,
  389. count,
  390. cid,
  391. )
  392. push_counts.clear()
  393. ticks_since_summary = 0
  394. except asyncio.CancelledError:
  395. break
  396. except Exception as e:
  397. logger.error("Periodic status push error: %s", e)
  398. logger.info("Periodic status push task stopped")
  399. async def push_raw_to_clients(self, topic: str, payload: bytes) -> None:
  400. """Publish a pre-serialized MQTT payload on `topic` to connected slicers.
  401. Called by MQTTBridge from the asyncio loop (scheduled via
  402. run_coroutine_threadsafe from paho's network thread).
  403. Routes the response only back to the originating slicer if the
  404. payload's sequence_id was previously recorded via
  405. ``_record_pending_request``. Falls back to fan-out for
  406. printer-initiated pushes (push_status etc.) and for sequence_ids
  407. we never saw (covers a slicer that subscribes mid-flight to a
  408. topic for which an earlier request is still in flight).
  409. """
  410. topic_bytes = topic.encode("utf-8")
  411. # MQTT remaining-length: 2-byte topic length prefix + topic + message body.
  412. remaining = 2 + len(topic_bytes) + len(payload)
  413. packet = bytearray([0x30]) # PUBLISH, QoS 0
  414. while True:
  415. byte = remaining % 128
  416. remaining //= 128
  417. if remaining > 0:
  418. byte |= 0x80
  419. packet.append(byte)
  420. if remaining == 0:
  421. break
  422. packet.extend([len(topic_bytes) >> 8, len(topic_bytes) & 0xFF])
  423. packet.extend(topic_bytes)
  424. packet.extend(payload)
  425. frame = bytes(packet)
  426. target_client_id = self._lookup_pending_request_client(payload)
  427. disconnected = []
  428. for client_id, writer in list(self._clients.items()):
  429. if target_client_id is not None and client_id != target_client_id:
  430. continue
  431. try:
  432. if writer.is_closing():
  433. disconnected.append(client_id)
  434. continue
  435. writer.write(frame)
  436. try:
  437. await asyncio.wait_for(writer.drain(), timeout=5)
  438. except TimeoutError:
  439. logger.debug("MQTT drain timeout pushing bridge frame to %s", client_id)
  440. except OSError as e:
  441. logger.debug("Failed to push bridge frame to %s: %s", client_id, e)
  442. disconnected.append(client_id)
  443. for client_id in disconnected:
  444. self._clients.pop(client_id, None)
  445. self._client_serials.pop(client_id, None)
  446. async def _handle_client(self, reader: asyncio.StreamReader, writer: asyncio.StreamWriter) -> None:
  447. """Handle an MQTT client connection."""
  448. addr = writer.get_extra_info("peername")
  449. client_id = f"{addr[0]}:{addr[1]}" if addr else "unknown"
  450. logger.info("%sMQTT client connected: %s", self._log_prefix, client_id)
  451. authenticated = False
  452. # Per-packet read timeout. Before CONNECT we default to 60 s so a
  453. # client that opens TCP but never sends anything still gets reaped.
  454. # After CONNECT we drop the application-level read timeout entirely
  455. # and rely on TCP keepalive (SO_KEEPALIVE) to detect dead connections
  456. # — this matches real Bambu firmware, which does not enforce MQTT
  457. # spec §4.4's 1.5× idle disconnect (#1548 round 2). OrcaSlicer's
  458. # MQTT client on some platforms does not emit PINGREQ at all on idle
  459. # connections; the same install that stays connected to a real P1S
  460. # indefinitely was disconnecting from us at keepalive×1.5.
  461. read_timeout: float | None = 60.0
  462. try:
  463. while self._running:
  464. # Read MQTT fixed header
  465. try:
  466. header = await asyncio.wait_for(reader.read(1), timeout=read_timeout)
  467. except TimeoutError:
  468. break
  469. if not header:
  470. break
  471. packet_type = (header[0] & 0xF0) >> 4
  472. # Read remaining length
  473. remaining_length = await self._read_remaining_length(reader)
  474. if remaining_length is None:
  475. break
  476. # Read payload
  477. payload = await reader.read(remaining_length) if remaining_length > 0 else b""
  478. # Handle packet types
  479. if packet_type == 1: # CONNECT
  480. source_ip = addr[0] if addr else "unknown"
  481. if self._is_auth_rate_limited(source_ip):
  482. logger.warning(
  483. "%sMQTT auth rate-limited from %s (>=%d failures in %ds)",
  484. self._log_prefix,
  485. source_ip,
  486. _AUTH_RATE_LIMIT_MAX_ATTEMPTS,
  487. int(_AUTH_RATE_LIMIT_WINDOW_SECONDS),
  488. )
  489. writer.write(bytes([0x20, 0x02, 0x00, 0x05])) # Not authorized
  490. await writer.drain()
  491. break
  492. authenticated, keep_alive = await self._handle_connect(payload, writer)
  493. if not authenticated:
  494. self._record_auth_failure(source_ip)
  495. break
  496. self._clear_auth_failures(source_ip)
  497. # Drop the application-level read timeout; rely on
  498. # SO_KEEPALIVE below for dead-connection detection.
  499. # Real Bambu firmware does the same — accept any
  500. # negotiated keepalive but never enforce §4.4's 1.5×
  501. # disconnect on the otherwise-idle MQTT session
  502. # (#1548 round 2). keep_alive is logged for support
  503. # bundles but no longer drives a disconnect.
  504. read_timeout = None
  505. logger.info(
  506. "%sMQTT client %s authenticated (negotiated keepalive=%ds, idle disconnect disabled)",
  507. self._log_prefix,
  508. client_id,
  509. keep_alive,
  510. )
  511. # Enable TCP keepalive so a hard network drop is detected
  512. # by the OS within a few minutes rather than waiting for
  513. # the next outbound write to ECONNRESET.
  514. sock = writer.get_extra_info("socket")
  515. if sock is not None:
  516. try:
  517. sock.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1)
  518. except OSError as e:
  519. logger.debug("%sFailed to set SO_KEEPALIVE on %s: %s", self._log_prefix, client_id, e)
  520. # Register client for periodic status pushes; start with
  521. # self.serial as the fallback until we learn the slicer's
  522. # preferred serial from the first SUBSCRIBE/PUBLISH.
  523. self._clients[client_id] = writer
  524. self._client_serials[client_id] = self.serial
  525. elif packet_type == 3: # PUBLISH
  526. if authenticated:
  527. await self._handle_publish(header[0], payload, writer, client_id)
  528. elif packet_type == 8: # SUBSCRIBE
  529. if authenticated:
  530. await self._handle_subscribe(payload, writer, client_id)
  531. elif packet_type == 12: # PINGREQ
  532. # Send PINGRESP
  533. writer.write(bytes([0xD0, 0x00]))
  534. await writer.drain()
  535. elif packet_type == 14: # DISCONNECT
  536. break
  537. except asyncio.CancelledError:
  538. pass # Expected when server is shutting down and cancels client tasks
  539. except Exception as e:
  540. # Outer handler — inner handlers already absorb expected parser
  541. # / IO failures at debug. Anything reaching here is unexpected
  542. # and would otherwise silently drop the slicer connection with
  543. # no actionable signal in production logs (defaults are INFO+).
  544. logger.warning("%sMQTT client session error from %s: %s", self._log_prefix, client_id, e)
  545. finally:
  546. logger.debug("MQTT client disconnected: %s", client_id)
  547. self._clients.pop(client_id, None)
  548. self._client_serials.pop(client_id, None)
  549. try:
  550. writer.close()
  551. await writer.wait_closed()
  552. except OSError:
  553. pass # Best-effort socket cleanup on client disconnect
  554. async def _read_remaining_length(self, reader: asyncio.StreamReader) -> int | None:
  555. """Read MQTT remaining length (variable byte integer)."""
  556. multiplier = 1
  557. value = 0
  558. for _ in range(4):
  559. try:
  560. byte = await reader.read(1)
  561. if not byte:
  562. return None
  563. encoded = byte[0]
  564. value += (encoded & 127) * multiplier
  565. if (encoded & 128) == 0:
  566. return value
  567. multiplier *= 128
  568. except OSError:
  569. return None
  570. return None
  571. def _record_pending_request(self, data: dict, client_id: str) -> None:
  572. """Stash sequence_id → client_id for any nested block with a sequence_id.
  573. Slicer commands typically wrap their seq id in ``{"print": {...}}`` or
  574. ``{"info": {...}}`` / ``{"system": {...}}`` etc. Walks top-level dict
  575. values once to find the seq id; if absent (some commands omit it) we
  576. skip — the response will fall through to broadcast which is fine for
  577. unsolicited pushes.
  578. """
  579. for block in data.values():
  580. if isinstance(block, dict):
  581. seq = block.get("sequence_id")
  582. if seq is not None:
  583. key = str(seq)
  584. # Evict oldest entry when over the cap. Python dicts
  585. # preserve insertion order so iter(self._pending_requests)
  586. # yields the oldest key first.
  587. while len(self._pending_requests) >= _PENDING_REQUEST_MAX_ENTRIES:
  588. oldest = next(iter(self._pending_requests))
  589. self._pending_requests.pop(oldest, None)
  590. self._pending_requests[key] = client_id
  591. return
  592. def _lookup_pending_request_client(self, payload: bytes) -> str | None:
  593. """Parse a bridge-forwarded MQTT payload and return the originating
  594. client_id if its sequence_id was recorded.
  595. Returns ``None`` for printer-initiated pushes (no recorded seq id) so
  596. push_raw_to_clients falls back to broadcast — required for push_status
  597. and the other unsolicited pushes that every connected slicer expects.
  598. """
  599. try:
  600. parsed = json.loads(payload)
  601. except (ValueError, TypeError):
  602. return None
  603. if not isinstance(parsed, dict):
  604. return None
  605. for block in parsed.values():
  606. if isinstance(block, dict):
  607. seq = block.get("sequence_id")
  608. if seq is not None:
  609. return self._pending_requests.pop(str(seq), None)
  610. return None
  611. def _is_auth_rate_limited(self, source_ip: str) -> bool:
  612. """Return True if ``source_ip`` has hit the per-IP failure cap.
  613. Prunes timestamps older than the window so the dict doesn't grow
  614. unbounded. Uses ``time.monotonic()`` for a wall-clock-jump-immune
  615. clock that's safe to call from any context (sync or async).
  616. """
  617. import time as _time
  618. now = _time.monotonic()
  619. window_start = now - _AUTH_RATE_LIMIT_WINDOW_SECONDS
  620. recent = [t for t in self._auth_failures.get(source_ip, []) if t >= window_start]
  621. if recent:
  622. self._auth_failures[source_ip] = recent
  623. else:
  624. self._auth_failures.pop(source_ip, None)
  625. return len(recent) >= _AUTH_RATE_LIMIT_MAX_ATTEMPTS
  626. def _record_auth_failure(self, source_ip: str) -> None:
  627. """Append a timestamp for ``source_ip``'s failed auth attempt."""
  628. import time as _time
  629. now = _time.monotonic()
  630. self._auth_failures.setdefault(source_ip, []).append(now)
  631. def _clear_auth_failures(self, source_ip: str) -> None:
  632. """Reset ``source_ip``'s failure history after a successful auth."""
  633. self._auth_failures.pop(source_ip, None)
  634. async def _handle_connect(self, payload: bytes, writer: asyncio.StreamWriter) -> tuple[bool, int]:
  635. """Handle MQTT CONNECT packet.
  636. Returns ``(authenticated, keep_alive_seconds)`` — the second element
  637. is the value the client advertised in CONNECT, so the caller's
  638. read-loop can honour it instead of the hardcoded default. ``0``
  639. means the client opted out of keepalive (#1548).
  640. """
  641. try:
  642. # Parse CONNECT packet
  643. # Skip protocol name length and name
  644. idx = 0
  645. proto_len = (payload[idx] << 8) | payload[idx + 1]
  646. idx += 2 + proto_len
  647. # Skip protocol level and connect flags
  648. # connect_flags = payload[idx + 1]
  649. idx += 2
  650. # Keepalive (2-byte big-endian, seconds). Honoured by the read
  651. # loop in `_handle_client` per MQTT spec §3.1.2.10 / §4.4 —
  652. # before #1548 we ignored this and used a hardcoded 60 s, which
  653. # closed OrcaSlicer's idle connection at exactly the negotiated
  654. # keepalive boundary instead of the spec-mandated 1.5×.
  655. keep_alive = (payload[idx] << 8) | payload[idx + 1]
  656. idx += 2
  657. # Read client ID
  658. client_id_len = (payload[idx] << 8) | payload[idx + 1]
  659. idx += 2
  660. # client_id = payload[idx : idx + client_id_len].decode("utf-8")
  661. idx += client_id_len
  662. # Read username
  663. username_len = (payload[idx] << 8) | payload[idx + 1]
  664. idx += 2
  665. username = payload[idx : idx + username_len].decode("utf-8")
  666. idx += username_len
  667. # Read password
  668. password_len = (payload[idx] << 8) | payload[idx + 1]
  669. idx += 2
  670. password = payload[idx : idx + password_len].decode("utf-8")
  671. # Authenticate. ``hmac.compare_digest`` is constant-time to keep
  672. # the auth check from leaking the access code via response timing
  673. # under network jitter — LAN-only threat is marginal, but it's
  674. # the standard fix and costs nothing.
  675. if username == "bblp" and hmac.compare_digest(password, self.access_code):
  676. # Send CONNACK with success
  677. writer.write(bytes([0x20, 0x02, 0x00, 0x00]))
  678. await writer.drain()
  679. logger.info("%sMQTT client authenticated successfully", self._log_prefix)
  680. # Send immediate status report after auth - slicer expects this
  681. await self._send_status_report(writer)
  682. return True, keep_alive
  683. else:
  684. # Send CONNACK with auth failure
  685. writer.write(bytes([0x20, 0x02, 0x00, 0x05])) # Not authorized
  686. await writer.drain()
  687. logger.warning("%sMQTT auth failed for user '%s' (access code mismatch)", self._log_prefix, username)
  688. return False, 0
  689. except (IndexError, ValueError) as e:
  690. logger.debug("MQTT CONNECT parse error: %s", e)
  691. # Send CONNACK with error
  692. writer.write(bytes([0x20, 0x02, 0x00, 0x02])) # Protocol error
  693. await writer.drain()
  694. return False, 0
  695. async def _handle_subscribe(self, payload: bytes, writer: asyncio.StreamWriter, client_id: str) -> None:
  696. """Handle MQTT SUBSCRIBE packet."""
  697. try:
  698. # Parse packet ID
  699. packet_id = (payload[0] << 8) | payload[1]
  700. # Parse topic filters (just acknowledge them)
  701. idx = 2
  702. granted_qos = []
  703. learned_serial: str | None = None
  704. while idx < len(payload):
  705. topic_len = (payload[idx] << 8) | payload[idx + 1]
  706. idx += 2
  707. topic = payload[idx : idx + topic_len].decode("utf-8")
  708. idx += topic_len
  709. requested_qos = payload[idx]
  710. idx += 1
  711. logger.info("%sMQTT subscribe: %s QoS=%s", self._log_prefix, topic, requested_qos)
  712. granted_qos.append(min(requested_qos, 1)) # Grant up to QoS 1
  713. # Remember the serial the slicer is listening on so status/version
  714. # responses go to a topic it actually subscribed to.
  715. if learned_serial is None:
  716. extracted = self._extract_serial_from_topic(topic)
  717. if extracted:
  718. learned_serial = extracted
  719. if learned_serial and learned_serial != self._client_serials.get(client_id):
  720. if learned_serial != self.serial:
  721. logger.info(
  722. "%sMQTT client subscribed with serial %s (VP serial is %s) — adapting responses",
  723. self._log_prefix,
  724. learned_serial,
  725. self.serial,
  726. )
  727. self._client_serials[client_id] = learned_serial
  728. # Send SUBACK
  729. suback = bytes([0x90, 2 + len(granted_qos), packet_id >> 8, packet_id & 0xFF])
  730. suback += bytes(granted_qos)
  731. writer.write(suback)
  732. await writer.drain()
  733. # Send initial status report after subscribe on the client's subscribed topic
  734. await self._send_status_report(writer, serial=self._client_serials.get(client_id, self.serial))
  735. except (IndexError, ValueError, OSError) as e:
  736. logger.debug("MQTT SUBSCRIBE error: %s", e)
  737. async def _send_status_report(self, writer: asyncio.StreamWriter, serial: str | None = None) -> None:
  738. """Send a status report to the slicer after connection.
  739. When a bridge is active and has cached the real printer's latest
  740. push_status, send a copy of the real push with only the upload-state-
  741. machine fields we own (gcode_state, gcode_file, prepare_percent,
  742. subtask_name) overridden. BambuStudio's Send pre-flight checks the
  743. push_status shape against what it expects from the printer model, and
  744. the synthetic stub introduced fields the real H2D doesn't have (storage,
  745. the wrong chamber_temper shape, etc.) which trip the check.
  746. """
  747. try:
  748. self._sequence_id += 1
  749. cached = self._bridge.get_latest_print_state() if self._bridge is not None else None
  750. if isinstance(cached, dict):
  751. # Real-printer-shaped response. Copy the cache, then replace the
  752. # protocol / upload-state fields with values under our control.
  753. # Deep copy — current mutations are top-level only, but a future
  754. # override that writes into a nested dict (e.g. ``online``,
  755. # ``upgrade_state``, ``ipcam``) would otherwise corrupt the
  756. # bridge cache and be read by every subsequent subscriber until
  757. # the next real-printer push lands. Cost is one allocation per
  758. # status report; the cached dict is already short-lived.
  759. print_block = copy.deepcopy(cached)
  760. print_block["sequence_id"] = str(self._sequence_id)
  761. print_block["command"] = "push_status"
  762. print_block["msg"] = 0
  763. print_block["gcode_state"] = self._gcode_state
  764. print_block["gcode_file"] = self._current_file
  765. print_block["gcode_file_prepare_percent"] = self._prepare_percent
  766. if self._current_file:
  767. print_block["subtask_name"] = self._current_file.replace(".3mf", "")
  768. else:
  769. # Don't override real subtask_name with empty if no upload pending.
  770. print_block.setdefault("subtask_name", "")
  771. # Storage-availability indicators the slicer's "Send" pre-flight reads
  772. # (#1228). P1S/A1-class firmware doesn't always include these in
  773. # push_status (no SD card inserted, older field shapes), and BambuStudio
  774. # rejects the send pre-flight with the generic "storage needs to be
  775. # inserted before send to printer" error before even attempting FTP.
  776. # For VP usage the slicer uploads via FTPS to Bambuddy's filesystem —
  777. # the printer's actual SD/storage state is irrelevant on that path.
  778. # Force "available" indicators so the pre-flight passes regardless of
  779. # what the real printer reports. Restores the 0.2.3.2 synthetic-stub
  780. # behaviour for these fields without losing the live AMS / k-profile /
  781. # camera mirror cached-as-base provides.
  782. print_block["home_flag"] = print_block.get("home_flag", 0) | 0x100 # bit 8 = HAS_SDCARD_NORMAL
  783. print_block["sdcard"] = True
  784. print_block.setdefault("storage", {"free": 1_000_000_000, "total": 32_000_000_000})
  785. # Live-progress fields the slicer's Send pre-flight reads
  786. # (#1558). When the real target printer is mid-print, the
  787. # cached push_status carries the real values for these
  788. # fields and the slicer reads the VP as "busy" — refusing
  789. # Send — even though gcode_state above is forced to IDLE.
  790. # For VP usage the VP isn't actually running the print
  791. # the printer is, so these need to mirror the synthetic
  792. # stub's idle values. Same shape as #1228 (storage) — the
  793. # cached-branch override set just needed extending.
  794. print_block["mc_print_stage"] = ""
  795. print_block["mc_percent"] = 0
  796. print_block["mc_remaining_time"] = 0
  797. print_block["stg"] = []
  798. print_block["stg_cur"] = 0
  799. print_block["layer_num"] = 0
  800. print_block["total_layer_num"] = 0
  801. print_block["print_error"] = 0
  802. status = {"print": print_block}
  803. dump_wire(self.vp_name, "out", status)
  804. await self._publish_to_report(writer, status, serial or self.serial)
  805. return
  806. # No bridge / no cache yet — fall back to the synthetic stub.
  807. status = {
  808. "print": {
  809. "sequence_id": str(self._sequence_id),
  810. "command": "push_status",
  811. "msg": 0,
  812. "gcode_state": self._gcode_state,
  813. "gcode_file": self._current_file,
  814. "gcode_file_prepare_percent": self._prepare_percent,
  815. "subtask_name": self._current_file.replace(".3mf", "") if self._current_file else "",
  816. "mc_print_stage": "",
  817. "mc_percent": 0,
  818. "mc_remaining_time": 0,
  819. "wifi_signal": "-44dBm",
  820. "print_error": 0,
  821. "print_type": "",
  822. "bed_temper": 25.0,
  823. "bed_target_temper": 0.0,
  824. "nozzle_temper": 25.0,
  825. "nozzle_target_temper": 0.0,
  826. "chamber_temper": 25.0,
  827. "cooling_fan_speed": "0",
  828. "big_fan1_speed": "0",
  829. "big_fan2_speed": "0",
  830. "heatbreak_fan_speed": "0",
  831. "spd_lvl": 1,
  832. "spd_mag": 100,
  833. "stg": [],
  834. "stg_cur": 0,
  835. "layer_num": 0,
  836. "total_layer_num": 0,
  837. "home_flag": 256, # Bit 8 = SD card present (HAS_SDCARD_NORMAL)
  838. "hw_switch_state": 0,
  839. "online": {"ahb": False, "rfid": False, "version": 7},
  840. "ams_status": 0,
  841. "sdcard": True,
  842. "storage": {"free": 1000000000, "total": 32000000000},
  843. "upgrade_state": {
  844. "sequence_id": 0,
  845. "progress": "",
  846. "status": "",
  847. "consistency_request": False,
  848. "dis_state": 0,
  849. "err_code": 0,
  850. "force_upgrade": False,
  851. "message": "",
  852. "module": "",
  853. "new_version_state": 2,
  854. "new_ver_list": [],
  855. "ota_new_version_number": "",
  856. "ahb_new_version_number": "",
  857. },
  858. "ipcam": {
  859. "ipcam_dev": "1",
  860. "ipcam_record": "enable",
  861. "timelapse": "disable",
  862. "resolution": "1080p",
  863. "mode_bits": 0,
  864. },
  865. "xcam": {
  866. "allow_skip_parts": False,
  867. "buildplate_marker_detector": True,
  868. "first_layer_inspector": True,
  869. "halt_print_sensitivity": "medium",
  870. "print_halt": True,
  871. "printing_monitor": True,
  872. "spaghetti_detector": True,
  873. },
  874. "lights_report": [{"node": "chamber_light", "mode": "on"}],
  875. "nozzle_diameter": "0.4",
  876. "nozzle_type": "hardened_steel",
  877. }
  878. }
  879. await self._publish_to_report(writer, status, serial or self.serial)
  880. except OSError as e:
  881. logger.error("Failed to send status report: %s", e)
  882. async def _send_version_response(
  883. self, writer: asyncio.StreamWriter, sequence_id: str, serial: str | None = None
  884. ) -> None:
  885. """Send version info response to the slicer."""
  886. try:
  887. product_name = MODEL_PRODUCT_NAMES.get(self.model, self.model or "X1 Carbon")
  888. # The serial is embedded inside the module[].sn fields *and* used as
  889. # the report topic. Use the client's effective serial so the slicer
  890. # sees internal/topic consistency even when it differs from self.serial.
  891. serial = serial or self.serial
  892. # Build version response matching OrcaSlicer expectations
  893. # Required fields per module: name, product_name, sw_ver, sw_new_ver, sn, hw_ver, flag
  894. version_info = {
  895. "info": {
  896. "command": "get_version",
  897. "sequence_id": sequence_id,
  898. "module": [
  899. {
  900. "name": "ota",
  901. "product_name": product_name,
  902. "sw_ver": "01.07.00.00",
  903. "sw_new_ver": "",
  904. "hw_ver": "OTA",
  905. "sn": serial,
  906. "flag": 0,
  907. },
  908. {
  909. "name": "esp32",
  910. "product_name": product_name,
  911. "sw_ver": "01.07.22.25",
  912. "sw_new_ver": "",
  913. "hw_ver": "AP05",
  914. "sn": serial,
  915. "flag": 0,
  916. },
  917. {
  918. "name": "rv1126",
  919. "product_name": product_name,
  920. "sw_ver": "00.00.27.38",
  921. "sw_new_ver": "",
  922. "hw_ver": "AP05",
  923. "sn": serial,
  924. "flag": 0,
  925. },
  926. {
  927. "name": "th",
  928. "product_name": product_name,
  929. "sw_ver": "00.00.04.00",
  930. "sw_new_ver": "",
  931. "hw_ver": "TH07",
  932. "sn": serial,
  933. "flag": 0,
  934. },
  935. {
  936. "name": "mc",
  937. "product_name": product_name,
  938. "sw_ver": "00.00.10.00",
  939. "sw_new_ver": "",
  940. "hw_ver": "MC07",
  941. "sn": serial,
  942. "flag": 0,
  943. },
  944. ],
  945. }
  946. }
  947. # Overlay real version modules from the bridge cache when available
  948. # (specifically the AMS modules ams/0, n3f/0, n3s/128 etc. that
  949. # BambuStudio's Prepare tab uses to identify AMS hardware — without
  950. # them every AMS unit shows as "unknown" in the Prepare panel).
  951. if self._bridge is not None:
  952. cached_modules = self._bridge.get_latest_version_modules()
  953. if isinstance(cached_modules, list) and cached_modules:
  954. version_info["info"]["module"] = cached_modules
  955. await self._publish_to_report(writer, version_info, serial)
  956. logger.info("Sent version response (product_name=%s)", product_name)
  957. except OSError as e:
  958. logger.error("Failed to send version response: %s", e)
  959. def set_gcode_state(self, state: str, filename: str = "", prepare_percent: str = "0") -> None:
  960. """Update the gcode state reported to connected slicers.
  961. Called by the manager to reflect FTP upload progress/completion.
  962. """
  963. self._gcode_state = state
  964. self._current_file = filename
  965. self._prepare_percent = prepare_percent
  966. async def _publish_to_report(self, writer: asyncio.StreamWriter, payload: dict, serial: str = "") -> None:
  967. """Publish a message on the device report topic.
  968. Real Bambu printers wire-format push_status JSON with 4-space indentation
  969. (32254 bytes for an idle H2D push vs 14268 bytes compact). BambuStudio's
  970. Send pre-flight rejects compact JSON — without matching the on-wire
  971. format the slicer never proceeds to FTP upload.
  972. """
  973. topic = f"device/{serial or self.serial}/report"
  974. message = json.dumps(payload, indent=4)
  975. topic_bytes = topic.encode("utf-8")
  976. message_bytes = message.encode("utf-8")
  977. remaining = 2 + len(topic_bytes) + len(message_bytes)
  978. packet = bytes([0x30]) # PUBLISH, QoS 0
  979. while remaining > 0:
  980. byte = remaining % 128
  981. remaining //= 128
  982. if remaining > 0:
  983. byte |= 0x80
  984. packet += bytes([byte])
  985. packet += bytes([len(topic_bytes) >> 8, len(topic_bytes) & 0xFF])
  986. packet += topic_bytes
  987. packet += message_bytes
  988. writer.write(packet)
  989. # Timeout the drain to prevent blocking the event loop if the
  990. # MQTT client stops reading (e.g. slicer busy with FTP upload).
  991. try:
  992. await asyncio.wait_for(writer.drain(), timeout=5)
  993. except TimeoutError:
  994. logger.debug("MQTT drain timeout for %s — client may be busy", topic)
  995. async def _send_print_response(
  996. self, writer: asyncio.StreamWriter, sequence_id: str, filename: str, serial: str | None = None
  997. ) -> None:
  998. """Send project_file acknowledgment matching real Bambu printer behavior."""
  999. # Update state so periodic status pushes reflect preparation
  1000. self._gcode_state = "PREPARE"
  1001. self._current_file = filename
  1002. self._prepare_percent = "0"
  1003. try:
  1004. # Send command acknowledgment — slicer expects to see
  1005. # command: "project_file" echoed back before starting FTP upload
  1006. subtask_name = filename.replace(".3mf", "") if filename else ""
  1007. response = {
  1008. "print": {
  1009. "command": "project_file",
  1010. "sequence_id": sequence_id,
  1011. "param": "Metadata/plate_1.gcode",
  1012. "subtask_name": subtask_name,
  1013. "gcode_state": "PREPARE",
  1014. "gcode_file": filename,
  1015. "gcode_file_prepare_percent": "0",
  1016. "result": "SUCCESS",
  1017. "msg": 0,
  1018. }
  1019. }
  1020. await self._publish_to_report(writer, response, serial or self.serial)
  1021. logger.info("Sent project_file acknowledgment for %s", filename)
  1022. except OSError as e:
  1023. logger.error("Failed to send print response: %s", e)
  1024. async def _handle_publish(self, header: int, payload: bytes, writer: asyncio.StreamWriter, client_id: str) -> None:
  1025. """Handle MQTT PUBLISH packet."""
  1026. try:
  1027. # Parse topic
  1028. idx = 0
  1029. topic_len = (payload[idx] << 8) | payload[idx + 1]
  1030. idx += 2
  1031. topic = payload[idx : idx + topic_len].decode("utf-8")
  1032. idx += topic_len
  1033. # Check for packet ID (QoS > 0)
  1034. qos = (header & 0x06) >> 1
  1035. if qos > 0:
  1036. # packet_id = (payload[idx] << 8) | payload[idx + 1]
  1037. idx += 2
  1038. # Parse message
  1039. message = payload[idx:].decode("utf-8")
  1040. logger.info("MQTT publish to %s: %s...", topic, message[:100])
  1041. # Only handle publishes on *some* device/.../request topic. The
  1042. # serial is taken from the topic rather than compared against
  1043. # self.serial: the client is already authenticated via the access
  1044. # code, and Orca/BambuStudio may have a cached serial that differs
  1045. # from the VP's computed self.serial (#927). Use the topic's serial
  1046. # for all responses so they land on the topic the slicer subscribed
  1047. # to.
  1048. if not topic.startswith("device/") or "/request" not in topic:
  1049. return
  1050. client_serial = self._extract_serial_from_topic(topic) or self.serial
  1051. if client_serial and client_serial != self._client_serials.get(client_id):
  1052. if client_serial != self.serial:
  1053. logger.info(
  1054. "%sMQTT client publishing with serial %s (VP serial is %s) — adapting responses",
  1055. self._log_prefix,
  1056. client_serial,
  1057. self.serial,
  1058. )
  1059. self._client_serials[client_id] = client_serial
  1060. try:
  1061. # Some slicer builds (observed with OrcaSlicer on Linux, #927)
  1062. # include the C-string null terminator in the MQTT payload
  1063. # length, so the decoded message ends with \x00. Real brokers
  1064. # pass the bytes through; strict json.loads raises "Extra data"
  1065. # and every pushall/get_version/project_file silently dropped.
  1066. data = json.loads(message.rstrip("\x00 \r\n\t"))
  1067. except json.JSONDecodeError as e:
  1068. logger.debug(
  1069. "MQTT publish JSON decode failed: %s (payload=%r)",
  1070. e,
  1071. message[:200],
  1072. )
  1073. return
  1074. # The synthetic flow below is the original (pre-bridge) behaviour and is
  1075. # what the proven-working FTP "Send" depends on. Do NOT replace any
  1076. # synthetic response with a forward — only ADD forwarding alongside,
  1077. # at the bottom, for commands the synthetic flow doesn't handle
  1078. # (AMS write / xcam / system / etc., which need to actually reach
  1079. # the real printer).
  1080. handled_locally = False
  1081. # Handle pushing command (status request)
  1082. if "pushing" in data:
  1083. pushing_data = data["pushing"]
  1084. command = pushing_data.get("command", "")
  1085. logger.info("MQTT pushing command: %s", command)
  1086. if command == "pushall":
  1087. logger.info("Sending status report in response to pushall")
  1088. await self._send_status_report(writer, serial=client_serial)
  1089. handled_locally = True
  1090. elif command == "start":
  1091. logger.info("Starting status push stream")
  1092. await self._send_status_report(writer, serial=client_serial)
  1093. handled_locally = True
  1094. # Handle info commands (get_version, etc.)
  1095. if "info" in data:
  1096. info_data = data["info"]
  1097. command = info_data.get("command", "")
  1098. sequence_id = info_data.get("sequence_id", "0")
  1099. logger.info("MQTT info command: %s", command)
  1100. if command == "get_version":
  1101. await self._send_version_response(writer, sequence_id, serial=client_serial)
  1102. handled_locally = True
  1103. # Handle print commands
  1104. if "print" in data:
  1105. print_data = data["print"]
  1106. command = print_data.get("command", "")
  1107. filename = print_data.get("subtask_name", "")
  1108. sequence_id = print_data.get("sequence_id", "0")
  1109. logger.info("MQTT print command: %s for %s", command, filename)
  1110. if command in ("project_file", "gcode_file"):
  1111. # File lives on Bambuddy, not the printer — synthetic only.
  1112. file_3mf = print_data.get("file", filename)
  1113. await self._send_print_response(writer, sequence_id, file_3mf, serial=client_serial)
  1114. if self.on_print_command:
  1115. await self._notify_print_command(filename, print_data)
  1116. handled_locally = True
  1117. # Forward anything the synthetic flow didn't handle to the real
  1118. # printer. AMS load / dry / xcam / system / extrusion_cali_get etc.
  1119. if not handled_locally and self._bridge is not None and self._bridge.is_active:
  1120. # Remember which client originated this command so the
  1121. # printer's response goes back only to them (not fanned
  1122. # out to every connected slicer).
  1123. self._record_pending_request(data, client_id)
  1124. self._bridge.forward_to_printer(data)
  1125. except (IndexError, ValueError, OSError) as e:
  1126. logger.debug("MQTT PUBLISH error: %s", e)
  1127. async def _notify_print_command(self, filename: str, data: dict) -> None:
  1128. """Notify callback of print command."""
  1129. if self.on_print_command:
  1130. try:
  1131. result = self.on_print_command(filename, data)
  1132. if asyncio.iscoroutine(result):
  1133. await result
  1134. except Exception as e:
  1135. logger.error("Print command callback error: %s", e)