diff --git a/homeassistant/components/esphome/__init__.py b/homeassistant/components/esphome/__init__.py index a5428f7d6c5..23b6a6550e4 100644 --- a/homeassistant/components/esphome/__init__.py +++ b/homeassistant/components/esphome/__init__.py @@ -249,6 +249,8 @@ async def async_setup_entry( # noqa: C901 async def on_disconnect() -> None: """Run disconnect callbacks on API disconnect.""" + name = entry_data.device_info.name if entry_data.device_info else host + _LOGGER.debug("%s: %s disconnected, running disconnected callbacks", name, host) for disconnect_cb in entry_data.disconnect_callbacks: disconnect_cb() entry_data.disconnect_callbacks = [] diff --git a/homeassistant/components/esphome/bluetooth/__init__.py b/homeassistant/components/esphome/bluetooth/__init__.py index b4d5fdbd04d..b5be5362474 100644 --- a/homeassistant/components/esphome/bluetooth/__init__.py +++ b/homeassistant/components/esphome/bluetooth/__init__.py @@ -30,13 +30,15 @@ def _async_can_connect_factory( @hass_callback def _async_can_connect() -> bool: """Check if a given source can make another connection.""" + can_connect = bool(entry_data.available and entry_data.ble_connections_free) _LOGGER.debug( - "Checking if %s can connect, available=%s, ble_connections_free=%s", + "%s: Checking can connect, available=%s, ble_connections_free=%s result=%s", source, entry_data.available, entry_data.ble_connections_free, + can_connect, ) - return bool(entry_data.available and entry_data.ble_connections_free) + return can_connect return _async_can_connect @@ -55,7 +57,7 @@ async def async_connect_scanner( version = entry_data.device_info.bluetooth_proxy_version connectable = version >= 2 _LOGGER.debug( - "Connecting scanner for %s, version=%s, connectable=%s", + "%s: Connecting scanner version=%s, connectable=%s", source, version, connectable, diff --git a/homeassistant/components/esphome/bluetooth/client.py b/homeassistant/components/esphome/bluetooth/client.py index 68f1788afdb..5f20a73f4d6 100644 --- a/homeassistant/components/esphome/bluetooth/client.py +++ b/homeassistant/components/esphome/bluetooth/client.py @@ -61,7 +61,7 @@ def verify_connected(func: _WrapFuncType) -> _WrapFuncType: if disconnected_event.is_set(): task.cancel() raise BleakError( - f"{self._ble_device.name} ({self._ble_device.address}): " # pylint: disable=protected-access + f"{self._source}: {self._ble_device.name} - {self._ble_device.address}: " # pylint: disable=protected-access "Disconnected during operation" ) return next(iter(done)).result() @@ -120,7 +120,10 @@ class ESPHomeClient(BaseBleakClient): self._cancel_connection_state() except (AssertionError, ValueError) as ex: _LOGGER.debug( - "Failed to unsubscribe from connection state (likely connection dropped): %s", + "%s: %s - %s: Failed to unsubscribe from connection state (likely connection dropped): %s", + self._source, + self._ble_device.name, + self._ble_device.address, ex, ) self._cancel_connection_state = None @@ -134,13 +137,23 @@ class ESPHomeClient(BaseBleakClient): self._disconnected_event.set() self._disconnected_event = None if was_connected: - _LOGGER.debug("%s: BLE device disconnected", self._source) + _LOGGER.debug( + "%s: %s - %s: BLE device disconnected", + self._source, + self._ble_device.name, + self._ble_device.address, + ) self._async_call_bleak_disconnected_callback() self._unsubscribe_connection_state() def _async_esp_disconnected(self) -> None: """Handle the esp32 client disconnecting from hass.""" - _LOGGER.debug("%s: ESP device disconnected", self._source) + _LOGGER.debug( + "%s: %s - %s: ESP device disconnected", + self._source, + self._ble_device.name, + self._ble_device.address, + ) self.entry_data.disconnect_callbacks.remove(self._async_esp_disconnected) self._async_ble_device_disconnected() @@ -170,7 +183,10 @@ class ESPHomeClient(BaseBleakClient): ) -> None: """Handle a connect or disconnect.""" _LOGGER.debug( - "Connection state changed: connected=%s mtu=%s error=%s", + "%s: %s - %s: Connection state changed to connected=%s mtu=%s error=%s", + self._source, + self._ble_device.name, + self._ble_device.address, connected, mtu, error, @@ -203,6 +219,12 @@ class ESPHomeClient(BaseBleakClient): connected_future.set_exception(BleakError("Disconnected")) return + _LOGGER.debug( + "%s: %s - %s: connected, registering for disconnected callbacks", + self._source, + self._ble_device.name, + self._ble_device.address, + ) self.entry_data.disconnect_callbacks.append(self._async_esp_disconnected) connected_future.set_result(connected) @@ -230,7 +252,10 @@ class ESPHomeClient(BaseBleakClient): if self.entry_data.ble_connections_free: return _LOGGER.debug( - "%s: Out of connection slots, waiting for a free one", self._source + "%s: %s - %s: Out of connection slots, waiting for a free one", + self._source, + self._ble_device.name, + self._ble_device.address, ) async with async_timeout.timeout(timeout): await self.entry_data.wait_for_ble_connections_free() @@ -272,20 +297,29 @@ class ESPHomeClient(BaseBleakClient): cached_services := entry_data.get_gatt_services_cache(address_as_int) ): _LOGGER.debug( - "Cached services hit for %s - %s", + "%s: %s - %s: Cached services hit", + self._source, self._ble_device.name, self._ble_device.address, ) self.services = cached_services return self.services _LOGGER.debug( - "Cached services miss for %s - %s", + "%s: %s - %s: Cached services miss", + self._source, self._ble_device.name, self._ble_device.address, ) esphome_services = await self._client.bluetooth_gatt_get_services( address_as_int ) + _LOGGER.debug( + "%s: %s - %s: Got services: %s", + self._source, + self._ble_device.name, + self._ble_device.address, + esphome_services, + ) max_write_without_response = self.mtu_size - GATT_HEADER_SIZE services = BleakGATTServiceCollection() # type: ignore[no-untyped-call] for service in esphome_services.services: @@ -309,7 +343,8 @@ class ESPHomeClient(BaseBleakClient): ) self.services = services _LOGGER.debug( - "Cached services saved for %s - %s", + "%s: %s - %s: Cached services saved", + self._source, self._ble_device.name, self._ble_device.address, ) diff --git a/homeassistant/components/esphome/entry_data.py b/homeassistant/components/esphome/entry_data.py index 5d474b0fb15..faa9074b880 100644 --- a/homeassistant/components/esphome/entry_data.py +++ b/homeassistant/components/esphome/entry_data.py @@ -99,6 +99,11 @@ class RuntimeEntryData: default_factory=lambda: LRU(MAX_CACHED_SERVICES) # type: ignore[no-any-return] ) + @property + def name(self) -> str: + """Return the name of the device.""" + return self.device_info.name if self.device_info else self.entry_id + def get_gatt_services_cache( self, address: int ) -> BleakGATTServiceCollection | None: @@ -114,8 +119,13 @@ class RuntimeEntryData: @callback def async_update_ble_connection_limits(self, free: int, limit: int) -> None: """Update the BLE connection limits.""" - name = self.device_info.name if self.device_info else self.entry_id - _LOGGER.debug("%s: BLE connection limits: %s/%s", name, free, limit) + _LOGGER.debug( + "%s: BLE connection limits: used=%s free=%s limit=%s", + self.name, + limit - free, + free, + limit, + ) self.ble_connections_free = free self.ble_connections_limit = limit if free: @@ -186,7 +196,8 @@ class RuntimeEntryData: subscription_key = (type(state), state.key) self.state[type(state)][state.key] = state _LOGGER.debug( - "Dispatching update with key %s: %s", + "%s: dispatching update with key %s: %s", + self.name, subscription_key, state, )