fenopy/KX-Bridge-Release
1
1
Fork 0
forked from viewit/KX-Bridge-Release
Code Pull Requests Activity

fix(mqtt): detect a dead printer connection promptly instead of hanging offline detection forever

Browse Source 
Discovered while testing the smart-plug power-switch feature: unplugging
the printer left the dashboard stuck showing it as online/"ready"
indefinitely. Live-tested against a real printer to isolate two
independent, compounding causes:

1. The MQTT socket had no TCP keepalive. A connection killed without a
   clean TCP close (unplugged, not a graceful shutdown) looks alive to the
   OS for as long as its default dead-connection timeout - 15+ minutes on
   Linux - since a send on a half-open connection is buffered by the
   kernel and doesn't fail immediately. Fixed with SO_KEEPALIVE (short
   idle/interval/count) plus TCP_USER_TIMEOUT, since keepalive probes alone
   only fire on an idle connection - verified live that a printer
   disappearing while a send was still in flight (the common case, since
   the poll loop sends every few seconds) instead falls back to the far
   slower normal TCP retransmission timer, which keepalive settings don't
   affect at all.

2. Even after the socket was correctly detected as dead, the status poll
   loop could hang indefinitely inside publish() waiting for a reconnect
   attempt already running on the MQTT reader thread (the Issue #105
   reconnect-lock serialization), and therefore never reached the
   is_connected() check that flips kobra_state to "offline". _reconnect()
   now takes wait_if_in_progress/persist flags so the poll loop's call
   returns immediately with at most one attempt instead of blocking
   through someone else's multi-minute backoff loop - persistent retrying
   stays the reader thread's job.

A disconnected printer is now detected and reflected on the dashboard
within about 15 seconds. Live-verified across repeated disconnect/
reconnect cycles that no sockets, threads, or file descriptors are left
behind (checked via /proc/<pid>/fd and /proc/<pid>/task) - the transient
FIN-WAIT-2 entries seen while the printer's TLS service is still booting
belong to the kernel's own connection teardown, not to processes held by
the bridge, and clear on their own.
This commit is contained in:
viewit
2026-08-04 14:44:51 +02:00
parent 5a44d0abab
commit 7e33cc9eda
4 changed files with 215 additions and 13 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
NIGHTLY_CHANGELOG.md
View File

