core icon indicating copy to clipboard operation
core copied to clipboard
Published 1 week ago • verified publisher icon home-assistant

Unifi Protect: errors when getting snapshots

Open sellison2 opened this issue 8 months ago • 20 comments

The problem

With the new update to the UI Port you can pair multiple cameras. I have paired 5 cameras with mine, and now the snapshots that show up in the picture glance cards on my dashboard are blank most of the time. I enabled debug logging and it looks like it's getting an error when retrieving the snapshots. Unfortunately the error reason isn't getting passed along into the debug logs. The attached error message gets repeated, once per camera, each time it fails to get a snapshot. Sometimes one or two of the cameras will be successful, but then they'll go back to failing.

It's more likely this is an issue with Ubiquiti and not with Home Assistant, but I wanted to report this so:

  1. Other people with the issue know it's not just them,
  2. Someone could confirm there's nothing wrong with the API calls, or that could be done better, and
  3. Maybe we could figure out the error that's coming back from the NVR so we can create a bug ticket with Ubiquiti instead.

What version of Home Assistant Core has the issue?

core-2025.4.0

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Unifi Protect

Link to integration documentation on our website

https://www.home-assistant.io/integrations/unifiprotect

Diagnostics information

No response

Example YAML snippet

Anything in the logs that might be useful for us?

2025-04-09 17:04:05.362 DEBUG (MainThread) [uiprotect.api] Request failed: https://192.168.0.**/proxy/protect/api/cameras/638ff2950236f003e41f1fe7/snapshot?ts=1744243445031&force=true&w=473&h=266 - Status: 500 - Reason:

Additional information

No response

sellison2 avatar Apr 10 '25 00:04 sellison2

Hey there @rahehl, mind taking a look at this issue as it has been labeled with an integration (unifiprotect) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of unifiprotect can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign unifiprotect Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

unifiprotect documentation unifiprotect source (message by IssueLinks)

home-assistant[bot] avatar Apr 10 '25 00:04 home-assistant[bot]

Which Cams and which encoding?

RaHehl avatar Apr 10 '25 21:04 RaHehl

One of the cameras is a G4 Doorbell Pro using enhanced encoding. The 4 others are all G3 Instants, those only support standard encoding.

sellison2 avatar Apr 10 '25 23:04 sellison2

I too am seeing this issue, after adding an AI Port to my unifi setup. I have 4 cameras, a G4 doorbell, 2x G5 turret ultras and a AI Bullet Pro. The g4 doorbell and the g5 turrets are configured to use the AI Port, and its those where I get the errors. From the logs, I noted the errors are only logged when extra query parameters are used, if that gives any one clues:

2025-05-02 11:22:32.689 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:22:32.577 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:22:32.572 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:22:32.568 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:22:22.701 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181342579&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:22:22.579 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:22:22.575 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:22:22.570 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:22:12.716 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181332580&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:22:12.580 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:22:12.575 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:22:12.567 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:22:02.706 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181322576&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:22:02.576 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:22:02.571 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:22:02.567 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:52.820 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181312574&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:21:52.575 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:21:52.569 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:21:52.564 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:42.802 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot?ts=1746181302574&force=true&w=996&h=492 - Status: 500 - Reason: 
2025-05-02 11:21:42.579 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:21:42.575 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:42.570 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:21:32.964 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181292832&force=true&w=996&h=560 - Status: 500 - Reason: 
2025-05-02 11:21:32.832 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:21:32.828 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:21:32.823 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:22.707 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181282580&force=true&w=996&h=560 - Status: 500 - Reason: 
2025-05-02 11:21:22.580 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:21:22.575 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot
2025-05-02 11:21:22.571 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:12.289 DEBUG (MainThread) [uiprotect.api] Request failed: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181272119&force=true&w=996&h=560 - Status: 500 - Reason: 
2025-05-02 11:21:12.119 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot
2025-05-02 11:21:12.115 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot
2025-05-02 11:21:12.110 DEBUG (MainThread) [uiprotect.api] Request url: https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66ce0e45028a9f03e4003583/snapshot

I tried that URL directly in my browser (and using curl in a loop) to see if I could get more of the error message, but it loaded correctly there.

tomwilkie avatar May 02 '25 10:05 tomwilkie

Got the debug logs from unifi protect, and this seem to correlate with the first entry above:

