collector: survive bluetoothd hangs and restarts

- every BlueZ call runs off the asyncio thread with a timeout; if bluetoothd
  stays unresponsive for 30 s the collector restarts bluetooth.service and
  exits for a clean re-registration
- Type=notify + WatchdogSec for buttontask-collector, never give up restarting
- bluetooth.service drop-in: Restart=always (BlueZ 5.55 crashes on assert/SEGV),
  installed by device-install.sh and OTA (bt-update)
- bt-service: bluez-restart action for the collector

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-11-10 07:10:02 +00:00
co-authored by Claude Opus 5.5
parent 588c2e0135
commit 115879ab67
10 changed files with 265 additions and 89 deletions
+3
View File
@@ -142,6 +142,9 @@ sudo cp webconfig/buttontask-web.service /etc/systemd/system/
sudo cp webconfig/buttontask-collector.service /etc/systemd/system/
# BLE collector needs BlueZ + bless (see collector/requirements.txt / wheels/)
sudo usermod -aG bluetooth buttontask
# auto-restart bluetoothd after crashes (stock unit has no Restart=)
sudo install -D -m0644 webconfig/bluetooth.service.d/override.conf \
/etc/systemd/system/bluetooth.service.d/override.conf
sudo systemctl daemon-reload
sudo systemctl enable --now bluetooth buttontask buttontask-web buttontask-collector
+4 -13
View File
@@ -115,20 +115,11 @@ class BlessAdvertiser:
except Exception as e:
log.debug("stop_advertising: %s", e)
# Do NOT unregister/re-register the GATT application here: doing it on
# every adv update (~1/min) is a suspect for bluetoothd 5.55 crashes
# (GLib assert / SEGV). If bluetoothd restarts, main.py exits and
# systemd restarts the collector, which registers everything afresh.
try:
try:
gatt_manager = adapter.get_interface("org.bluez.GattManager1")
# Сначала убираем старую регистрацию, чтобы не было конфликта
await gatt_manager.call_unregister_application(app.base_path)
except Exception:
pass
try:
# Регистрируем GATT-сервер (сервисы и характеристики) заново
await gatt_manager.call_register_application(app.base_path, {})
log.debug("GATT application re-registered successfully")
except Exception as e:
log.debug("GATT re-register failed (already active?): %s", e)
await app.set_name(adapter, LOCAL_NAME)
advertisement = BlueZLEAdvertisement(
Type.PERIPHERAL, len(app.advertisements) + 1, app
+45 -45
View File
@@ -1,9 +1,14 @@
#!/usr/bin/env python3
"""BlueZ helpers for connected devices (RSSI / disconnect). Advertising is via bless."""
"""BlueZ helpers for connected devices (RSSI / disconnect). Advertising is via bless.
All calls here are blocking (python3-dbus). main.py runs them in a worker
thread with a timeout, so they must raise on failure instead of returning
empty results: an empty list would look like "everyone disconnected".
"""
from __future__ import annotations
import logging
from typing import Optional
from typing import Dict, Optional
log = logging.getLogger("collector.bluez_adv")
@@ -16,8 +21,11 @@ except Exception: # pragma: no cover
dbus = None
BLUEZ = "org.bluez"
PROPS = "org.freedesktop.DBus.Properties"
OBJECT_MANAGER = "org.freedesktop.DBus.ObjectManager"
DEVICE_IFACE = "org.bluez.Device1"
# Per-call D-Bus timeout (python3-dbus default is 25 s).
CALL_TIMEOUT_S = 5.0
def system_bus():
@@ -26,32 +34,45 @@ def system_bus():
return dbus.SystemBus()
def read_device_rssi(bus, device_path: str) -> Optional[int]:
if dbus is None:
return None
def _managed_objects(bus) -> dict:
# introspect=False: no extra Introspect round-trip (it has its own 25 s timeout).
obj = bus.get_object(BLUEZ, "/", introspect=False)
mgr = dbus.Interface(obj, OBJECT_MANAGER)
return mgr.GetManagedObjects(timeout=CALL_TIMEOUT_S)
def bluez_owner(bus) -> Optional[str]:
"""Unique bus name of the running bluetoothd, or None if it is not running.
Asks dbus-daemon only, so it does not depend on bluetoothd being responsive.
"""
try:
obj = bus.get_object(BLUEZ, device_path)
props = dbus.Interface(obj, PROPS)
return int(props.Get("org.bluez.Device1", "RSSI"))
except Exception:
return str(bus.get_name_owner(BLUEZ))
except dbus.exceptions.DBusException as e:
if e.get_dbus_name() == "org.freedesktop.DBus.Error.NameHasNoOwner":
return None
raise
def connected_devices(bus) -> Dict[str, Optional[int]]:
"""{ADDR: rssi or None} for all connected devices. Raises on D-Bus errors."""
out: Dict[str, Optional[int]] = {}
for _path, ifaces in _managed_objects(bus).items():
dev = ifaces.get(DEVICE_IFACE)
if not dev or not bool(dev.get("Connected", False)):
continue
addr = str(dev.get("Address", "")).upper()
rssi = dev.get("RSSI")
out[addr] = int(rssi) if rssi is not None else None
return out
def find_device_path(bus, addr: str) -> Optional[str]:
if dbus is None:
return None
addr_u = (addr or "").upper()
try:
obj = bus.get_object(BLUEZ, "/")
mgr = dbus.Interface(obj, OBJECT_MANAGER)
for path, ifaces in mgr.GetManagedObjects().items():
dev = ifaces.get("org.bluez.Device1")
if not dev:
continue
if str(dev.get("Address", "")).upper() == addr_u:
for path, ifaces in _managed_objects(bus).items():
dev = ifaces.get(DEVICE_IFACE)
if dev and str(dev.get("Address", "")).upper() == addr_u:
return str(path)
except Exception as e:
log.debug("find_device: %s", e)
return None
@@ -59,26 +80,5 @@ def disconnect_device(bus, addr: str) -> None:
path = find_device_path(bus, addr)
if not path:
return
try:
obj = bus.get_object(BLUEZ, path)
dbus.Interface(obj, "org.bluez.Device1").Disconnect()
except Exception as e:
log.warning("disconnect %s: %s", addr, e)
def list_connected_addresses(bus) -> list:
if dbus is None:
return []
out = []
try:
obj = bus.get_object(BLUEZ, "/")
mgr = dbus.Interface(obj, OBJECT_MANAGER)
for _path, ifaces in mgr.GetManagedObjects().items():
dev = ifaces.get("org.bluez.Device1")
if not dev:
continue
if bool(dev.get("Connected", False)):
out.append(str(dev.get("Address", "")).upper())
except Exception as e:
log.debug("list_connected: %s", e)
return out
obj = bus.get_object(BLUEZ, path, introspect=False)
dbus.Interface(obj, DEVICE_IFACE).Disconnect(timeout=CALL_TIMEOUT_S)
+9
View File
@@ -10,6 +10,15 @@ TICK_INTERVAL_S = 0.5 # connect poll + flush cadence
ADV_DEBOUNCE_S = 1.0
UI_LOG_LIMIT = 200
# BlueZ health. Every BlueZ call gets a timeout; if bluetoothd keeps failing
# for BLUEZ_HANG_S, the collector restarts bluetooth.service and exits so
# systemd starts it again with a clean registration.
BLUEZ_CALL_TIMEOUT_S = 8.0 # wrapper timeout around one blocking/async BlueZ call
BLUEZ_START_TIMEOUT_S = 30.0 # GATT server start
BLUEZ_HANG_S = 30.0
BLUEZ_OWNER_CHECK_S = 2.0
BT_SERVICE_HELPER = "/opt/buttontask/scripts/bt-service"
SERVICE_UUID = "0000a000-0000-1000-8000-00805f9b34fb"
CHAR_REPORT_UUID = "0000a001-0000-1000-8000-00805f9b34fb"
CHAR_INTERVAL_UUID = "0000a002-0000-1000-8000-00805f9b34fb"
+161 -24
View File
@@ -17,10 +17,13 @@ from __future__ import annotations
import asyncio
import logging
import os
import signal
import socket
import sys
import threading
import time
from concurrent.futures import ThreadPoolExecutor
from logging.handlers import RotatingFileHandler
from pathlib import Path
from typing import Any, Dict, List, Optional
@@ -32,13 +35,17 @@ if str(_HERE) not in sys.path:
from adv import BlessAdvertiser, build_manufacturer_data # noqa: E402
from bluez_adv import ( # noqa: E402
bluez_owner,
connected_devices,
disconnect_device,
find_device_path,
list_connected_addresses,
read_device_rssi,
system_bus,
)
from config import ( # noqa: E402
BLUEZ_CALL_TIMEOUT_S,
BLUEZ_HANG_S,
BLUEZ_OWNER_CHECK_S,
BLUEZ_START_TIMEOUT_S,
BT_SERVICE_HELPER,
LOCAL_NAME,
N,
TICK_INTERVAL_S,
@@ -71,6 +78,9 @@ def setup_logging() -> None:
run_dir()
root = logging.getLogger("collector")
root.setLevel(logging.INFO)
# python3-dbus calls logging.basicConfig() on its first error; without this
# every collector line would be printed twice from then on.
root.propagate = False
fmt = logging.Formatter("%(asctime)s %(levelname)s %(name)s: %(message)s")
sh = logging.StreamHandler(sys.stderr)
sh.setFormatter(fmt)
@@ -85,6 +95,33 @@ def setup_logging() -> None:
root.warning("file log unavailable: %s", e)
def sd_notify(state: str) -> None:
"""Minimal sd_notify(3): READY=1 / WATCHDOG=1 for Type=notify units."""
addr = os.environ.get("NOTIFY_SOCKET")
if not addr:
return
if addr.startswith("@"):
addr = "\0" + addr[1:]
try:
with socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) as s:
s.connect(addr)
s.sendall(state.encode())
except OSError as e:
log.debug("sd_notify: %s", e)
class BluezGone(Exception):
"""bluetoothd restarted or hung — our GATT/adv registrations are lost."""
def __init__(self, msg: str, restart_bluez: bool = False):
super().__init__(msg)
self.restart_bluez = restart_bluez
def _err(e: BaseException) -> str:
return f"{type(e).__name__}: {e}" if str(e) else type(e).__name__
def preflight() -> None:
try:
import bless # noqa: F401
@@ -119,6 +156,13 @@ class CollectorApp:
self._history = History()
self._history.load_dict(read_history())
self._dirty_history = False
self.exit_code = 0
# All blocking python3-dbus calls go here, never on the asyncio thread:
# a hung bluetoothd must not freeze bless (same event loop).
self._executor = ThreadPoolExecutor(max_workers=1, thread_name_prefix="bluez")
self._bluez_owner: Optional[str] = None
self._bluez_fail_since: Optional[float] = None
self._last_owner_check = 0.0
self.gatt.on_write = self._on_write
self.gatt.on_read_slot = self._on_read_slot
@@ -183,7 +227,7 @@ class CollectorApp:
return
self.advertiser.set_mirror(self._mirror_bytes(), force=force)
def _on_connect(self, addr: str) -> bool:
def _on_connect(self, addr: str, rssi: Optional[int] = None) -> bool:
addr = self.registry.normalize_addr(addr)
sensor = self.registry.get(addr)
if sensor is None:
@@ -197,11 +241,6 @@ class CollectorApp:
log.info("assigned slot=%s addr=%s", sensor.slot, addr)
else:
self.registry.touch(addr)
rssi = None
if self.bus is not None:
path = find_device_path(self.bus, addr)
if path:
rssi = read_device_rssi(self.bus, path)
if rssi is not None:
sensor.rssi = rssi
self.gatt.set_current_addr(addr)
@@ -275,18 +314,97 @@ class CollectorApp:
def _on_read_interval(self) -> bytes:
return pack_interval_min(self.gatt.report_interval_min)
def _poll_connections(self) -> None:
# --- BlueZ health -------------------------------------------------------
async def _bluez(self, fn, *args):
"""Run a blocking bluez_adv helper in the worker thread with a timeout."""
loop = asyncio.get_running_loop()
return await asyncio.wait_for(
loop.run_in_executor(self._executor, fn, self.bus, *args),
BLUEZ_CALL_TIMEOUT_S,
)
def _bluez_ok(self) -> None:
if self._bluez_fail_since is not None:
log.info(
"bluez responsive again after %.1f s",
time.monotonic() - self._bluez_fail_since,
)
self._bluez_fail_since = None
def _bluez_failed(self, what: str, e: BaseException) -> None:
now = time.monotonic()
if self._bluez_fail_since is None:
self._bluez_fail_since = now
log.warning("bluez %s failed: %s", what, _err(e))
return
down_s = now - self._bluez_fail_since
if down_s >= BLUEZ_HANG_S:
raise BluezGone(
f"bluetoothd unresponsive for {down_s:.0f} s ({what}: {_err(e)})",
restart_bluez=True,
)
async def _check_bluez_owner(self) -> None:
now = time.monotonic()
if now - self._last_owner_check < BLUEZ_OWNER_CHECK_S:
return
self._last_owner_check = now
try:
owner = await self._bluez(bluez_owner)
except Exception as e:
self._bluez_failed("owner check", e)
return
if owner != self._bluez_owner:
raise BluezGone(f"bluetoothd owner changed {self._bluez_owner} -> {owner}")
async def _restart_bluetoothd(self) -> None:
log.error("restarting bluetooth.service via %s", BT_SERVICE_HELPER)
try:
proc = await asyncio.create_subprocess_exec(
"sudo", "-n", BT_SERVICE_HELPER, "bluez-restart",
stdout=asyncio.subprocess.DEVNULL,
stderr=asyncio.subprocess.PIPE,
)
_, err = await asyncio.wait_for(proc.communicate(), 30)
if proc.returncode != 0:
log.error(
"bluez-restart exit=%s: %s",
proc.returncode,
(err or b"").decode(errors="replace").strip(),
)
except Exception as e:
log.error("bluez-restart failed: %s", _err(e))
async def _advertise(self) -> None:
if self.advertiser is None:
return
try:
await asyncio.wait_for(self.advertiser.tick(), BLUEZ_CALL_TIMEOUT_S)
except asyncio.TimeoutError as e:
log.error("adv update timed out")
self.advertiser.force_reregister()
self._bluez_failed("adv update", e)
# --- connections ---------------------------------------------------------
async def _poll_connections(self) -> None:
if self.bus is None:
return
try:
connected = set(list_connected_addresses(self.bus))
devices = await self._bluez(connected_devices)
except Exception as e:
log.debug("conn poll: %s", e)
self._bluez_failed("conn poll", e)
return
self._bluez_ok()
connected = set(devices)
for addr in connected - self._known_connected:
ok = self._on_connect(addr)
ok = self._on_connect(addr, devices.get(addr))
if not ok:
disconnect_device(self.bus, addr)
try:
await self._bluez(disconnect_device, addr)
except Exception as e:
log.warning("disconnect %s: %s", addr, _err(e))
for addr in self._known_connected - connected:
self._on_disconnect(addr)
self._known_connected = connected
@@ -360,30 +478,46 @@ class CollectorApp:
self.bus = system_bus()
loop = asyncio.get_running_loop()
self.server = await build_bless_server(self.gatt, loop, LOCAL_NAME)
# Owner before registration: if bluetoothd restarts later, the owner
# changes and we know our GATT app / advertisement are gone.
self._bluez_owner = await self._bluez(bluez_owner)
if self._bluez_owner is None:
raise RuntimeError("bluetoothd is not running")
self.server = await asyncio.wait_for(
build_bless_server(self.gatt, loop, LOCAL_NAME), BLUEZ_START_TIMEOUT_S
)
await self.server.start()
log.info("GATT server started (%s)", LOCAL_NAME)
await asyncio.wait_for(self.server.start(), BLUEZ_START_TIMEOUT_S)
log.info("GATT server started (%s, bluez=%s)", LOCAL_NAME, self._bluez_owner)
self.advertiser = BlessAdvertiser(self.server)
self._refresh_mirror(force=True)
await self.advertiser.tick()
await self._advertise()
sd_notify("READY=1")
while not self._stop.is_set():
sd_notify("WATCHDOG=1")
try:
await self._check_bluez_owner()
# Pick up web/Qt edits to names & interval without a separate watcher.
self._reload_settings()
self._poll_connections()
await self._poll_connections()
if self.registry.reevaluate(period_s=self.gatt.period_s()):
self._mark_dirty(registry=True, status=True, adv=True)
self._handle_cmd()
self._flush_dirty()
if self.advertiser and not self._connected():
await self.advertiser.tick()
if not self._connected():
await self._advertise()
# Refresh age_s even when nothing else changed.
self._sync_status()
except BluezGone as e:
log.error("%s — exiting for a clean restart", e)
if e.restart_bluez:
await self._restart_bluetoothd()
self.exit_code = 1
break
except Exception as e:
log.error("tick error: %s", e)
log.error("tick error: %s", _err(e))
try:
await asyncio.sleep(TICK_INTERVAL_S)
except asyncio.CancelledError:
@@ -396,9 +530,10 @@ class CollectorApp:
append_ui_log("info", "shutdown")
try:
if self.server is not None:
await self.server.stop()
await asyncio.wait_for(self.server.stop(), 5)
except Exception as e:
log.warning("server stop: %s", e)
log.warning("server stop: %s", _err(e))
self._executor.shutdown(wait=False)
self._flush_dirty()
self.registry.save()
self._sync_status()
@@ -433,6 +568,8 @@ def main() -> None:
pass
finally:
loop.close()
# Non-zero → systemd (Restart=always) starts a fresh collector.
sys.exit(app.exit_code)
if __name__ == "__main__":
@@ -0,0 +1,10 @@
# Installed as /etc/systemd/system/bluetooth.service.d/override.conf
# bluetoothd 5.55 on this board crashes now and then (GLib assert / SEGV).
# Stock unit has no Restart=, so after a crash BLE stayed dead until something
# happened to D-Bus-activate it again.
[Unit]
StartLimitIntervalSec=0
[Service]
Restart=always
RestartSec=2
+10 -2
View File
@@ -2,9 +2,17 @@
Description=ButtonTask BLE Sensor Collector
After=bluetooth.service dbus.service
Wants=bluetooth.service
# Never give up restarting: the collector exits on purpose whenever
# bluetoothd restarts or hangs, to re-register GATT/advertising from scratch.
StartLimitIntervalSec=0
[Service]
Type=simple
# Type=notify + watchdog: the collector sends READY=1 after GATT start and
# WATCHDOG=1 every loop tick; a stuck event loop gets killed and restarted.
Type=notify
NotifyAccess=main
WatchdogSec=60
TimeoutStartSec=90
User=buttontask
Group=buttontask
SupplementaryGroups=bluetooth
@@ -12,7 +20,7 @@ WorkingDirectory=/opt/buttontask/current/collector
Environment=BUTTONTASK_ROOT=/opt/buttontask
Environment=PYTHONUNBUFFERED=1
ExecStart=/usr/bin/python3 /opt/buttontask/current/collector/main.py
Restart=on-failure
Restart=always
RestartSec=3
[Install]
+5 -1
View File
@@ -48,6 +48,10 @@ run_action() {
collector-off)
systemctl disable --now buttontask-collector
;;
bluez-restart)
# Called by the collector when bluetoothd stops answering D-Bus.
systemctl restart bluetooth
;;
units)
systemctl list-units --type=service --all --no-legend --plain --no-pager \
|| systemctl list-units --type=service --all --no-legend --no-pager
@@ -60,7 +64,7 @@ run_action() {
emit_journal
;;
*)
echo "usage: bt-service {start|stop|restart|collector-on|collector-off|units|journal}" >&2
echo "usage: bt-service {start|stop|restart|collector-on|collector-off|bluez-restart|units|journal}" >&2
exit 2
;;
esac
+7
View File
@@ -210,6 +210,13 @@ cmd_stage() {
fi
log "synced buttontask-collector.service"
fi
if [ -f "$dest/webconfig/bluetooth.service.d/override.conf" ]; then
install -d /etc/systemd/system/bluetooth.service.d
sed 's/\r$//' "$dest/webconfig/bluetooth.service.d/override.conf" \
> /etc/systemd/system/bluetooth.service.d/override.conf
systemctl daemon-reload 2>/dev/null || true
log "synced bluetooth.service.d/override.conf"
fi
write_status switching "$ver"
switch_to "$dest"
+7
View File
@@ -161,6 +161,13 @@ fi
# ---------------------------------------------------------------------------
# все юниты из бандла (buttontask, buttontask-web и, если есть, buttontask-network)
install -m0644 "$BUNDLE_DIR"/systemd/*.service /etc/systemd/system/
# авто-рестарт bluetoothd после падений (BlueZ 5.55 иногда падает по assert/SEGV)
BT_OVR="$BUNDLE_DIR/webconfig/bluetooth.service.d/override.conf"
if [ -f "$BT_OVR" ]; then
install -d /etc/systemd/system/bluetooth.service.d
sed 's/\r$//' "$BT_OVR" > /etc/systemd/system/bluetooth.service.d/override.conf
log "bluetooth.service: Restart=always"
fi
# ---------------------------------------------------------------------------
# 8. Авто-детект тачскрина -> override.conf (eventN зависит от платы)