Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Only half of the videos are actually downloading, the other half are failing to. #150

Open
cyberpower678 opened this issue May 21, 2024 · 35 comments
Labels
help wanted Extra attention is needed

Comments

@cyberpower678
Copy link
Contributor

  • Unifi Protect Backup version: no idea, I don't see any version on the docker's log output. I pull the latest image when deploying.
  • Unifi Protect version: 4.0.19
  • Python version: Whatever's on the Docker
  • Operating System: Whatever's on the Docker, host is Debian based TrueNAS
  • Are you using a docker container or native?: Docker

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.

2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :  Config:
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    address='unvr.th.cybercloudhub.org'
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    port=443
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    username='unifiprotectbackupagent'
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    password=REDACTED
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    verify_ssl=False
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    rclone_destination='local:/data'
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    retention=relativedelta(months=+2)
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    rclone_args=''
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    rclone_purge_args=''
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    ignore_cameras=()
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    verbose=1
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    detection_types=['motion', 'person', 'vehicle', 'ring']
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    file_structure_format='{camera_name}/{event.start:%Y-%m-%d}/{event.start:%Y-%m-%dT%H-%M-%S} {detection_type}.mp4'
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    sqlite_path='/config/database/events.sqlite'
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    download_buffer_size=8.0GiB
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    purge_interval=relativedelta(days=+1)
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    apprise_notifiers=()
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    skip_missing=False
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    download_rate_limit=None events per minute
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :    max_event_length=7200s
2024-05-22 06:22:43 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :  Starting...
2024-05-22 06:22:43 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :  Checking rclone configuration...
2024-05-22 06:22:43 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :  rclone found: /usr/bin/rclone
2024-05-22 06:22:43 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :  Connecting to Unifi Protect...
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :  Found cameras:
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07102a16503e70003f7: Interior Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07102706503e70003f5: Back Yard Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07101fc6503e70003ee: Garage Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07102516503e70003f3: Front Door Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07102886503e70003f6: Server Room Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc07102196503e70003ef: Left Yard Camera
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :   - 65ddc071022e6503e70003f0: Right Yard Camera
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :  NVR TZ: Asia/Bangkok
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.unifi_protect_backup_core :  Local TZ: +07
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            :  ffprobe found: /usr/bin/ffprobe
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.unifi_protect_backup_core :  Starting Tasks...
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.downloader            :  Starting Downloader
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.uploader              :  Starting Uploader
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.event_listener        :  Subscribed to websocket
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.missing_event_checker :  Starting Missing Event Checker
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.missing_event_checker :  Running check for missing events...
2024-05-22 06:22:45 [  WARNING  ] unifi_protect_backup.missing_event_checker :   Found missing events, adding to backup queue
2024-05-22 06:22:45 [   INFO    ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]  Downloading event: 661b4a170261cf03e4101899
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]  Remaining Download Queue: 311
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]  Video Download Buffer: 0.0B/8.0GiB
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Camera: Front Door Camera
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Type: smartDetectZone (vehicle)
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Start: 2024-04-14T10-14-29 (1713064469.226)
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    End: 2024-04-14T10-14-37 (1713064477.466)
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Duration: 8.24s
2024-05-22 06:22:45 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Downloading video...
2024-05-22 06:22:46 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Downloaded video size: 8.1MiBs
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]    Downloaded video length: 10.250s(+2.010s)
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661b4a170261cf03e4101899]  Added to upload queue
2024-05-22 06:22:47 [   INFO    ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]  Downloading event: 661e54c40024cf03e4125898
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]  Remaining Download Queue: 733
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]  Video Download Buffer: 8.1MiB/8.0GiB
2024-05-22 06:22:47 [   INFO    ] unifi_protect_backup.uploader              : [661b4a170261cf03e4101899]  Uploading event: 661b4a170261cf03e4101899
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.uploader              : [661b4a170261cf03e4101899]   Remaining Upload Queue: 0 (0.0B)
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.uploader              : [661b4a170261cf03e4101899]   Destination: local:/data/Front Door Camera/2024-04-14/2024-04-14T10-14-29 smartDetectZone (vehicle).mp4
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Camera: Right Yard Camera
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Type: smartDetectZone (person)
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Start: 2024-04-16T17-36-49 (1713263809.641)
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    End: 2024-04-16T17-37-06 (1713263826.021)
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Duration: 16.38s
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Downloading video...
2024-05-22 06:22:47 [   DEBUG   ] unifi_protect_backup.uploader              : [661b4a170261cf03e4101899]  Uploaded
2024-05-22 06:22:48 [   ERROR   ] unifi_protect_backup.missing_event_checker :  Unexpected exception occurred during missing event check:
Traceback (most recent call last):
  File "/usr/lib/python3.11/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.11/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.11/site-packages/pyunifiprotect/api.py", line 935, in get_events
    response = await self.get_events_raw(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyunifiprotect/api.py", line 894, in get_events_raw
    return await self.api_request_list("events", params=params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyunifiprotect/api.py", line 400, in api_request_list
    data = await self.api_request(
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyunifiprotect/api.py", line 358, in api_request
    data = await self.api_request_raw(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/pyunifiprotect/api.py", line 333, in api_request_raw
    raise NotAuthorized(msg % (url, response.status, reason))
pyunifiprotect.exceptions.NotAuthorized: Request failed: /proxy/protect/api/events - Status: 401 - Reason: {'code': 401, 'message': 'Unauthorized'}
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Downloaded video size: 9.1MiBs
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]    Downloaded video length: 18.250s(+1.870s)
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661e54c40024cf03e4125898]  Added to upload queue
2024-05-22 06:22:48 [   INFO    ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]  Downloading event: 661be0db0064cf03e4108744
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]  Remaining Download Queue: 1231
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]  Video Download Buffer: 9.1MiB/8.0GiB
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    Camera: Front Door Camera
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    Type: smartDetectZone (vehicle)
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    Start: 2024-04-14T20-57-44 (1713103064.732)
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    End: 2024-04-14T20-57-51 (1713103071.334)
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    Duration: 6.602s
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]    Downloading video...
2024-05-22 06:22:48 [   INFO    ] unifi_protect_backup.uploader              : [661e54c40024cf03e4125898]  Uploading event: 661e54c40024cf03e4125898
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.uploader              : [661e54c40024cf03e4125898]   Remaining Upload Queue: 0 (0.0B)
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.uploader              : [661e54c40024cf03e4125898]   Destination: local:/data/Right Yard Camera/2024-04-16/2024-04-16T17-36-49 smartDetectZone (person).mp4
2024-05-22 06:22:48 [   DEBUG   ] unifi_protect_backup.uploader              : [661e54c40024cf03e4125898]  Uploaded
2024-05-22 06:22:49 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]      Failed download attempt 1, retying in 1s
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 185, in _download
    assert isinstance(video, bytes)
