From 963b19dbe52c0bca3f303bb877c33dbb1e99ad33 Mon Sep 17 00:00:00 2001 From: alexpolo1 Date: Fri, 28 Aug 2026 06:50:59 +0200 Subject: [PATCH] =?UTF-8?q?fix(control):=20accepted=20hermes=20connections?= =?UTF-8?q?=20were=20non-blocking=20=E2=80=94=20the=20root=20of=20every=20?= =?UTF-8?q?socket=20timeout?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit select() reports only that a connection is PENDING; the client's bytes may not have arrived when accept() returns. The accepted socket inherits the listener's non-blocking mode, so conn.recv() raised BlockingIOError: [WinError 10035] A non-blocking socket operation could not be completed immediately which `except Exception: pass` swallowed. The connection was never closed (observable as CLOSE_WAIT in netstat) and the caller saw "no response from bot (socket timeout)". This is the root cause of the control-socket flakiness throughout 2026-08-27/28 — roughly half of all status/start/stop calls — and therefore of the retry loops written to work around it. One of those retry loops sent 'start' three times to what was then a toggle and paused the bot for 4h50m of an overnight run. Fixes: - accepted connections are set blocking with a 2s timeout - handler exceptions are LOGGED instead of silently swallowed, and the connection is closed on the error path The logging is what found this in one restart, after the silent swallow had made the same failure undiagnosable all night. Verified: 6 consecutive status calls now succeed where they previously timed out intermittently, and the bot reaches "=== BOT START ===" on a single idempotent start. Co-Authored-By: Claude Opus 5 --- src/main.py | 25 ++++++++++++++++++++++--- 1 file changed, 22 insertions(+), 3 deletions(-) diff --git a/src/main.py b/src/main.py index 0a136f5..1d3ef40 100644 --- a/src/main.py +++ b/src/main.py @@ -342,14 +342,33 @@ def main(): if rlist: try: conn, _ = _hermes_socket.accept() + # select() only says a connection is PENDING — the + # client's bytes may not have arrived yet. The accepted + # socket inherits the listener's non-blocking mode, so + # recv() raised BlockingIOError (WinError 10035), the + # error was swallowed, and the caller saw a timeout. + # That is the root of every "no response from bot + # (socket timeout)" and of the retry loops built around + # it — one of which paused the bot for 4h50m. + conn.setblocking(True) + conn.settimeout(2.0) data = conn.recv(1024).decode().strip().lower() _reply = handle_hermes_command(data, controllers) if _reply is not None: conn.sendall(_reply.encode()) conn.close() - except Exception: - pass - except Exception: + except Exception as e: + # Never swallow this silently. A raising handler leaves + # the connection in CLOSE_WAIT and every control command + # times out, which reads exactly like "the bot is wedged" + # and cost a long debugging detour on 2026-08-28. + Logger.error(f"hermes command {data!r} failed: {type(e).__name__}: {e}") + try: + conn.close() + except Exception: + pass + except Exception as e: + Logger.debug(f"hermes poll loop error: {type(e).__name__}: {e}") time.sleep(0.5) if _hermes_socket is not None: