core icon indicating copy to clipboard operation
core copied to clipboard

Yale Access Bluetooth Disconnecting When Sending Command via Dashboard or Automation

Open twinkie0101 opened this issue 7 months ago • 9 comments

The problem

As title describes, every time a command is sent via HA dashboard or via automation, the yale assure lock 2 via esphome bluetooth proxy is disconnecting and throwing the following errors. The issue appears to have come with the updgrade to core-2025.4.0.

What version of Home Assistant Core has the issue?

core-2025.4.2

What was the last working version of Home Assistant Core?

core-2025.3.4

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Yale Access Bluetooth

Link to integration documentation on our website

https://www.home-assistant.io/integrations/yalexs_ble

Diagnostics information

No response

Example YAML snippet


Anything in the logs that might be useful for us?

`Logger: yalexs_ble.push
Source: /usr/local/lib/python3.13/site-packages/yalexs_ble/push.py:1071
First occurred: 11:39:24 PM (1 occurrences)
Last logged: 11:39:24 PM

Back Door (LF0058C): Disconnected while updating
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 271, in execute
    return await self._write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 139, in _write
    return await self._locked_write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 194, in _locked_write
    await self.client.write_gatt_char(
        self.write_characteristic, command, True
    )
  File "/usr/local/lib/python3.13/site-packages/bleak/__init__.py", line 786, in write_gatt_char
    await self._backend.write_gatt_char(characteristic, data, response)
  File "/usr/local/lib/python3.13/site-packages/bleak/backends/bluezdbus/client.py", line 835, in write_gatt_char
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
    ...<15 lines>...
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/dbus_fast/aio/message_bus.py", line 398, in call
    await future
asyncio.exceptions.CancelledError: Interrupted by interrupt context manager

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 1040, in _execute_deferred_update
    await self._update()
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 118, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 162, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 720, in _update
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 585, in _ensure_connected
    raise ex
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 574, in _ensure_connected
    await self._client.connect(max_attempts)
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/lock.py", line 188, in connect
    await self._setup_session()
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/lock.py", line 246, in _setup_session
    response = await self.secure_session.execute(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        cmd, "SEC_LOCK_TO_MOBILE_KEY_EXCHANGE"
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 268, in execute
    async with interrupt(
               ~~~~~~~~~^
        disconnected_future, DisconnectedError, f"{self.name}: Disconnected"
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ):
    ^
  File "/usr/local/lib/python3.13/site-packages/async_interrupt/__init__.py", line 89, in __aexit__
    raise self._exception(self._message) from exc_val
yalexs_ble.session.DisconnectedError: Back Door (LF0058C): Disconnected`

Also seeing these errors in log:

`Logger: homeassistant.components.esphome.manager
Source: components/esphome/manager.py:387
integration: ESPHome (documentation, issues)
First occurred: April 16, 2025 at 11:47:50 PM (4 occurrences)
Last logged: April 16, 2025 at 11:57:02 PM

Movie-Yale 8e3918: [W][bluetooth_proxy.connection:085]: [0] [98:1B:B5:6A:30:7C] Error writing char/descriptor at handle 0x77, status=133`

And this error msg as well:

`Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:112
First occurred: April 16, 2025 at 11:56:48 PM (1 occurrences)
Last logged: April 16, 2025 at 11:56:48 PM

Error doing job: Future exception was never retrieved (None)
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 158, in _notify
    self._validate_response(data)
    ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/usr/local/lib/python3.13/site-packages/yalexs_ble/secure_session.py", line 69, in _validate_response
    raise ResponseError(
        f"Security checksum mismatch: {response_checksum} != {expected}"
    )
yalexs_ble.session.ResponseError: Security checksum mismatch: 2782499602 != 603419484`

Additional information

Log from BLE proxy:

