Core: Unifi Device Tracker not marking offline devices

[rslota]

The problem

In one of the most recent releases something has changed in the Unifi Device Tracker. I haven't managed to figure out what exactly is not working correctly, but to simply put - device trackers' state is not updated if the device is not connected to the network. This is an issue, because it seems that UniFiDeviceTracker.is_connected callback is not called either, and thus the device is marked as online forever. Both state updates and UniFiDeviceTracker.is_connected callback is called if the device is connected to the network. I'm not exactly sure what triggers those updates, but I'm guessing it's Unifi Controller client, so if this client does not get info for disconnected clients, it may not trigger the updates that in turn does not give HA chance to mark device as offline.

Also, I tried to change return value of UniFiDeviceTracker.should_poll from False to True which fixed the issue, as expected.

Environment

• Home Assistant release with the issue: 0.106b3
• Last working Home Assistant release (if known): 1.103
• Operating environment (Hass.io/Docker/Windows/etc.): Docker
• Integration causing this issue: unifi
• Link to integration documentation on our website: https://www.home-assistant.io/integrations/unifi

Problem-relevant configuration.yaml

No relevant configuration (integration configured via frontend).

Traceback/Error logs

No relevant logs.

Additional information

[probot-home-assistant[bot]]

Hey there @kane610, mind taking a look at this issue as its been labeled with a integration (unifi) you are listed as a codeowner for? Thanks!

[WilldabeastHA]

@rslota where do I find the place to change UniFiDeviceTracker.should_poll to true?

[rslota]

@WilldabeastHA ,

I was referring to code change here: https://github.com/home-assistant/home-assistant/blob/4cac0443e25d7637cf0f3d02d60d1113d7b8f5fc/homeassistant/components/unifi/device_tracker.py#L336

[WilldabeastHA]

@rslota - Thanks for pointing to the spot. I've made the change and restarted HA but that doesn't appear to do anything for my set up. Devices never change their state.

[KennethLavrsen]

I can confirm the issue. Devices never get updated to not home when it leaves the network.
If you reboot Home Assistant the correct state is restored but while the system is running, the Unifi integration as device tracker is no longer able to tell if you are home or not.

[rslota]

@rslota - Thanks for pointing to the spot. I've made the change and restarted HA but that doesn't appear to do anything for my set up. Devices never change their state.

@WilldabeastHA , sorry, my bad, I meant this: https://github.com/home-assistant/home-assistant/blob/4cac0443e25d7637cf0f3d02d60d1113d7b8f5fc/homeassistant/components/unifi/unifi_client.py#L65 .

[WilldabeastHA]

@rslota - no luck on my end. when changing that to True all my devices show away. Thank you.

[cbulock]

Started seeing this issue as well after upgrading to .106

[jfournierphoto]

Same issue here after upgrade to .106

[Kane610]

Does this happen for all your devices or just for a few?

[jfournierphoto]

Seem to be all devices for me. Restarting HA fixes the issue on the spot, but devices don't change state after...

[WilldabeastHA]

@Kane610 it appears to happen to all my devices.

[jfournierphoto]

I went in the unifi integration, openned the settings and specified the SSID to track the clients on, it was blank.. and now it seems to work fine again.

[WilldabeastHA]

@jfournierphoto I've tried that myself without any success

[rslota]

I went in the unifi integration, openned the settings and specified the SSID to track the clients on, it was blank.. and now it seems to work fine again.

For me this has nothing to do with wireless. I only have Unifi USG, so all my clients are working as "wired".

[jfournierphoto]

it works fine for my iphone, ipad and macbook. But not for other devices. I guess there is really something with the code...

[kmlucy]

None of my devices are updating their statuses. If I restart home assistant they will update, but they won't update on their own. It works on 0.105, and is broken in 0.106. When I upgraded the network filter was blank, but I've since checked the correct networks.

[Kane610]

What version of the controller are you running?

[Kane610]

Can I get some logs?

logger:
  default: info
  logs:
    aiounifi: debug
    homeassistant.components.unifi: debug

[reinder83]

After updating to 0.106.0 and 0.106.1 unifi device tracker does not work correctly anymore, possible related to https://github.com/home-assistant/home-assistant/pull/31086?

Reverted back to 0.105.5 for now, everything seems to work fine again.

The unifi controller im using the latest released version of https://github.com/hassio-addons/addon-unifi

[kmlucy]

I'm running 5.6.42.

These are the messages when Home Assistant starts:

