rfpludwick / unifi-phantom-clients-cleanup

Application to clean up phantom clients in the UniFi Controller
Apache License 2.0
3 stars 3 forks source link

Error determining UniFi unique ID #7

Open cblt2l opened 10 months ago

cblt2l commented 10 months ago

I'm running the Linuxserver.io Unifi controller container in docker on a Synology. The controller version is 7.5.174.

I cloned & built the latest from this repo, filled in the config file and when I try to run I get the following:

user@mypc ~/P/unifi-phantom-clients-cleanup (main)> ./unifi-phantom-clients-cleanup -verbose
Executing for host https://192.168.50.5:8443
Error determining UniFi unique ID

My config file looks like this:

---
version: "0.2"
httpLogDirectory: ""
sites:
  - host: "https://192.168.50.5:8443"
    site: "Default"
    username: "username"
    password: "password"
    udmp: false
    validateCertificate: false

Any idea what could be wrong? I figured there would be more output from the -verbose flag.

rfpludwick commented 10 months ago

Hi @cblt2l,

The line that's output from is 112 in main.go. I just pushed a new commit to main to log that HTTP call if the unique ID cannot be found. Please update the repo and run with httpLogDirectory in your config YAML set to a writeable directory on your host. After running, that directly should have HTTP call logs in it, including the log for that particular unique ID call if it fails. Hopefully that response body should have a clue in it. If you want additional help once you have that response body, feel free to post it here in this issue with sensitive information like usernames, etc. redacted.

cblt2l commented 10 months ago

I pulled latest from git and got this. I don't see anything obvious that would be causing the problem. Any ideas?

Request

&{Method:POST URL:https://192.168.50.5:8443/api/login Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Content-Type:[application/json]] Body:{Reader:} GetBody:0x65ffa0 ContentLength:53 TransferEncoding:[] Close:false Host:192.168.50.5:8443 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr: RequestURI: TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc0001a65b8}

Request Body

Response

&{Status:200  StatusCode:200 Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Access-Control-Allow-Credentials:[true] Access-Control-Expose-Headers:[Access-Control-Allow-Origin,Access-Control-Allow-Credentials] Content-Length:[30] Content-Type:[application/json;charset=UTF-8] Date:[Tue, 26 Sep 2023 21:04:01 GMT] Set-Cookie:[unifises=02x0Qj1dRoeG4HHwyyFvt4l5dEDdD7rh; Path=/; Secure; HttpOnly csrf_token=**REDACTED**; Path=/; Secure] Vary:[Origin] X-Frame-Options:[DENY]] Body:{Reader:} ContentLength:30 TransferEncoding:[] Close:false Uncompressed:false Trailer:map[] Request:0xc00021c000 TLS:0xc0001ee370}

Response Body

TLS

&{Version:771 HandshakeComplete:true DidResume:false CipherSuite:49199 NegotiatedProtocol: NegotiatedProtocolIsMutual:true ServerName: PeerCertificates:[0xc0001fc580] VerifiedChains:[] SignedCertificateTimestamps:[] OCSPResponse:[] TLSUnique:[**REDACTED**] ekm:0x616c00}
rfpludwick commented 10 months ago

You have your site as "Default" in caps - have you tried lowercasing that?

cblt2l commented 10 months ago

I tried "default" as well as "DEFAULT" with the same result. The actual site name is "Default" in the settings.

rfpludwick commented 10 months ago

At this point my guess is that there's a change in the 7.5.x controller version that breaks this utility. I'm still on 7.4.x. Once I upgrade to 7.5.x, I'll check to see if it's a version issue, and will circle back.

rfpludwick commented 9 months ago

@cblt2l I've upgraded my network controller to 7.5.x and tested; it doesn't appear to be an issue with the controller version. There's conditional logic in the utility based upon whether or not the network controller is running on a UniFi Dream Machine Pro device - that's what I suspect next is the issue. Perhaps the UniFi folks have changed some functionality for the controller when it isn't running on a UDM Pro.

What version of Go do you have installed?