AssertionError
2024-05-22 06:22:50 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]      Failed download attempt 2, retying in 1s
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 185, in _download
    assert isinstance(video, bytes)
AssertionError
2024-05-22 06:22:51 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]      Failed download attempt 3, retying in 1s
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 185, in _download
    assert isinstance(video, bytes)
AssertionError
2024-05-22 06:22:53 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]      Failed download attempt 4, retying in 1s
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 185, in _download
    assert isinstance(video, bytes)
AssertionError
2024-05-22 06:22:54 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]      Failed download attempt 5, retying in 1s
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 185, in _download
    assert isinstance(video, bytes)
AssertionError
2024-05-22 06:22:55 [   ERROR   ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]  Download failed after 5 attempts, abandoning event 661be0db0064cf03e4108744:
2024-05-22 06:22:55 [  WARNING  ] unifi_protect_backup.downloader            : [661be0db0064cf03e4108744]  Event failed download attempt 1
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/unifi_protect_backup/downloader.py", line 145, in start
    assert video is not None
           ^^^^^^^^^^^^^^^^^
AssertionError
@ep1cman
Copy link
Owner

ep1cman commented May 22, 2024

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

@cyberpower678
Copy link
Contributor Author

Might be related to other pull requests that were merged which fixed auths?

@cyberpower678
Copy link
Contributor Author

Will it re-attempt the abandoned events eventually?

@ep1cman
Copy link
Owner

ep1cman commented May 22, 2024

It will retry in 10 minutes by default I believe

@AngellusMortis
Copy link

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.

@cyberpower678
Copy link
Contributor Author

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.

@ep1cman
Copy link
Owner

ep1cman commented May 27, 2024

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.

@cyberpower678
Copy link
Contributor Author

I’m just waiting on him to approve or request changes. Hopefully soon.

@cyberpower678
Copy link
Contributor Author

@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.

@ep1cman
Copy link
Owner

ep1cman commented Jun 4, 2024

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

@cyberpower678
Copy link
Contributor Author

Won't work on TrueNAS. It will just redeploy the image/tag.

@ep1cman
Copy link
Owner

ep1cman commented Jun 4, 2024

Ok I'll see what I can do

@ep1cman
Copy link
Owner

ep1cman commented Jun 5, 2024

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

@mmolitor87
Copy link
Contributor

mmolitor87 commented Jun 6, 2024

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

@ep1cman
Copy link
Owner

ep1cman commented Jun 6, 2024

Whoops, forgot to also build x86. I'll sort this out later today

@cyberpower678
Copy link
Contributor Author

Let me know when this is fixed, I have the container ready to deploy.

@ep1cman
Copy link
Owner

ep1cman commented Jun 6, 2024

x86 build published

@hydazz
Copy link

hydazz commented Jun 7, 2024

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'}

@ep1cman
Copy link
Owner

ep1cman commented Jun 7, 2024

@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?

@ep1cman ep1cman added the help wanted Extra attention is needed label Jun 7, 2024
@cyberpower678
Copy link
Contributor Author

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.

@cyberpower678
Copy link
Contributor Author

Make sure you are defining cache_dir when instantiating ProtectApiClient, it doesn't seem like you are.

@ep1cman
Copy link
Owner

ep1cman commented Jun 7, 2024

@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

@cyberpower678
Copy link
Contributor Author

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?

@ep1cman
Copy link
Owner

ep1cman commented Jun 7, 2024

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

@cyberpower678
Copy link
Contributor Author

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.

@ep1cman
Copy link
Owner

ep1cman commented Jun 7, 2024

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.

@cyberpower678
Copy link
Contributor Author

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'}

@cyberpower678
Copy link
Contributor Author

Seems to me, it's using the site package and not your fork.

@ep1cman
Copy link
Owner

ep1cman commented Jun 7, 2024

my bad, forgot to point it to the correct brach. Hopefully now its fixed!

@cyberpower678
Copy link
Contributor Author

Now we're ripping. No download errors either.

@cyberpower678
Copy link
Contributor Author

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.

@wssweb
Copy link

wssweb commented Jun 10, 2024

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?

@cyberpower678
Copy link
Contributor Author

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.

@wssweb
Copy link

wssweb commented Jun 10, 2024

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.

@ep1cman
Copy link
Owner

ep1cman commented Jun 10, 2024

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
help wanted Extra attention is needed
Projects
None yet
Development

No branches or pull requests

6 participants