@@ -2,3 +2,4 @@
- Fix: **combined ACE-RFID filament tags (e.g. "GEEETECH PLA Bas" from third-party RFID tools) still weren't auto-matching to imported OrcaSlicer profiles**, even after the first attempt at this in a previous nightly — the matching logic was only ever wired into the OrcaSlicer slicer-sync endpoint, never into the actual MQTT status path that feeds the dashboard and Happy-Hare gate data, so the dashboard kept showing the raw unmatched RFID string. Centralized the matching so all three places that resolve a slot's filament profile benefit identically. Also added variant-token disambiguation (e.g. "Bas" vs. "Matte") for when a vendor has multiple profiles of the same material, and fixed a related edge case where a manual per-slot override could be incorrectly treated as stale on an RFID-tagged spool (Issue #101, thanks @Blaim for the extensive debugging that pinpointed this).
- Feat: new setting under Settings → Print — "Delete file from printer after successful print" — automatically removes a GCode file from the printer's own storage once it finishes printing successfully, keeping only the copy in the bridge's own GCode store. Off by default, and only ever applies to files that were uploaded through the bridge itself (so there's always a backup); files started directly from the printer or Anycubic Slicer are never touched.
- Fix: **the dashboard could stay stuck showing a printer as online/"ready" indefinitely after it was physically switched off or unplugged**, discovered while testing the new smart-plug power-switch feature. Root cause was two-fold: the MQTT socket had no TCP keepalive, so a connection killed without a clean close (unplugged, not a graceful shutdown) could look alive to the OS for 15+ minutes; and even once the dead connection was detected, the status poll loop could get stuck waiting on a reconnect attempt that was already running elsewhere, so it never reached the code that flips the dashboard to "offline". Live-tested against a real printer, including that no sockets, threads, or file descriptors are left behind across repeated disconnect/reconnect cycles — a disconnected printer is now detected and reflected on the dashboard within about 15 seconds.

89
kobrax_client.py
View File

@@ -101,6 +101,46 @@ def _parse_publish(pkt: bytes):
return topic, payload
def _enable_tcp_keepalive(sock: socket.socket) -> None:
"""Without this, a printer that goes dark without a clean TCP close (e.g.
unplugged, not gracefully shut down) leaves the socket looking alive to
is_connected() for as long as the OS's default dead-connection timeout
(often 15+ minutes on Linux) - sendall() on a half-open connection is
buffered by the kernel and doesn't fail immediately, so the poll loop's
is_connected() check (kobrax_moonraker_bridge.py's _poll_loop) never
sees the failure it needs to flip kobra_state to "offline". Short
keepalive probes make the OS notice and fail the socket within seconds
instead. Linux/macOS only (TCP_KEEPIDLE/INTVL/CNT); best-effort on other
platforms - not fatal if unsupported.
SO_KEEPALIVE alone is NOT enough, verified live by unplugging a real
printer mid-connection: keepalive probes only fire while the connection
is idle (no unacknowledged data outstanding). If the printer disappears
while a send is still in flight - the common case, since the poll loop
sends a request roughly every poll_interval - the kernel instead retries
that specific send via the normal TCP retransmission timer
(tcp_retries2, default 15 attempts with exponential backoff = 13-30+
minutes on Linux), which keepalive settings don't affect at all.
TCP_USER_TIMEOUT (Linux-specific) closes that gap: it caps how long ANY
unacknowledged data may sit in the send queue before the kernel gives up
on the connection outright, regardless of which mechanism (keepalive or
retransmission) would otherwise still be retrying."""
try:
sock.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1)
if hasattr(socket, "TCP_KEEPIDLE"):
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPIDLE, 5)
elif hasattr(socket, "TCP_KEEPALIVE"): # macOS
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPALIVE, 5)
if hasattr(socket, "TCP_KEEPINTVL"):
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPINTVL, 3)
if hasattr(socket, "TCP_KEEPCNT"):
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPCNT, 3)
if hasattr(socket, "TCP_USER_TIMEOUT"):
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_USER_TIMEOUT, 15000)
except OSError as e:
log.debug("TCP keepalive not fully supported on this platform: %s", e)
# ---------------------------------------------------------------------------
# KobraXClient
# ---------------------------------------------------------------------------
@@ -189,6 +229,7 @@ class KobraXClient:
# senders. Only the finished socket is swapped in under the lock (#53).
_ai = socket.getaddrinfo(self.host, self.port, socket.AF_INET, socket.SOCK_STREAM)
raw = socket.create_connection(_ai[0][4], timeout=5)
_enable_tcp_keepalive(raw)
new_sock = ctx.wrap_socket(raw)
log.info("TLS connected cipher=%s", new_sock.cipher()[0])
@@ -252,19 +293,31 @@ class KobraXClient:
with self._lock:
return self._sock is not None
def _reconnect(self):
"""Persistent reconnect: keeps retrying forever until the printer is
responds or disconnect() was called. Backoff caps at 60 s. The
first 5 attempts log as WARNING (acute connection issue), afterwards
only DEBUG to avoid log spam during long printer outages (e.g. switched
ausgeschaltet) zu vermeiden.
def _reconnect(self, wait_if_in_progress: bool = True, persist: bool = True):
"""Reconnect the MQTT/TLS session. With persist=True (the default, used
by the reader-thread keepalive path) it keeps retrying forever until
the printer responds or disconnect() was called, backoff capped at 60s.
The first 5 attempts log as WARNING (acute connection issue), afterwards
only DEBUG to avoid log spam during long printer outages (e.g. switched off).
Guarded by _reconnect_lock (Issue #105): if another thread's reconnect
is already in flight, this call waits for it to finish instead of
starting a second, competing _do_connect() - the printer likely only
is already in flight, this call normally waits for it to finish instead
of starting a second, competing _do_connect() - the printer likely only
accepts one mTLS session at a time, so two parallel handshakes would
just interfere with each other and neither converges."""
just interfere with each other and neither converges.
wait_if_in_progress=False + persist=False are used by the poll loop's
publish()/publish_web(): that thread MUST return promptly so the poll
loop can observe the dead session (via is_connected()) and flip
kobra_state to "offline". It must neither block on the lock waiting for
the reader thread's persistent reconnect (wait_if_in_progress=False),
nor run the multi-minute backoff loop itself (persist=False -> at most
one immediate attempt). Otherwise the poll loop hangs inside publish()
for the entire outage and the dashboard stays stuck on the last known
state - the exact bug seen when a printer was unplugged mid-connection."""
if not self._reconnect_lock.acquire(blocking=False):
if not wait_if_in_progress:
return self._sock is not None
self._reconnect_lock.acquire()
self._reconnect_lock.release()
return self._sock is not None
@@ -290,6 +343,12 @@ class KobraXClient:
return True
except Exception as e:
attempt += 1
if not persist:
# One-shot: don't block the caller (poll loop) in the
# backoff loop - leave persistent retrying to the
# reader thread's keepalive path.
log.debug("Reconnect (one-shot) failed: %s", e)
return False
lvl = log.warning if attempt <= 5 else log.debug
lvl("Reconnect fehlgeschlagen (%s, Versuch %d), warte %ss…", e, attempt, delay)
# Split sleep so disconnect() breaks the loop faster.
@@ -522,7 +581,10 @@ class KobraXClient:
self._pending_msgid.pop(msgid, None)
if report_registered:
self._pending_report.pop(report_key, None)
if not self._reconnect():
# Non-blocking: never hang the poll-loop thread inside publish()
# while a reconnect is running / during backoff (see _reconnect
# docstring) - it must return so kobra_state can flip to "offline".
if not self._reconnect(wait_if_in_progress=False, persist=False):
return None
# retry once after reconnect
try:
@@ -569,10 +631,11 @@ class KobraXClient:
except Exception as e:
log.error("web send error: %s, reconnecting…", e)
# Trigger a reconnect (like publish()); no retry because it is
# fire-and-forget - the next call will hit the fresh socket
# treffen.
# fire-and-forget - the next call will hit the fresh socket.
# Non-blocking for the same reason as publish() (see _reconnect
# docstring) - never hang this thread through a backoff loop.
try:
self._reconnect()
self._reconnect(wait_if_in_progress=False, persist=False)
except Exception:
pass

58
tests/test_mqtt_reconnect.py
View File

@@ -92,3 +92,61 @@ def test_reconnect_second_waiter_returns_after_first_completes():
assert result is True
assert c._sock is not None
def test_reconnect_non_blocking_returns_immediately_while_reconnect_in_progress():
"""The poll-loop path (publish/publish_web) must NOT block while the reader
thread's persistent reconnect is running its multi-minute backoff loop -
it has to return so the poll loop can flip kobra_state to "offline".
A printer unplugged mid-connection otherwise left the dashboard stuck on
the last known state indefinitely (Issue #103 follow-up)."""
c = _client()
c._running = True
started = threading.Event()
release = threading.Event()
def slow_persistent_do_connect():
started.set()
# Simulate the printer still being gone: never succeeds until released.
release.wait(timeout=5.0)
raise OSError("still unreachable")
c._do_connect = slow_persistent_do_connect
# First reconnect (reader-thread style): persistent, holds the lock, stuck
# in backoff.
t1 = threading.Thread(target=lambda: c._reconnect(persist=True), daemon=True)
t1.start()
assert started.wait(timeout=2.0)
# Poll-loop style call must return basically instantly, not block on t1.
t0 = time.time()
result = c._reconnect(wait_if_in_progress=False, persist=False)
elapsed = time.time() - t0
assert elapsed < 0.5, f"non-blocking reconnect blocked for {elapsed:.2f}s"
assert result is False # socket is down while the other reconnect churns
release.set() # let the daemon thread unwind
def test_reconnect_one_shot_does_not_loop_on_failure():
"""persist=False must attempt the handshake at most once and return,
instead of entering the backoff loop (which would block the caller)."""
c = _client()
c._running = True
attempts = []
def failing_do_connect():
attempts.append(1)
raise OSError("unreachable")
c._do_connect = failing_do_connect
t0 = time.time()
result = c._reconnect(persist=False)
elapsed = time.time() - t0
assert result is False
assert len(attempts) == 1 # exactly one attempt, no backoff retries
assert elapsed < 0.5

80
tests/test_tcp_keepalive.py Normal file
View File

@@ -0,0 +1,80 @@
"""TCP keepalive + TCP_USER_TIMEOUT on the MQTT socket (Issue #103 follow-up).
Without these, a printer that disappears without a clean TCP close
(unplugged, not gracefully shut down) leaves the socket looking alive to
is_connected() for as long as the OS's default dead-connection timeout -
often 15+ minutes on Linux - since sendall() on a half-open connection is
buffered by the kernel and doesn't fail immediately. This left the
dashboard's printer-state indicator stuck showing the last known state
(e.g. green "ready") long after the printer was actually unreachable,
reported when testing the smart-plug power-switch feature by physically
unplugging the printer.
Verified live (real printer, physically unplugged) that SO_KEEPALIVE alone
is not sufficient: keepalive probes only fire on an idle connection, but if
the printer disappears while a send is still unacknowledged - the normal
case, since the poll loop is sending every few seconds - the kernel's
regular TCP retransmission timer takes over instead (tcp_retries2, 13-30+
minutes on Linux), which keepalive settings don't affect. TCP_USER_TIMEOUT
closes that gap by capping how long ANY unacknowledged data may sit in the
send queue, regardless of which retry mechanism would otherwise still be
running.
"""
import socket
from unittest.mock import MagicMock
import pytest
from kobrax_client import _enable_tcp_keepalive
def test_enable_tcp_keepalive_sets_so_keepalive():
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
try:
_enable_tcp_keepalive(s)
assert s.getsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE) == 1
finally:
s.close()
@pytest.mark.skipif(not hasattr(socket, "TCP_KEEPIDLE"), reason="Linux-specific option")
def test_enable_tcp_keepalive_sets_short_idle_and_interval():
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
try:
_enable_tcp_keepalive(s)
idle = s.getsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPIDLE)
intvl = s.getsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPINTVL)
cnt = s.getsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPCNT)
# Short enough that a dead connection is detected within a couple of
# poll cycles (default poll_interval is 3s), not the OS default of
# minutes.
assert idle <= 10
assert intvl <= 5
assert cnt <= 5
finally:
s.close()
@pytest.mark.skipif(not hasattr(socket, "TCP_USER_TIMEOUT"), reason="Linux-specific option")
def test_enable_tcp_keepalive_sets_user_timeout():
"""The critical fix, verified live against a real printer: without this,
a dead connection with unacknowledged data in flight is only detected
after the OS's normal TCP retransmission timeout (13-30+ minutes on
Linux), not the keepalive interval."""
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
try:
_enable_tcp_keepalive(s)
user_timeout_ms = s.getsockopt(socket.IPPROTO_TCP, socket.TCP_USER_TIMEOUT)
# Short enough that a dead connection with in-flight data is detected
# within a couple of poll cycles, not tens of minutes.
assert 0 < user_timeout_ms <= 20000
finally:
s.close()
def test_enable_tcp_keepalive_does_not_raise_on_unsupported_platform():
"""A platform without TCP_KEEPIDLE/INTVL/CNT (e.g. some Windows builds)
must not crash the connection attempt - keepalive is best-effort."""
s = MagicMock()
s.setsockopt.side_effect = OSError("unsupported")
_enable_tcp_keepalive(s) # must not raise