fix(control): accepted hermes connections were non-blocking — the root of every socket timeout

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 <[email protected]>
This commit is contained in:
alexpolo1
2026-08-28 06:50:59 +02:00
co-authored by Claude Opus 5
parent 93185cb93c
commit 963b19dbe5
+22 -3
View File
@@ -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: