diff --git a/README.md b/README.md index a606c49..31662b9 100644 --- a/README.md +++ b/README.md @@ -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 diff --git a/collector/adv.py b/collector/adv.py index e4e447f..76fd38b 100644 --- a/collector/adv.py +++ b/collector/adv.py @@ -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 diff --git a/collector/bluez_adv.py b/collector/bluez_adv.py index 69793de..fb2afd5 100644 --- a/collector/bluez_adv.py +++ b/collector/bluez_adv.py @@ -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 None + 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: - return str(path) - except Exception as e: - log.debug("find_device: %s", e) + 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) 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) diff --git a/collector/config.py b/collector/config.py index 908d6e0..a3f6c17 100644 --- a/collector/config.py +++ b/collector/config.py @@ -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" diff --git a/collector/main.py b/collector/main.py index 27f282e..5793c5e 100644 --- a/collector/main.py +++ b/collector/main.py @@ -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,13 +241,8 @@ 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 + if rssi is not None: + sensor.rssi = rssi self.gatt.set_current_addr(addr) self._mark_dirty(registry=True, status=True) return True @@ -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__": diff --git a/webconfig/bluetooth.service.d/override.conf b/webconfig/bluetooth.service.d/override.conf new file mode 100644 index 0000000..29222e6 --- /dev/null +++ b/webconfig/bluetooth.service.d/override.conf @@ -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 diff --git a/webconfig/buttontask-collector.service b/webconfig/buttontask-collector.service index ace7cd4..bfd3515 100644 --- a/webconfig/buttontask-collector.service +++ b/webconfig/buttontask-collector.service @@ -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] diff --git a/webconfig/scripts/bt-service b/webconfig/scripts/bt-service index 4c7bf23..6cce497 100755 --- a/webconfig/scripts/bt-service +++ b/webconfig/scripts/bt-service @@ -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 diff --git a/webconfig/scripts/bt-update b/webconfig/scripts/bt-update index f349d08..75a9293 100755 --- a/webconfig/scripts/bt-update +++ b/webconfig/scripts/bt-update @@ -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" diff --git a/winDeployScripts/device-install.sh b/winDeployScripts/device-install.sh index dd64b2a..a566681 100644 --- a/winDeployScripts/device-install.sh +++ b/winDeployScripts/device-install.sh @@ -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 зависит от платы)