core icon indicating copy to clipboard operation
core copied to clipboard

Yale Access Bluetooth crashing after few hours

Open ntKarlsson opened this issue 1 year ago • 4 comments

The problem

Yale Access Bluetooth connection is somehow crashing. It always connects and works after restarting HA few hours and then it crashes. After crash it always needs full restart. Reloading integration is not working. HA is running on Raspberry and there is Shelly gen 2 plug as a proxy right by the door and lock. Lock is Yale Doorman V2N and it is using Yale access module. I think adding proxy so close made it run a bit longer but it still crashed. I'm not sure but this might have something to do with door opening and closing multiple times in short time periods or staying open longer periods when kids are running in and out but I haven't been able gather any data to back this theory up.

Setup was done using August integration to fetch offline key. August integration is still installed and auto-unlock is still enabled. Shelly plug plus proxy is in active mode. Raspberry bluetooth is in passive mode.

What version of Home Assistant Core has the issue?

core-2024.1.6

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Yale Access Bluetooth / yalexs_ble

Link to integration documentation on our website

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

Diagnostics information

home-assistant_yalexs_ble_2024-02-03T21-52-19.608Z.log

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/commands.py:238
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 15.35.57 (1 occurrences)
Last logged: 15.35.57

[547552370112] Etuovi (98:1B:B5:01:95:EE): Disconnected
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 269, in execute
    return await self._write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 137, in _write
    return await self._locked_write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 192, in _locked_write
    await self.client.write_gatt_char(
  File "/usr/local/lib/python3.11/site-packages/bleak/__init__.py", line 776, in write_gatt_char
    await self._backend.write_gatt_char(characteristic, data, response)
  File "/usr/local/lib/python3.11/site-packages/bleak/backends/bluezdbus/client.py", line 834, in write_gatt_char
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dbus_fast/aio/message_bus.py", line 375, 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/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 238, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 272, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 882, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 952, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/lock/__init__.py", line 215, in async_handle_lock_service
    await self.async_lock(**self.add_default_code(kwargs))
  File "/usr/src/homeassistant/homeassistant/components/yalexs_ble/lock.py", line 64, in async_lock
    await self._device.lock()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 574, in lock
    await self._execute_lock_operation(
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 108, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 152, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 600, in _execute_lock_operation
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 558, in _ensure_connected
    await self._client.connect()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/lock.py", line 186, in connect
    await self._setup_session()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/lock.py", line 244, in _setup_session
    response = await self.secure_session.execute(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 266, in execute
    async with interrupt(
  File "/usr/local/lib/python3.11/site-packages/async_interrupt/__init__.py", line 91, in __aexit__
    raise self._exception(self._message) from exc_val
yalexs_ble.session.DisconnectedError: Etuovi (98:1B:B5:01:95:EE): Disconnected



--------------------------------------------------------------------------



Logger: yalexs_ble.push
Source: /usr/local/lib/python3.11/site-packages/yalexs_ble/push.py:1033
First occurred: 15.34.49 (9 occurrences)
Last logged: 15.37.23

Etuovi (98:1B:B5:01:95:EE): Disconnected while updating
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 269, in execute
    return await self._write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 137, in _write
    return await self._locked_write(command, command_name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 192, in _locked_write
    await self.client.write_gatt_char(
  File "/usr/local/lib/python3.11/site-packages/bleak/__init__.py", line 776, in write_gatt_char
    await self._backend.write_gatt_char(characteristic, data, response)
  File "/usr/local/lib/python3.11/site-packages/bleak/backends/bluezdbus/client.py", line 834, in write_gatt_char
    reply = await self._bus.call(
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/dbus_fast/aio/message_bus.py", line 375, 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.11/site-packages/yalexs_ble/push.py", line 1007, in _execute_deferred_update
    await self._update()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 108, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 152, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 694, in _update
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/push.py", line 558, in _ensure_connected
    await self._client.connect()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/lock.py", line 186, in connect
    await self._setup_session()
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/lock.py", line 244, in _setup_session
    response = await self.secure_session.execute(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/yalexs_ble/session.py", line 266, in execute
    async with interrupt(
  File "/usr/local/lib/python3.11/site-packages/async_interrupt/__init__.py", line 91, in __aexit__
    raise self._exception(self._message) from exc_val
yalexs_ble.session.DisconnectedError: Etuovi (98:1B:B5:01:95:EE): Disconnected


--------------------------------------------------------------------


Logger: yalexs_ble.lock
Source: runner.py:188
First occurred: 6. helmikuuta 2024 klo 15.43.01 (136 occurrences)
Last logged: 00.07.50

Etuovi (98:1B:B5:01:95:EE): Failed to connect to the lock: Etuovi (98:1B:B5:01:95:EE) - 98:1B:B5:01:95:EE: Failed to connect after 9 attempt(s): No backend with an available connection slot that can reach address 98:1B:B5:01:95:EE was found: The proxy/adapter is out of connection slots or the device is no longer reachable; Add additional proxies (https://esphome.github.io/bluetooth-proxies/) near this device
Etuovi (98:1B:B5:01:95:EE): Missing characteristic bd4ac614-0b45-11e3-8ffd-0800200c9a66; Clearing cache
Etuovi (98:1B:B5:01:95:EE): Missing characteristic bd4ac612-0b45-11e3-8ffd-0800200c9a66; Clearing cache

Additional information

No response

ntKarlsson avatar Feb 06 '24 22:02 ntKarlsson

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 Feb 06 '24 22:02 home-assistant[bot]

I have noticed this same issue with a similar setup, a Yale security door lock using a Shelly plus 1 switch (with esphome Bluetooth active proxy). Over 1 day or so, the lock no longer responds to commands via the BT proxy. Trawling the logs shows a similar error as above that there are no connection slots. My current workaround to reestablish connectivity is to restart the Bluetooth proxy (Shelly plus1) when the lock becomes unknown/ unavailable. I think this releases the slots and starts it all again. I have added an automation to home assistant whilst this issue is worked through.

newok05 avatar Feb 07 '24 21:02 newok05

Shelly devices can't make active connections so you will be connecting from your local adapter which likely means you have a range problem

https://www.home-assistant.io/integrations/bluetooth/#remote-adapters-bluetooth-proxies

bdraco avatar Feb 07 '24 21:02 bdraco

Just to clarify - in my circumstance it is a physical Shelly Plus1 but it is flashed with esphome with an active Bluetooth proxy enabled. Reading between the lines it looks like the OP also has done the same because they refer to an active Bluetooth connection.

newok05 avatar Feb 07 '24 23:02 newok05

I have the same issue and am using it the same way. I have an ESPHome Bluetooth proxy located right beside the lock I’m using.

It works for a few hours then crashes. I need to reload the integration to fix it.

andredigenova avatar Feb 09 '24 06:02 andredigenova

Try disabling active scans on the Bluetooth proxy. It may be getting overloaded.

If that doesn't fix it you'll need to check the esphome device console logs and enable debug logs for the integration

bdraco avatar Feb 09 '24 13:02 bdraco

Another reason it might be disconnecting is the key changed.

Its best to create another owner account for Home Assistant to use in the august integration so when you use your phone locally the key doesn't get rotated out from under Home Assistant

bdraco avatar Feb 09 '24 19:02 bdraco

Will try switching the proxy to passive and see what the behaviour is. I don't think my issue is the key getting rotated as I am the only user and the only time I open the August app is after the integration has failed.

andredigenova avatar Feb 09 '24 19:02 andredigenova

I get the following error on my esphome Shelly 1plus. I haven’t yet tried a separate account for use in the August integration. The error displays about 30 seconds after the Bluetooth lock connects to the proxy. I had already disabled active scans on the Bluetooth proxy.

IMG_9765 IMG_9764

newok05 avatar Feb 12 '24 20:02 newok05

It sure looks like an auth error as thats what the device does when the key has changed... but it can also unceremoniously drop the connection for other reasons which we don't know why.

bdraco avatar Feb 12 '24 20:02 bdraco

Ok, I’ll try creating a separate account owner for home assistant and see how that goes

newok05 avatar Feb 12 '24 23:02 newok05

Another reason it might be disconnecting is the key changed.

Its best to create another owner account for Home Assistant to use in the august integration so when you use your phone locally the key doesn't get rotated out from under Home Assistant

What did you mean when you tell him "create another owner account for Home Assistant to use in the august integration" Just install the integration with another account instead of admin user we typically use ??

simtreti avatar Feb 13 '24 03:02 simtreti

I have tried to add a new ‘home assistant’ user from the Yale Home app. It looks like you can only send an invite to a phone number and not an email address which is a pain. Is that what you mean by essentially creating a ‘service account’? I’ll have to figure out who I send the invite to as it will need to be to someone who I don’t also want to give access to the house to (in case the keys rotate) but who I can trust to have access to the house!

newok05 avatar Feb 13 '24 06:02 newok05

I have a few updates on this ticket. I have done the following:

  1. Added a new Yale owner account for the August integration and ensured that there is no device with that account used (to prevent any keys being cycled).
  2. I have also purchased a separate poe esp32 bluetooth proxy that I have flashed with esphome with an active connection. It is located about 2 metres from the lock and has an external antenna - so range is not a problem.
  3. I have disabled the shelly esphome bluetooth proxy when using the poe proxy.

For both the shelly esphome bluetooth proxy and also for the poe esphome bluetooth proxy I am consistently getting the following error display in the esphome device logs.

Is this contributing to the crashing on the Shelly?


[14:42:47][I][bluetooth_proxy:278]: [0] [XX:XX:XX:XX:XX:XX] Connecting v3 with cache
[14:42:47][D][esp32_ble_tracker:215]: Pausing scan to make connection...
[14:42:47][I][esp32_ble_client:069]: [0] [XX:XX:XX:XX:XX:XX] 0x00 Attempting BLE connection
[14:42:47][I][esp32_ble_client:149]: [0] [XX:XX:XX:XX:XX:XX] Connected
[14:42:47][D][esp32_ble_tracker:266]: Starting scan...
[14:43:18][D][esp-idf:000]: W (2612220) BT_APPL: gattc_conn_cb: if=3 st=0 id=3 rsn=0x13

[14:43:18][D][esp-idf:000]: W (2612223) BT_APPL: gattc_conn_cb: if=4 st=0 id=4 rsn=0x13

[14:43:18][D][esp-idf:000]: W (2612224) BT_APPL: gattc_conn_cb: if=5 st=0 id=5 rsn=0x13

[14:43:18][D][esp-idf:000]: W (2612226) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x13

[14:43:20][I][bluetooth_proxy:278]: [0] [XX:XX:XX:XX:XX:XX] Connecting v3 with cache
[14:43:20][D][esp32_ble_tracker:215]: Pausing scan to make connection...
[14:43:20][D][esp32_ble_tracker:215]: Pausing scan to make connection...
[14:43:20][D][esp-idf:000]: E (2613753) BT_BTM: BTM_BleScan scan not active


[14:43:20][D][esp-idf:000]: W (2613757) BT_APPL:  bta_dm_ble_scan stop scan failed, status=0x6


[14:43:20][I][esp32_ble_client:069]: [0] [XX:XX:XX:XX:XX:XX] 0x00 Attempting BLE connection
[14:43:20][I][esp32_ble_client:149]: [0] [XX:XX:XX:XX:XX:XX] Connected

newok05 avatar Feb 20 '24 03:02 newok05

I just realized that I am seeing the same problem in my similar setup:

[12:14:03][D][esp-idf:000]: W (3996632) BT_APPL: gattc_conn_cb: if=3 st=0 id=3 rsn=0x13

[12:14:03][D][esp-idf:000]: W (3996638) BT_APPL: gattc_conn_cb: if=4 st=0 id=4 rsn=0x13

[12:14:03][D][esp-idf:000]: W (3996640) BT_APPL: gattc_conn_cb: if=5 st=0 id=5 rsn=0x13

[12:14:03][D][esp-idf:000]: W (3996642) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x13

[12:14:03][D][esp32_ble_client:110]: [0] [XX:XX:XX:XX:XX:XX] ESP_GATTC_WRITE_CHAR_EVT [12:14:03][W][bluetooth_proxy.connection:096]: [0] [XX:XX:XX:XX:XX:XX] Error writing char/descriptor at handle 0x17, status=133 [12:14:03][D][esp32_ble_client:172]: [0] [XX:XX:XX:XX:XX:XX] ESP_GATTC_DISCONNECT_EVT, reason 19 [12:14:03][D][esp32_ble_client:110]: [0] [] ESP_GATTC_CLOSE_EVT

What can I do to help narrow down the problem? ESP-32S Yale Linus All software are the latest and greatest.

korttoma avatar Feb 21 '24 10:02 korttoma

I noticed that there is now a new release of esphome 2024.2.0 so I have upgraded to that version on my Poe Bluetooth proxy from 2023.12 just to check. The issue still persists in 2024.2.0.

I am wondering if this is an issue with the esp-idf framework? Just a guess …

newok05 avatar Feb 21 '24 19:02 newok05

I moved the whole setup to NUC and changed the Shelly plug to ESP-32S board also to test if it would perform better but issue is still the same. I also added new user to the lock, but that does not seem to help. I guessed this because I never use the Yale access app on my phone.

I don't know how to test this, but I think sometimes the lock tries to connect to the NUC's bluetooth adapter, instead of the ESP-32 next to the door. I also tried to install the integration without activating the local bluetooth adapter at all, but that didn't work.

ntKarlsson avatar Mar 06 '24 20:03 ntKarlsson

Not sure if it is related but I note that the Esphome Bluetooth proxy in this ticket displays a similar error to the one I have been seeing. https://github.com/home-assistant/core/issues/111966

newok05 avatar Mar 09 '24 06:03 newok05

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.