diff --git a/ap/van-ap-watchdog b/ap/van-ap-watchdog index 3880355..5d68a40 100644 --- a/ap/van-ap-watchdog +++ b/ap/van-ap-watchdog @@ -8,16 +8,23 @@ exits and systemd restarts it (Restart=always, no start limit) until the interfa returns. This daemon is the backstop for the case systemd *can't* see: hostapd stays running but the radio has wedged and stopped serving (dmesg "timed out to flush queues"). -Every `interval` seconds it checks two things: hostapd's self-reported state via the -control socket (hostapd_cli status -> state=ENABLED), AND the kernel's ground truth for -the netdev (operstate up + still a port of the bridge). Both matter because they fail -independently: hostapd_cli keeps answering state=ENABLED off stale in-memory state after -the USB radio is torn down and re-enumerated underneath a still-running hostapd — the -netdev is recreated DOWN and dropped from the bridge, but hostapd never noticed and never -exited, so Restart=always never fired. The link check catches exactly that. If the AP is -unhealthy for `fail_threshold` checks in a row, it clears any failed state and restarts -hostapd. If the interface is simply gone (mid re-enumeration) it waits — there is -nothing to restart onto, and Restart=always reclaims it when it reappears. Stdlib only. +Every `interval` seconds it checks three things: hostapd's self-reported state via the +control socket (hostapd_cli status -> state=ENABLED), the kernel's ground truth for the +netdev (operstate up + still a port of the bridge), and the kernel log for a TX-queue +wedge on this radio's driver (rtw88/rtw89 "timed out to flush queue(s)"). All three +matter because they fail independently: hostapd_cli keeps answering state=ENABLED off +stale in-memory state after the USB radio is torn down and re-enumerated underneath a +still-running hostapd — the netdev is recreated DOWN and dropped from the bridge, but +hostapd never noticed and never exited, so Restart=always never fired. The link check +catches exactly that. Separately, the radio can wedge without any re-enumeration at +all: hostapd keeps reporting state=ENABLED and the netdev stays up/bridged throughout, +but the driver silently stops moving frames (2026-08-19: 5GHz AP unreachable for ~1.5h, +hostapd and link both reported healthy the whole time; dmesg showed +"rtw89_8852bu ...: timed out to flush queues" at the moment clients dropped). The +queue-flush check catches that. If the AP is unhealthy for `fail_threshold` checks in a +row, it clears any failed state and restarts hostapd. If the interface is simply gone +(mid re-enumeration) it waits — there is nothing to restart onto, and Restart=always +reclaims it when it reappears. Stdlib only. Usage: van-ap-watchdog [hostapd.conf path] [systemd unit] Defaults watch the 5GHz AP (/etc/hostapd/hostapd.conf, unit hostapd); the 2.4GHz @@ -28,6 +35,7 @@ import re import subprocess import sys import time +from datetime import datetime from pathlib import Path HOSTAPD_CONF = sys.argv[1] if len(sys.argv) > 1 else "/etc/hostapd/hostapd.conf" @@ -85,6 +93,47 @@ def link_healthy(ifname, bridge): return True +def driver_name(ifname): + """Kernel driver bound to the interface's USB device (e.g. rtw89_8852bu). Used to + scope the queue-flush-timeout check to this radio, so the 2.4GHz and 5GHz watchdog + instances don't trip on each other's dmesg lines. + + Path.resolve() doesn't raise on a missing path — it just returns the syntactic + path unchanged — so if this runs before the interface has enumerated (e.g. right + at watchdog startup, mid USB re-enum) a naive .resolve().name silently returns the + literal string "driver" instead of None, and that bogus value gets cached forever + by the caller's `if driver is None: retry` check. Explicitly check existence first + so a not-yet-enumerated device correctly yields None and gets retried.""" + p = Path(f"/sys/class/net/{ifname}/device/driver") + try: + if not p.exists(): + return None + return p.resolve().name + except OSError: + return None + + +def queue_flush_wedged(driver, since): + """True if this radio's driver logged a TX-queue-flush timeout since `since`. Both + rtw88 ("timed out to flush queue %d") and rtw89 ("timed out to flush queues") share + the substring "timed out to flush queue". This is the one signal that still catches + a wedge when hostapd_cli and the netdev both keep reporting healthy (see module + docstring, 2026-08-19 incident).""" + if not driver: + return False + pattern = rf"^{re.escape(driver)} .*timed out to flush queue" + try: + out = subprocess.run( + ["journalctl", "-k", "--since", since.strftime("%Y-%m-%d %H:%M:%S"), + "-g", pattern, "-o", "cat", "--no-pager"], + capture_output=True, text=True, timeout=10, + ).stdout + except (OSError, subprocess.SubprocessError) as e: + log(f"journalctl queue-flush check failed: {e}", "warn") + return False + return bool(out.strip()) + + def ap_enabled(ifname): """True if hostapd reports the AP as beaconing (state=ENABLED). False if it's running but not enabled; None if the control socket is unreachable (hostapd down).""" @@ -120,13 +169,17 @@ def main(): log("no interface= in hostapd.conf; nothing to watch", "crit") sys.exit(1) bridge = ap_bridge() + driver = driver_name(ifname) log(f"van-ap-watchdog up: watching {ifname}" - f"{f' on {bridge}' if bridge else ''} every {INTERVAL}s " + f"{f' on {bridge}' if bridge else ''}" + f"{f' (driver {driver})' if driver else ''} every {INTERVAL}s " f"(restart after {FAIL_THRESHOLD} bad checks)") bad = 0 waiting = False # latch so "interface absent" logs once, not every tick + last_check = datetime.now() # window start for the queue-flush dmesg check while True: + now = datetime.now() if not iface_present(ifname): if not waiting: log(f"{ifname} absent — USB re-enumeration in progress; " @@ -135,7 +188,13 @@ def main(): bad = 0 else: waiting = False - if ap_enabled(ifname) and link_healthy(ifname, bridge): + if driver is None: # fill in late if the watchdog started before the device existed + driver = driver_name(ifname) + wedged = queue_flush_wedged(driver, last_check) + if wedged: + log(f"{ifname} ({driver}) logged a TX queue flush timeout — " + f"radio wedged despite healthy hostapd/link state", "warn") + if ap_enabled(ifname) and link_healthy(ifname, bridge) and not wedged: if bad: log(f"AP {ifname} beaconing again") bad = 0 @@ -144,6 +203,7 @@ def main(): if bad >= FAIL_THRESHOLD: recover(ifname) bad = 0 + last_check = now time.sleep(INTERVAL)