Airthings-ble becomes flaky with HA Core > 2024.1.5

JesusSanchezLopez commented 5 months ago

The problem

Airthings-BLE device starts reporting sporadically, sometimes going hours between successful reporting. Based on my testing the issue was introduced in 2024.1.6 with 2024.1.5 being the last version working correctly. I verified that issue still exists in HA Core 2024.3.

The issue is resolved with downgrading to 2024.1.5 or lower

Here's an image of flaky behavior HA core

What version of Home Assistant Core has the issue?

2024.1.6

What was the last working version of Home Assistant Core?

2024.1.5

What type of installation are you running?

Home Assistant OS

Integration causing the issue

airthings-ble

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

home-assistant[bot] commented 5 months ago

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

Code owner commands

Code owners of `airthings_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 airthings_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)}}

airthings_ble documentation airthings_ble source _{^{(message by IssueLinks)}}

jaydeethree commented 4 months ago

I've done some testing and I believe the problems were caused by this PR (which unfortunately contains a ton of changes, so it's hard to say which specific change is the bad one).

For now I've worked around this by rolling back to the version of the airthings_ble integration that was in use prior to that PR. There's a little bit of info about how to do this in the Home Assistant docs, but here's a slightly more detailed version of the process:

Go to the last working version of the airthings_ble integration, open each file, and download the raw file.
Create a custom_components/airthings_ble/ directory and add all of those files to it.
Edit the manifest.json file to add this line (the specific version number doesn't matter, but you have to specify some version number for this to work):
- "version": "0.0.1",
- It should look something like this:
Restart Home Assistant.
Check your Devices & Services page to confirm that the Airthings integration now shows the "Custom integration" icon (the yellow icon in the lower-right corner):

This seems to have fixed the instability problems that I've been having.

JesusSanchezLopez commented 4 months ago

@jaydeethree : Thanks for the instructions on how to replace broken airthings_ble integration with custom one!

Once custom integration was in place, I upgraded HA core to 2024.4.1. It's been 12+ hours and communication with Airthings wave plus has been solid, no dropouts!

@vincegio, @LaStrada This is yet another confirmation that changes in airthings_ble v0.6.0 broke ble communication.

JesusSanchezLopez commented 4 months ago

@jaydeethree : Can you sequentially try versions between v0.5.0 to v0.6.0 to see if the exact version causing the issue could be identified? Let me know if this is not possible or suggest next steps.

jaydeethree commented 4 months ago

I agree that testing against each PR to identify the bad change is the next step, but I'm just a random user of this integration and I personally don't have time to do that. @LaStrada 's GitHub profile indicates that they are an Airthings employee, so it seems like Airthings maintains their own Home Assistant integration. Since they have paid employees maintaining this and there are widespread reports of it being broken (https://github.com/home-assistant/core/issues/109499), I feel like it should be their responsibility to spend the time debugging this and fixing it.

def1149 commented 4 months ago

I thought this Aithings BLE fiasco had been fixed but no. You see where it flatlined until a reset. Core 2024.4.2 This is harder to notice than when it used to go to Unknown. You must look at the graph to determine that it's stuck. I guess it's time to implement the automatic periodic reset hack Sigh. Need to use a highly variable element like CO2 and check to see if it's changed over the last n minutes. Anyone know how to reference the previous value in an automation or do I need to create a kludge number helper as a global variable to check and set

Has anyone else seen flatlining?

LaStrada commented 4 months ago

It's really hard to debug this, since it does not happen on any of my Home Assistant machines. I have multiple instances running (RPI4 + RPI5 + Intel Nuc + a Mac for development) and I don't see this problem. With and without using ESPHome BLE proxies.

What Bluetooth interface are you using? Is it any of the recommended ones listed here? https://www.home-assistant.io/integrations/bluetooth/#known-working-high-performance-adapters
Are any of you with the problems using ESPHome with BLE Proxies?
When this happens, what do you see in the logs? (please enable debug logging and attache the logs)

I asked similar questions in a different ticket before the version bump, but I'll ask the questions again here.

The only thing I can think of right now is to add more logging, both to the framework and the integration, if the current logs doesn't give me anything.

def1149 commented 4 months ago

HA Yellow BT is the on Pi CM4. Other BT devices do not have any issues I don't use ESPHome BT Proxies I'll have to check the log the next time it occurs. This time because the value stuck, aka flatlined, and didn't go to Unknown, I didn't realize it had occurred until days latter

JesusSanchezLopez commented 4 months ago

I am using RPI 4 and BT that comes with it I don't use other BT devices I don't use ESPHome BT Proxy

Here are some log messages (note timestamps for Unexpectedly disconnected from FC:A8:9B:XX:XX:XX and compare to screenshot)

2024-04-09 15:27:16.409 DEBUG (MainThread) [custom_components.airthings-ble.config_flow] Discovered BT device: <habluetooth.models.BluetoothServiceInfoBleak object at 0x7f8dc7aec0> 2024-04-09 15:32:19.876 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:32:19.877 DEBUG (MainThread) [custom_components.airthings-ble] Finished fetching airthings_ble data in 4.877 seconds (success: True) 2024-04-09 15:37:23.864 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:37:23.867 DEBUG (MainThread) [custom_components.airthings-ble] Finished fetching airthings_ble data in 3.868 seconds (success: True) 2024-04-09 15:42:25.164 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:42:31.756 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:42:37.617 DEBUG (MainThread) [custom_components.airthings-ble] Unexpectedly disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:42:39.858 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:42:39.861 DEBUG (MainThread) [custom_components.airthings-ble] Finished fetching airthings_ble data in 15.862 seconds (success: True) 2024-04-09 15:47:44.864 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 15:47:44.868 DEBUG (MainThread) [custom_components.airthings-ble] Finished fetching airthings_ble data in 4.869 seconds (success: True) 2024-04-09 16:02:59.320 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 16:03:05.636 DEBUG (MainThread) [custom_components.airthings-ble] Unexpectedly disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 16:03:08.024 DEBUG (MainThread) [custom_components.airthings-ble] Disconnected from FC:A8:9B:XX:XX:XX 2024-04-09 16:03:08.025 DEBUG (MainThread) [custom_components.airthings-ble] Finished fetching airthings_ble data in 12.026 seconds (success: True)

airthing-ble

To generate above error:

I copied 2024.1.6 version into custom components from here (I am currently on HA Core 2024.4.2)

To fix error:

Change manifest.json

from

"requirements": ["airthings-ble==0.6.0"]

to

"requirements": ["airthings-ble==0.5.6-4"]

also works with "0.5.5", "0.5.6-1", "0.5.6-2"

jaydeethree commented 4 months ago

What Bluetooth interface are you using? Is it any of the recommended ones listed here? https://www.home-assistant.io/integrations/bluetooth/#known-working-high-performance-adapters

Yes, I'm using a CSR8510A10-based adapter that's in that list (TRENDnet TBW-106UB).

Are any of you with the problems using ESPHome with BLE Proxies?

Yes, I use ESPHome BLE proxies on a mix of ESP32 and ESP32-S3 boards.

When this happens, what do you see in the logs? (please enable debug logging and attache the logs)

Unfortunately I don't have debug logs. Hopefully the logs provided by @JesusSanchezLopez can help.

The only thing I can think of right now is to add more logging, both to the framework and the integration, if the current logs doesn't give me anything.

It might be good to roll back to an older version of the airthings-ble library until this has been fixed. Currently the Airthings BLE integration is broken for a significant number of Home Assistant users, and those users are reporting that it worked correctly until airthings-ble was bumped to 0.6.0. Here's a few weeks of data from a Wave Plus device:

Screenshot 2024-04-09 140925

Zooming in you can see that even when it's "working" it's frequently missing data:

Screenshot 2024-04-09 141118

And for comparison, here's what I'm seeing since I rolled back to an older version of the integration:

Screenshot 2024-04-09 141402

(and yes, I know my CO2 numbers in that room are terrible - that's why I monitor it 😄 )

bobloadmire commented 4 months ago

Has anyone found a temporary workaround?

JesusSanchezLopez commented 4 months ago

@bobloadmire - The temporary workaround is to create a custom component as outlined by @jaydeethree above

@LaStrada Did you have any luck looking into this issue? Based on my testing the bug was introduced in version 0.6.0 (v0.5.6-4 works, while 0.6.0 does not) When you look at my logs above, it appears that issue happens when initial data fetch fails, there is a successful follow up fetch but the data doesn't seem to be passed over to HA.

gmlupatelli commented 3 months ago

I am also having the issue.

Hardware: Raspberry Pi 4 Bluetooth: Bluetooth Radio (0bda:a725) by Realtek (Hardware: usb:v1D6Bp0246d0548)

Version of airthigs-ble used 0.5.6-2

Debug Logs:


2024-04-23 09:10:59.302 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:10:59.305 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 13.776 seconds (success: True)
2024-04-23 09:16:04.290 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:16:04.293 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 4.765 seconds (success: True)
2024-04-23 09:21:18.303 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:21:18.306 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 13.777 seconds (success: True)
2024-04-23 09:26:33.303 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:26:33.306 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 14.777 seconds (success: True)
2024-04-23 09:31:35.571 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:31:42.661 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:31:50.188 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:31:52.302 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:31:52.305 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 18.775 seconds (success: True)
2024-04-23 09:36:54.558 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:37:02.135 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:37:10.698 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:37:20.107 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:37:22.356 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:37:22.358 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 29.828 seconds (success: True)
2024-04-23 09:42:30.604 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:42:37.159 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:43:14.227 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:43:14.278 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:43:14.281 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 51.752 seconds (success: True)
2024-04-23 09:48:22.300 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:48:22.304 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 7.774 seconds (success: True)
2024-04-23 09:53:30.106 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:53:35.984 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:53:38.321 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:53:38.323 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 15.795 seconds (success: True)
2024-04-23 09:58:39.661 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:58:47.195 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:58:49.308 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 09:58:49.309 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 10.780 seconds (success: True)
2024-04-23 10:04:05.300 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:04:05.303 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 15.775 seconds (success: True)
2024-04-23 10:09:27.866 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:09:27.934 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 22.404 seconds (success: True)
2024-04-23 10:14:35.640 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:14:37.148 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:14:38.074 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:14:40.277 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:14:40.281 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 12.750 seconds (success: True)
2024-04-23 10:19:49.345 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:19:49.347 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 5.356 seconds (success: True)
2024-04-23 10:25:03.297 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:25:03.300 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 11.436 seconds (success: True)
2024-04-23 10:30:15.543 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:30:22.619 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:30:30.692 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:30:33.345 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:30:33.349 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 29.820 seconds (success: True)
2024-04-23 10:35:37.385 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:35:37.389 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 3.857 seconds (success: True)
2024-04-23 10:40:43.321 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:40:43.324 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 5.795 seconds (success: True)
2024-04-23 10:45:48.547 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:45:48.551 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 5.021 seconds (success: True)
2024-04-23 10:50:52.067 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:50:59.150 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:51:05.734 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:51:12.140 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:51:14.293 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:51:14.296 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 25.767 seconds (success: True)
2024-04-23 10:56:16.966 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:56:24.526 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:56:31.998 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:56:34.290 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 10:56:34.293 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 19.764 seconds (success: True)
2024-04-23 11:01:48.304 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:01:48.306 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 13.777 seconds (success: True)
2024-04-23 11:07:00.664 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:07:08.281 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:07:10.304 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:07:10.308 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 21.779 seconds (success: True)
2024-04-23 11:12:23.348 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:12:23.349 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 12.820 seconds (success: True)
2024-04-23 11:17:24.488 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:17:31.060 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:17:38.583 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:17:41.281 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:17:41.284 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 17.756 seconds (success: True)
2024-04-23 11:22:46.323 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:22:46.329 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 4.799 seconds (success: True)
2024-04-23 11:27:53.287 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:27:53.290 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 6.762 seconds (success: True)
2024-04-23 11:30:42.367 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B
2024-04-23 11:30:42.374 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 9.200 seconds (success: True)
2024-04-23 11:30:42.375 DEBUG (MainThread) [homeassistant.components.airthings_ble.sensor] got sensors: {'humidity': 54.5, 'illuminance': 34, 'radon_1day_avg': 21, 'radon_longterm_avg': 45, 'temperature': 17.87, 'pressure': 993.0, 'co2': 703.0, 'voc': 136.0, 'radon_1day_level': 'very low', 'radon_longterm_level': 'very low', 'battery': 93}
2024-04-23 11:35:48.123 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from 7C:E2:69:7C:9B:2B

AT 2024-04-23 11:30:42.374 I manually reloaded the integration to make it start working again. As a workaround, I created an integration reloading automation triggered when the Airthings data is unavailable.

I can test more things if needed, just explain to me what you need like if I was 5 years old....lol

def1149 commented 3 months ago

Going unknown is now happening multiple times a day. I created an automation that restarts the integration if the status goes unknown for more than a minute and creates a persistent notification to document the event. I woke up to four notifications today

I hope someone creates a reliable integration. But my failure detection hack automation is working for now and one minute of data loss is not critical

bdraco commented 3 months ago

Its possible you have either a problem with the Bluetooth adapter, or an integration blocking the event loop and the root cause is something else. That would explain why some users have no issue.

If its an integration blocking the event loop, you may be able to find it with:

Install profiler integration https://my.home-assistant.io/redirect/config_flow_start/?domain=profiler
Enable asyncio debug service as soon as possible after startup https://www.home-assistant.io/integrations/profiler/#service-profilerset_asyncio_debug
Watch logs for RuntimeError: Non-thread-safe operation and long asyncio delays
Download and post logs with full trace

For 2024.5.x and later Home Assistant debug mode can also be enabled in configuration.yaml

homeassistant:
  debug: true

JesusSanchezLopez commented 3 months ago

@bdraco I can recreate this issue and resolve it at will by changing airthings-ble integration version.

With only airthings-ble component changing I am pretty confident that this integrations is the issue. Our current workaround as described by @jaydeethree above is to use an older version as a custom component.

Based on what I saw in the log it appears that integration works as long as the connection is made on first try, however when there is an initial fail and a second try the data is not processed. See my findings

It's a bit frustrating that @LaStrada is not engaging to try and fix this issue even though he is an employee of Airthings. I would recommend everyone who is experiencing this issue to email Airthings support to get some movement.

bdraco commented 3 months ago

It's a bit frustrating that @LaStrada is not engaging to try and fix this issue even though he is an employee of Airthings. I would recommend everyone who is experiencing this issue to email Airthings support to get some movement.

It's nice that we have someone at the vendor supporting Home Assistant. The unintended consequence of complaining about that might be that fewer vendors want to contribute to Home Assistant.

bdraco commented 3 months ago

You have a lot of Unexpectedly disconnected from xxxx in the log which means the underlying BLE connection is being dropped. Versions before 0.6.0 were not capable of detecting the connection drops so its a expected that you'll see the data go unknown if the connection gets dropped. Previously it would return the stale data.

That can be caused by problem with the adapter, a problem with the bluetooth stack, or something blocking the event loop.

I'd recommend enabling debug logs for the bluetooth integration or if you have an ESPHome based adapter, turn on debug logging with the developer tools:

service: logger.set_level
data:
  bleak_esphome: debug
  habluetooth: debug
  airthings_ble: debug
  homeassistant.components.airthings_ble: debug
  homeassistant.components.bluetooth: debug
  bleak: debug
  bleak_retry_connector: debug

jaydeethree commented 3 months ago

It's nice that we have someone at the vendor supporting Home Assistant. The unintended consequence of complaining about that might be that fewer vendors want to contribute to Home Assistant.

While I understand your point here, I feel like the situation is a bit more nuanced than that. The Airthings BLE integration generally worked well, but started having problems for many people in the very first release after Airthings took over the underlying library. It has been more than 3 months since then and the problems have not been resolved. So in my opinion the complaints are warranted - from a user's perspective it looks like Airthings broke this and now they won't fix it.

You have a lot of Unexpectedly disconnected from xxxx in the log which means the underlying BLE connection is being dropped. Versions before 0.6.0 were not capable of detecting the connection drops so its a expected that you'll see the data go unknown if the connection gets dropped. Previously it would return the stale data.

While this is very helpful information I still think there's something else going on here. Please look at the graphs in my previous comment (https://github.com/home-assistant/core/issues/113610#issuecomment-2046064088) - the current version of the integration often stops receiving data for multiple days at a time. Here's a similar graph showing several weeks of data after reverting to an old version of the integration:

Screenshot 2024-05-01 091138

If the old version of the integration was doing the same thing but just returning stale data then I would expect to see a flat line in that graph that spans several hours/days, but there isn't one. Additionally I use a lot of Bluetooth devices in Home Assistant and the Airthings devices are the only ones that are unstable.

bdraco commented 3 months ago

While this is very helpful information I still think there's something else going on here.

There may very well be but without the logs that were requested in https://github.com/home-assistant/core/issues/113610#issuecomment-2045884136 , its nearly impossible to troubleshoot or diagnose that.

Pim-Infuzed commented 3 months ago

First info (stil waiting for Airthing BLE to fail again while debug logging is on), although I doubt it is related to this serious issue which was introduced as of 2024.1.6:

Logger: homeassistant.components.airthings_ble
Bron: helpers/update_coordinator.py:350
integratie: Airthings BLE ([documentation](https://www.home-assistant.io/integrations/airthings_ble), [issues](https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22))
First occurred: 27 april 2024 om 17:36:28 (1 gebeurtenissen)
Laatst gelogd: 27 april 2024 om 17:36:28

Error fetching airthings_ble data: Unable to fetch data: 'NoneType' object has no attribute 'address'

bdraco commented 3 months ago

First info (stil waiting for Airthing BLE to fail again while debug logging is on), although I doubt it is related to this serious issue which was introduced as of 2024.1.6:

Logger: homeassistant.components.airthings_ble
Bron: helpers/update_coordinator.py:350
integratie: Airthings BLE ([documentation](https://www.home-assistant.io/integrations/airthings_ble), [issues]([https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22](https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22+sort%3Aupdated-desc)))
First occurred: 27 april 2024 om 17:36:28 (1 gebeurtenissen)
Laatst gelogd: 27 april 2024 om 17:36:28

Error fetching airthings_ble data: Unable to fetch data: 'NoneType' object has no attribute 'address'

Thats fixed in 2024.5.x via https://github.com/home-assistant/core/pull/115699

Pim-Infuzed commented 3 months ago

And this one (still waiting for the issue to arise, nowadays this can take minutes to approx 10 hours):

Logger: homeassistant.components.airthings_ble
Bron: components/airthings_ble/__init__.py:49
integratie: Airthings BLE ([documentation](https://www.home-assistant.io/integrations/airthings_ble), [issues](https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22))
First occurred: 25 april 2024 om 23:48:17 (8 gebeurtenissen)
Laatst gelogd: 18:06:11

Timeout getting command data.

def1149 commented 3 months ago

First info (stil waiting for Airthing BLE to fail again while debug logging is on), although I doubt it is related to this serious issue which was introduced as of 2024.1.6:

Logger: homeassistant.components.airthings_ble
Bron: helpers/update_coordinator.py:350
integratie: Airthings BLE ([documentation](https://www.home-assistant.io/integrations/airthings_ble), [issues]([https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22](https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22+sort%3Aupdated-desc)))
First occurred: 27 april 2024 om 17:36:28 (1 gebeurtenissen)
Laatst gelogd: 27 april 2024 om 17:36:28

Error fetching airthings_ble data: Unable to fetch data: 'NoneType' object has no attribute 'address'

Thats fixed in 2024.5.x via #115699

We'll see, I'm running b6 with HomeAssistant: debug: true

JesusSanchezLopez commented 3 months ago

@bdraco - see debug info home-assistant.log to go along this image:

airthings-2024-05-01

bdraco commented 3 months ago

@bdraco - see debug info home-assistant.log to go along this image:

It doesn't look like the airthings debug loggers are turned on in that log

bdraco commented 3 months ago

And this one (still waiting for the issue to arise, nowadays this can take minutes to approx 10 hours):

Logger: homeassistant.components.airthings_ble
Bron: components/airthings_ble/__init__.py:49
integratie: Airthings BLE ([documentation](https://www.home-assistant.io/integrations/airthings_ble), [issues]([https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22](https://github.com/home-assistant/core/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+airthings_ble%22+sort%3Aupdated-desc)))
First occurred: 25 april 2024 om 23:48:17 (8 gebeurtenissen)
Laatst gelogd: 18:06:11

Timeout getting command data.

It looks like the library assumes the timeout of 1s is enough, but thats likely not long enough if there is interference and a retry has to happen

bdraco commented 3 months ago

https://github.com/Airthings/airthings-ble/pull/36

HomeAssistantPim commented 3 months ago

Here is my logging: home-assistant_airthings_ble_2024-05-01T18-35-21.269Z.log

I do have a automation running that kicks ass against the config of the Airthings BLE integration until the battery of my Wave+ is available again (loop with 1 minute delay).

JesusSanchezLopez commented 3 months ago

@bdraco Here's a single failure @ ~14:35 home-assistant.log

airthings-2024-05-01

bdraco commented 3 months ago

@bdraco Here's a single failure @ ~14:35 home-assistant.log

Looks like you are definitely getting unexpected disconnects 2024-05-01 14:35:17.268 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from FC:A8:9B:F2:CA:CD

bdraco commented 3 months ago

Here is my logging: home-assistant_airthings_ble_2024-05-01T18-35-21.269Z.log

I do have a automation running that kicks ass against the config of the Airthings BLE integration until the battery of my Wave+ is available again (loop with 1 minute delay).

Same issue there 2024-05-01 20:33:52.782 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from 74:D2:85:05:8A:70

JesusSanchezLopez commented 3 months ago

Yep. Is it possible to add some retries?

[core-ssh config]$ tail -f home-assistant.log | grep expectedly 2024-05-01 15:11:04.085 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from FC:A8:9B:F2:CA:CD 2024-05-01 15:21:19.184 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from FC:A8:9B:F2:CA:CD 2024-05-01 15:31:36.040 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from FC:A8:9B:F2:CA:CD 2024-05-01 15:42:00.760 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from FC:A8:9B:F2:CA:CD

bdraco commented 3 months ago

https://github.com/Airthings/airthings-ble/pull/37

def1149 commented 3 months ago

Still happening 2024.5.0 but my integration restart hack is working

2024-05-01 17:45:01.508 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 4.724 seconds (success: True) 2024-05-01 17:50:02.680 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from F4:60:77:79:xx:xx 2024-05-01 17:50:09.521 DEBUG (MainThread) [homeassistant.components.airthings_ble] Unexpectedly disconnected from F4:60:77:79:xx:xx 2024-05-01 17:50:11.469 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from F4:60:77:79:xx:xx 2024-05-01 17:50:11.471 DEBUG (MainThread) [homeassistant.components.airthings_ble] Finished fetching airthings_ble data in 9.687 seconds (success: True) 2024-05-01 17:51:16.501 DEBUG (MainThread) [homeassistant.components.airthings_ble] Disconnected from F4:60:77:79:xx:xx

bdraco commented 3 months ago

The fixes in https://github.com/Airthings/airthings-ble/pull/37 and https://github.com/Airthings/airthings-ble/pull/36 are merged now and we should get a new airthings-ble release in a few days. We will get that in one of the upcoming patch release once testing is completed.

def1149 commented 3 months ago

Ahh OK .. it wasn't clear that the fix didn't make it to 5.0

bdraco commented 3 months ago

https://github.com/home-assistant/core/pull/116616 is targeted for 2024.5.1 to fix the two issues identified above.

While hopefully that will solve it for everyone, if you still have a problem after updating to 2024.5.1, please send a new round of logs with the debug logging in https://github.com/home-assistant/core/issues/113610#issuecomment-2088674166 enabled in a fresh issue as this one will close as soon as the linked PR merges

mwaterbu commented 3 months ago

The 2024.5.2 update seems to have addressed this for me, not a single dropout so far, thanks!

def1149 commented 3 months ago

I've had one dropout since 2024.5.2 but my dropout detection automation successfully restarted the integration

AllenBurgett commented 3 months ago

I continue to see frequent drops, but the logs are telling me to install more bluetooth proxies. I know this isn't really the appropriate forum, but does anyone know what the appropriate ratio of proxies to bluetooth devices is?

JesusSanchezLopez commented 3 months ago

No drop outs since installing 2024.5.2!!!

Only minor issue is that some readings are more than 5 minutes apart and create a gap on the chart:

Reading 1 @ 8:50:19 AM and Reading 2 @ 8:55:48 AM ---> 5 minutes and 29 seconds. I assume request takes ~5 seconds to time out then integrations waits a minute before retrying ---> 5th try will take more than 5 minutes.

This minor gap happens maybe once a day and is totally fine with me. At least logic ensures that I get the next reading as soon as possible.

5min

home-assistant / core