cblt2l commented 9 months ago

This is the version I used to build. (Debian 12.1)

user@mypc:~$ go version
go version go1.19.8 linux/amd64
rfpludwick commented 9 months ago

@cblt2l I've tried building and executing via go version go1.19.8 linux/amd64 in a VSCode devcontainer and it still works as expected.

Can you post the entire contents of all files with logged HTTP calls (sensitive information redacted) and not just the most recent one? I this same error crops up, it should result in two logged files - the first one may have more information I need.

rfpludwick commented 9 months ago

I've now tested against network controller 7.5.187 which was just made available on my UDM Pro and everything still works as expected on that version as well.

cblt2l commented 9 months ago

@cblt2l I've tried building and executing via go version go1.19.8 linux/amd64 in a VSCode devcontainer and it still works as expected.

Can you post the entire contents of all files with logged HTTP calls (sensitive information redacted) and not just the most recent one? I this same error crops up, it should result in two logged files - the first one may have more information I need.

@rfpludwick When I run the compiled binary it only generates 1 log file in the local directory with a timestamp in the filename (ex. "2023-10-1919-15-48-0400.log")

I will try updating the controller via docker and see if that changes anything.

rfpludwick commented 9 months ago

I think I see an issue with the HTTP logging system. I'm going to make some adjustments there and when I publish the changes, I'll let you know for retesting.

rfpludwick commented 9 months ago

@cblt2l I've added logic to the logging to make sure that same-second HTTP calls don't get clobbered. If you update the repo and try again, you should hopefully have correct logs this time.

cblt2l commented 7 months ago

@rfpludwick

Apologies for the delay. I pulled the latest from git and rebuilt the go binary. There was 1 log file generated named "01-2023-12-1714-26-17-0500.log". The contents are below.

I have also updated my unifi controller to 8.0.7 and still see the same behavior as before.

Thanks.

Request

&{Method:POST URL:https://192.168.50.5:8443/api/login Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Content-Type:[application/json]] Body:{Reader:} GetBody:0x65ffa0 ContentLength:53 TransferEncoding:[] Close:false Host:192.168.50.5:8443 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr: RequestURI: TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc0001a65b8}

Request Body

{"username":"myusername","password":"mypassword"}

Response

&{Status:200  StatusCode:200 Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Access-Control-Allow-Credentials:[true] Access-Control-Expose-Headers:[Access-Control-Allow-Origin,Access-Control-Allow-Credentials] Content-Length:[30] Content-Type:[application/json;charset=UTF-8] Date:[Sun, 17 Dec 2023 19:26:19 GMT] Set-Cookie:[unifises=tMYWhZCIHnh67mOB7Mhkv9KHrmysiluO; Path=/; Secure; HttpOnly csrf_token=Xph4bpj9vlW31XQMrik4uNMJvFFRTm25; Path=/; Secure] Vary:[Origin] X-Frame-Options:[DENY]] Body:0xc000112080 ContentLength:30 TransferEncoding:[] Close:false Uncompressed:false Trailer:map[] Request:0xc00021c000 TLS:0xc0001ee370}

Response Body

{"meta":{"rc":"ok"},"data":[]}

TLS

&{Version:772 HandshakeComplete:true DidResume:false CipherSuite:4865 NegotiatedProtocol: NegotiatedProtocolIsMutual:true ServerName: PeerCertificates:[0xc0001fc580] VerifiedChains:[] SignedCertificateTimestamps:[] OCSPResponse:[] TLSUnique:[] ekm:0x614940}
rfpludwick commented 7 months ago

@cblt2l I'm a bit stumped here as to what the issue is. I took a brief look at the Docker image you're using and that's the only explanation I've got - it's that there's something awry in the UniFi Network Controller in that image. They say to migrate to a new version of the image anyhow.

Here's a log from the login auth on my UniFi Network Controller, which is the running on UniFi hardware:

Request

