Reconnect right after a dropped link instead of waiting out the poll
Measured on a real bike: after every unexpected disconnect the integration sat idle for 26.5s before reconnecting, in a suspiciously tight band across nine consecutive drops. Two causes, both introduced with the restore work: `async_set_updated_data` runs on every BLE notification, which reschedules the coordinator's next poll to now + SCAN_INTERVAL. The last notification lands just before the link dies, bleak reports the disconnect ~3.5s later, so the poll that would reconnect is still ~26.5s out. The advertisement watch was supposed to cover exactly this, but does not: instrumenting the callback showed one advertisement in seven minutes across five drop cycles. These bikes stop advertising after an unexpected link loss, so the watch only helps when the bike is switched on fresh. The disconnected callback now starts a reconnect itself. A link that did not survive MIN_LINK_SECONDS_FOR_FAST_RECONNECT is left to the poll so a bike that cannot hold a connection at all does not spin. Measured after the change: 0.7s instead of 26.5s. Also fixes an advertisement storm. Home Assistant invokes bluetooth callbacks on every advertisement, and this bike advertises every 0.27s, so while disconnected the callback queued a background task several times a second - roughly a hundred per reconnect window - all serialising behind _connect_lock, each running a full establish_connection retry cycle against a proxy already struggling to hold the link. A claim guard reduces that to one attempt in flight at a time; the test covers 50 advertisements. Keeps the advertisement counter as debug output - it is what made the second cause visible, and it is the first thing to look at when a bike reconnects slowly. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FyabWZzd7HoLpyBwEa5Zzh
This commit is contained in:
co-authored by
Claude Opus 5
parent
76c3d91ff9
commit
7c1a23a8b4
@@ -53,3 +53,8 @@ VOLATILE_FIELDS: Final[dict[str, tuple[str, ...]]] = {
|
|||||||
"battery_secondary": ("current", "is_charging"),
|
"battery_secondary": ("current", "is_charging"),
|
||||||
"ebm": ("status", "accel_y", "accel_z"),
|
"ebm": ("status", "accel_y", "accel_z"),
|
||||||
}
|
}
|
||||||
|
|
||||||
|
# A link that survived at least this long is worth reconnecting immediately when
|
||||||
|
# it drops; anything shorter is left to the regular poll so a bike that cannot
|
||||||
|
# hold a connection does not spin in a reconnect loop.
|
||||||
|
MIN_LINK_SECONDS_FOR_FAST_RECONNECT: Final = 5.0
|
||||||
|
|||||||
@@ -35,6 +35,7 @@ from .const import (
|
|||||||
PROTOCOL_REQUEST_MESSAGE,
|
PROTOCOL_REQUEST_MESSAGE,
|
||||||
CLOSE_MESSAGE,
|
CLOSE_MESSAGE,
|
||||||
SCAN_INTERVAL,
|
SCAN_INTERVAL,
|
||||||
|
MIN_LINK_SECONDS_FOR_FAST_RECONNECT,
|
||||||
STORAGE_SAVE_DELAY,
|
STORAGE_SAVE_DELAY,
|
||||||
STORAGE_VERSION,
|
STORAGE_VERSION,
|
||||||
RESTORE_STATE_KEYS,
|
RESTORE_STATE_KEYS,
|
||||||
@@ -84,6 +85,9 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
self._last_seen: datetime | None = None
|
self._last_seen: datetime | None = None
|
||||||
self._save_armed = False
|
self._save_armed = False
|
||||||
self._unreachable_reason: str | None = None
|
self._unreachable_reason: str | None = None
|
||||||
|
self._connecting = False
|
||||||
|
self._advertisements_seen = 0
|
||||||
|
self._connected_since: float | None = None
|
||||||
self._store: Store[dict[str, Any]] = Store(
|
self._store: Store[dict[str, Any]] = Store(
|
||||||
hass, STORAGE_VERSION, storage_key(entry)
|
hass, STORAGE_VERSION, storage_key(entry)
|
||||||
)
|
)
|
||||||
@@ -213,15 +217,36 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
BluetoothScanningMode.ACTIVE,
|
BluetoothScanningMode.ACTIVE,
|
||||||
)
|
)
|
||||||
|
|
||||||
|
@callback
|
||||||
|
def _async_claim_connect(self) -> bool:
|
||||||
|
"""Reserve the right to run one connect attempt.
|
||||||
|
|
||||||
|
Home Assistant invokes the bluetooth callback on *every* advertisement,
|
||||||
|
and these bikes advertise several times a second. Without a claim, a
|
||||||
|
disconnected bike would queue hundreds of connect tasks behind
|
||||||
|
`_connect_lock`, each running a full `establish_connection` retry cycle
|
||||||
|
against a proxy that is already struggling to hold the link.
|
||||||
|
"""
|
||||||
|
if self._is_connected or self._manual_disconnect or self._connecting:
|
||||||
|
return False
|
||||||
|
self._connecting = True
|
||||||
|
return True
|
||||||
|
|
||||||
@callback
|
@callback
|
||||||
def _async_device_appeared(
|
def _async_device_appeared(
|
||||||
self, service_info: BluetoothServiceInfoBleak, change: BluetoothChange
|
self, service_info: BluetoothServiceInfoBleak, change: BluetoothChange
|
||||||
) -> None:
|
) -> None:
|
||||||
"""Handle the bike showing up in range."""
|
"""Handle the bike showing up in range."""
|
||||||
if self._is_connected or self._manual_disconnect:
|
self._advertisements_seen += 1
|
||||||
|
if not self._async_claim_connect():
|
||||||
return
|
return
|
||||||
|
_LOGGER.debug(
|
||||||
|
"Advertisement from %s (%d seen) - connecting now",
|
||||||
|
self._address,
|
||||||
|
self._advertisements_seen,
|
||||||
|
)
|
||||||
self._entry.async_create_background_task(
|
self._entry.async_create_background_task(
|
||||||
self.hass, self._async_try_connect(), f"{DOMAIN} connect {self._address}"
|
self.hass, self._async_run_connect(), f"{DOMAIN} connect {self._address}"
|
||||||
)
|
)
|
||||||
|
|
||||||
@callback
|
@callback
|
||||||
@@ -239,6 +264,25 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
self._is_connected = False
|
self._is_connected = False
|
||||||
self.async_update_listeners()
|
self.async_update_listeners()
|
||||||
|
|
||||||
|
# Don't sit out the poll interval. These bikes stop advertising after an
|
||||||
|
# unexpected link loss, so the advertisement watch does not fire, and
|
||||||
|
# every notification has just pushed the poll timer another 30s out -
|
||||||
|
# leaving the bike disconnected far longer than necessary.
|
||||||
|
held_for = (
|
||||||
|
self.hass.loop.time() - self._connected_since
|
||||||
|
if self._connected_since is not None
|
||||||
|
else 0.0
|
||||||
|
)
|
||||||
|
self._connected_since = None
|
||||||
|
if held_for < MIN_LINK_SECONDS_FOR_FAST_RECONNECT:
|
||||||
|
# A link that died almost immediately would spin; let the poll retry.
|
||||||
|
return
|
||||||
|
if not self._async_claim_connect():
|
||||||
|
return
|
||||||
|
self._entry.async_create_background_task(
|
||||||
|
self.hass, self._async_run_connect(), f"{DOMAIN} reconnect {self._address}"
|
||||||
|
)
|
||||||
|
|
||||||
async def async_first_connect(self) -> None:
|
async def async_first_connect(self) -> None:
|
||||||
"""Attempt the initial connection without blocking setup."""
|
"""Attempt the initial connection without blocking setup."""
|
||||||
if self._manual_disconnect:
|
if self._manual_disconnect:
|
||||||
@@ -250,6 +294,12 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
await self._async_try_connect()
|
await self._async_try_connect()
|
||||||
|
|
||||||
async def _async_try_connect(self) -> None:
|
async def _async_try_connect(self) -> None:
|
||||||
|
"""Run a connect attempt unless one is already in flight."""
|
||||||
|
if not self._async_claim_connect():
|
||||||
|
return
|
||||||
|
await self._async_run_connect()
|
||||||
|
|
||||||
|
async def _async_run_connect(self) -> None:
|
||||||
"""Connect, reporting the expected 'bike is off' failures once each."""
|
"""Connect, reporting the expected 'bike is off' failures once each."""
|
||||||
try:
|
try:
|
||||||
await self._connect()
|
await self._connect()
|
||||||
@@ -257,6 +307,8 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
self._async_report_unreachable(str(ex))
|
self._async_report_unreachable(str(ex))
|
||||||
except Exception as ex: # noqa: BLE001
|
except Exception as ex: # noqa: BLE001
|
||||||
self._async_report_unreachable(f"Connection attempt failed: {ex}")
|
self._async_report_unreachable(f"Connection attempt failed: {ex}")
|
||||||
|
finally:
|
||||||
|
self._connecting = False
|
||||||
|
|
||||||
def _async_report_unreachable(self, reason: str) -> None:
|
def _async_report_unreachable(self, reason: str) -> None:
|
||||||
"""Log why we cannot connect - once per distinct reason.
|
"""Log why we cannot connect - once per distinct reason.
|
||||||
@@ -376,6 +428,13 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
state["rssi"] = None
|
state["rssi"] = None
|
||||||
|
|
||||||
state["last_seen"] = self._last_seen
|
state["last_seen"] = self._last_seen
|
||||||
|
_LOGGER.debug(
|
||||||
|
"%s: connected=%s advertisements_seen=%s rssi=%s",
|
||||||
|
self._address,
|
||||||
|
self._is_connected,
|
||||||
|
self._advertisements_seen,
|
||||||
|
state["rssi"],
|
||||||
|
)
|
||||||
return state
|
return state
|
||||||
|
|
||||||
async def _connect(self) -> None:
|
async def _connect(self) -> None:
|
||||||
@@ -418,6 +477,7 @@ class MySmartBikeCoordinator(DataUpdateCoordinator[dict[str, Any]]):
|
|||||||
return
|
return
|
||||||
|
|
||||||
self._is_connected = True
|
self._is_connected = True
|
||||||
|
self._connected_since = self.hass.loop.time()
|
||||||
self._unreachable_reason = None
|
self._unreachable_reason = None
|
||||||
_LOGGER.debug("Connected to %s", self._address)
|
_LOGGER.debug("Connected to %s", self._address)
|
||||||
|
|
||||||
|
|||||||
@@ -269,7 +269,12 @@ async def test_reconnects_when_bike_appears(
|
|||||||
"""An advertisement triggers a connect instead of waiting for the poll."""
|
"""An advertisement triggers a connect instead of waiting for the poll."""
|
||||||
await setup_offline(hass, restore_config_entry)
|
await setup_offline(hass, restore_config_entry)
|
||||||
coordinator = restore_config_entry.runtime_data
|
coordinator = restore_config_entry.runtime_data
|
||||||
coordinator._is_connected = False
|
await wait_connected(hass, coordinator)
|
||||||
|
|
||||||
|
# Drop the link the way bleak reports one
|
||||||
|
coordinator._async_client_disconnected(coordinator._client)
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
assert coordinator.is_connected is False
|
||||||
|
|
||||||
with patch.object(
|
with patch.object(
|
||||||
coordinator, "_connect", new_callable=AsyncMock
|
coordinator, "_connect", new_callable=AsyncMock
|
||||||
@@ -446,3 +451,89 @@ async def test_unreachable_warning_is_not_repeated(
|
|||||||
await hass.async_block_till_done()
|
await hass.async_block_till_done()
|
||||||
|
|
||||||
assert "turn on the bike" not in caplog.text
|
assert "turn on the bike" not in caplog.text
|
||||||
|
|
||||||
|
|
||||||
|
async def test_advertisement_storm_starts_one_connect_attempt(
|
||||||
|
hass: HomeAssistant,
|
||||||
|
restore_config_entry: MockConfigEntry,
|
||||||
|
mock_bleak_client,
|
||||||
|
mock_device_in_range,
|
||||||
|
mock_bluetooth_service_info,
|
||||||
|
) -> None:
|
||||||
|
"""Home Assistant fires the callback on every advertisement.
|
||||||
|
|
||||||
|
These bikes advertise several times a second, so an unguarded callback
|
||||||
|
would queue a connect task per advertisement, all serialising behind
|
||||||
|
_connect_lock and each hammering the proxy with a full retry cycle.
|
||||||
|
"""
|
||||||
|
await setup_offline(hass, restore_config_entry)
|
||||||
|
coordinator = restore_config_entry.runtime_data
|
||||||
|
await wait_connected(hass, coordinator)
|
||||||
|
coordinator._async_client_disconnected(coordinator._client)
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
|
||||||
|
started = 0
|
||||||
|
release = asyncio.Event()
|
||||||
|
|
||||||
|
async def slow_connect() -> None:
|
||||||
|
nonlocal started
|
||||||
|
started += 1
|
||||||
|
await release.wait()
|
||||||
|
|
||||||
|
with patch.object(coordinator, "_connect", side_effect=slow_connect):
|
||||||
|
for _ in range(50):
|
||||||
|
coordinator._async_device_appeared(mock_bluetooth_service_info, None)
|
||||||
|
await asyncio.sleep(0)
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
|
||||||
|
assert started == 1, f"{started} connect attempts for 50 advertisements"
|
||||||
|
|
||||||
|
release.set()
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
|
||||||
|
# ...and the claim is released, so a later advertisement can still connect
|
||||||
|
assert coordinator._connecting is False
|
||||||
|
|
||||||
|
|
||||||
|
async def test_fast_reconnect_after_established_link_drops(
|
||||||
|
hass: HomeAssistant,
|
||||||
|
restore_config_entry: MockConfigEntry,
|
||||||
|
mock_bleak_client,
|
||||||
|
mock_device_in_range,
|
||||||
|
) -> None:
|
||||||
|
"""A dropped link reconnects at once instead of waiting out the poll.
|
||||||
|
|
||||||
|
These bikes stop advertising after an unexpected disconnect, so the
|
||||||
|
advertisement watch never fires, and every notification has just pushed the
|
||||||
|
poll timer another SCAN_INTERVAL out.
|
||||||
|
"""
|
||||||
|
await setup_offline(hass, restore_config_entry)
|
||||||
|
coordinator = restore_config_entry.runtime_data
|
||||||
|
await wait_connected(hass, coordinator)
|
||||||
|
|
||||||
|
# Pretend the link had been up comfortably longer than the spin guard
|
||||||
|
coordinator._connected_since = hass.loop.time() - 120
|
||||||
|
|
||||||
|
with patch.object(coordinator, "_connect", new_callable=AsyncMock) as mock_connect:
|
||||||
|
coordinator._async_client_disconnected(coordinator._client)
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
mock_connect.assert_called_once()
|
||||||
|
|
||||||
|
|
||||||
|
async def test_no_fast_reconnect_when_link_died_immediately(
|
||||||
|
hass: HomeAssistant,
|
||||||
|
restore_config_entry: MockConfigEntry,
|
||||||
|
mock_bleak_client,
|
||||||
|
mock_device_in_range,
|
||||||
|
) -> None:
|
||||||
|
"""A link that collapses at once must not spin; the poll retries instead."""
|
||||||
|
await setup_offline(hass, restore_config_entry)
|
||||||
|
coordinator = restore_config_entry.runtime_data
|
||||||
|
await wait_connected(hass, coordinator)
|
||||||
|
|
||||||
|
coordinator._connected_since = hass.loop.time() # just connected
|
||||||
|
|
||||||
|
with patch.object(coordinator, "_connect", new_callable=AsyncMock) as mock_connect:
|
||||||
|
coordinator._async_client_disconnected(coordinator._client)
|
||||||
|
await hass.async_block_till_done()
|
||||||
|
mock_connect.assert_not_called()
|
||||||
|
|||||||
Reference in New Issue
Block a user