home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.4k stars 30.3k forks source link

Bluetooth integration causing duplicate entries for H5100 sensor #76510

Closed SignalGroup closed 2 years ago

SignalGroup commented 2 years ago

The problem

I am on HAOS 8.2 with a XDO BT802 adapter. After I updated to the 8.2 version with the new Bluetooth integration I started seeing duplicate entries for my H5100 sensors. Some of them up to 5 times. I am not sure where to start.

What version of Home Assistant Core has the issue?

8.2

What was the last working version of Home Assistant Core?

New feature

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Govee Bluetooth

Link to integration documentation on our website

https://www.home-assistant.io/integrations/govee_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

probot-home-assistant[bot] commented 2 years ago

govee_ble documentation govee_ble source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

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

rsiv commented 2 years ago

I have a similar issue with Govee H5075. I see duplicates being added over and over again. There are 7 actual thermometers but over 20 are now detected. For example, the first one (B7CC) repeats 5 times. If I configure one of them, after a while it is discovered again.

I still have the custom Passive BLE Monitor integration enabled and it works fine. I remember I had a somewhat similar issue with it and had to set discovery:false to stop the duplicates.

I'm ready to help debugging it if you point me in the right direction. HA 2022.8.2 running in a container on an Intel box.

Screen Shot 2022-08-07 at 2 25 32 PM
bdraco commented 2 years ago

Please send debug logs for homeassistant.components.bluetooth and homeassistant.components.govee_ble

Thanks

bdraco commented 2 years ago

Also if you ignored them, a copy of the ignored entries in .storage/core.config_entries would be helpful as well

rsiv commented 2 years ago

Bluetooth/govee log and relevant part of config_entries attached. I see it's detecting macs of unrelated BT devices, please let me know if I can assist debugging this further.

I have 7 actual devices, but 22 govee_ble integrations right now - 10 configured and 12 ignored. During the two hours that I was collecting this log, new integrations were discovered for H5075_D931 and H5075_6E47.

Screen Shot 2022-08-09 at 9 03 58 PM

core.config_entries.txt ha-log-bluetooth-govee-2022-08-09.log

bdraco commented 2 years ago

That's a very interesting bug

