Unifi OS 4.03 not working (yet) with current HA

[jasperslits]

Just in case others run into this. Unifi OS 4.03 is released by Ubiquiti as Early Access. If used together with Home Assistant latest (2024.05b3) the integration won't load. This may not come as a surprise with EA stuff but wanted to flag this to others who may run into the same.

In the logs I see the following repeated several times:

2024-04-30 09:45:36.370 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('unifi', 'f94a0b341666a7ba3bd06f553852d930'): 407409.328150781} 

The issue is not created to add support for it, just for awareness.

Upon turning debug on, the logs show some interesting stuff:

2024-04-30 09:49:49.426 DEBUG (MainThread) [aiounifi.interfaces.connectivity] Logged in to UniFi https://192.168.178.1:443/api/auth/login
2024-04-30 09:49:49.426 DEBUG (MainThread) [aiounifi.interfaces.connectivity] sending (to https://192.168.178.1:443/proxy/network/api/s/default/stat/sta) get, None, {}
2024-04-30 09:49:49.428 DEBUG (MainThread) [aiounifi.interfaces.connectivity] received (from https://192.168.178.1:443/proxy/network/api/s/default/stat/sta) 401 application/json <ClientResponse(https://192.168.178.1:443/proxy/network/api/s/default/stat/sta) [401 Unauthorized]>
<CIMultiDictProxy('Server': 'nginx', 'Date': 'Tue, 30 Apr 2024 07:49:49 GMT', 'Content-Type': 'application/json', 'Content-Length': '47', 'Connection': 'keep-alive', 'Referrer-Policy': 'no-referrer', 'Strict-Transport-Security': 'max-age=15552000; includeSubDomains', 'X-Content-Type-Options': 'nosniff', 'X-DNS-Prefetch-Control': 'off', 'X-Frame-Options': 'SAMEORIGIN', 'X-XSS-Protection': '1; mode=block', 'Set-Cookie': 'UOS_TOKEN=; path=/; expires=Thu, 01 Jan 1970 00:00:00 GMT; samesite=none; secure; httponly; partitioned')>

2024-04-30 09:49:49.428 DEBUG (MainThread) [aiounifi.interfaces.connectivity] sending (to https://192.168.178.1:443/api/auth/login) post, {'username': 'YYYY', 'password': 'XXXXX', 'remember': True}, {}
2024-04-30 09:49:49.106 DEBUG (MainThread) [aiounifi.interfaces.connectivity] received (from https://192.168.178.1:443/api/auth/login) 429 application/json <ClientResponse(https://192.168.178.1:443/api/auth/login) [429 Too Many Requests]>
<CIMultiDictProxy('Server': 'nginx', 'Date': 'Tue, 30 Apr 2024 07:49:49 GMT', 'Content-Type': 'application/json; charset=utf-8', 'Content-Length': '113', 'Connection': 'keep-alive', 'X-Response-Time': '317ms', 'Access-Control-Allow-Credentials': 'false', 'Referrer-Policy': 'no-referrer', 'Strict-Transport-Security': 'max-age=15552000; includeSubDomains', 'X-Content-Type-Options': 'nosniff', 'X-DNS-Prefetch-Control': 'off', 'X-Frame-Options': 'SAMEORIGIN', 'X-XSS-Protection': '1; mode=block')>

2024-04-30 09:49:49.106 DEBUG (MainThread) [aiounifi.interfaces.connectivity] data (from https://192.168.178.1:443/api/auth/login) b'{"code":"AUTHENTICATION_FAILED_LIMIT_REACHED","message":"You\'ve reached the login attempt limit","level":"debug"}'

I'd expect to see "You've reached the login attempt limit" as a warning instead of debug, but maybe there's a different behavior with 4.xx Unifi OS compared to 3.x

Obviously the credentials of the account used for local API access did not change. Will give a it a try later on but this is the out of the box experience for now.

[jasperslits]

Better logs

2024-04-30 20:31:30.545 DEBUG (MainThread) [aiounifi.interfaces.connectivity] sending (to https://192.168.178.1:443) get, None, {'allow_redirects': False}
2024-04-30 20:31:30.558 DEBUG (MainThread) [aiounifi.interfaces.connectivity] received (from https://192.168.178.1:443) 200 text/html <ClientResponse(https://192.168.178.1:443) [200 OK]>
<CIMultiDictProxy('Server': 'nginx', 'Date': 'Tue, 30 Apr 2024 18:31:30 GMT', 'Content-Type': 'text/html', 'Content-Length': '819', 'Last-Modified': 'Tue, 30 Apr 2024 07:01:41 GMT', 'Connection': 'keep-alive', 'Etag': '"66309755-333"', 'Expires': 'Tue, 30 Apr 2024 18:31:29 GMT', 'Cache-Control': 'no-cache', 'Access-Control-Allow-Credentials': 'false', 'Access-Control-Expose-Headers': 'Content-Disposition, Content-Range, Filename, Location, Range, Upload-Length, Upload-Offset, X-Connection-Type, X-Csrf-Token, X-File-Id, X-Token-Expire-Time, X-Updated-Csrf-Token', 'Referrer-Policy': 'no-referrer', 'Strict-Transport-Security': 'max-age=15552000; includeSubDomains', 'X-Content-Type-Options': 'nosniff', 'X-DNS-Prefetch-Control': 'off', 'X-Frame-Options': 'SAMEORIGIN', 'X-XSS-Protection': '1; mode=block', 'Accept-Ranges': 'bytes')>

2024-04-30 20:31:30.558 DEBUG (MainThread) [aiounifi.interfaces.connectivity] data (from https://192.168.178.1:443) b'<!doctype html><html lang="en"><head><meta charset="utf-8"><link rel="icon" href="/favicon.ico?v3" sizes="any"><link rel="icon" href="/favicon.svg?v3" type="image/svg+xml"><link rel="apple-touch-icon" href="/apple-touch-icon.png?v3"><title>UniFi OS</title><meta name="viewport" content="width=device-width,initial-scale=1"><script>window.UNIFI_OS_MANIFEST = {"model":{"id":"UDMPRO","shortName":"UDM Pro","longName":"UniFi Dream Machine Pro"},"images":[{"size":1024,"url":"/assets/images/1024.png?udmpro-3.0.0"},{"size":64,"url":"/assets/images/64.png?udmpro-3.0.0"},{"size":48,"url":"/assets/images/48.png?udmpro-3.0.0"}]}</script><script defer="defer" src="/main.25b16840f1c6a49ff40b.js"></script><link href="/main.0e9197a3.css" rel="stylesheet"></head><body id="portal-body"><div id="portal-root"></div></body></html>'
2024-04-30 20:31:30.559 DEBUG (MainThread) [aiounifi.interfaces.connectivity] Talking to UniFi OS device: True
2024-04-30 20:31:30.560 DEBUG (MainThread) [aiounifi.interfaces.connectivity] sending (to https://192.168.178.1:443/api/auth/login) post, {'username': 'homeassistant2', 'password': 'XXXXX', 'remember': True}, {}
2024-04-30 20:31:31.022 DEBUG (MainThread) [aiounifi.interfaces.connectivity] received (from https://192.168.178.1:443/api/auth/login) 200 application/json <ClientResponse(https://192.168.178.1:443/api/auth/login) [200 OK]>
<CIMultiDictProxy('Server': 'nginx', 'Date': 'Tue, 30 Apr 2024 18:31:31 GMT', 'Content-Type': 'application/json; charset=utf-8', 'Content-Length': '3324', 'Connection': 'keep-alive', 'Set-Cookie': 'UOS_TOKEN=XXXX; path=/; expires=Tue, 30 Apr 2024 20:31:30 GMT; samesite=none; secure; httponly; partitioned', 'x-updated-csrf-token': 'e58eea89-d658-404b-ab68-990e19195f40', 'x-token-expire-time': '1714509090903', 'X-Response-Time': '440ms', 'Access-Control-Allow-Credentials': 'false', 'Access-Control-Expose-Headers': 'Content-Disposition, Content-Range, Filename, Location, Range, Upload-Length, Upload-Offset, X-Connection-Type, X-Csrf-Token, X-File-Id, X-Token-Expire-Time, X-Updated-Csrf-Token', 'Referrer-Policy': 'no-referrer', 'Strict-Transport-Security': 'max-age=15552000; includeSubDomains', 'X-Content-Type-Options': 'nosniff', 'X-DNS-Prefetch-Control': 'off', 'X-Frame-Options': 'SAMEORIGIN', 'X-XSS-Protection': '1; mode=block', 'X-Csrf-Token': 'e58eea89-d658-404b-ab68-990e19195f40')>

2024-04-30 20:31:31.022 DEBUG (MainThread) [aiounifi.interfaces.connectivity] data (from https://192.168.178.1:443/api/auth/login) b'{"unique_id":"57a51fab-9dbd-4b91-9064-5d3d33b875e4","first_name":"Home","last_name":"Assistant","alias":"","full_name":"Home Assistant","email":"","email_status":"UNVERIFIED","email_is_null":true,"user_email":"","phone":"","avatar_relative_path":"","avatar_rpath2":"","status":"ACTIVE","employee_number":"","create_time":1626811056,"login_time":1714463520,"extras":{},"username":"homeassistant2","local_account_exist":true,"password_revision":1700297379,"sso_account":"","sso_uuid":"","sso_username":"","sso_picture":"","uid_sso_id":"","uid_sso_account":"","uid_account_status":"","groups":[{"unique_id":"192d06ea-6cb6-4469-9883-9e689b3ae12e","name":"UDMXX","up_id":"","up_ids":[],"system_name":"UDMXX","create_time":"2021-07-02T12:06:37+02:00"}],"roles":[{"unique_id":"acef01b4-9c71-4b75-becb-43a1403f2d69","name":"role_private_1700297373","system_role":false,"system_key":"custom_administrator_af9c4592-eb24-4e03-a503-b1fc6906a883","level":5,"create_time":"2023-08-02T10:37:31+02:00","update_time":"2023-11-18T09:49:38+01:00","is_private":true}],"permissions":{"network.management":["readonly"],"protect.management":["admin"]},"scopes":["write:protect.viewer","write:protect.user:$","write:protect.user","write:protect.sensor","write:protect.schedule","write:protect.nvr","write:protect.light","write:protect.legacyUFV","write:protect.group","write:protect.doorlock","write:protect.deviceGroup","write:protect.chime","write:protect.camera","write:protect.bridge","view:controller:protect","view:controller:network","readmedia:protect.camera","readlive:protect.camera","read:protect.viewer","read:protect.user:$","read:protect.user","read:protect.sensor","read:protect.schedule","read:protect.nvr","read:protect.light","read:protect.legacyUFV","read:protect.group","read:protect.doorlock","read:protect.deviceGroup","read:protect.chime","read:protect.camera","read:protect.bridge","read:network-site:all","read:network-site:60dee48f6573ae03e1f837d7","manage:controller:protect","deletemedia:protect.camera","delete:protect.viewer","delete:protect.user:$","delete:protect.user","delete:protect.sensor","delete:protect.schedule","delete:protect.nvr","delete:protect.light","delete:protect.legacyUFV","delete:protect.group","delete:protect.doorlock","delete:protect.deviceGroup","delete:protect.chime","delete:protect.camera","delete:protect.bridge","create:protect.viewer","create:protect.user","create:protect.sensor","create:protect.schedule","create:protect.liveview","create:protect.light","create:protect.group","create:protect.doorlock","create:protect.deviceGroup","create:protect.chime","create:protect.camera","create:protect.bridge"],"cloud_access_granted":false,"only_local_account":true,"update_time":1679376931,"avatar":null,"nfc_token":"","nfc_display_id":"","nfc_card_type":"","nfc_card_status":"","role":"custom","roleId":"acef01b4-9c71-4b75-becb-43a1403f2d69","id":"57a51fab-9dbd-4b91-9064-5d3d33b875e4","isOwner":false,"isSuperAdmin":false,"isMember":false,"maskedEmail":"","accessMask":192,"permissionMask":0,"deviceToken":"eyJhXXX","ssoAuth":{}}'
2024-04-30 20:31:31.022 INFO (MainThread) [aiounifi.interfaces.connectivity] Token e58eea89-d658-404b-ab68-990e19195f40 found
2024-04-30 20:31:31.022 DEBUG (MainThread) [aiounifi.interfaces.connectivity] Logged in to UniFi https://192.168.178.1:443/api/auth/login
2024-04-30 20:31:31.022 DEBUG (MainThread) [aiounifi.interfaces.connectivity] sending (to https://192.168.178.1:443/proxy/network/api/self/sites) get, None, {}
2024-04-30 20:31:31.024 DEBUG (MainThread) [aiounifi.interfaces.connectivity] received (from https://192.168.178.1:443/proxy/network/api/self/sites) 401 application/json <ClientResponse(https://192.168.178.1:443/proxy/network/api/self/sites) [401 Unauthorized]>

The 401 triggers a reauth request endless loop which eventually leads to AUTHENTICATION_FAILED_LIMIT_REACHED but error message is not the root cause.

Perhaps additional headers are required to the self/sites call?

[Kane610]

Thanks! Looking at logs I think it's the websocket falling to setup causing reauthentication triggering this error

[jasperslits]

I see. Any additional logs I can turn on? I have access to the UDM Pro but wondering how to proceed.

Or is it a matter of looking at network logs in browser when using the UX?

[Kane610]

If you can verify that it's the websocket that fails in the integration setup then it's looking at network logs in the browser yes 👍🏻

[lcollins]

@Kane610 - I have made the following observation using Dev Tools.

I see here the request body - https://github.com/Kane610/aiounifi/blob/master/aiounifi/interfaces/connectivity.py#L63-L67

When I login to a Unifi OS 4.0.3 console I can see the request body for /api/auth/login is

{
"username":"<user>",
"password":"<pass>",
"token":"",
"rememberMe":false
}

Note remember has changed to rememberMe. It might be a red-herring but thought best to mention.

[Kane610]

Thanks. Will update

[jasperslits]

Problem is with cookie.

I inserted this logic on Cookie in line 79 of connectivity.py:

if (csrf_token := response.headers.get("x-csrf-token")) is not None:
                self.headers["x-csrf-token"] = csrf_token
                LOGGER.info("Token %s found", csrf_token)
if (cookie := response.headers.get("Set-Cookie")) is not None:
                self.headers["Cookie"] = cookie

Seems the x-csrf-token is not even needed (anymore) but the cookie is.

The call to ws_connect should also get the cookie passed on via headers=

  async with self.config.session.ws_connect(
                url, ssl=self.config.ssl_context, headers=self.headers, heartbeat=15, compress=12
            ) as websocket_connection:

The above changes made the problems go away. I dont know if making these changes break current / GA Unifi 3.2.x but it works for 4.0 so reluctant to make a PR for this

[Kane610]

I can try this out tomorrow

[jasperslits]

Note to self: turn off debugging of UniFi integration when the problem is solved. I got a notification from HA that there was 0% space left. 12GB of logs ate all available disk space.

[Kane610]

Tested and works with 3.2 so I will put up a patch

[Kane610]

Fix has been merged and marked for adding to 2024.5.1. Thank you very much for your work here <3 @jasperslits @lcollins