search

agittins / bermuda

Bermuda Bluetooth/BLE Triangulation / Trilateration for HomeAssistant
MIT License
452 stars 10 forks source link

Stuck in reload loop with 2024.6.0b6 after adding device [was: Bermuda does not generate unique IDs] #210

Closed andreasbrett closed 3 months ago

andreasbrett commented 3 months ago

Version of the custom_component

0.6.6

Configuration

no changes / default config

Describe the bug

When adding a device Bermuda hangs in a loop trying to add the area and distance sensors and the device tracker. HA 2024.6.0b6 (yes, beta) reports that the ID is not unique. Bermuda does not stop trying to add the sensors and the device tracker. HA can not be restarted from within HA anymore.

Debug log


2024-06-04 00:20:06.381 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_area
2024-06-04 00:20:06.382 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1_range already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_distance
2024-06-04 00:20:06.386 ERROR (MainThread) [homeassistant.components.device_tracker] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring device_tracker.bermuda_7c_2f_80_b9_6b_d1_bermuda_tracker
2024-06-04 00:20:06.420 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_area
2024-06-04 00:20:06.421 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1_range already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_distance
2024-06-04 00:20:06.427 ERROR (MainThread) [homeassistant.components.device_tracker] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring device_tracker.bermuda_7c_2f_80_b9_6b_d1_bermuda_tracker
2024-06-04 00:20:06.460 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_area
2024-06-04 00:20:06.461 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1_range already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_distance
2024-06-04 00:20:06.468 ERROR (MainThread) [homeassistant.components.device_tracker] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring device_tracker.bermuda_7c_2f_80_b9_6b_d1_bermuda_tracker
2024-06-04 00:20:06.502 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1 already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_area
2024-06-04 00:20:06.502 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID 7c:2f:80:b9:6b:d1_range already exists - ignoring sensor.bermuda_7c_2f_80_b9_6b_d1_distance
andreasbrett commented 3 months ago

with debug logging enabled

