August Bluetooth lock constantly disconnecting using yale Bluetooth integration.

roabyd commented 2 months ago

          @Samywamy10 Can you also try watching `bluetoothctl` from the CLI while you are connecting to the lock. Is the device being constantly being added and removed from the bus?

Originally posted by @bdraco in https://github.com/home-assistant/core/issues/100275#issuecomment-1719493180

I saw the above comment in a now closed issue, however I am experiencing exactly this. I have had the August bluetooth lock for a few months now, and at first it integrated with HA well, with the occasional drops here and there. Lately however the lock is constantly unavailable with the yale bluetooth integration constantly in a state of initializing or Failed to connect.

The logs reported in the HA UI are very similar to the ones listed in the refernced issue, and when I check the bluetoothctl logs, I see the following constatnly:

I have tried factory resetting the device, powering it off for some time, moving it closer to the Bluetooth dongle (is it usually 3 meters away in direct line of sight) enabling and disabling the internal and external Bluetooth adapters (I am running HAOS on a trigkey G4 mini PC, with a usb Bluetooth external dongle from the HA supported list - on a USB extension cable) but nothing seems to bring it back.

The lock connects fine to the august mobile app, but i am running out of ideas on how to get it back into HA. Please let me know if there is anything I have forgotten to mention, and thank you for any help.

roabyd commented 2 months ago

Attaching some more error logs if it helps:

Logger: yalexs_ble.push
Source: /usr/local/lib/python3.12/site-packages/yalexs_ble/push.py:1041
First occurred: April 29, 2024 at 3:16:50 PM (674 occurrences)
Last logged: 12:14:45 PM