Here is the advertisment [36mhomeassistant | 2022-08-09 19:31:58.649 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: DA:BA:A1:8A:9A:4C with advertisement_data: AdvertisementData(local_name='N009Q', manufacturer_data={76: b'\x10\x05\x1b\x1ci5\x14', 60552: b'\x00\x04\xa6d\x00', 301: b'\x02\x00\x01\x100\x861\r\x14\xe3@\x14\xa5\x8d\xdf\x9b\xcb\xbc\xa6>\r\xf0Q\xf1\x9aA', 820: b's\x85\xa4\xaeI\x00'}, service_data={'0000feaf-0000-1000-8000-00805f9b34fb': b'\x10\x01\x00\x02Z#\t\x00\xc30\xce\x00\x00f\x16d\x00', '0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000feaf-0000-1000-8000-00805f9b34fb', '0000fe9f-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb', 'b42e1c08-ade7-11e4-89d3-123b93f75cba']) matched domains: set()`

govee_ble isn't in the matched domain set but it had to have generated a discovery or you wouldn't have been able to ignore it.

      {
        "entry_id": "76fb806770102f07027e4070f738fb2b",
        "version": 1,
        "domain": "govee_ble",
        "title": "H5075_658F",
        "data": {},
        "options": {},
        "pref_disable_new_entities": false,
        "pref_disable_polling": false,
        "source": "ignore",
        "unique_id": "DA:BA:A1:8A:9A:4C",
        "disabled_by": null
      }
bdraco commented 2 years ago

Can you try unignoring them all, make sure you have debug logs for homeassistant.components.bluetooth enabled, then restart

Check the log for ones that aren't govee but have govee_ble in the matched_domains

rsiv commented 2 years ago

I don't even know what that device is, DA:BA:A1 prefix doesn't seem to even be assigned to any OEM. Should I also delete the 10 already configured govee integrations?

rsiv commented 2 years ago

I deleted all existing govee devices and unignored all previously ignored ones. On restart it correctly detected the 7 actual devices (all with A4:C1:38 prefix):

homeassistant    | 2022-08-09 21:50:50.883 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:F1:71:5F with advertisement_data: AdvertisementData(local_name='GVH5075_715F', manufacturer_data={60552: b'\x00\x03\xb7{\\\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:50:51.677 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:B3:B7:CC with advertisement_data: AdvertisementData(local_name='GVH5075_B7CC', manufacturer_data={60552: b'\x00\x04z$J\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\x0c', 820: b's\x85\xa4\xaeI\x00'}, service_data={'0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb', '0000fe9f-0000-1000-8000-00805f9b34fb', 'b42e1c08-ade7-11e4-89d3-123b93f75cba']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:50:51.679 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:31:34:A5 with advertisement_data: AdvertisementData(local_name='GVH5075_34A5', manufacturer_data={60552: b'\x00\x04?\xd2L\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\x0c'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:50:54.956 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:B4:D9:31 with advertisement_data: AdvertisementData(local_name='GVH5075_D931', manufacturer_data={60552: b'\x00\x82c\xba-\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb', '0000feaf-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:50:55.636 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:40:65:8F with advertisement_data: AdvertisementData(local_name='GVH5075_658F', manufacturer_data={60552: b'\x00\x04\x16\\d\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:51:13.939 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:D5:6E:47 with advertisement_data: AdvertisementData(local_name='GVH5075_6E47', manufacturer_data={60552: b'\x00\x04\x96pG\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 21:51:15.048 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:20:B6:41 with advertisement_data: AdvertisementData(local_name='GVH5075_B641', manufacturer_data={60552: b'\x00\x01\tEI\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}

After ~25 minutes it detected these two:

homeassistant    | 2022-08-09 22:13:25.389 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:40:65:8F with advertisement_data: AdvertisementData(local_name='GVH5075_658F', manufacturer_data={60552: b'\x00\x04\x0e\x94d\x00', 76: b'\x02\x15INTELLI_ROCKS_HWPu\xf2\xff\xc2'}, service_data={'0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb', '0000fe9f-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-09 22:16:14.271 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: 61:C3:90:2C:2D:42 with advertisement_data: AdvertisementData(local_name='GVH5075_715F', manufacturer_data={76: b'\x0c\x0e\x00N\xc4\xb65\xabb\xf8\xb1\xa6\x8d\n\xb0$\x10\x05B\x1c7\xcc\x7f', 60552: b'\x00\x03\xa3\xcb\\\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}

The first has the correct mac for H5075_658F but no duplicate was created. The second now appears as duplicate for H5075_715F.

bdraco commented 2 years ago

Wow it seems like a bug in the underlying Bluetooth stack as we are actually getting govee data for a random Mac

Can you try enabling debug logs for 'bleak' as well?

We need to see how the data is being fed into the Bluetooth integration

rsiv commented 2 years ago

Here are the relevant logs for the 3 duplicate devices detected so far Let me know if you want the complete log

Device 1 - mac has govee prefix A4:C1:38 but I don't have any actual devices with this mac

homeassistant    | 2022-08-09 23:12:21.360 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_A4_C1_38_87_94_83): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -78)>, 'Name': <dbus_next.signature.Variant ('s', GVH5075_658F)>, 'Alias': <dbus_next.signature.Variant ('s', GVH5075_658F)>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x06\x12\x1e\xa1\xbc\xfeR')>, 60552: <dbus_next.signature.Variant ('ay', b'\x00\x03\xfe\xfdd\x00')>, 1151: <dbus_next.signature.Variant ('ay', b'\x05\x00')>, 820: <dbus_next.signature.Variant ('ay', b's\x85\xa4\xaeI\x00')>, 301: <dbus_next.signature.Variant ('ay', b'\x02\x00\x01\x100\x861\r\x14\xe3@\x14\xa5\x8d\xdf\x9b\xcb\xbc\xa6>&-Z\x82\xd2:')>, 4780: <dbus_next.signature.Variant ('ay', b'/\xd5v\x0c\x00\x00')>})>}, []]
homeassistant    | 2022-08-09 23:12:21.360 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:87:94:83 with advertisement_data: AdvertisementData(local_name='GVH5075_658F', manufacturer_data={76: b'\x10\x06\x12\x1e\xa1\xbc\xfeR', 60552: b'\x00\x03\xfe\xfdd\x00', 1151: b'\x05\x00', 820: b's\x85\xa4\xaeI\x00', 301: b'\x02\x00\x01\x100\x861\r\x14\xe3@\x14\xa5\x8d\xdf\x9b\xcb\xbc\xa6>&-Z\x82\xd2:', 4780: b'/\xd5v\x0c\x00\x00'}, service_data={'0000252a-0000-1000-8000-00805f9b34fb': b'\xe0c\xda_\x08\xf1', '0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb', '0000ffff-0000-1000-8000-00805f9b34fb', '0000feaf-0000-1000-8000-00805f9b34fb', 'd83b80e3-e81f-4f66-879b-779be5f6a693', '0000fe9f-0000-1000-8000-00805f9b34fb', '0000fe32-0000-1000-8000-00805f9b34fb', 'b42e1c08-ade7-11e4-89d3-123b93f75cba', 'daf52801-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}

Device 2:

homeassistant    | 2022-08-09 23:44:59.046 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_C6_5B_A3_6A_11_1B): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -76)>, 'Name': <dbus_next.signature.Variant ('s', GVH5075_715F)>, 'Alias': <dbus_next.signature.Variant ('s', GVH5075_715F)>, 'UUIDs': <dbus_next.signature.Variant ('as', ['0000feaf-0000-1000-8000-00805f9b34fb', '0000ffff-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb'])>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {60552: <dbus_next.signature.Variant ('ay', b'\x00\x03\xab\xa2\\\x00')>})>}, []]
homeassistant    | 2022-08-09 23:44:59.046 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: C6:5B:A3:6A:11:1B with advertisement_data: AdvertisementData(local_name='GVH5075_715F', manufacturer_data={60552: b'\x00\x03\xab\xa2\\\x00'}, service_data={'0000feaf-0000-1000-8000-00805f9b34fb': b'\x10\x01\x00\x02\x00\xe1\x08\x00L\xf24d\x00f\x16d\x02'}, service_uuids=['0000feaf-0000-1000-8000-00805f9b34fb', '0000ffff-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}

Device 3:

homeassistant    | 2022-08-09 23:47:06.362 DEBUG (MainThread) [bleak.backends.bluezdbus.manager] received D-Bus signal: org.freedesktop.DBus.Properties.PropertiesChanged (/org/bluez/hci0/dev_73_7B_AA_79_68_24): ['org.bluez.Device1', {'RSSI': <dbus_next.signature.Variant ('n', -74)>, 'Name': <dbus_next.signature.Variant ('s', GVH5075_6E47)>, 'Alias': <dbus_next.signature.Variant ('s', GVH5075_6E47)>, 'UUIDs': <dbus_next.signature.Variant ('as', ['0000ec88-0000-1000-8000-00805f9b34fb'])>, 'ManufacturerData': <dbus_next.signature.Variant ('a{qv}', {76: <dbus_next.signature.Variant ('ay', b'\x10\x05\x14\x1c\x8f\x07\xfc')>, 60552: <dbus_next.signature.Variant ('ay', b'\x00\x04w*G\x00')>})>}, []]
homeassistant    | 2022-08-09 23:47:06.362 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: 73:7B:AA:79:68:24 with advertisement_data: AdvertisementData(local_name='GVH5075_6E47', manufacturer_data={76: b'\x10\x05\x14\x1c\x8f\x07\xfc', 60552: b'\x00\x04w*G\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
bdraco commented 2 years ago

So the data is actually coming in bluez that way

Is a chance you have something that is repeating your sensors?

Do you have a long range bluetooth adapter that could be picking up the neighbors?

rsiv commented 2 years ago

No long range adapter, and neighbors are not close enough I now suspect this might be happening because I still have custom-components/ble_monitor enabled:

During the transition, BLE monitor will still be available, but it is possible that the core HA Bluetooth integrations will not work niceley parallel to BLE monitor. If it is not working together, try to enable active scan in the BLE Monitor

I disabled ble_monitor for now, will update if I still see duplicates

rsiv commented 2 years ago

Still happening with custom-components/ble_monitor disabled and HA 2022.8.3:

homeassistant    | 2022-08-10 13:36:30.428 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: A4:C1:38:87:94:83 with advertisement_data: AdvertisementData(local_name='GVH5075_B7CC', manufacturer_data={76: b'\x10\x05G\x1c\x03\xde\xfb', 4780: b'/\xd5v\x0c\x00\x00', 60552: b'\x00\x05XMI\x00'}, service_data={'0000252a-0000-1000-8000-00805f9b34fb': b'\xe0c\xda_\x08\xf1', '0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000feaf-0000-1000-8000-00805f9b34fb', 'd83b80e3-e81f-4f66-879b-779be5f6a693', '0000fe9f-0000-1000-8000-00805f9b34fb', 'daf52801-0000-1000-8000-00805f9b34fb', '0000ffff-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-10 13:44:42.890 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: D2:27:A0:39:F7:33 with advertisement_data: AdvertisementData(local_name='GVH5075_B7CC', manufacturer_data={60552: b'\x00\x05L\x9bJ\x00'}, service_data={'0000feaf-0000-1000-8000-00805f9b34fb': b'\x10\x01\x00\x02Z#\t\x00\xc30\xce\x00\x00f\x16d\x00'}, service_uuids=['0000feaf-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-10 13:53:59.723 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: C4:2F:C4:93:35:B2 with advertisement_data: AdvertisementData(local_name='GVH5075_715F', manufacturer_data={76: b'\x12\x02\x00\x03', 60552: b'\x00\x03\x98\x18\\\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-10 14:29:03.726 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: 4A:0A:0A:F2:18:6E with advertisement_data: AdvertisementData(local_name='GVH5075_B641', manufacturer_data={224: b'\x01n\xcaikc', 60552: b'\x00\x01\x18pI\x00'}, service_data={'0000fe9f-0000-1000-8000-00805f9b34fb': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'}, service_uuids=['0000fe9f-0000-1000-8000-00805f9b34fb', '0000feaf-0000-1000-8000-00805f9b34fb', '0000ffff-0000-1000-8000-00805f9b34fb', '0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
homeassistant    | 2022-08-10 14:35:17.376 DEBUG (MainThread) [homeassistant.components.bluetooth] Device detected: 43:06:F3:35:A9:DC with advertisement_data: AdvertisementData(local_name='GVH5075_B7CC', manufacturer_data={76: b"\x0c\x0e\x00\xa3\xed\xa4@0\x14\x08\xcd'\x86\x14}\x94\x10\x05N\x1c\x82\x8d=", 60552: b'\x00\x05=\x00I\x00'}, service_uuids=['0000ec88-0000-1000-8000-00805f9b34fb']) matched domains: {'govee_ble'}
bdraco commented 2 years ago

I don't think there is anything we can do about this at the integration level, as the data is coming from the operating system stack.

It could be a bug in the bluetooth driver for the device in the kernel. I'd try updating to HAOS 8.4 to see if it goes away.

rsiv commented 2 years ago

Yep, I understand. Is there a way to disable automatic discovery for now? Thanks for your help and great job with the integration!

bdraco commented 2 years ago

Yep, I understand. Is there a way to disable automatic discovery for now?

Not yet. Hopefully in the future though

SignalGroup commented 2 years ago

I'm on 8.4 and it is still occurring. Loving the integration. Would it help identify if it a driver bug if I use a different bluetooth dongle or is it lower then that in the stack?

SignalGroup commented 2 years ago

Where could I pursue a solution to this issue next? You mentioned the OS, Alpine Linus?

rsiv commented 2 years ago

Probably somewhere in BlueZ stack? By the way, what adapter do you have? Mine is Intel(R) Dual Band Wireless AC 7260 (M.2 card with wifi+bluetooth)

SignalGroup commented 2 years ago

I have an XDO classic long range.

SignalGroup commented 2 years ago

ng we can do about this at the integration level, as the data is coming from the operating system stack.

It could be a bug in the bluetooth driver

Do you mean HAOS or the Alpine Linux underneath?

SignalGroup commented 2 years ago

More information here: https://github.com/home-assistant/core/issues/76544

SignalGroup commented 2 years ago

I was able to work around the issue by disabling one of my Bluetooth adapters. Deleting all relevant devices and restarting. Been good for 2 days now.