2025-05-02T10:22:32.630Z - error: Fetch snapshot task error Request 'GetRequest' rejected. Non-zero status code. MESSAGE_ID: 273002 
Error: Request 'GetRequest' rejected. Non-zero status code. MESSAGE_ID: 273002
    at v.rejectRequest (/usr/share/unifi-protect/app/webpack:/unifi-protect/src/middleware/cameras/avclient/UVCServer/Connection.ts:227:19)
    at v.onWSMessage (/usr/share/unifi-protect/app/webpack:/unifi-protect/src/middleware/cameras/avclient/UVCServer/Connection.ts:325:23)
    at WebSocket.emit (node:events:519:28)
    at WebSocket.emit (node:domain:488:12)
    at Receiver.receiverOnMessage (/usr/share/unifi-protect/app/node_modules/ws/lib/websocket.js:1211:20)
    at Receiver.emit (node:events:519:28)
    at Receiver.emit (node:domain:488:12)
    at Receiver.dataMessage (/usr/share/unifi-protect/app/node_modules/ws/lib/receiver.js:567:14)
    at Receiver.getData (/usr/share/unifi-protect/app/node_modules/ws/lib/receiver.js:496:10)
    at Receiver.startLoop (/usr/share/unifi-protect/app/node_modules/ws/lib/receiver.js:167:16)
    at Receiver._write (/usr/share/unifi-protect/app/node_modules/ws/lib/receiver.js:94:10)
    at writeOrBuffer (node:internal/streams/writable:564:12)
    at _write (node:internal/streams/writable:493:10)
    at Receiver.Writable.write (node:internal/streams/writable:502:10)
    at TLSSocket.socketOnData (/usr/share/unifi-protect/app/node_modules/ws/lib/websocket.js:1305:35)
    at TLSSocket.emit (node:events:519:28)
[metadata]: {
  "code": 1
}
2025-05-02T10:22:32.631Z - info: Sending REST snapshot request for AI Port [942A6FECC89A @ 192.168.3.112].
2025-05-02T10:22:32.679Z - error: Error with REST snapshot request Camera API request failed: https://192.168.3.112/api/1.2/snapshot. Camera responded with a status code of 404 
Error: Camera API request failed: https://192.168.3.112/api/1.2/snapshot. Camera responded with a status code of 404
    at IncomingMessage.<anonymous> (/usr/share/unifi-protect/app/webpack:/unifi-protect/src/middleware/cameras/api/request.js:130:25)
    at IncomingMessage.emit (node:events:531:35)
    at IncomingMessage.emit (node:domain:488:12)
    at endReadableNT (node:internal/streams/readable:1696:12)
    at processTicksAndRejections (node:internal/process/task_queues:82:21)
2025-05-02T10:22:32.681Z - error: Fetch snapshot task error Camera API request failed: https://192.168.3.112/api/1.2/snapshot. Camera responded with a status code of 404 
Error: Camera API request failed: https://192.168.3.112/api/1.2/snapshot. Camera responded with a status code of 404
    at IncomingMessage.<anonymous> (/usr/share/unifi-protect/app/webpack:/unifi-protect/src/middleware/cameras/api/request.js:130:25)
    at IncomingMessage.emit (node:events:531:35)
    at IncomingMessage.emit (node:domain:488:12)
    at endReadableNT (node:internal/streams/readable:1696:12)
    at processTicksAndRejections (node:internal/process/task_queues:82:21)

tomwilkie avatar May 02 '25 10:05 tomwilkie

And from the AI Port logs themselves, I can see:

May  2 18:22:32 genio-700-ai-port-pro-4G ubnt_cgi[3740]: Invalid cookie ' HttpOnly' [ubnt_cgi:ubnt_cgi.cpp:Parse:177] 
May  2 18:22:32 genio-700-ai-port-pro-4G rest_snapshot[3740]: File /usr/www/snap.jpeg does not exist or is not a file [ubnt_cgi:rest_snapshot.cpp:rest_snapshot_main:82]

(NB timezone seems to be off on this device, but i think this is the right timestamp)

tomwilkie avatar May 02 '25 10:05 tomwilkie