2024-06-04 00:40:07.152 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.153 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.153 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.153 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.153 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.154 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.154 DEBUG (MainThread) [custom_components.bermuda] Finished fetching bermuda data in 0.019 seconds (success: True)
2024-06-04 00:40:07.155 DEBUG (MainThread) [custom_components.bermuda] Registering device_new callback.
2024-06-04 00:40:07.160 DEBUG (MainThread) [custom_components.bermuda] Firing device_new for None (fc:8a:7a:7e:3a:a3)
2024-06-04 00:40:07.161 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.161 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.161 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.161 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.162 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.162 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.162 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.162 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.163 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.163 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.163 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.163 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.163 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.164 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.164 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.164 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.164 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.165 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.165 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.165 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.166 DEBUG (MainThread) [custom_components.bermuda] Sensor received new_device signal for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.166 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID fc:8a:7a:7e:3a:a3 already exists - ignoring sensor.bermuda_fc_8a_7a_7e_3a_a3_area
2024-06-04 00:40:07.167 ERROR (MainThread) [homeassistant.components.sensor] Platform bermuda does not generate unique IDs. ID fc:8a:7a:7e:3a:a3_range already exists - ignoring sensor.bermuda_fc_8a_7a_7e_3a_a3_distance
2024-06-04 00:40:07.173 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.174 ERROR (MainThread) [homeassistant.components.device_tracker] Platform bermuda does not generate unique IDs. ID fc:8a:7a:7e:3a:a3 already exists - ignoring device_tracker.bermuda_fc_8a_7a_7e_3a_a3_bermuda_tracker
2024-06-04 00:40:07.175 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.175 DEBUG (MainThread) [custom_components.bermuda] Finished fetching bermuda data in 0.019 seconds (success: True)
2024-06-04 00:40:07.177 DEBUG (MainThread) [custom_components.bermuda] Unloaded platforms.
2024-06-04 00:40:07.180 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 7a:7a:fa:96:7c:32
2024-06-04 00:40:07.184 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 7c:29:72:58:ab:86
2024-06-04 00:40:07.185 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 7c:2f:80:b9:6b:d1
2024-06-04 00:40:07.186 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 6c:e8:2a:dd:80:6b
2024-06-04 00:40:07.187 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 5a:7a:2a:ce:77:08
2024-06-04 00:40:07.187 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 54:6d:51:4a:ff:4c
2024-06-04 00:40:07.188 DEBUG (MainThread) [custom_components.bermuda] Identified IRK address on 50:ef:cb:1b:70:33
2024-06-04 00:40:07.190 DEBUG (MainThread) [custom_components.bermuda] Device None was in 'None', now in 'Flur'
2024-06-04 00:40:07.191 DEBUG (MainThread) [custom_components.bermuda] Loaded entry 89eaad35f4ebaa1db2eb575eaee8dbf1
2024-06-04 00:40:07.192 DEBUG (MainThread) [custom_components.bermuda] Replacing config data scanners was {'00:1a:7d:da:71:13': {'name': 'hci0 (00:1A:7D:DA:71:13)', 'local_name': None, 'prefname': None, 'address': '00:1a:7d:da:71:13', 'options': {'attenuation': 3, 'devtracker_nothome_timeout': 30, 'max_area_radius': 20, 'max_velocity': 3, 'ref_power': -55.0, 'smoothing_samples': 20, 'update_interval': 10}, 'unique_id': '00:1a:7d:da:71:13', 'address_type': 'bd_addr_type_unknown', 'area_id': None, 'area_name': None, 'area_distance': None, 'area_rssi': None, 'area_scanner': None, 'zone': 'not_home', 'manufacturer': None, 'connectable': False, 'is_scanner': True, 'beacon_type': [], 'beacon_sources': [], 'beacon_unique_id': None, 'beacon_uuid': None, 'beacon_major': None, 'beacon_minor': None, 'beacon_power': None, 'entry_id': '6306020b858efa2f17760bf563b0f817', 'create_sensor': False, 'create_sensor_done': False, 'create_tracker_done': False, 'last_seen': 0, 'scanners': {}}, '30:ae:a4:e9:30:64': {'name': 'Bluetooth Proxy (Flur)', 'local_name': None, 'prefname': None, 'address': '30:ae:a4:e9:30:64', 'options': {'attenuation': 3, 'devtracker_nothome_timeout': 30, 'max_area_radius': 20, 'max_velocity': 3, 'ref_power': -55.0, 'smoothing_samples': 20, 'update_interval': 10}, 'unique_id': '30:ae:a4:e9:30:64', 'address_type': 'bd_addr_type_unknown', 'area_id': '6ad1abc7e378690562a879dbe9e3db45', 'area_name': 'Flur', 'area_distance': None, 'area_rssi': None, 'area_scanner': None, 'zone': 'not_home', 'manufacturer': None, 'connectable': False, 'is_scanner': True, 'beacon_type': [], 'beacon_sources': [], 'beacon_unique_id': None, 'beacon_uuid': None, 'beacon_major': None, 'beacon_minor': None, 'beacon_power': None, 'entry_id': '5ad0c1016cb27e8ac608c4bbb4606c15', 'create_sensor': False, 'create_sensor_done': False, 'create_tracker_done': False, 'last_seen': 0, 'scanners': {}}} now {'00:1a:7d:da:71:13': {'name': 'hci0 (00:1A:7D:DA:71:13)', 'local_name': None, 'prefname': None, 'address': '00:1a:7d:da:71:13', 'options': {'attenuation': 3, 'devtracker_nothome_timeout': 30, 'max_area_radius': 20, 'max_velocity': 3, 'ref_power': -55.0, 'smoothing_samples': 20, 'update_interval': 10}, 'unique_id': '00:1a:7d:da:71:13', 'address_type': 'bd_addr_type_unknown', 'area_id': None, 'area_name': None, 'area_distance': None, 'area_rssi': None, 'area_scanner': None, 'zone': 'not_home', 'manufacturer': None, 'connectable': False, 'is_scanner': True, 'beacon_type': [], 'beacon_sources': [], 'beacon_unique_id': None, 'beacon_uuid': None, 'beacon_major': None, 'beacon_minor': None, 'beacon_power': None, 'entry_id': '6306020b858efa2f17760bf563b0f817', 'create_sensor': False, 'create_sensor_done': False, 'create_tracker_done': False, 'last_seen': 0, 'scanners': {}}, '30:ae:a4:e9:30:64': {'name': 'Bluetooth Proxy (Flur)', 'local_name': None, 'prefname': None, 'address': '30:ae:a4:e9:30:64', 'options': {'attenuation': 3, 'devtracker_nothome_timeout': 30, 'max_area_radius': 20, 'max_velocity': 3, 'ref_power': -55.0, 'smoothing_samples': 20, 'update_interval': 10}, 'unique_id': '30:ae:a4:e9:30:64', 'address_type': 'bd_addr_type_unknown', 'area_id': '6ad1abc7e378690562a879dbe9e3db45', 'area_name': 'Flur', 'area_distance': None, 'area_rssi': None, 'area_scanner': None, 'zone': 'not_home', 'manufacturer': None, 'connectable': False, 'is_scanner': True, 'beacon_type': [], 'beacon_sources': [], 'beacon_unique_id': None, 'beacon_uuid': None, 'beacon_major': None, 'beacon_minor': None, 'beacon_power': None, 'entry_id': '5ad0c1016cb27e8ac608c4bbb4606c15', 'create_sensor': False, 'create_sensor_done': False, 'create_tracker_done': False, 'last_seen': 0, 'scanners': {}}}
2024-06-04 00:40:07.195 DEBUG (MainThread) [custom_components.bermuda] Refreshing Private BLE Device list
2024-06-04 00:40:07.196 DEBUG (MainThread) [custom_components.bermuda] Firing device_new for None (fc:8a:7a:7e:3a:a3)
2024-06-04 00:40:07.196 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.197 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.197 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.197 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.197 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.197 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.198 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.198 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.198 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.198 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.199 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.199 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.199 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.199 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.199 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.200 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.203 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.204 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.205 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.205 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.206 DEBUG (MainThread) [custom_components.bermuda] Ignoring duplicate creation request for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.206 DEBUG (MainThread) [custom_components.bermuda] Sensor confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.206 DEBUG (MainThread) [custom_components.bermuda] Ignoring create request for existing dev_tracker fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.206 DEBUG (MainThread) [custom_components.bermuda] Device_tracker confirmed created for fc:8a:7a:7e:3a:a3
2024-06-04 00:40:07.207 DEBUG (MainThread) [custom_components.bermuda] Finished fetching bermuda data in 0.028 seconds (success: True)
agittins commented 3 months ago