Lounge door (1C:BA:8C:27:22:60): Bluetooth error updating
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 363, in establish_connection
    await client.connect(
  File "/usr/local/lib/python3.12/site-packages/habluetooth/wrappers.py", line 300, in connect
    connected = await super().connect(**kwargs)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 249, in connect
    assert_reply(reply)
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/utils.py", line 22, in assert_reply
    raise BleakDBusError(reply.error_name, reply.body)
bleak.exc.BleakDBusError: [org.bluez.Error.Failed] Operation already in progress

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 1020, in _execute_deferred_update
    await self._update()
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 113, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 157, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 707, in _update
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 566, in _ensure_connected
    await self._client.connect(max_attempts)
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 155, in connect
    raise err
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 144, in connect
    self.client = await establish_connection(
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 472, in establish_connection
    _raise_if_needed(name, device.address, exc)
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 339, in _raise_if_needed
    raise BleakConnectionError(msg) from exc
bleak_retry_connector.BleakConnectionError: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 1 attempt(s): [org.bluez.Error.Failed] Operation already in progress

Logger: yalexs_ble.lock
Source: runner.py:189
First occurred: April 29, 2024 at 3:07:50 PM (7566 occurrences)
Last logged: 12:14:45 PM

Lounge door (1C:BA:8C:27:22:60): Failed to connect to the lock: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 2 attempt(s): [org.bluez.Error.Failed] Operation already in progress
Lounge door (1C:BA:8C:27:22:60): Failed to connect to the lock: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 8 attempt(s): failed to discover services, device disconnected
Lounge door (1C:BA:8C:27:22:60): Failed to connect to the lock: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 1 attempt(s): failed to discover services, device disconnected
Lounge door (1C:BA:8C:27:22:60): Failed to connect to the lock: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 1 attempt(s): TimeoutError
Lounge door (1C:BA:8C:27:22:60): Failed to connect to the lock: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 3 attempt(s): [org.bluez.Error.Failed] Operation already in progress

Logger: yalexs_ble.push
Source: /usr/local/lib/python3.12/site-packages/yalexs_ble/push.py:1046
First occurred: April 29, 2024 at 3:08:42 PM (965 occurrences)
Last logged: 12:13:25 PM

Lounge door (1C:BA:8C:27:22:60): Disconnected while updating
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 363, in establish_connection
    await client.connect(
  File "/usr/local/lib/python3.12/site-packages/habluetooth/wrappers.py", line 300, in connect
    connected = await super().connect(**kwargs)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 268, in connect
    await self.get_services(
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/client.py", line 656, in get_services
    self.services = await manager.get_services(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/manager.py", line 644, in get_services
    await self._wait_for_services_discovery(device_path)
  File "/usr/local/lib/python3.12/site-packages/bleak/backends/bluezdbus/manager.py", line 779, in _wait_for_services_discovery
    raise BleakError("failed to discover services, device disconnected")
bleak.exc.BleakError: failed to discover services, device disconnected

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 157, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 707, in _update
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 566, in _ensure_connected
    await self._client.connect(max_attempts)
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 155, in connect
    raise err
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 144, in connect
    self.client = await establish_connection(
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 472, in establish_connection
    _raise_if_needed(name, device.address, exc)
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/__init__.py", line 339, in _raise_if_needed
    raise BleakConnectionError(msg) from exc
bleak_retry_connector.BleakConnectionError: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 1 attempt(s): failed to discover services, device disconnected

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 1020, in _execute_deferred_update
    await self._update()
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 113, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 219, in _async_wrap_retry_bluetooth_connection_error
    raise DisconnectedError(str(err))
yalexs_ble.session.DisconnectedError: Lounge door (1C:BA:8C:27:22:60) - 1C:BA:8C:27:22:60: Failed to connect after 1 attempt(s): failed to discover services, device disconnected

These are 3 example of repeated logs in the last 24 hours

home-assistant[bot] commented 2 months ago

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)}}

feens commented 1 month ago

I'm experiencing the same issue. I have 3 locks, two that are quite close together on my main level and one in my basement, which is also where my HA box is. The August locks are the only Bluetooth devices I use with Home Assistant.

I have a Sena long range BT adapter on a USB extension as well as an Olimex ESP32 proxy (using POE), though I've been trying to get it to work on a single device (ideally).

The behaviours I had:

Initially I was running the Olimex in my basement. It would work great for a little bit (half a day to a day) and then become more or less unresponsive until I reset the device. (unresponsive as in I could connect to in it ESPHome, but it basically had no logs or BT traffic)
I then purchased the BT adapter and set it up (also running on a USB extension cable). It worked really well for the first ~3 or so days, and then the last few days has become quite unresponsive, similar error messages to above.
I put the adapter into passive mode, and the errors go away...but then I don't get any updates when the locks are manually operated.

I did use bluetoothctl to try and sort out what's going on. I'm pretty sure it's not a range issues that adapter is quite close to my basement door. My best guess is this: The BT adapter finds a significant number of devices, and my guess is that if it's operating in active mode it's spending a lot of time trying to query each device and can't keep up. My understanding of how active/passive works is that passive just consumes that data that's initially broadcast, where active will probe for more data (but not stay connected all of the time).

Edit: Looked it up, and RSSI for the locks are -46, -66, -69

Ideally, I'd be able to configure my adapter to be active scan, but also filter by the devices I specify. I spent a bunch of time digging into BlueZ and Bleak to see what scan options there are, and BlueZ does have a Pattern option when scanning, and when I used that with the bluetoothctl I could see that it was correctly filtering the traffic. It looks like that while Bleak supports the Pattern filter, the Home Assistant wrapper for it does not.

Anyway, I suspect the issue (or at least mine) isn't with the August integration but how HA Bluetooth works. I'm still learning a lot in this area and would love more pointers on how to debug though. I'm a developer by trade, so happy to spend time in code as well (as I have time).

bdraco commented 1 month ago

HAOS 12.3 has BlueZ 5.75 which has some stability fixes that might help

I'd also try ESP-IDF 4.4.7 on the Olimex board as there are some known issues with active scan https://github.com/esphome/issues/issues/5119

roabyd commented 1 month ago

I've just updated and HAOS with no change. I have also tried removing all Bluetooth proxies from my network, with no change

bdraco commented 1 month ago

Did you try only using the Bluetooth proxies after updating them to 4.4.7 and disabling the config entry for the local adapter?

esphome yaml:

esp32:
  framework:
    type: esp-idf
    version: 4.4.7

feens commented 1 month ago

@bdraco I updated mine last night, so far so good, but I'll need a couple of days to be sure. I'll report back here.

I'm curious if there's a way to keep tabs on signal strength and connection status of the locks?

bdraco commented 1 month ago

You can enable debug logging and the advertisements and rssi will show up in the log.

logger:
  default: info
  logs:
    homeassistant.components.bluetooth: debug
    homeassistant.components.yalexs_ble: debug
    yalexs_ble: debug
    yalexs_ble_adv: debug

feens commented 1 month ago

@bdraco ESP-IDF update seems to have fixed the hanging issue, same with the HAOS update.

However, response times seem to be pretty slow at times. Trying a few different combos of adapters/sensors. I have my Olimex up in the front hall now, basically about 5' from the two doors there, and a basic ESP32 proxy (just a generic ESP32) in the basement about 5' from that door, and the BT adapter in the basement. I've tried with various forms of them enabled, i.e. currently running just the proxies and not the adapter to see if having less signal overlap is helpful.

Any suggestions? I've also tried working on a custom esp32_ble_tracker component, by sub-classing the main one, with the idea of allowing it to make use of the whitelist feature. I can't seem to get the config to play nicely with the bluetooth proxy component though. I'm still a bit new in developing on the platform though.

bdraco commented 1 month ago

Sorry I don't have any suggestions for making it faster. All of mine are very quick when using the proxies. The local adapters are a bit slower so I dont use them for production

feens commented 1 month ago

@bdraco sorry to keep bugging you...there doesn't seem to be a good place to ask more technical questions around the august/esphome stuff (and the docs for building components are very sparse...especially tricky as python/c++ are languages I've worked with really)

Do you run your scanner as active or passive? I tried mine as passive, but then I don't get any notifications when the lock is manually operated. I once tried setting up the lock in a separate Home, but then that causes side-effects like Siri always having to ask which home I was intending to use.
Do you know if there's any way to use the connections config param in esp32_ble_tracker to have the scanner work such that it only connects to the devices I specify, but without keeping a fully active connection (which kills the battery)
Alternatively, is there a way to use the tracker in passive mode but use the advertisement callbacks to get the same data that an active scanner would?

I appreciate the help.

bdraco commented 1 month ago

@bdraco sorry to keep bugging you...there doesn't seem to be a good place to ask more technical questions around the august/esphome stuff (and the docs for building components are very sparse...especially tricky as python/c++ are languages I've worked with really)

Do you run your scanner as active or passive? I tried mine as passive, but then I don't get any notifications when the lock is manually operated. I once tried setting up the lock in a separate Home, but then that causes side-effects like Siri always having to ask which home I was intending to use.

Passive. But I also have HomeKit setup since the HAP spec sends notifications passively. The yalexs-ble library knows how to watch for them. See https://www.home-assistant.io/integrations/yalexs_ble/#push-updates

Do you know if there's any way to use the connections config param in esp32_ble_tracker to have the scanner work such that it only connects to the devices I specify, but without keeping a fully active connection (which kills the battery)

There is no way to do that currently.

Alternatively, is there a way to use the tracker in passive mode but use the advertisement callbacks to get the same data that an active scanner would?

I don't think that is possible.

I appreciate the help.

feens commented 1 month ago

Passive. But I also have HomeKit setup since the HAP spec sends notifications passively. The yalexs-ble library knows how to watch for them. See https://www.home-assistant.io/integrations/yalexs_ble/#push-updates

Do you have them in a separate home, or the same? I had tried a separate home previously but it was annoying. Though now that I’ve re-read that section, I mis-interpreted the “can’t use HA HomeKit controller” as meaning that it had to be on a different home. I suppose I could have it in the same home but just hidden with an obscure name.

I also just tried setting up my proxies using ble_client setup for my three locks and auto_connect: false to see if that would basically block out the 3 connection slots from other devices. Currently they seem responsive but that may just be coincidental.

bdraco commented 1 month ago

Do you have them in a separate home, or the same? I had tried a separate home previously but it was annoying.

Its the same home.

roabyd commented 1 month ago

Did you try only using the Bluetooth proxies after updating them to 4.4.7 and disabling the config entry for the local adapter?

esphome yaml:
esp32:
  framework:
    type: esp-idf
    version: 4.4.7

So I have now tried this and can confirm it fixed my issue. I also tested using the arduino framework with no version and this also worked.

As soon as I enable either of the bluetooth adapters connected to my homeassesistant server, the lock stops responding. Definitely seems like some stability issues on the native bluetooth implementation in HA, noting that I am on the latest version of HAOS (Generic x86-64 12.3) and home assistant (2024.5.3)

feens commented 1 month ago

@bdraco FYI, I have a draft PR up to use the ESP-IDF scanner whitelisting...seems to be super snappy so far on my setup. I think it'll be a useful feature for the Yale Bluetooth integration. I can look at updating the docs if/when this PR goes through if you think that would be useful.

It also allows me to be specific about which proxy is used for which lock so that there's no overlap.

ntKarlsson commented 1 week ago

Is this same problem? The longest it has been working is something like 3 days. Then I need to restart ESP and it gets connection on again.

Lokikirjaaja: yalexs_ble.push
Lähde: /usr/local/lib/python3.12/site-packages/yalexs_ble/push.py:1041
Ensimmäistä kertaa ilmennyt: 17.36.05 (2 tapahtumat)
Viimeksi kirjattu: 17.38.10

Etuovi (98:1B:B5:01:95:EE): Bluetooth error updating
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 568, in bluetooth_device_connect
    await connect_future
TimeoutError

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/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.12/site-packages/bleak_esphome/backend/client.py", line 297, in connect
    await self._client.bluetooth_device_connect(
  File "/usr/local/lib/python3.12/site-packages/aioesphomeapi/client.py", line 588, in bluetooth_device_connect
    raise TimeoutAPIError(
aioesphomeapi.core.TimeoutAPIError: Timeout waiting for connect response while connecting to 98:1B:B5:01:95:EE after 20.0s, disconnect timed out: False,  after 20.0s

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/_init_.py", line 363, in establish_connection
    await client.connect(
  File "/usr/local/lib/python3.12/site-packages/habluetooth/wrappers.py", line 300, in connect
    connected = await super().connect(**kwargs)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/_init_.py", line 605, in connect
    return await self._backend.connect(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_esphome/backend/client.py", line 79, in _async_wrap_bluetooth_operation
    raise asyncio.TimeoutError(str(err)) from err
TimeoutError: Timeout waiting for connect response while connecting to 98:1B:B5:01:95:EE after 20.0s, disconnect timed out: False,  after 20.0s

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 1020, in _execute_deferred_update
    await self._update()
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 113, in _async_wrap_operation_lock
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 157, in _async_wrap_retry_bluetooth_connection_error
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 707, in _update
    lock = await self._ensure_connected()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/push.py", line 566, in _ensure_connected
    await self._client.connect(max_attempts)
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 155, in connect
    raise err
  File "/usr/local/lib/python3.12/site-packages/yalexs_ble/lock.py", line 144, in connect
    self.client = await establish_connection(
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/_init_.py", line 387, in establish_connection
    _raise_if_needed(name, device.address, exc)
  File "/usr/local/lib/python3.12/site-packages/bleak_retry_connector/_init_.py", line 327, in _raise_if_needed
    raise BleakNotFoundError(msg) from exc
bleak_retry_connector.BleakNotFoundError: Etuovi (98:1B:B5:01:95:EE) - 98:1B:B5:01:95:EE: Failed to connect after 4 attempt(s): Timeout waiting for connect response while connecting to 98:1B:B5:01:95:EE after 20.0s, disconnect timed out: False,  after 20.0s

home-assistant / core

August Bluetooth lock constantly disconnecting using yale Bluetooth integration. #116366