Apparently, snapshot behaves differently with an AI port in between (https://github.com/home-assistant/core/issues/143476#issuecomment-2833414519) — I'll take a look at that.

RaHehl avatar May 02 '25 12:05 RaHehl

@tomwilkie In the meantime, could you please check the user's permissions? The TS parameter could be a problem, for example, with live only.

RaHehl avatar May 02 '25 12:05 RaHehl

With a G4 Bullet with AI Port, I don't get the errors. Can you describe your setup in more detail, especially the software versions?

RaHehl avatar May 02 '25 12:05 RaHehl

@tomwilkie In the meantime, could you please check the user's permissions? The TS parameter could be a problem, for example, with live only.

I have a "homeassistant" user setup in unifi, and its a superadmin - so I assume that has permission to do anything.

tomwilkie avatar May 02 '25 12:05 tomwilkie

With a G4 Bullet with AI Port, I don't get the errors. Can you describe your setup in more detail, especially the software versions?

UniFi OS Status Version Release Channel Auto Update
UDM Pro Max Up to Date 4.1.22 Official On
Application Status Version Release Channel Auto Update
Network Up to Date 9.1.120 Official On
Protect Up to Date 5.3.45 Official On
Image

tomwilkie avatar May 02 '25 13:05 tomwilkie

Oh and home assistant:

Core 2025.4.4
Supervisor 2025.04.1
Operating System 15.2
Frontend 20250411.0

tomwilkie avatar May 02 '25 13:05 tomwilkie

I have a theory: its a race conditioning in snapshotting in the ai port. I notice that when the dashboard refreshes (a dashboard containing two panels that use the ai port), one panel always fails. But when I have a dashboard with only one panel, it always works.

I'll see if I can reproduce this with my curl script.

tomwilkie avatar May 02 '25 13:05 tomwilkie

Reproduced with attached script - running one in a loop vs trying to simultaneously fetch both:

% bash curl.sh "https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492" 

Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492
Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492
Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492
Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492
...

% bash curl.sh "https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492" "https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot?ts=1746181352577&force=true&w=996&h=492"

Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66c32a59021b9f03e40003f3/snapshot?ts=1746181352577&force=true&w=996&h=492
Polling https://XXXXXX.id.ui.direct/proxy/protect/api/cameras/66d496900305b203e4000501/snapshot?ts=1746181352577&force=true&w=996&h=492
500
  
curl.sh: line 73: 74805 Terminated: 15          ( while :; do
    echo "Polling ${urls[$i]}"; response=$(curl -s -w "\n%{http_code}"       -b "TOKEN=$TOKEN"       "${urls[$i]}"); http_code=$(printf "%s" "$response" | tail -n1); body=$(printf "%s" "$response" | sed '$d'); if [ "$http_code" -ne 200 ]; then
        printf "%s\n %s\n" "$http_code" "$body" > "${tmpfiles[$i]}"; exit 0;
    fi; sleep 1;
done )

The script (made by cursor):

#!/usr/bin/env bash

# Usage: ./poll_until_error.sh <URL1> <URL2>
# Polls each URL every second in parallel, discarding output while HTTP status is 200.
# When either returns a non-200 status, prints that response body and exits.

set -uo pipefail

if [ "$#" -lt 1 ]; then
  echo "Usage: $0 <URL1> [<URL2> ...]"
  exit 1
fi

urls=("$@")

declare -a pids

declare -a tmpfiles

# Start polling in background for each URL
for i in "${!urls[@]}"; do
  tmpfiles[$i]=$(mktemp)
  (
    while :; do
      echo "Polling ${urls[$i]}"
      # Perform the request: capture body and status code
      response=$(curl -s -w "\n%{http_code}" \
      -b "TOKEN=$TOKEN" \
      "${urls[$i]}")
      http_code=$(printf "%s" "$response" | tail -n1)
      body=$(printf "%s" "$response" | sed '$d')

      if [ "$http_code" -ne 200 ]; then
        # Found non-200: save body to tmp file and exit
        printf "%s\n %s\n" "$http_code"  "$body" > "${tmpfiles[$i]}"
        exit 0
      fi

      sleep 1
    done  
  ) &
  pids[$i]=$!
done

# Wait for any of the background jobs to finish
while :; do
  for pid in "${pids[@]}"; do
    if ! kill -0 "$pid" 2>/dev/null; then
      finished_pid=$pid
      break 2
    fi
  done
  sleep 0.1
done

# Print the response body from the finished job
finished_index=""
for i in "${!pids[@]}"; do
  if [ "$finished_pid" -eq "${pids[$i]}" ]; then
    finished_index=$i
    break
  fi
done

if [ -n "$finished_index" ]; then
  cat "${tmpfiles[$finished_index]}"
fi

# Clean up: kill remaining job(s) and remove temp files
for pid in "${pids[@]}"; do
  kill "$pid" 2>/dev/null || true
done
rm -f "${tmpfiles[@]}"

tomwilkie avatar May 02 '25 14:05 tomwilkie

@RaHehl you mentioned in the other issue a way to open bugs with unifi - any pointers here? I'll go and open this with them.

tomwilkie avatar May 02 '25 14:05 tomwilkie

Oh wow, I just saw that they really put some obstacles in the way with this AI chat. I'm having issues in the Protect web app as well — see the screenshot." Image

RaHehl avatar May 02 '25 14:05 RaHehl

maybe related to the doorbell that's special because it has 2 cams

RaHehl avatar May 02 '25 15:05 RaHehl

@RaHehl you mentioned in the other issue a way to open bugs with unifi - any pointers here? I'll go and open this with them.

Only through regular support — and the hardest mission is getting past first-level support.

RaHehl avatar May 02 '25 15:05 RaHehl

@tomwilkie I updated my UNVR to the latest EA release earlier. I'm currently not experiencing the issue — are you still encountering it?

I’ve since received a response from UI who wanted to take a look at it, but I’m currently not experiencing the issue anymore :/

RaHehl avatar May 07 '25 19:05 RaHehl

Just to give a quick update: I think the issue is now in good hands with the UI team. The problem still occurs randomly on my end and seems to be clearly related to the AI port. I was also able to find some entries in the error log, which I’ve forwarded and hopefully will help in resolving the issue.

RaHehl avatar May 12 '25 19:05 RaHehl

Thanks @RaHehl! I haven't had a chance to update and try the latest release. I switched to the live stream for my dashboards to avoid this problem.

tomwilkie avatar May 13 '25 09:05 tomwilkie

fixed by ubiquiti

RaHehl avatar May 25 '25 20:05 RaHehl

@home-assistant close

RaHehl avatar May 25 '25 20:05 RaHehl

For what it's worth, I'm on Protect 5.3.48, NVR OS 4.2.12, and AI Port 4.75.9 and the problem is very much not solved. But I do agree it's a Ubiquiti problem and not a home assistant problem so this can remain closed.

sellison2 avatar Jun 04 '25 01:06 sellison2