Closed cyberpower678 closed 1 month ago
I'm not sure about the first error where it was unauthorised but the second one means UniFi protect returned a blank file when you requested to download an event.
It has always done this occasionally but I've been seeing it more often with recent updates. I'm not really sure what else we can do except retry which the tool already does
Might be related to other pull requests that were merged which fixed auths?
Will it re-attempt the abandoned events eventually?
It will retry in 10 minutes by default I believe
I'm not sure about the first error where it was unauthorised but the second one means UniFi protect returned a blank file when you requested to download an event.
UniFi OS has a really strict rate limit for auth. It returns a 401 for unauthorized and rate limit issues. You need to make sure cached sessions are being used so it is not trying to re-auth each time, especially if the API client connects/creates a new session more than once every 30 minutes.
Regarding empty downloads, https://github.com/AngellusMortis/pyunifiprotect/pull/397 might help resolve it. Either way, it’s how it’s done on the new versions of UniFi Protect which could mean the existing method will be dropped at some point.
I'm not sure about the first error where it was unauthorised but the second one means UniFi protect returned a blank file when you requested to download an event.
UniFi OS has a really strict rate limit for auth. It returns a 401 for unauthorized and rate limit issues. You need to make sure cached sessions are being used so it is not trying to re-auth each time, especially if the API client connects/creates a new session more than once every 30 minutes.
@AngellusMortis Thanks for letting me know about this. Since I am only using a single instance of ProtectApiClient
across the whole program, would that mean that it is always using the same cached session or is there more that needs to be done to ensure this?
@cyberpower678 Your pr looks promising, please let me know when it is merged and I can add a different downloader as an experimental option that can be enabled to see if it improves this. How bad is the +/- a few seconds on the generated clips? It occassionally happens with the current method but when it does occur almost always its longer than requested. I think ive only seen a handful of short events get returned in my setup.
I’m just waiting on him to approve or request changes. Hopefully soon.
@ep1cman I don't suppose you'd be willing to fashion up a Docker tag that pulls my fork of the pyunifiprotect library. Aside from my changes, it should be up to date otherwise. Would like to really test the unifi-protect-backup with this patch.
You could do docker exec to get a shell into the container and update the version of pyunifiprotect inside to be yours, then just restart the container
Won't work on TrueNAS. It will just redeploy the image/tag.
Ok I'll see what I can do
Ok there should now be a 'experimental' docker tag thats added the new experimental downloader using this. You will need to set the EXPERIMENTAL_DOWNLOADER
env var to true.
I suspect you might hit the bug beign discussed in #151, let me know if you do. I will work on that next
When trying to run the experimental tag and env variable I get the following upon spinning the container up:
unifi-protect-backup The requested image's platform (linux/arm64) does not match the detected host platform (linux/amd64/v1) and no specific platform was requested
I tried to force it to linux/amd64 and received:
image with reference ghcr.io/ep1cman/unifi-protect-backup:experimental was found but does not match the specified platform: wanted linux/amd64, actual: linux/arm64
Whoops, forgot to also build x86. I'll sort this out later today
Let me know when this is fixed, I have the container ready to deploy.
x86 build published
experimental downloader does not appear to work on 4.0.27
😔
2024-06-07 11:05:42 [ INFO ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Downloading event: 666140ac03101d03e4000a5e
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Remaining Download Queue: 60
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Video Download Buffer: 0.0B/512.0MiB
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Camera: Backyard G4 Bullet
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Type: smartDetectZone (person)
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Start: 2024-06-06T14-52-58 (1717649578.143)
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] End: 2024-06-06T14-53-28 (1717649608.939)
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Duration: 30.796s
2024-06-07 11:05:42 [ DEBUG ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Downloading video...
2024-06-07 11:05:42 [ WARNING ] unifi_protect_backup.downloader_experimental : [666140ac03101d03e4000a5e] Event failed download attempt 1
Traceback (most recent call last):
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 144, in start
video = await self._download(event)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 184, in _download
prepared_video_file = await self._protect.prepare_camera_video(event.camera_id, event.start, event.end)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1273, in prepare_camera_video
return await self.api_request(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 274, in api_request
data = await self.api_request_raw(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 249, in api_request_raw
await self._os.verify_response(url, response)
File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 332, in verify_response
raise NotAuthorized(msg % (url, response.status, reason))
pyunifiprotect.exceptions.NotAuthorized: Request failed: /proxy/protect/api/video/prepare - Status: 401 - Reason: {'code': 401, 'message': 'Unauthorized'}
@AngellusMortis We seem to be hitting the 401 issue you mentioned. I've spent some time looking at how you've used ProtectApiClient
but can't see what I am doing differently. As far as I can tell store_sessions
is set by default, so it should be re-using the cached sessions. However when I check the file on disk it is empty, so I am doing something wrong.
Do you have any advice?
I have run the Pyunifiprotect library on my local machine using a test script and it's communicating with my UNVR just fine. No 401 issues. prepare/download is also working as expected. So it's highly likely this is an issue with the unifi-protect-backup environment.
Make sure you are defining cache_dir when instantiating ProtectApiClient, it doesn't seem like you are.
@cyberpower678, I managed to track down the cause of the 401 issues, which you can see explained here: https://github.com/AngellusMortis/pyunifiprotect/issues/401
Still working on a work around
It would stand to reason that once the ProtectAPIClient has successfully connected, the session will remain persistent while the container is active? If that is the case, maybe just running the protect_client.update() command repeatedly, while backing off might be the most effective workaround, until it gets a session going?
That is what I had thought I initially but it turns out there is an is_authenticated method that checks if the token from the cookie has been set and if it hasn't (because UniFi now send out a cookie entry python counts as invalid currently) it considers it not authenticated and redoes the authentication on every request which quickly starts getting 401 responses as unfi rate limits the authentication requests
If you you know how to fix and want to push a fix to my fork which should propagate to the experimental, presumably, I'll approve the pull and fix the build issue checks.
Please try the latest experimental
container. I have forked from your fork, as it made more sense for this to depend on a repo I own rather than a thirdy pary one.
Still getting a 401
2024-06-08 06:40:07 [ DEBUG ] unifi_protect_backup.missing_event_checker : Running check for missing events... 2024-06-08 06:40:09 [ ERROR ] unifi_protect_backup.missing_event_checker : Unexpected exception occurred during missing event check: Traceback (most recent call last): File "/usr/lib/python3.12/site-packages/unifi_protect_backup/missing_event_checker.py", line 151, in start async for event in self._get_missing_events(): File "/usr/lib/python3.12/site-packages/unifi_protect_backup/missing_event_checker.py", line 65, in _get_missing_events events_chunk = await self._protect.get_events( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 786, in get_events response = await self.get_events_raw( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 745, in get_events_raw return await self.api_request_list("events", params=params) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 316, in api_request_list data = await self.api_request( ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 274, in api_request data = await self.api_request_raw( ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 249, in api_request_raw await self._os.verify_response(url, response) File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 332, in verify_response raise NotAuthorized(msg % (url, response.status, reason)) pyunifiprotect.exceptions.NotAuthorized: Request failed: /proxy/protect/api/events - Status: 401 - Reason: {'code': 401, 'message': 'Unauthorized'}
Seems to me, it's using the site package and not your fork.
my bad, forgot to point it to the correct brach. Hopefully now its fixed!
Now we're ripping. No download errors either.
Decided to nuke the sqlite DB so it can start from scratch. Not one single error right now. No blank downloads. Paradise. Now we just need both of our fixes to make their way to pyunifiprotect repo.
I am still seeing a few errors when using the experimental downloader:
2024-06-10 18:50:46 [ DEBUG ] unifi_protect_backup.missing_event_checker : Running check for missing events...
2024-06-10 18:50:48 [ WARNING ] unifi_protect_backup.missing_event_checker : Found missing events, adding to backup queue
2024-06-10 18:50:48 [ INFO ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading event: 6660e73b002cc703e4093573
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Remaining Download Queue: 0
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Video Download Buffer: 0.0B/512.0MiB
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Camera: West Approach
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Type: motion
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Start: 2024-06-05T16-31-16 (1717626676.8)
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] End: 2024-06-05T16-31-28 (1717626688.81)
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Duration: 12.01s
2024-06-10 18:50:48 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading video...
2024-06-10 18:50:49 [ WARNING ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Event failed download attempt 4
Traceback (most recent call last):
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 144, in start
video = await self._download(event)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 184, in _download
prepared_video_file = await self._protect.prepare_camera_video(event.camera_id, event.start, event.end)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1273, in prepare_camera_video
return await self.api_request(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 274, in api_request
data = await self.api_request_raw(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 249, in api_request_raw
await self._os.verify_response(url, response)
File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 348, in verify_response
raise NvrError(msg % (url, response.status, reason))
pyunifiprotect.exceptions.NvrError: Request failed: /proxy/protect/api/video/prepare - Status: 500 - Reason:
2024-06-10 18:55:49 [ DEBUG ] unifi_protect_backup.missing_event_checker : Running check for missing events...
2024-06-10 18:55:52 [ WARNING ] unifi_protect_backup.missing_event_checker : Found missing events, adding to backup queue
2024-06-10 18:55:52 [ INFO ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading event: 6660e73b002cc703e4093573
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Remaining Download Queue: 0
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Video Download Buffer: 0.0B/512.0MiB
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Camera: West Approach
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Type: motion
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Start: 2024-06-05T16-31-16 (1717626676.8)
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] End: 2024-06-05T16-31-28 (1717626688.81)
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Duration: 12.01s
2024-06-10 18:55:52 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading video...
2024-06-10 18:55:52 [ WARNING ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Event failed download attempt 5
Traceback (most recent call last):
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 144, in start
video = await self._download(event)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 184, in _download
prepared_video_file = await self._protect.prepare_camera_video(event.camera_id, event.start, event.end)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1273, in prepare_camera_video
return await self.api_request(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 274, in api_request
data = await self.api_request_raw(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 249, in api_request_raw
await self._os.verify_response(url, response)
File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 348, in verify_response
raise NvrError(msg % (url, response.status, reason))
pyunifiprotect.exceptions.NvrError: Request failed: /proxy/protect/api/video/prepare - Status: 500 - Reason:
2024-06-10 19:00:53 [ DEBUG ] unifi_protect_backup.missing_event_checker : Running check for missing events...
2024-06-10 19:00:55 [ WARNING ] unifi_protect_backup.missing_event_checker : Found missing events, adding to backup queue
2024-06-10 19:00:55 [ INFO ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading event: 6660e73b002cc703e4093573
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Remaining Download Queue: 0
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Video Download Buffer: 0.0B/512.0MiB
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Camera: West Approach
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Type: motion
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Start: 2024-06-05T16-31-16 (1717626676.8)
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] End: 2024-06-05T16-31-28 (1717626688.81)
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Duration: 12.01s
2024-06-10 19:00:55 [ DEBUG ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Downloading video...
2024-06-10 19:00:55 [ WARNING ] unifi_protect_backup.downloader_experimental : [6660e73b002cc703e4093573] Event failed download attempt 6
Traceback (most recent call last):
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 144, in start
video = await self._download(event)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader_experimental.py", line 184, in _download
prepared_video_file = await self._protect.prepare_camera_video(event.camera_id, event.start, event.end)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1273, in prepare_camera_video
return await self.api_request(
^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 274, in api_request
data = await self.api_request_raw(
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 249, in api_request_raw
await self._os.verify_response(url, response)
File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 348, in verify_response
raise NvrError(msg % (url, response.status, reason))
pyunifiprotect.exceptions.NvrError: Request failed: /proxy/protect/api/video/prepare - Status: 500 - Reason:
I am not sure if this is from the previous que that was having trouble before (it stacked up pretty high). It looks like by in large however the vast majority of the downloads work (all but this one really). It may be a different issue all together seeing as it's a 500 error now?
My experience on the matter is that the downloader is running so fast the UDM occasionally doesn’t keep up hence the 500 meaning an internal server error happened. Simply reattempting them by restarting the queue should clear those out and pull any still missing. My queue is sitting at 0 missing events.
it killed it after 10 tries and just ignored it. For whatever reason it was just that one video with the problem. Its been smooth sailing the past 45min. no errors.
It should retry immediately a few times, and then fall back and try again when the missing event checker fires. It will do this upto 5 or 10 times (I don't recall exactly) and if all of those attempts (25, or 50 in total) it will just give up on the event and ignore it.
Some times I've noticed UniFi protect will just fail to record an event. You can try open them in the WebUI and they just don't play
Description
Getting sporadic and random download failures. About 50% hit or miss when downloading videos.
What I Did
I restarted the UNVR and the docker and force pulled a new image.