Closed agrant-dxc closed 2 years ago
unifi documentation unifi source (message by IssueLinks)
Hey there @kane610, mind taking a look at this issue as it has been labeled with an integration (unifi
) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)
Not sure if related but I have the same behavior in my dev environment on the entity filter view. I get the following error when I view this in debug mode from vscode:
457010178854,"vwireEnabled":true,"uplink_table":[],"num_sta":11,"user-num_sta":11,"user-wlan-num_sta":11,"guest-num_sta":0,"guest-wlan-num_sta":0,"x_has_ssh_hostkey":true}]} 2022-01-26 20:08:43 ERROR (MainThread) [frontend.js.latest.202201240] http://localhost:8123/frontend_latest/2d7a3299.js:23:31 Uncaught TypeError: Cannot read properties of undefined (reading 'state')
Tested core-2022.2.0b0 and same behavior.
Thanks for using the beta and reporting issues! Unfortunately there is nothing to go on in this issue so far.
Running it at home it works as expected to me, maybe it is related to the strip since I don't have one of them myself. Or maybe a combination with another integration causes this issue? Are you running any custom components?
Thanks for checking.
Since my last report I have updated the UDR OS with today's latest update (v2.3.12) and yesterday latest UNA (v7.0.20). Since then, core-2022.2.0b0 has been working and I can see all device_tracker entities.
If it occurs again, do you recommend any additional troubleshooting/logs to be provided?
Aaaand she stopped working, but only partially this time. I removed the debug entries from configuration.yaml and reloaded core. I can browse entities, but my phone which is definitely on wifi, is "not_home" and reloading the Unifi integration says HA needs to restart (every time, even after a reload of core). This reboot prompt has been 1:1 with it not working. When it works, I can reload the Unifi integration without it prompting to restart HA. Thoughts welcome.
As for custom components, they are: Alarmo, Scheduler component and Wyze.
How long is it running prior to behaving like this?
How long is it running prior to behaving like this?
Yesterdays dev it occurred immediately upon HA core restart.
Interestingly enough - reverting to dev25 I couldn't browse the Unifi Network entities filter (and didn't notice) but the device_trackers worked. Unclear if this timeline helps.
Today they worked for about 5 hours on 2022.2.0b0 (after a UnifiOS reload) until I reloaded HA core.
Have since tried systemctl restart unifi
on the UDR to no success. And reloaded HA core many times.
If it helps - I have a LOT of disabled device_trackers since I only care about phones, not all the IOT. Have had problems in the past w/ Sonos when disabling entities.
What I have noticed during this endeavor is that the phones can get "disabled by integration" for some reason.
Just reloaded Unifi OS and HA core together - that seems to do the trick.
Prior to dev25 I could reload HA core or the Unifi integration all day long no issue. So perhaps "fragile" is the term that best describes it atm.
~~I keep reverting to 2022.2.0.dev20220125 in order to have reliable device_tracking.
while on 2022.2.0b1 my phone no longer showed as home, even though it was in the actual Unifi app. No HA reboot or phone disconnect/reconnect would change that.~~
[edit] - going to backtrack this statement. Because while reverting worked for a bit, and solves the reload issue. Lost the phones device tracker #again.
The Change was merged on the 24th so it should be a part of the 2022.2.0.dev20220125, though I couldn't find any build logs to verify this.
Is it only the UniFi integration you experience these issues with?
reloading the Unifi integration says HA needs to restart
Never heard of this before, can you share a screenshot?
If it occurs again, do you recommend any additional troubleshooting/logs to be provided?
It would be to share full debug logs for the integration and something to look for
Is it only the UniFi integration you experience these issues with?
Affirmative, just Unifi
Never heard of this before, can you share a screenshot?
Here ya go, https://imgur.com/a/HTi9acd
Will turn debug back on and wait for phone to drop.
I ran 2022.2.0b2 overnight. 2 phones connected at bedtime, 0 at wake up (<00:30 actually).
Would you mind trying to disable all other integrations and see if that has any effect?
Would you mind trying to disable all other integrations and see if that has any effect?
Effect on the Unifi integration reload? (aka, a five minute test?)
Or effect on dropping trackers after a number of hours even though they are still on wifi?
The dropping of trackers, the reload thing I'll try tonight as well.
Yeah we'd have to run an, "all integrations off" test overnight for sure. Motion lighting here has become a staple.
Until then, I'll post a debug log when things drop.
Going out on a limb here. Is it possible to test a custom version without the recent powersave changes?
I went to enabled a device_tracker that is normally disabled. As soon as I enabled it, all other device_trackers went unavailable. This happened at 8:15AM. Logs attached.
[edit] - thinking about this further. Enabling an entity reloads the integration?
A clue? My phone just went to "away", is it roaming triggering the device_tracker to faulter? The other two devices being tracked during this endeavor have not physically moved since the last HA restart and are still "home"
2022-01-28 10:01:53 DEBUG (MainThread) [homeassistant.components.unifi.unifi_entity_base] Updating client entity device_tracker.pixel_4a (60:b7:6e:2d:1e:16)
2022-01-28 10:01:53 DEBUG (MainThread) [aiounifi.websocket] {"meta":{"rc":"ok","message":"events"},"data":[{"user":"60:b7:6e:2d:1e:16","ap_from":"f4:92:bf:a1:91:18","ap_to":"78:45:58:4b:44:6c","radio_from":"na","radio_to":"na","radio":"na","channel_from":"60","channel_to":"100","channel":"100","ssid":"replaced_SSID","key":"EVT_WU_Roam","subsystem":"wlan","is_negative":false,"site_id":"5b21393fb150b6c08a49dca0","time":1643382084230,"datetime":"2022-01-28T15:01:24Z","msg":"User[60:b7:6e:2d:1e:16] roams from AP[f4:92:bf:a1:91:18] to AP[78:45:58:4b:44:6c] from \"channel 60(na)\" to \"channel 100(na)\" on \"replaced_SSID\"","_id":"61f4055e5f820913b5939690"}]}
2022-01-28 10:02:55 DEBUG (MainThread) [aiounifi.websocket] {"meta":{"rc":"ok","message":"device:update","mac":"24:5a:4c:9f:e1:75"},"data":[{"temperatures":[{"name":"Local","type":"board","value":44.0},{"name":"CPU","type":"cpu","value":43.625}]}]}
2022-01-28 10:02:55 DEBUG (MainThread) [aiounifi.controller] Unsupported message type {'data': [{'_id': '61c0287e6b7d321fb18bedc7', 'adopt_state': 0, 'adoptable_when_upgraded': False, 'adopted': True, 'bytes-r': 0, 'connection_network_name': 'LAN', 'countrycode_table': [840, 124, 630], 'default': False, 'device_type': 'MANAGED', 'disabled': False, 'displayable_version': '2.3.12', 'download_speed_bytes_per_second': 43, 'ethernet_overrides': [{'ifname': 'eth4', 'networkgroup': 'WAN'}, {'ifname': 'eth0', 'networkgroup': 'LAN'}, {'ifname': 'eth1', 'networkgroup': 'LAN'}, {'ifname': 'eth2', 'networkgroup': 'LAN'}, {'ifname': 'eth3', 'networkgroup': 'LAN'}], 'fw_caps': 1676582447, 'ip': 'replace_IP', 'isolated': False, 'last_seen': 1643382175, 'license_state': 'registered', 'locating': False, 'lte_connected': False, 'mac': '24:5a:4c:9f:e1:75', 'model': 'UDR', 'model_in_eol': False, 'model_in_lts': False, 'model_incompatible': False, 'name': 'UDR', 'num_sta': 6, 'port_table': [{'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth0', 'is_uplink': False, 'media': 'GE', 'name': 'Port 1', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 1, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': True, 'ifname': 'eth1', 'ip': '192.168.2.254', 'is_uplink': False, 'media': 'GE', 'name': 'Port 2', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 2, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 72079538478, 'rx_bytes-r': 894480, 'rx_dropped': 1, 'rx_errors': 0, 'rx_packets': 54639979, 'satisfaction': 0, 'speed': 1000, 'speed_caps': 1048623, 'tx_bytes': 2492900794, 'tx_bytes-r': 31996, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 32767437, 'up': True}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth2', 'is_uplink': False, 'media': 'GE', 'name': 'Port 3', 'op_mode': 'switch', 'poe_caps': 1, 'poe_enable': False, 'port_idx': 3, 'port_poe': True, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth3', 'is_uplink': False, 'media': 'GE', 'name': 'Port 4', 'op_mode': 'switch', 'poe_caps': 1, 'poe_enable': False, 'port_idx': 4, 'port_poe': True, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': True, 'ifname': 'eth4', 'ip': 'replace_IP', 'is_uplink': True, 'media': 'GE', 'name': 'Port 5', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 5, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 16226465, 'rx_bytes-r': 43, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 205201, 'satisfaction': 0, 'speed': 1000, 'speed_caps': 1048623, 'tx_bytes': 5606796, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 82525, 'up': True}], 'product_line': 'NETWORK', 'radio_table': [{'antenna_gain': 0, 'builtin_ant_gain': 3, 'builtin_antenna': True, 'channel': 1, 'current_antenna_gain': 0, 'hard_noise_floor_enabled': False, 'has_dfs': False, 'has_fccdfs': False, 'has_ht160': False, 'has_restricted_channels': False, 'ht': 20, 'is_11ac': False, 'is_11ax': False, 'loadbalance_enabled': False, 'max_txpower': 23, 'min_rssi_enabled': False, 'min_txpower': 6, 'name': 'ra0', 'nss': 4, 'radio': 'ng', 'radio_caps': 67256324, 'radio_caps2': 1, 'sens_level_enabled': False, 'tx_power_mode': 'low', 'vwire_enabled': True}, {'antenna_gain': 0, 'builtin_ant_gain': 4, 'builtin_antenna': True, 'channel': 36, 'current_antenna_gain': 0, 'hard_noise_floor_enabled': False, 'has_dfs': True, 'has_fccdfs': True, 'has_ht160': True, 'has_restricted_channels': False, 'ht': 80, 'is_11ac': True, 'is_11ax': True, 'loadbalance_enabled': False, 'max_txpower': 26, 'min_rssi_enabled': False, 'min_txpower': 6, 'name': 'rai0', 'nss': 4, 'radio': 'na', 'radio_caps': 251805700, 'radio_caps2': 15, 'sens_level_enabled': False, 'tx_power_mode': 'low', 'vwire_enabled': False}], 'radio_table_stats': [{'channel': 1, 'cu_self_rx': 0, 'cu_self_tx': 0, 'cu_total': 12, 'extchannel': 0, 'gain': 3, 'guest-num_sta': 0, 'name': 'ra0', 'num_sta': 0, 'radio': 'ng', 'satisfaction': -1, 'state': 'RUN', 'tx_packets': 0, 'tx_power': 6, 'tx_retries': 0, 'user-num_sta': 0}, {'channel': 36, 'cu_self_rx': 0, 'cu_self_tx': 0, 'cu_total': 2, 'extchannel': 1, 'gain': 4, 'guest-num_sta': 0, 'name': 'rai0', 'num_sta': 0, 'radio': 'na', 'satisfaction': -1, 'state': 'RUN', 'tx_packets': 0, 'tx_power': 6, 'tx_retries': 0, 'user-num_sta': 0}], 'restarting': False, 'rx_bytes': 5606796, 'rx_bytes-d': 0, 'satisfaction': -1, 'spectrum_scanning': False, 'state': 1, 'sys_stats': {'loadavg_1': 1.3, 'loadavg_15': 0.97, 'loadavg_5': 1.05, 'mem_buffer': 81281024, 'mem_total': 2030968832, 'mem_used': 1717915648}, 'system-stats': {'cpu': 31.7, 'mem': 84.6, 'uptime': 61442}, 'tx_bytes': 16226465, 'tx_bytes-d': 0, 'type': 'udm', 'unsupported': False, 'unsupported_reason': 0, 'upgradable': False, 'upgrade_state': 0, 'uplink': {'name': 'eth4', 'port_idx': 5, 'speed': 1000, 'type': 'wire'}, 'uplink_table': [], 'upload_speed_bytes_per_second': 0, 'uptime': 61442, 'vap_table': [], 'version': '2.3.12.6542', 'wlan_overrides': []}], 'meta': {'message': 'unifi-device:sync', 'product_line': 'NETWORK', 'rc': 'ok'}}
2022-01-28 10:02:55 DEBUG (MainThread) [aiounifi.websocket] {"data":[{"_id":"61c0287e6b7d321fb18bedc7","adopt_state":0,"adoptable_when_upgraded":false,"adopted":true,"bytes-r":0,"connection_network_name":"LAN","countrycode_table":[840,124,630],"default":false,"device_type":"MANAGED","disabled":false,"displayable_version":"2.3.12","download_speed_bytes_per_second":43,"ethernet_overrides":[{"ifname":"eth4","networkgroup":"WAN"},{"ifname":"eth0","networkgroup":"LAN"},{"ifname":"eth1","networkgroup":"LAN"},{"ifname":"eth2","networkgroup":"LAN"},{"ifname":"eth3","networkgroup":"LAN"}],"fw_caps":1676582447,"ip":"replace_IP","isolated":false,"last_seen":1643382175,"license_state":"registered","locating":false,"lte_connected":false,"mac":"24:5a:4c:9f:e1:75","model":"UDR","model_in_eol":false,"model_in_lts":false,"model_incompatible":false,"name":"UDR","num_sta":6,"port_table":[{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth0","is_uplink":false,"media":"GE","name":"Port 1","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":1,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":true,"ifname":"eth1","ip":"192.168.2.254","is_uplink":false,"media":"GE","name":"Port 2","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":2,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":72079538478,"rx_bytes-r":894480,"rx_dropped":1,"rx_errors":0,"rx_packets":54639979,"satisfaction":0,"speed":1000,"speed_caps":1048623,"tx_bytes":2492900794,"tx_bytes-r":31996,"tx_dropped":0,"tx_errors":0,"tx_packets":32767437,"up":true},{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth2","is_uplink":false,"media":"GE","name":"Port 3","op_mode":"switch","poe_caps":1,"poe_enable":false,"port_idx":3,"port_poe":true,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth3","is_uplink":false,"media":"GE","name":"Port 4","op_mode":"switch","poe_caps":1,"poe_enable":false,"port_idx":4,"port_poe":true,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":true,"ifname":"eth4","ip":"replace_IP","is_uplink":true,"media":"GE","name":"Port 5","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":5,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":16226465,"rx_bytes-r":43,"rx_dropped":0,"rx_errors":0,"rx_packets":205201,"satisfaction":0,"speed":1000,"speed_caps":1048623,"tx_bytes":5606796,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":82525,"up":true}],"product_line":"NETWORK","radio_table":[{"antenna_gain":0,"builtin_ant_gain":3,"builtin_antenna":true,"channel":1,"current_antenna_gain":0,"hard_noise_floor_enabled":false,"has_dfs":false,"has_fccdfs":false,"has_ht160":false,"has_restricted_channels":false,"ht":20,"is_11ac":false,"is_11ax":false,"loadbalance_enabled":false,"max_txpower":23,"min_rssi_enabled":false,"min_txpower":6,"name":"ra0","nss":4,"radio":"ng","radio_caps":67256324,"radio_caps2":1,"sens_level_enabled":false,"tx_power_mode":"low","vwire_enabled":true},{"antenna_gain":0,"builtin_ant_gain":4,"builtin_antenna":true,"channel":36,"current_antenna_gain":0,"hard_noise_floor_enabled":false,"has_dfs":true,"has_fccdfs":true,"has_ht160":true,"has_restricted_channels":false,"ht":80,"is_11ac":true,"is_11ax":true,"loadbalance_enabled":false,"max_txpower":26,"min_rssi_enabled":false,"min_txpower":6,"name":"rai0","nss":4,"radio":"na","radio_caps":251805700,"radio_caps2":15,"sens_level_enabled":false,"tx_power_mode":"low","vwire_enabled":false}],"radio_table_stats":[{"channel":1,"cu_self_rx":0,"cu_self_tx":0,"cu_total":12,"extchannel":0,"gain":3,"guest-num_sta":0,"name":"ra0","num_sta":0,"radio":"ng","satisfaction":-1,"state":"RUN","tx_packets":0,"tx_power":6,"tx_retries":0,"user-num_sta":0},{"channel":36,"cu_self_rx":0,"cu_self_tx":0,"cu_total":2,"extchannel":1,"gain":4,"guest-num_sta":0,"name":"rai0","num_sta":0,"radio":"na","satisfaction":-1,"state":"RUN","tx_packets":0,"tx_power":6,"tx_retries":0,"user-num_sta":0}],"restarting":false,"rx_bytes":5606796,"rx_bytes-d":0,"satisfaction":-1,"spectrum_scanning":false,"state":1,"sys_stats":{"loadavg_1":1.3,"loadavg_15":0.97,"loadavg_5":1.05,"mem_buffer":81281024,"mem_total":2030968832,"mem_used":1717915648},"system-stats":{"cpu":31.7,"mem":84.6,"uptime":61442},"tx_bytes":16226465,"tx_bytes-d":0,"type":"udm","unsupported":false,"unsupported_reason":0,"upgradable":false,"upgrade_state":0,"uplink":{"name":"eth4","port_idx":5,"speed":1000,"type":"wire"},"uplink_table":[],"upload_speed_bytes_per_second":0,"uptime":61442,"vap_table":[],"version":"2.3.12.6542","wlan_overrides":[]}],"meta":{"message":"unifi-device:sync","product_line":"NETWORK","rc":"ok"}}
2022-01-28 10:03:56 DEBUG (MainThread) [aiounifi.websocket] {"meta":{"rc":"ok","message":"device:update","mac":"24:5a:4c:9f:e1:75"},"data":[{"temperatures":[{"name":"Local","type":"board","value":44.0},{"name":"CPU","type":"cpu","value":43.5}]}]}
2022-01-28 10:03:56 DEBUG (MainThread) [aiounifi.controller] Unsupported message type {'data': [{'_id': '61c0287e6b7d321fb18bedc7', 'adopt_state': 0, 'adoptable_when_upgraded': False, 'adopted': True, 'bytes-r': 0, 'connection_network_name': 'LAN', 'countrycode_table': [840, 124, 630], 'default': False, 'device_type': 'MANAGED', 'disabled': False, 'displayable_version': '2.3.12', 'download_speed_bytes_per_second': 134, 'ethernet_overrides': [{'ifname': 'eth4', 'networkgroup': 'WAN'}, {'ifname': 'eth0', 'networkgroup': 'LAN'}, {'ifname': 'eth1', 'networkgroup': 'LAN'}, {'ifname': 'eth2', 'networkgroup': 'LAN'}, {'ifname': 'eth3', 'networkgroup': 'LAN'}], 'fw_caps': 1676582447, 'ip': 'replace_IP', 'isolated': False, 'last_seen': 1643382236, 'license_state': 'registered', 'locating': False, 'lte_connected': False, 'mac': '24:5a:4c:9f:e1:75', 'model': 'UDR', 'model_in_eol': False, 'model_in_lts': False, 'model_incompatible': False, 'name': 'UDR', 'num_sta': 6, 'port_table': [{'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth0', 'is_uplink': False, 'media': 'GE', 'name': 'Port 1', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 1, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': True, 'ifname': 'eth1', 'ip': '192.168.2.254', 'is_uplink': False, 'media': 'GE', 'name': 'Port 2', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 2, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 72124251927, 'rx_bytes-r': 698647, 'rx_dropped': 1, 'rx_errors': 0, 'rx_packets': 54676588, 'satisfaction': 0, 'speed': 1000, 'speed_caps': 1048623, 'tx_bytes': 2494744300, 'tx_bytes-r': 28804, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 32793125, 'up': True}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth2', 'is_uplink': False, 'media': 'GE', 'name': 'Port 3', 'op_mode': 'switch', 'poe_caps': 1, 'poe_enable': False, 'port_idx': 3, 'port_poe': True, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': False, 'ifname': 'eth3', 'is_uplink': False, 'media': 'GE', 'name': 'Port 4', 'op_mode': 'switch', 'poe_caps': 1, 'poe_enable': False, 'port_idx': 4, 'port_poe': True, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 0, 'rx_bytes-r': 0, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 0, 'satisfaction': 0, 'speed': 10, 'speed_caps': 1048623, 'tx_bytes': 0, 'tx_bytes-r': 0, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 0, 'up': False}, {'aggregated_by': False, 'autoneg': True, 'full_duplex': True, 'ifname': 'eth4', 'ip': 'replace_IP', 'is_uplink': True, 'media': 'GE', 'name': 'Port 5', 'op_mode': 'switch', 'poe_caps': 0, 'poe_enable': False, 'port_idx': 5, 'port_poe': False, 'portconf_id': '5b213940b150b6c08a49dcad', 'rx_bytes': 16246777, 'rx_bytes-r': 134, 'rx_dropped': 0, 'rx_errors': 0, 'rx_packets': 205421, 'satisfaction': 0, 'speed': 1000, 'speed_caps': 1048623, 'tx_bytes': 5612397, 'tx_bytes-r': 83, 'tx_dropped': 0, 'tx_errors': 0, 'tx_packets': 82608, 'up': True}], 'product_line': 'NETWORK', 'radio_table': [{'antenna_gain': 0, 'builtin_ant_gain': 3, 'builtin_antenna': True, 'channel': 1, 'current_antenna_gain': 0, 'hard_noise_floor_enabled': False, 'has_dfs': False, 'has_fccdfs': False, 'has_ht160': False, 'has_restricted_channels': False, 'ht': 20, 'is_11ac': False, 'is_11ax': False, 'loadbalance_enabled': False, 'max_txpower': 23, 'min_rssi_enabled': False, 'min_txpower': 6, 'name': 'ra0', 'nss': 4, 'radio': 'ng', 'radio_caps': 67256324, 'radio_caps2': 1, 'sens_level_enabled': False, 'tx_power_mode': 'low', 'vwire_enabled': True}, {'antenna_gain': 0, 'builtin_ant_gain': 4, 'builtin_antenna': True, 'channel': 36, 'current_antenna_gain': 0, 'hard_noise_floor_enabled': False, 'has_dfs': True, 'has_fccdfs': True, 'has_ht160': True, 'has_restricted_channels': False, 'ht': 80, 'is_11ac': True, 'is_11ax': True, 'loadbalance_enabled': False, 'max_txpower': 26, 'min_rssi_enabled': False, 'min_txpower': 6, 'name': 'rai0', 'nss': 4, 'radio': 'na', 'radio_caps': 251805700, 'radio_caps2': 15, 'sens_level_enabled': False, 'tx_power_mode': 'low', 'vwire_enabled': False}], 'radio_table_stats': [{'channel': 1, 'cu_self_rx': 0, 'cu_self_tx': 0, 'cu_total': 10, 'extchannel': 0, 'gain': 3, 'guest-num_sta': 0, 'name': 'ra0', 'num_sta': 0, 'radio': 'ng', 'satisfaction': -1, 'state': 'RUN', 'tx_packets': 0, 'tx_power': 6, 'tx_retries': 0, 'user-num_sta': 0}, {'channel': 36, 'cu_self_rx': 0, 'cu_self_tx': 0, 'cu_total': 3, 'extchannel': 1, 'gain': 4, 'guest-num_sta': 0, 'name': 'rai0', 'num_sta': 0, 'radio': 'na', 'satisfaction': -1, 'state': 'RUN', 'tx_packets': 0, 'tx_power': 6, 'tx_retries': 0, 'user-num_sta': 0}], 'restarting': False, 'rx_bytes': 5612397, 'rx_bytes-d': 0, 'satisfaction': -1, 'spectrum_scanning': False, 'state': 1, 'sys_stats': {'loadavg_1': 0.92, 'loadavg_15': 0.96, 'loadavg_5': 1.0, 'mem_buffer': 81485824, 'mem_total': 2030968832, 'mem_used': 1718325248}, 'system-stats': {'cpu': 30.1, 'mem': 84.6, 'uptime': 61505}, 'tx_bytes': 16246777, 'tx_bytes-d': 0, 'type': 'udm', 'unsupported': False, 'unsupported_reason': 0, 'upgradable': False, 'upgrade_state': 0, 'uplink': {'name': 'eth4', 'port_idx': 5, 'speed': 1000, 'type': 'wire'}, 'uplink_table': [], 'upload_speed_bytes_per_second': 83, 'uptime': 61505, 'vap_table': [], 'version': '2.3.12.6542', 'wlan_overrides': []}], 'meta': {'message': 'unifi-device:sync', 'product_line': 'NETWORK', 'rc': 'ok'}}
2022-01-28 10:03:56 DEBUG (MainThread) [aiounifi.websocket] {"data":[{"_id":"61c0287e6b7d321fb18bedc7","adopt_state":0,"adoptable_when_upgraded":false,"adopted":true,"bytes-r":0,"connection_network_name":"LAN","countrycode_table":[840,124,630],"default":false,"device_type":"MANAGED","disabled":false,"displayable_version":"2.3.12","download_speed_bytes_per_second":134,"ethernet_overrides":[{"ifname":"eth4","networkgroup":"WAN"},{"ifname":"eth0","networkgroup":"LAN"},{"ifname":"eth1","networkgroup":"LAN"},{"ifname":"eth2","networkgroup":"LAN"},{"ifname":"eth3","networkgroup":"LAN"}],"fw_caps":1676582447,"ip":"replace_IP","isolated":false,"last_seen":1643382236,"license_state":"registered","locating":false,"lte_connected":false,"mac":"24:5a:4c:9f:e1:75","model":"UDR","model_in_eol":false,"model_in_lts":false,"model_incompatible":false,"name":"UDR","num_sta":6,"port_table":[{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth0","is_uplink":false,"media":"GE","name":"Port 1","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":1,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":true,"ifname":"eth1","ip":"192.168.2.254","is_uplink":false,"media":"GE","name":"Port 2","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":2,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":72124251927,"rx_bytes-r":698647,"rx_dropped":1,"rx_errors":0,"rx_packets":54676588,"satisfaction":0,"speed":1000,"speed_caps":1048623,"tx_bytes":2494744300,"tx_bytes-r":28804,"tx_dropped":0,"tx_errors":0,"tx_packets":32793125,"up":true},{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth2","is_uplink":false,"media":"GE","name":"Port 3","op_mode":"switch","poe_caps":1,"poe_enable":false,"port_idx":3,"port_poe":true,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":false,"ifname":"eth3","is_uplink":false,"media":"GE","name":"Port 4","op_mode":"switch","poe_caps":1,"poe_enable":false,"port_idx":4,"port_poe":true,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":0,"rx_bytes-r":0,"rx_dropped":0,"rx_errors":0,"rx_packets":0,"satisfaction":0,"speed":10,"speed_caps":1048623,"tx_bytes":0,"tx_bytes-r":0,"tx_dropped":0,"tx_errors":0,"tx_packets":0,"up":false},{"aggregated_by":false,"autoneg":true,"full_duplex":true,"ifname":"eth4","ip":"replace_IP","is_uplink":true,"media":"GE","name":"Port 5","op_mode":"switch","poe_caps":0,"poe_enable":false,"port_idx":5,"port_poe":false,"portconf_id":"5b213940b150b6c08a49dcad","rx_bytes":16246777,"rx_bytes-r":134,"rx_dropped":0,"rx_errors":0,"rx_packets":205421,"satisfaction":0,"speed":1000,"speed_caps":1048623,"tx_bytes":5612397,"tx_bytes-r":83,"tx_dropped":0,"tx_errors":0,"tx_packets":82608,"up":true}],"product_line":"NETWORK","radio_table":[{"antenna_gain":0,"builtin_ant_gain":3,"builtin_antenna":true,"channel":1,"current_antenna_gain":0,"hard_noise_floor_enabled":false,"has_dfs":false,"has_fccdfs":false,"has_ht160":false,"has_restricted_channels":false,"ht":20,"is_11ac":false,"is_11ax":false,"loadbalance_enabled":false,"max_txpower":23,"min_rssi_enabled":false,"min_txpower":6,"name":"ra0","nss":4,"radio":"ng","radio_caps":67256324,"radio_caps2":1,"sens_level_enabled":false,"tx_power_mode":"low","vwire_enabled":true},{"antenna_gain":0,"builtin_ant_gain":4,"builtin_antenna":true,"channel":36,"current_antenna_gain":0,"hard_noise_floor_enabled":false,"has_dfs":true,"has_fccdfs":true,"has_ht160":true,"has_restricted_channels":false,"ht":80,"is_11ac":true,"is_11ax":true,"loadbalance_enabled":false,"max_txpower":26,"min_rssi_enabled":false,"min_txpower":6,"name":"rai0","nss":4,"radio":"na","radio_caps":251805700,"radio_caps2":15,"sens_level_enabled":false,"tx_power_mode":"low","vwire_enabled":false}],"radio_table_stats":[{"channel":1,"cu_self_rx":0,"cu_self_tx":0,"cu_total":10,"extchannel":0,"gain":3,"guest-num_sta":0,"name":"ra0","num_sta":0,"radio":"ng","satisfaction":-1,"state":"RUN","tx_packets":0,"tx_power":6,"tx_retries":0,"user-num_sta":0},{"channel":36,"cu_self_rx":0,"cu_self_tx":0,"cu_total":3,"extchannel":1,"gain":4,"guest-num_sta":0,"name":"rai0","num_sta":0,"radio":"na","satisfaction":-1,"state":"RUN","tx_packets":0,"tx_power":6,"tx_retries":0,"user-num_sta":0}],"restarting":false,"rx_bytes":5612397,"rx_bytes-d":0,"satisfaction":-1,"spectrum_scanning":false,"state":1,"sys_stats":{"loadavg_1":0.92,"loadavg_15":0.96,"loadavg_5":1.0,"mem_buffer":81485824,"mem_total":2030968832,"mem_used":1718325248},"system-stats":{"cpu":30.1,"mem":84.6,"uptime":61505},"tx_bytes":16246777,"tx_bytes-d":0,"type":"udm","unsupported":false,"unsupported_reason":0,"upgradable":false,"upgrade_state":0,"uplink":{"name":"eth4","port_idx":5,"speed":1000,"type":"wire"},"uplink_table":[],"upload_speed_bytes_per_second":83,"uptime":61505,"vap_table":[],"version":"2.3.12.6542","wlan_overrides":[]}],"meta":{"message":"unifi-device:sync","product_line":"NETWORK","rc":"ok"}}
2022-01-28 10:05:28 DEBUG (MainThread) [aiounifi.websocket] {"meta":{"rc":"ok","message":"events"},"data":[{"user":"60:b7:6e:2d:1e:16","ap_from":"78:45:58:4b:44:6c","ap_to":"f4:92:bf:a1:91:18","radio_from":"na","radio_to":"na","radio":"na","channel_from":"100","channel_to":"60","channel":"60","ssid":"replaced_SSID","key":"EVT_WU_Roam","subsystem":"wlan","is_negative":false,"site_id":"5b21393fb150b6c08a49dca0","time":1643382290067,"datetime":"2022-01-28T15:04:50Z","msg":"User[60:b7:6e:2d:1e:16] roams from AP[78:45:58:4b:44:6c] to AP[f4:92:bf:a1:91:18] from \"channel 100(na)\" to \"channel 60(na)\" on \"replaced_SSID\"","_id":"61f406345f820913b59396a0"}]}
is it roaming triggering the device_tracker to faulter?
Confirmed.
Reloaded HA core. My pixel_4a is "home". Walk to other room and roam to that rooms AP. Wait for Unifi scan interval (default 300 sec). My pixel_4a is "away". The only way to get it back is to reload HA because the Unifi integration no longer reloads w/o a restart.
Good catch.
The device tracker primarily looks at "sta:sync" messages from web socket and in particular the last_seen timestamp in order to see if the client is still active on the network. Can you share those messages before and after roaming? What happens if client roams back to the other access point?
Previously it was more dependent on using the web socket events but there where many issues reported that they wasn't trustworthy, also with regard to roaming...
Can you share those messages before and after roaming? What happens if client roams back to the other access point?
Sure thing. Is it ok to reduce the "time until device considered away" from 300 down to 90 for testing?
I will include everything from grep -iF unifi home-assistant.log > unifi_log.txt
w/ some regex find/replace for IP's/name/etc
Sure
Reload works for me
I performed the following w/ attached log:
So it looks like it isn't just roaming - sta's in general. unifi 2022.2.0b1-sta.txt
[edit] - thinking about this further. Enabling an entity reloads the integration?
IIRC yes
I performed the following w/ attached log:
- reloaded HA core ~11:45AM
moved pixel_4a to another room so it roams ~11:49AM
- confirmed roaming successful in Unifi app ~11:51
- confirmed that device_tracker.pixel_4a now "away" in HA
- moved pixel_4a back to original room ~11:53
- confirmed roaming successful back to original AP in Unifi app ~11:55
- device_tracker.pixel_4a still "away" in HA when back on original AP
tested 2nd device - FireHD8 - shows as "home" ok in HA
- in the Unifi App I clicked "reconnect" ~11:57
- reconnected successfully to same AP (per Unifi app) as it has not physically moved
- shows as "away" in HA ~11:59
So it looks like it isn't just roaming - sta's in general. unifi 2022.2.0b1-sta.txt
Yes, it seems your log doesn't have a single "sta:sync" message
it seems your log doesn't have a single "sta:sync" message
Are they supposed to?
Only see roam events in Unifi syslog output for pixel_4a mac. Will check FireHD8..
1/28/2022 12:03 PM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 12:03 PM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 12:01 PM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:59 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:57 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:56 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:55 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:55 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:55 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:55 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""478674.992948"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""auth_delta"":""0"",""vap"":""rai0"",""event_type"":""soft failure"",""assoc_status"":""0"",""ip_assign_type"":""roamed"",""wpa_auth_delta"":""10000"",""assoc_delta"":""-1632070144"",""event_id"":""1"",""dns_resp_seen"":""yes""}
1/28/2022 11:55 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0"",""sta_dc_reason"":""roam""}
1/28/2022 11:55 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""sta_roam"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_id"":""1""}
1/28/2022 11:55 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:55 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:54 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:54 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:54 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:53 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:53 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:53 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:52 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:52 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:51 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:50 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:50 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_type"":""fixup"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""dns_resp_seen"":""yes"",""assoc_status"":""0"",""event_id"":""1"",""auth_ts"":""0.0""}
1/28/2022 11:49 AM,Info,192.168.2.5,7845584b446c,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""ip_assign_type"":""roamed"",""message_type"":""STA_ASSOC_TRACKER"",""event_type"":""soft failure"",""assoc_delta"":""-1063270144"",""mac"":""60:b7:6e:2d:1e:16"",""auth_delta"":""0"",""vap"":""rai0"",""assoc_status"":""0"",""event_id"":""1"",""wpa_auth_delta"":""10000"",""auth_ts"":""478107.358659""}
1/28/2022 11:49 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""sta_dc_reason"":""roam""}
1/28/2022 11:49 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""sta_roam""}
1/28/2022 11:49 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:46 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
1/28/2022 11:45 AM,Info,192.168.2.4,f492bfa19118,U6-Lite-6.0.10+13599: stahtd: stahtd[2965]: [STA-TRACKER].stahtd_dump_event(): {""auth_ts"":""0.0"",""event_id"":""1"",""message_type"":""STA_ASSOC_TRACKER"",""mac"":""60:b7:6e:2d:1e:16"",""vap"":""rai0"",""assoc_status"":""0"",""event_type"":""fixup"",""dns_resp_seen"":""yes""}
FireHD8 had sta-leave but no sync's.
Foregoing all filters on the syslog in that time period; zero hits on a "sync" search.
I added this to configuration.yaml
logger:
default: info
logs:
aiounifi: debug
homeassistant.components.unifi: debug
And I get lots of debug data
2022-01-28 21:59:23 DEBUG (MainThread) [aiounifi.websocket] {"meta":{"rc":"ok","message":"sta:sync"},"data":[{"site_id":"5f3edd27ba4cc816a19f2d9c","assoc_time":1642171679,"latest_assoc_time":1642274388,"oui":"Apple","user_id":"5f411331c75312038d9b1e14","_id":"5f411331c75312038d9b1e14","mac":"......
I added this to configuration.yaml
logger: default: info logs: aiounifi: debug homeassistant.components.unifi: debug
And I get lots of debug data
I followed the docs so added;
logs:
aiounifi: debug
homeassistant.components.unifi: debug
homeassistant.components.device_tracker.unifi: debug
homeassistant.components.switch.unifi: debug
Is the sta:sync a new or old requirement?
I've been running UNA v7.0.x since mid/late Dec '21 and its worked great. Began misbehaving after Jan 25 Unifi integration dev.
Users reported events not working properly so I changed to something based on an old strategy for presence detection
The New entry point gateway? Ubiquiti likes to mix things around so could be something like that
I'll go back and review syslog from earlier dates if I can. Don't remember how long my retention is. See if I can find some sta:sync
messages.
Reviewing my file downloads. The last Unifi Controller v6 I used was v6.5.55 on Dec 15 '21. Reviewing those syslogs I see no sta:sync
messages from the AP's but realize they are only AP logs. So if that message comes from the controller itself, sadly I don't have it.
Being that I am running Unifi Controller v7 in early access. Please let me know how to proceed.
Can I run a custom Unifi integration w/o that changes you made? I have done so w/ the Sonos integration for bugfix testing. The dev was kind enough to provide a version to test.
If it is possible to revert that one change and provide a git link to clone (edit manifest version) please let me know.
The data is from the controller.
Perhaps this means there is a storm coming with unifi v7 controller (I hope not). You can always try to downgrade to v6 and see if that works.
Perhaps this means there is a storm coming with unifi v7 controller (I hope not).
Kinda what I was wondering as well.
You can always try to downgrade to v6 and see if that works.
Gotta factory the UDR in order to do that :(
I don't know git very well. Do I need to fork the entire core in order to revert #64147 to run a custom version or is that something you guys can help w/ ?
I went back to dev on Jan 24 and roaming works ok for me. Would like to finally get on 2022.2 when it GA's.
I guess you need to copy everything to a custom component, don't really know much about that.
Gotta factory the UDR in order to do that :(
I can't support an in-development software. UniFi is sketchy enough as it is.
Yeah the copy everything part is the slow part.
Hence me wondering if you developed off a forked repo where you could create a branch, revert the suspected commit and I could just clone that branch.
Did that while testing some Sonos component fixes a while back. And it was far quicker than me cloning all of core (because I don't know a better way).
That's not how it works, developing in home-assistant core gives you a snapshot of everything, so if you where to revert the commit you'd still be on dev prior to the change getting merged
So if this issue is only regarding UniFi controller 7 I can close this issue.
That's not how it works, developing in home-assistant core gives you a snapshot of everything, so if you where to revert the commit you'd still be on dev prior to the change getting merged
Yes. Then you take that unifi folder, copy it to custom_components and add a version to manifest. Then upgrade core, but that upgraded version of core will use the custom version of the component. So it wouldn't use unifi including in 2022.2.0b2 but the one copied into the custom_components folder from Jan24'ish.
It gives you a little icon on the integration to know that you aren't using the stock version of the integration.
So if this issue is only regarding UniFi controller 7 I can close this issue.
Yes, the version that's right around the corner and if this thread is anything to go by, will break everyone's Unifi component :(
That's how it works with reverse engineered apis, they break
That's how it works with reverse engineered apis, they break
I completely understand. I don't have the skills to do it. And appreciate your work. You have the heads up of a breaking change. I've tried to contribute with all I know.
Leaving this here for anyone on Unifi Network v7 w/ the same sta/roaming issue. The following has allowed me to update to 2022.2.0 (beta at writing) using the version of the Unifi component prior to commit a15bdbb which causes the regression observed. My roaming now works again.
You will need to;
git revert a15bdbb
.\homeassistant\components\unifi\
folder to your HA installation into .\config\custom_components
.\config\custom_components\unifi\manifest.json
"version": "2022.2.0dev24",
)You will know that this has been successful with the little icon in the upper right corner of the integration.
This is an unsupported workaround with a high level of effort likely to interfere with future updates. Hopefully there isn't a disaster when UI releases Unifi Network v7 and the devs go mad. Don't know what we would do without them. This is a really useful integration.
Yikes... V7 is forcing us back to events.... Sure hope they fixed the event generator. @Andy-BG - Is your configuration using multiple AP's with roaming? Do your devices roam and sometimes show as away when they are actually "home"? With V6, we have seen the controller declare a device disconnected when it is actually connected, and it typically can be found in the unifi event log showing device disconnects, then some time later a roam will appear (without a connect event).
Is your configuration using multiple AP's with roaming? Do your devices roam and sometimes show as away when they are actually "home"?
Yes, two AP's; roaming between them. With v7 & the a15bdbb
commit my phone goes from "home" to "away" on every roam and only a reload of the integration brings it back.
With V6, we have seen the controller declare a device disconnected when it is actually connected, and it typically can be found in the unifi event log showing device disconnects, then some time later a roam will appear (without a connect event).
Yes I have seen this as well on v6. Albeit only on occasion and a reload of the Unifi integration typically solved this for me. Which is the second problem I have encountered - I cannot reload the Unifi integration and it requires a reload of HA core.
Have you seen it on V7 with the a15bdbb version (aka going back to event based code)?
The problem
Updated from core-2022.2.0.dev20220125 to core-2022.2.0.dev20220126
Unifi Integration displays count of entities in Integration page but clicking through to Entities list (with default filter) shows none.
Dev tools shows entity state immediately after HA core restart. Then goes unavailable after a few minutes.
A reload of the Unifi integration fails. Orange box around integration, all entities unavailable.
Cannot control USP-Strip (this is new feature? untested before by me). Toggling a switch reverts back in a few seconds. And once in five tries (after reloading HA each time) actually changed the relay. Then the state reverted so it was incorrectly shown.[edit] care about the trackers, not the stripWhat version of Home Assistant Core has the issue?
core-2022.2.0.dev20220126
What was the last working version of Home Assistant Core?
core-2022.2.0.dev20220125
What type of installation are you running?
Home Assistant OS
Integration causing the issue
Unifi
Link to integration documentation on our website
https://www.home-assistant.io/integrations/unifi/
Example YAML snippet
Anything in the logs that might be useful for us?
Additional information
No response