&{Method:POST URL:https://<hostname>/api/auth/login Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Content-Type:[application/json]] Body:{Reader:} GetBody:0x1046f8700 ContentLength:52 TransferEncoding:[] Close:false Host:<hostname> Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr: RequestURI: TLS:<nil> Cancel:<nil> Response:<nil> ctx:{emptyCtx:{}}}

Request Body

{"username":"username","password":"password"}

Response

&{Status:200 OK StatusCode:200 Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[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] Connection:[keep-alive] Content-Length:[7438] Content-Type:[application/json; charset=utf-8] Date:[Fri, 29 Dec 2023 22:06:28 GMT] Referrer-Policy:[no-referrer] Set-Cookie:[TOKEN=...; path=/; expires=Sat, 30 Dec 2023 00:06:28 GMT; samesite=none; secure; httponly] Strict-Transport-Security:[max-age=15552000; includeSubDomains] X-Content-Type-Options:[nosniff] X-Csrf-Token:[...] X-Dns-Prefetch-Control:[off] X-Frame-Options:[SAMEORIGIN] X-Response-Time:[327ms] X-Token-Expire-Time:[1703894788873] X-Updated-Csrf-Token:[...] X-Xss-Protection:[1; mode=block]] Body:0x14000092080 ContentLength:7438 TransferEncoding:[] Close:false Uncompressed:false Trailer:map[] Request:0x1400018a000 TLS:0x14000138370}

Response Body