2020-02-28 06:14:04 INFO (SyncWorker_16) [homeassistant.loader] Loaded unifi from homeassistant.components.unifi
2020-02-28 06:14:05 INFO (MainThread) [homeassistant.setup] Setting up unifi
2020-02-28 06:14:05 INFO (MainThread) [homeassistant.setup] Setup of domain unifi took 0.9 seconds.
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.api] [{'_id': '<ID>',
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.api] [{'_id': '<ID>',
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.api] [{'_id': '<ID>',
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.api] [{'_id': '<ID>',
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.controller] [{'_id': '<ID>',
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.websocket] Websocket starting
2020-02-28 06:14:07 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.unifi
2020-02-28 06:14:07 INFO (MainThread) [homeassistant.components.switch] Setting up switch.unifi
2020-02-28 06:14:07 INFO (MainThread) [homeassistant.components.device_tracker] Setting up device_tracker.unifi
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Richard (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client OnePlus7Pro (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Rachael (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Lexi (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Ellie (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Dina (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Katie (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Galaxy-Note10 (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Sammie (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Samsung-Galaxy-S7 (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Crystal (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Galaxy-S10 (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Kellie (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Mary (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Devon (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Annick (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client None (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [homeassistant.components.unifi.unifi_client] New UniFi client Hannah (<MAC>)
2020-02-28 06:14:07 DEBUG (MainThread) [aiounifi.websocket] Websocket running

There was a lot of additional information under each of the aiounifi.api lines at the beginning. Please let me know if you need that.

When I disconnect a client, I get this, but the entity does not update in Home Assistant:

2020-02-28 06:24:59 DEBUG (MainThread) [aiounifi.websocket] { "data" : [ { "_id" : "<ID>" , "ap" : "<AP_MAC>" , "bytes" : 1497089640 , "datetime" : "2020-02-28T11:19:42Z" , "duration" : 28936 , "key" : "EVT_WU_Disconnected" , "msg" : "User[<MAC>] disconnected from \"<SSID>\" (8h 2m connected, 1.39G bytes, last AP[<AP_MAC])" , "site_id" : "<ID>" , "ssid" : "<SSID>" , "subsystem" : "wlan" , "time" : 1582888782000 , "user" : "<MAC>"}] , "meta" : { "message" : "events" , "rc" : "ok"}}

When I reconnect, I get this:

2020-02-28 06:30:04 DEBUG (MainThread) [aiounifi.websocket] { "data" : [ { "_id" : "<ID>" , "ap" : "<AP_MAC>" , "channel" : "48" , "datetime" : "2020-02-28T11:29:38Z" , "key" : "EVT_WU_Connected" , "msg" : "User[<MAC>] has connected to AP[<AP_MAC] with ssid \"<SSID>\" on \"channel 48(na)\"" , "radio" : "na" , "site_id" : "<ID>" , "ssid" : "<SSID>" , "subsystem" : "wlan" , "time" : 1582889378160 , "user" : "<MAC>"}] , "meta" : { "message" : "events" , "rc" : "ok"}}
2020-02-28 06:31:20 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_protocol.py", line 418, in start
    resp = await task
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_app.py", line 458, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/web_middlewares.py", line 119, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/real_ip.py", line 39, in real_ip_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 72, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 135, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 123, in handle
    result = await result
  File "/usr/src/homeassistant/homeassistant/components/camera/__init__.py", line 485, in get
    return await self.handle(request, camera)
  File "/usr/src/homeassistant/homeassistant/components/camera/__init__.py", line 502, in handle
    image = await camera.async_camera_image()
  File "/usr/src/homeassistant/homeassistant/components/camera/__init__.py", line 369, in async_camera_image
    return await self.hass.async_add_job(self.camera_image)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/skybell/camera.py", line 94, in camera_image
    return self._response.content
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 828, in content
    self._content = b''.join(self.iter_content(CONTENT_CHUNK_SIZE)) or b''
  File "/usr/local/lib/python3.7/site-packages/requests/models.py", line 750, in generate
    for chunk in self.raw.stream(chunk_size, decode_content=True):
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 564, in stream
    data = self.read(amt=amt, decode_content=decode_content)
  File "/usr/local/lib/python3.7/site-packages/urllib3/response.py", line 507, in read
    data = self._fp.read(amt) if not fp_closed else b""
  File "/usr/local/lib/python3.7/http/client.py", line 457, in read
    n = self.readinto(b)
  File "/usr/local/lib/python3.7/http/client.py", line 505, in readinto
    self._close_conn()
  File "/usr/local/lib/python3.7/http/client.py", line 411, in _close_conn
    fp.close()
AttributeError: 'NoneType' object has no attribute 'close'

The error and traceback then repeats.

[kmlucy]

One note, after rolling back to 0.105.5 (working), I get regular messages for each device tracker like this:

2020-02-28 06:56:58 DEBUG (MainThread) [homeassistant.components.unifi.device_tracker] Updating UniFi tracked client device_tracker.ben

I do not get these with 0.106.1.

[blackskull182]

Hello,

same issue on 0.106.1

[sverleysen]

Also having this issue on 0.106.1

[Nixon506E]

Same issue here on 0.106.0, had to roll back to 0.105.5

[brandondb1]

Happening in .106.1 for me, and can confirm its happening to multiple Android phones, an iPhone, and an Asus laptop, so it doesn't seem to be device or brand specific.

[KennethLavrsen]

I am home now. I get 1 MB logging with the suggested setting per minute. Anything I should filter for?

[KennethLavrsen]

I assume the log piece you want is the periodic updates that happens

I found an example where two iPhones were listed followed by the long JSON string of all devices

In this case the two iPhones are really home. I will try and turn off a phone and wait and then post another log where the phone is supposed to be not home so expect another post

unifi-kenneth.log

[KennethLavrsen]

Here is the example.
I have just disconnected the Kenneth iPhone 7 from wifi. I see an immadiate message and then followed the large JSON block.

And I checked in HA. Kenneths iPhone 7 is still Home so it is an example of not working

unifi-ip7-disconnected.log

[derfloh]

so, pure speculation:
with the move to the event driven / push approach, HA get's periodic updates about the clients. When a client disconnects, HA gets the disconnect message, and after a (short) while Unifi stops sending information about this client (e.g. in the Unifi Controller, you won't see the client anymore).

The periodic updates/events are updating the entity on HA, but with no new events coming in, the flow where in the end is_connected() (and the comparison between now()-last_seen) doesn't get called anymore.

That's why enabling polling again for the entities as rslota described (this fixed the issue for me as well) helps. With this HA seems to go over the entities and calls the is_connected() function on its own (regardless of updates from unifi).

I think this sounds at least reasonable ;)

[reinder83]

I also don't see them going to state away when the devices disconnect, after a few hours eventually it updates.

[blackskull182]

In addiction to the broken status update, I tried to add a new device to the Wifi network and I had to reboot Home Assistant to sync up the new device ("Enable newly added entities" is enabled in the add-on option).

[Kane610]

@derfloh yes that is the issue, I don't know what I was thinking, it was obviously never working properly. I will see if I can use the poll work around for this release and get a proper implementation done for next release.

[Kane610]

Balloob agrees on the work around, I will start looking at doing a proper implementation for 0.107. I apologise for this and thank you all for your support in solving this

[WilldabeastHA]

@Kane610 the proposed fix by @rslota and what @derfloh states, doesn't fix the issue for me. My devices remain in their current state even if they are not on the network.

[Kane610]

@WilldabeastHA are you sure?

[WilldabeastHA]

@Kane610 my devices all show away when I make these changes here but they are connected to the controller and "home"

[Kane610]

@WilldabeastHA well it is not worse than now that you only get a one shot states

[kmlucy]

This isn't fixed. On 0.106.1, I could restart home assistant and devices would report correctly, though they wouldn't update. Now, on 0.106.2, devices just don't report as home at all, even if I restart.

I don't get the regular status update logs I got in 0.105. I still get the disconnect/connect debug logs the same as 0.106.1, but the traceback and error are gone.

[cbulock]

Can confirm, just got .106.2 installed and not getting updates

[WilldabeastHA]

@cbulock @kmlucy I’m having the same issue on 0.106.2 all my devices show away and don’t update.

[derfloh]

hmhm, interesting... 106.2 is working for me

[jfournierphoto]

106.2 fixed it for me as well

[mike9011]

106.2 Not receiving updates anymore. All my devices are "away".

[blackskull182]

106.2 not getting updates. All my devices are not home.

[derfloh]

Beside @kmlucy who mentioned it, did the others that have „all devices away“ problems with 106.2 didn’t have them with 106.1 ? Just wanting to rule out that the other update to unifi in 106.1 causes unexpected side issues.

[m1k3n34l]

106.2 not getting updates. All my devices are not home.

Same. Previous working version for me was 105.3. Updated to 106.2 and all devices get a not_home state shortly after ha restart.

[mike9011]

Beside @kmlucy who mentioned it, did the others that have „all devices away“ problems with 106.2 didn’t have them with 106.1 ? Just wanting to rule out that the other update to unifi in 106.1 causes unexpected side issues.

In 106.1 all my devices were at "home" and didn't update to "not_home".

In 106.2 I have the opposite, all devices are "not_home" and don't update to "home" anymore.

I'll send some logs when I'm able to.

[KennethLavrsen]

I upgraded to 0.106.2 and I see devices change between home and away normally. Ie to home in seconds and to away after a minute or so

[borpin]

I hate it when issues get closed when clearly a) there is still a problem, and b) it was only a 'temporary' fix.

[cadwal]

0.106.2 works for me as well.

[m1k3n34l]

UniFi controller 5.12.35 fixed this issue for me. Thought I already had installed it back in December, but apparently only downloaded.

[skank01]

106.2 Not receiving updates anymore. All my devices are "away".

Same here

[reinder83]

0.106.2 fixed it for me, controller version 5.12.35

For the people still having issues on 0.106.2 there is a new issue here: https://github.com/home-assistant/home-assistant/issues/32345