Move bluetooth watchdog into the scanner base class (#83888)

This commit is contained in:
J. Nick Koston 2022-12-13 11:57:40 -10:00 committed by GitHub
parent b97ec8125f
commit 0e2ebfe5c4
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 73 additions and 43 deletions

View File

@ -6,6 +6,7 @@ from collections.abc import Callable, Generator
from contextlib import contextmanager from contextlib import contextmanager
import datetime import datetime
from datetime import timedelta from datetime import timedelta
import logging
from typing import Any, Final from typing import Any, Final
from bleak.backends.device import BLEDevice from bleak.backends.device import BLEDevice
@ -29,10 +30,13 @@ from . import models
from .const import ( from .const import (
CONNECTABLE_FALLBACK_MAXIMUM_STALE_ADVERTISEMENT_SECONDS, CONNECTABLE_FALLBACK_MAXIMUM_STALE_ADVERTISEMENT_SECONDS,
FALLBACK_MAXIMUM_STALE_ADVERTISEMENT_SECONDS, FALLBACK_MAXIMUM_STALE_ADVERTISEMENT_SECONDS,
SCANNER_WATCHDOG_INTERVAL,
SCANNER_WATCHDOG_TIMEOUT,
) )
from .models import HaBluetoothConnector from .models import HaBluetoothConnector
MONOTONIC_TIME: Final = monotonic_time_coarse MONOTONIC_TIME: Final = monotonic_time_coarse
_LOGGER = logging.getLogger(__name__)
class BaseHaScanner(ABC): class BaseHaScanner(ABC):
@ -47,6 +51,8 @@ class BaseHaScanner(ABC):
"name", "name",
"scanning", "scanning",
"_last_detection", "_last_detection",
"_start_time",
"_cancel_watchdog",
) )
def __init__( def __init__(
@ -65,6 +71,47 @@ class BaseHaScanner(ABC):
self.name = adapter_human_name(adapter, source) if adapter != source else source self.name = adapter_human_name(adapter, source) if adapter != source else source
self.scanning = True self.scanning = True
self._last_detection = 0.0 self._last_detection = 0.0
self._start_time = 0.0
self._cancel_watchdog: CALLBACK_TYPE | None = None
@hass_callback
def _async_stop_scanner_watchdog(self) -> None:
"""Stop the scanner watchdog."""
if self._cancel_watchdog:
self._cancel_watchdog()
self._cancel_watchdog = None
@hass_callback
def _async_setup_scanner_watchdog(self) -> None:
"""If something has restarted or updated, we need to restart the scanner."""
self._start_time = self._last_detection = MONOTONIC_TIME()
if not self._cancel_watchdog:
self._cancel_watchdog = async_track_time_interval(
self.hass, self._async_scanner_watchdog, SCANNER_WATCHDOG_INTERVAL
)
@hass_callback
def _async_watchdog_triggered(self) -> bool:
"""Check if the watchdog has been triggered."""
time_since_last_detection = MONOTONIC_TIME() - self._last_detection
_LOGGER.debug(
"%s: Scanner watchdog time_since_last_detection: %s",
self.name,
time_since_last_detection,
)
return time_since_last_detection > SCANNER_WATCHDOG_TIMEOUT
async def _async_scanner_watchdog(self, now: datetime.datetime) -> None:
"""Check if the scanner is running.
Override this method if you need to do something else when the watchdog is triggered.
"""
if self._async_watchdog_triggered():
_LOGGER.info(
"%s: Bluetooth scanner has gone quiet for %ss, check logs on the scanner device for more information",
self.name,
SCANNER_WATCHDOG_TIMEOUT,
)
@contextmanager @contextmanager
def connecting(self) -> Generator[None, None, None]: def connecting(self) -> Generator[None, None, None]:
@ -93,6 +140,7 @@ class BaseHaScanner(ABC):
"""Return diagnostic information about the scanner.""" """Return diagnostic information about the scanner."""
return { return {
"name": self.name, "name": self.name,
"start_time": self._start_time,
"source": self.source, "source": self.source,
"scanning": self.scanning, "scanning": self.scanning,
"type": self.__class__.__name__, "type": self.__class__.__name__,
@ -166,10 +214,12 @@ class BaseHaRemoteScanner(BaseHaScanner):
cancel_stop = self.hass.bus.async_listen( cancel_stop = self.hass.bus.async_listen(
EVENT_HOMEASSISTANT_STOP, self._save_history EVENT_HOMEASSISTANT_STOP, self._save_history
) )
self._async_setup_scanner_watchdog()
@hass_callback @hass_callback
def _cancel() -> None: def _cancel() -> None:
self._save_history() self._save_history()
self._async_stop_scanner_watchdog()
cancel_track() cancel_track()
cancel_stop() cancel_stop()

View File

@ -20,13 +20,11 @@ from bleak_retry_connector import restore_discoveries
from bluetooth_adapters import DEFAULT_ADDRESS from bluetooth_adapters import DEFAULT_ADDRESS
from dbus_fast import InvalidMessageError from dbus_fast import InvalidMessageError
from homeassistant.core import CALLBACK_TYPE, HomeAssistant, callback as hass_callback from homeassistant.core import HomeAssistant, callback as hass_callback
from homeassistant.exceptions import HomeAssistantError from homeassistant.exceptions import HomeAssistantError
from homeassistant.helpers.event import async_track_time_interval
from homeassistant.util.dt import monotonic_time_coarse
from homeassistant.util.package import is_docker_env from homeassistant.util.package import is_docker_env
from .base_scanner import BaseHaScanner from .base_scanner import MONOTONIC_TIME, BaseHaScanner
from .const import ( from .const import (
SCANNER_WATCHDOG_INTERVAL, SCANNER_WATCHDOG_INTERVAL,
SCANNER_WATCHDOG_TIMEOUT, SCANNER_WATCHDOG_TIMEOUT,
@ -37,7 +35,6 @@ from .models import BluetoothScanningMode, BluetoothServiceInfoBleak
from .util import async_reset_adapter from .util import async_reset_adapter
OriginalBleakScanner = bleak.BleakScanner OriginalBleakScanner = bleak.BleakScanner
MONOTONIC_TIME = monotonic_time_coarse
# or_patterns is a workaround for the fact that passive scanning # or_patterns is a workaround for the fact that passive scanning
# needs at least one matcher to be set. The below matcher # needs at least one matcher to be set. The below matcher
@ -137,8 +134,6 @@ class HaScanner(BaseHaScanner):
self.mode = mode self.mode = mode
self.adapter = adapter self.adapter = adapter
self._start_stop_lock = asyncio.Lock() self._start_stop_lock = asyncio.Lock()
self._cancel_watchdog: CALLBACK_TYPE | None = None
self._start_time = 0.0
self._new_info_callback = new_info_callback self._new_info_callback = new_info_callback
self.scanning = False self.scanning = False
@ -166,7 +161,6 @@ class HaScanner(BaseHaScanner):
base_diag = await super().async_diagnostics() base_diag = await super().async_diagnostics()
return base_diag | { return base_diag | {
"adapter": self.adapter, "adapter": self.adapter,
"start_time": self._start_time,
} }
@hass_callback @hass_callback
@ -315,24 +309,9 @@ class HaScanner(BaseHaScanner):
self._async_setup_scanner_watchdog() self._async_setup_scanner_watchdog()
await restore_discoveries(self.scanner, self.adapter) await restore_discoveries(self.scanner, self.adapter)
@hass_callback
def _async_setup_scanner_watchdog(self) -> None:
"""If Dbus gets restarted or updated, we need to restart the scanner."""
self._start_time = self._last_detection = MONOTONIC_TIME()
if not self._cancel_watchdog:
self._cancel_watchdog = async_track_time_interval(
self.hass, self._async_scanner_watchdog, SCANNER_WATCHDOG_INTERVAL
)
async def _async_scanner_watchdog(self, now: datetime) -> None: async def _async_scanner_watchdog(self, now: datetime) -> None:
"""Check if the scanner is running.""" """Check if the scanner is running."""
time_since_last_detection = MONOTONIC_TIME() - self._last_detection if not self._async_watchdog_triggered():
_LOGGER.debug(
"%s: Scanner watchdog time_since_last_detection: %s",
self.name,
time_since_last_detection,
)
if time_since_last_detection < SCANNER_WATCHDOG_TIMEOUT:
return return
if self._start_stop_lock.locked(): if self._start_stop_lock.locked():
_LOGGER.debug( _LOGGER.debug(
@ -346,6 +325,7 @@ class HaScanner(BaseHaScanner):
SCANNER_WATCHDOG_TIMEOUT, SCANNER_WATCHDOG_TIMEOUT,
) )
async with self._start_stop_lock: async with self._start_stop_lock:
time_since_last_detection = MONOTONIC_TIME() - self._last_detection
# Stop the scanner but not the watchdog # Stop the scanner but not the watchdog
# since we want to try again later if it's still quiet # since we want to try again later if it's still quiet
await self._async_stop_scanner() await self._async_stop_scanner()
@ -378,10 +358,8 @@ class HaScanner(BaseHaScanner):
async def async_stop(self) -> None: async def async_stop(self) -> None:
"""Stop bluetooth scanner.""" """Stop bluetooth scanner."""
if self._cancel_watchdog:
self._cancel_watchdog()
self._cancel_watchdog = None
async with self._start_stop_lock: async with self._start_stop_lock:
self._async_stop_scanner_watchdog()
await self._async_stop_scanner() await self._async_stop_scanner()
async def _async_stop_scanner(self) -> None: async def _async_stop_scanner(self) -> None:

View File

@ -604,6 +604,7 @@ async def test_diagnostics_remote_adapter(
"source": "esp32", "source": "esp32",
"storage": None, "storage": None,
"type": "FakeScanner", "type": "FakeScanner",
"start_time": ANY,
}, },
], ],
}, },

View File

@ -204,7 +204,7 @@ async def test_recovery_from_dbus_restart(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 10, return_value=start_time_monotonic + 10,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -214,7 +214,7 @@ async def test_recovery_from_dbus_restart(hass, one_adapter):
# Fire a callback to reset the timer # Fire a callback to reset the timer
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic, return_value=start_time_monotonic,
): ):
_callback( _callback(
@ -224,7 +224,7 @@ async def test_recovery_from_dbus_restart(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 20, return_value=start_time_monotonic + 20,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -234,7 +234,7 @@ async def test_recovery_from_dbus_restart(hass, one_adapter):
# We hit the timer, so we restart the scanner # We hit the timer, so we restart the scanner
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + SCANNER_WATCHDOG_TIMEOUT + 20, return_value=start_time_monotonic + SCANNER_WATCHDOG_TIMEOUT + 20,
): ):
async_fire_time_changed( async_fire_time_changed(
@ -279,7 +279,7 @@ async def test_adapter_recovery(hass, one_adapter):
start_time_monotonic = time.monotonic() start_time_monotonic = time.monotonic()
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic, return_value=start_time_monotonic,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.OriginalBleakScanner", "homeassistant.components.bluetooth.scanner.OriginalBleakScanner",
@ -294,7 +294,7 @@ async def test_adapter_recovery(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 10, return_value=start_time_monotonic + 10,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -304,7 +304,7 @@ async def test_adapter_recovery(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 20, return_value=start_time_monotonic + 20,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -314,7 +314,7 @@ async def test_adapter_recovery(hass, one_adapter):
# We hit the timer with no detections, so we reset the adapter and restart the scanner # We hit the timer with no detections, so we reset the adapter and restart the scanner
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic return_value=start_time_monotonic
+ SCANNER_WATCHDOG_TIMEOUT + SCANNER_WATCHDOG_TIMEOUT
+ SCANNER_WATCHDOG_INTERVAL.total_seconds(), + SCANNER_WATCHDOG_INTERVAL.total_seconds(),
@ -366,7 +366,7 @@ async def test_adapter_scanner_fails_to_start_first_time(hass, one_adapter):
start_time_monotonic = time.monotonic() start_time_monotonic = time.monotonic()
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic, return_value=start_time_monotonic,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.OriginalBleakScanner", "homeassistant.components.bluetooth.scanner.OriginalBleakScanner",
@ -381,7 +381,7 @@ async def test_adapter_scanner_fails_to_start_first_time(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 10, return_value=start_time_monotonic + 10,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -391,7 +391,7 @@ async def test_adapter_scanner_fails_to_start_first_time(hass, one_adapter):
# Ensure we don't restart the scanner if we don't need to # Ensure we don't restart the scanner if we don't need to
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic + 20, return_value=start_time_monotonic + 20,
): ):
async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL) async_fire_time_changed(hass, dt_util.utcnow() + SCANNER_WATCHDOG_INTERVAL)
@ -401,7 +401,7 @@ async def test_adapter_scanner_fails_to_start_first_time(hass, one_adapter):
# We hit the timer with no detections, so we reset the adapter and restart the scanner # We hit the timer with no detections, so we reset the adapter and restart the scanner
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic return_value=start_time_monotonic
+ SCANNER_WATCHDOG_TIMEOUT + SCANNER_WATCHDOG_TIMEOUT
+ SCANNER_WATCHDOG_INTERVAL.total_seconds(), + SCANNER_WATCHDOG_INTERVAL.total_seconds(),
@ -417,7 +417,7 @@ async def test_adapter_scanner_fails_to_start_first_time(hass, one_adapter):
# We hit the timer again the previous start call failed, make sure # We hit the timer again the previous start call failed, make sure
# we try again # we try again
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic return_value=start_time_monotonic
+ SCANNER_WATCHDOG_TIMEOUT + SCANNER_WATCHDOG_TIMEOUT
+ SCANNER_WATCHDOG_INTERVAL.total_seconds(), + SCANNER_WATCHDOG_INTERVAL.total_seconds(),
@ -474,7 +474,7 @@ async def test_adapter_fails_to_start_and_takes_a_bit_to_init(
"homeassistant.components.bluetooth.scanner.ADAPTER_INIT_TIME", "homeassistant.components.bluetooth.scanner.ADAPTER_INIT_TIME",
0, 0,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic, return_value=start_time_monotonic,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.OriginalBleakScanner", "homeassistant.components.bluetooth.scanner.OriginalBleakScanner",
@ -523,7 +523,7 @@ async def test_restart_takes_longer_than_watchdog_time(hass, one_adapter, caplog
"homeassistant.components.bluetooth.scanner.ADAPTER_INIT_TIME", "homeassistant.components.bluetooth.scanner.ADAPTER_INIT_TIME",
0, 0,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic, return_value=start_time_monotonic,
), patch( ), patch(
"homeassistant.components.bluetooth.scanner.OriginalBleakScanner", "homeassistant.components.bluetooth.scanner.OriginalBleakScanner",
@ -538,7 +538,7 @@ async def test_restart_takes_longer_than_watchdog_time(hass, one_adapter, caplog
# Now force a recover adapter 2x # Now force a recover adapter 2x
for _ in range(2): for _ in range(2):
with patch( with patch(
"homeassistant.components.bluetooth.scanner.MONOTONIC_TIME", "homeassistant.components.bluetooth.base_scanner.MONOTONIC_TIME",
return_value=start_time_monotonic return_value=start_time_monotonic
+ SCANNER_WATCHDOG_TIMEOUT + SCANNER_WATCHDOG_TIMEOUT
+ SCANNER_WATCHDOG_INTERVAL.total_seconds(), + SCANNER_WATCHDOG_INTERVAL.total_seconds(),

View File

@ -127,6 +127,7 @@ async def test_rpc_config_entry_diagnostics(
"monotonic_time": ANY, "monotonic_time": ANY,
"name": "Mock Title (12:34:56:78:9A:BC)", "name": "Mock Title (12:34:56:78:9A:BC)",
"scanning": True, "scanning": True,
"start_time": ANY,
"source": "12:34:56:78:9A:BC", "source": "12:34:56:78:9A:BC",
"storage": None, "storage": None,
"time_since_last_device_detection": {"AA:BB:CC:DD:EE:FF": ANY}, "time_since_last_device_detection": {"AA:BB:CC:DD:EE:FF": ANY},