Yikes!

Thanks for the excellent bug report. I figure this might be due to some upcoming change in 2024.6, assuming you haven't seen it in earlier versions.

I'll pull down the beta and see if I can reproduce this locally. Bermuda does often cycle through multiple attempts to create/register sensors, but it doesn't usually cause an issue, and doesn't usually trigger the "unique id" message.

You mentioned you couldn't restart HA from within HA, did you get the impression that Bermuda was hammering the system and preventing it from processing your shutdown request or was HA completely unresponsive and you couldn't navigate to the restart menu? (no stress if you don't have time to dig at it right now, these are just initial questions off the top of my head before I've had a crack at reproducing it).

agittins commented 3 months ago

Ahh. Problem replicated immediately once I'd pulled the beta and added a device. I should have a fix later today.

andreasbrett commented 3 months ago

Regarding your question: Bermuda was hammering the system and the menus for restarting did not load in time (I waited quite a bit). Unfortunately I can not help more since I have not been using Bermuda on a previous HA version and encountered this by pure "luck".

agittins commented 3 months ago

No worries, managed to track down the issue (it was a race condition during the reload, so that I think a previous instance was still in memory when HA tried to load its replacement) - due to a bug in my implementation though, not a fault of HA (it just never showed up before).

Thanks again for the solid bug report, always makes things a lot easier to track down!

The fix is in main now, and I'll do a proper release soon.