{"id":"<redacted>","unique_id":"<redacted>","first_name":"<redacted>","last_name":"<redacted>","alias":"","full_name":"<redacted>","email":"<redacted>","user_email":"","radius_username":"","email_status":"VERIFIED","email_is_null":false,"phone":"","avatar_relative_path":"","avatar_rpath2":"","avatar_encoded":"","status":"ACTIVE","employee_number":"","create_time":1620278146,"extras":{},"login_time":1703880007,"username":"<redacted>","local_account_exist":true,"password_revision":1620281289,"only_ui_account":false,"only_local_account":false,"sso_account":"<redacted>","sso_uuid":"408e7c8c-9299-4743-a417-fe09e5cad900","sso_username":"<redacted>","sso_picture":"","uid_sso_id":"","uid_sso_account":"","uid_account_status":"","groups":[{"unique_id":"<redacted>","name":"UDMP","up_id":"","up_ids":null,"system_name":"UDMP","create_time":"2021-05-05T22:15:47-07:00"}],"roles":[{"unique_id":"<redacted>","name":"Owner","system_role":true,"system_key":"owner","level":1,"create_time":"2020-06-03T11:53:44-07:00","update_time":"2020-06-03T04:53:44-07:00","is_private":false}],"permissions":{"access.management":["admin"],"calculus.management":["admin"],"connect.management":["admin"],"drive.management":["admin"],"innerspace.management":["admin"],"led.management":["admin"],"network.management":["admin"],"olympus.management":["admin"],"protect.management":["admin"],"system.management.location":["admin"],"system.management.user":["admin"],"talk.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.display","write:protect.deviceGroup","write:protect.chime","write:protect.camera","write:protect.bridge","view:wifi","view:vpn","view:user_timezone","view:user","view:update","view:unifi-os:user","view:systemlog","view:system_info","view:sso","view:settings","view:role:viewer","view:role:admin","view:role","view:permission:viewer","view:permission:super_admin","view:permission:owner","view:permission:admin","view:permission","view:os-menu:user","view:os-menu:system-log","view:os-menu:storage","view:os-menu:settings","view:os-menu:notify-settings","view:os-menu:map","view:os-menu:devices","view:os-menu:about","view:organization_info","view:notification","view:location_policy","view:location_device","view:location_activity","view:location","view:holiday_timezone","view:holiday","view:group","view:door_group","view:controller:uid-agent","view:controller:talk","view:controller:protect","view:controller:olympus","view:controller:network","view:controller:led","view:controller:innerspace","view:controller:drive","view:controller:connect","view:controller:calculus","view:controller:access","view:controller","view:cloud_access","view:backup","view:app:users","view:app:uid-agent","view:app:settings","view:app:locations","view:access:user","view:access.visitor","view:access.systemlog","view:access.settings","view:access.schedule","view:access.policy","view:access.pin_code","view:access.nfc_card","view:access.face","view:access.device","view:access.dashboard","update:access.device","systemlog:user","systemlog:system","systemlog:network","systemlog:location","systemlog:connect","systemlog:access","readmedia: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.display","read:protect.deviceGroup","read:protect.chime","read:protect.camera","read:protect.bridge","open:door","notify:user","notify:talk","notify:protect","notify:network","notify:location","notify:led","notify:access","manage:controller:talk","manage:controller:protect","manage:controller:olympus","manage:controller:network","manage:controller:led","manage:controller:innerspace","manage:controller:drive","manage:controller:connect","manage:controller:calculus","manage:controller:access","manage:controller","edit:wifi","edit:vpn","edit:user_timezone","edit:user_credential","edit:user","edit:update","edit:unifi-os:user_group","edit:unifi-os:user","edit:transfer_ownership","edit:systemlog","edit:system_info","edit:sso","edit:settings","edit:role:viewer","edit:role:admin","edit:role","edit:permission:viewer","edit:permission:super_admin","edit:permission:owner","edit:permission:admin","edit:permission","edit:os-settings:update_install","edit:os-settings:update_channel","edit:os-settings:transfer_owner","edit:os-settings:support_file","edit:os-settings:ssh","edit:os-settings:send_diagnostics","edit:os-settings:restart","edit:os-settings:reset","edit:os-settings:remote_access","edit:os-settings:raid","edit:os-settings:poweroff","edit:os-settings:notify","edit:os-settings:hotspare","edit:os-settings:general","edit:os-settings:client_network","edit:os-settings:backup","edit:os-settings:auto_update","edit:organization_info","edit:notification","edit:location_policy","edit:location_device","edit:location_activity","edit:location","edit:holiday_timezone","edit:holiday","edit:group","edit:feedback","edit:door_group","edit:controller:uid-agent","edit:cloud_access","edit:backup","edit:access:user","edit:access.visitor","edit:access.settings","edit:access.schedule","edit:access.policy","edit:access.pin_code","edit:access.nfc_card","edit:access.face","edit:access.device","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.display","delete:protect.deviceGroup","delete:protect.chime","delete:protect.camera","delete:protect.bridge","delete:access.device","credential:send_email","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.display","create:protect.deviceGroup","create:protect.chime","create:protect.camera","create:protect.bridge","cloud_access:system","cloud_access:controller","assign:wifi","assign:vpn","assign:role_super_admin","assign:role:viewer","assign:role:admin","assign:role","assign:evstation","adopt:access.device","access.open_door:location","access.open_door:floor","access.open_door:door_group","access.open_door:door","access.open_door:building"],"cloud_access_granted":true,"update_time":1703886071,"need_popup_ids_introduce":true,"avatar":null,"nfc_token":"","nfc_display_id":"","nfc_card_type":"","nfc_card_status":"","invalid_wg_ip":false,"role":"owner","roleId":"<redacted>","isOwner":true,"isSuperAdmin":true,"isMember":false,"maskedEmail":"<redacted>","accessMask":2014,"permissionMask":16382,"ucorePermission":{"hasUpdateAndInstallPermission":true},"deviceToken":"<redacted>","ssoAuth":{}}

TLS

&{Version:771 HandshakeComplete:true DidResume:false CipherSuite:49200 NegotiatedProtocol: NegotiatedProtocolIsMutual:true ServerName:<hostname> PeerCertificates:[0x14000187080 0x14000187600 0x14000187b80] VerifiedChains:[[0x14000188100 0x14000188680 0x14000188c00]] SignedCertificateTimestamps:[] OCSPResponse:[] TLSUnique:[108 116 52 12 71 104 71 128 219 152 38 154] ekm:0x104695ac0}

I'm not completely sure if the auth flows for UniFi Network Controller are different when they're not running on UniFi hardware, or even specific hardware. Can you give it a try on the newer version of the LinuxServer.io image?