[00:11:35][I][bluetooth_proxy:282]: [0] [98:1B:B5:6A:30:7C] Connecting v3 with cache [00:11:35][D][esp32_ble_tracker:115]: connecting: 0, discovered: 1, searching: 0, disconnecting: 0 [00:11:35][D][esp32_ble_tracker:231]: Pausing scan to make connection... [00:11:35][I][esp32_ble_client:110]: [0] [98:1B:B5:6A:30:7C] 0x00 Attempting BLE connection [00:11:35][D][esp32_ble_tracker:115]: connecting: 1, discovered: 0, searching: 0, disconnecting: 0 [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_CONNECT_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_OPEN_EVT [00:11:35][I][esp32_ble_client:263]: [0] [98:1B:B5:6A:30:7C] Connected [00:11:35][D][esp32_ble_tracker:115]: connecting: 0, discovered: 0, searching: 0, disconnecting: 0 [00:11:35][D][esp32_ble_tracker:282]: Starting scan... [00:11:35][D][esp32_ble_client:296]: [0] [98:1B:B5:6A:30:7C] cfg_mtu status 0, mtu 158 [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_REG_FOR_NOTIFY_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_DESCR_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_REG_FOR_NOTIFY_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_DESCR_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:35][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:36][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:36][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:36][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:36][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:39][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:39][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:11:54][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:11:54][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:12:00][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:00][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:12:02][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:02][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:05][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:05][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:12:07][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:07][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:08][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:08][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_WRITE_CHAR_EVT [00:12:10][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT [00:12:10][D][esp32_ble_client:191]: [0] [98:1B:B5:6A:30:7C] ESP_GATTC_NOTIFY_EVT

twinkie0101 avatar Apr 17 '25 04:04 twinkie0101

Hey there @bdraco, mind taking a look at this issue as it has been labeled with an integration (yalexs_ble) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of yalexs_ble can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign yalexs_ble Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


yalexs_ble documentation yalexs_ble source (message by IssueLinks)

home-assistant[bot] avatar Apr 17 '25 04:04 home-assistant[bot]

Adding some additional log entries that may be helpful:

`Logger: homeassistant.components.esphome.manager Source: components/esphome/manager.py:387 integration: ESPHome (documentation, issues) First occurred: 8:18:01 AM (8 occurrences) Last logged: 9:09:03 AM

Movie-Yale 8e3918: [W][bluetooth_proxy.connection:085]: [0] [98:1B:B5:6A:30:7C] Error writing char/descriptor at handle 0x77, status=133 Movie-Yale 8e3918: [W][bluetooth_proxy:268]: [0] [98:1B:B5:6A:30:7C] Connection request ignored, already connecting`

`Logger: homeassistant Source: /usr/src/homeassistant/homeassistant/runner.py:112 First occurred: 8:12:44 AM (4 occurrences) Last logged: 8:50:56 AM

Error doing job: Future exception was never retrieved (None) Traceback (most recent call last): File "/usr/local/lib/python3.13/site-packages/yalexs_ble/session.py", line 158, in _notify self._validate_response(data) ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^ File "/usr/local/lib/python3.13/site-packages/yalexs_ble/secure_session.py", line 69, in _validate_response raise ResponseError( f"Security checksum mismatch: {response_checksum} != {expected}" ) yalexs_ble.session.ResponseError: Security checksum mismatch: 1182573366 != 3002368730`

`Logger: yalexs_ble.push Source: /usr/local/lib/python3.13/site-packages/yalexs_ble/push.py:1056 First occurred: 8:09:39 AM (4 occurrences) Last logged: 8:50:26 AM

Back Door (LF0058C): Timed out updating Traceback (most recent call last): File "aioesphomeapi/connection.py", line 820, in send_messages_await_response_complex TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/usr/local/lib/python3.13/site-packages/bleak_esphome/backend/client.py", line 77, in _async_wrap_bluetooth_operation return await func(self, *args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.13/site-packages/bleak_esphome/backend/client.py", line 349, in disconnect return await self._disconnect() ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.13/site-packages/bleak_esphome/backend/client.py", line 352, in _disconnect await self._client.bluetooth_device_disconnect(self._address_as_int) File "/usr/local/lib/python3.13/site-packages/aioesphomeapi/client.py", line 697, in bluetooth_device_disconnect await self._bluetooth_device_request( ...<5 lines>... ) File "/usr/local/lib/python3.13/site-packages/aioesphomeapi/client.py", line 759, in _bluetooth_device_request [response] = await self._get_connection().send_messages_await_response_complex( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ...<5 lines>... ) ^ File "aioesphomeapi/connection.py", line 824, in send_messages_await_response_complex aioesphomeapi.core.TimeoutAPIError: Timeout waiting for BluetoothDeviceConnectionResponse after 20.0s

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 1040, in _execute_deferred_update await self._update() File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 118, in _async_wrap_operation_lock return await func(self, *args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 212, in _async_wrap_retry_bluetooth_connection_error await self._async_handle_disconnected(err) File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 537, in _async_handle_disconnected await self._execute_disconnect() File "/usr/local/lib/python3.13/site-packages/yalexs_ble/push.py", line 550, in _execute_disconnect await client.disconnect() File "/usr/local/lib/python3.13/site-packages/yalexs_ble/lock.py", line 408, in disconnect await self.client.disconnect() File "/usr/local/lib/python3.13/site-packages/habluetooth/wrappers.py", line 435, in disconnect return await self._backend.disconnect() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.13/site-packages/bleak_esphome/backend/client.py", line 79, in _async_wrap_bluetooth_operation raise TimeoutError(str(err)) from err TimeoutError: Timeout waiting for BluetoothDeviceConnectionResponse after 20.0s`

twinkie0101 avatar Apr 17 '25 13:04 twinkie0101

Please flash the ESPHome device with logger turned in the YAML and set to debug https://esphome.io/components/logger.html

Make sure logs are subscribed in the option flow (looks like they already are) https://www.home-assistant.io/integrations/esphome/#obtaining-logs-from-the-device

Than try reproducing again and send the whole raw log (snippets are not very useful as we need to look at the full flow)

bdraco avatar Apr 17 '25 17:04 bdraco

Also, I forgot to mention you need to have debug logs enabled on the HA side as well to see the log messages

https://www.home-assistant.io/docs/configuration/troubleshooting/#enabling-debug-logging

bdraco avatar Apr 17 '25 18:04 bdraco

Thanks for the new log. It looks like the problem didn't happen while the logging was turned on as I don't see the SEC_LOCK_TO_MOBILE_KEY_EXCHANGE error anywhere in the new log

bdraco avatar Apr 17 '25 21:04 bdraco

Adding new log that includes the SEC_LOCK_TO_MOBILE_KEY_EXCHANGE error.

home-assistant_2025-04-18T13-47-29.154Z.log

twinkie0101 avatar Apr 18 '25 13:04 twinkie0101

Been trying to trouble shoot some this weekend, got this message in the logs tonight, not sure if it is helpful but sharing in case:

`Logger: homeassistant.components.esphome.manager Source: components/esphome/manager.py:387 integration: ESPHome (documentation, issues) First occurred: 10:41:32 PM (2 occurrences) Last logged: 10:48:50 PM

Movie-Yale 8e3918: [W][bluetooth_proxy.connection:085]: [0] [98:1B:B5:6A:30:7C] Error writing char/descriptor at handle 0x77, status=133`

twinkie0101 avatar Apr 21 '25 02:04 twinkie0101

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.