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

How many retries for invalid event? #169

Open
Swallowtail23 opened this issue Oct 6, 2024 · 13 comments
Open

How many retries for invalid event? #169

Swallowtail23 opened this issue Oct 6, 2024 · 13 comments

Comments

@Swallowtail23
Copy link

  • Unifi Protect Backup version:
    0.11.0
  • Unifi Protect version:
    5.0.34
  • Python version:
    As per container
  • Operating System:
    RHEL9
  • Are you using a docker container or native?:
    Docker

Description

For some reason my UNVR had a bit of a glitch yesterday and I had to hard reboot it (it lost comms to all cameras and the network).

After the reboot, UPB regained comms to the UNVR and resumed connection and working.

But, it ran into an issue with a missed evnt:

2024-10-06T01:25:30.730797298+10:00 stderr F 2024-10-05 15:25:30 [   DEBUG   ] unifi_protect_backup.missing_event_checker :  Running check for missing events...
2024-10-06T01:25:45.993875670+10:00 stderr F 2024-10-05 15:25:45 [  WARNING  ] unifi_protect_backup.missing_event_checker :   Found missing events, adding to backup queue
2024-10-06T01:25:45.995940847+10:00 stderr F 2024-10-05 15:25:45 [   INFO    ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Downloading event: 67013c77018cda03e401338e
2024-10-06T01:25:45.995990296+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Remaining Download Queue: 0
2024-10-06T01:25:45.996044505+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Video Download Buffer: 0.0B/1.5GiB
2024-10-06T01:25:45.996258722+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Camera: Patio Camera
2024-10-06T01:25:45.996301811+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Type: smartDetectZone (person)
2024-10-06T01:25:45.996362080+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Start: 2024-10-05T23-17-41 (1728134261.005)
2024-10-06T01:25:45.996413529+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    End: 2024-10-05T23-17-59 (1728134279.616)
2024-10-06T01:25:45.996454718+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Duration: 18.611s
2024-10-06T01:25:45.996514637+10:00 stderr F 2024-10-05 15:25:45 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Downloading video...
2024-10-06T01:30:45.999159173+10:00 stderr F 2024-10-05 15:30:45 [   DEBUG   ] unifi_protect_backup.missing_event_checker :  Running check for missing events...
2024-10-06T01:30:46.983414097+10:00 stderr F 2024-10-05 15:30:46 [  WARNING  ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]      Failed download attempt 1, retying in 1s
2024-10-06T01:30:46.983414097+10:00 stderr F Traceback (most recent call last):
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader.py", line 184, in _download
2024-10-06T01:30:46.983414097+10:00 stderr F     video = await self._protect.get_camera_video(event.camera_id, event.start, event.end)
2024-10-06T01:30:46.983414097+10:00 stderr F             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1411, in get_camera_video
2024-10-06T01:30:46.983414097+10:00 stderr F     return await self.export_camera_video(
2024-10-06T01:30:46.983414097+10:00 stderr F            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1333, in export_camera_video
2024-10-06T01:30:46.983414097+10:00 stderr F     return await self.api_request_raw(
2024-10-06T01:30:46.983414097+10:00 stderr F            ^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 239, in api_request_raw
2024-10-06T01:30:46.983414097+10:00 stderr F     response = await self._os.request(
2024-10-06T01:30:46.983414097+10:00 stderr F                ^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 378, in request
2024-10-06T01:30:46.983414097+10:00 stderr F     response = await req_context.__aenter__()  # noqa: PLC2801
2024-10-06T01:30:46.983414097+10:00 stderr F                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client.py", line 1197, in __aenter__
2024-10-06T01:30:46.983414097+10:00 stderr F     self._resp = await self._coro
2024-10-06T01:30:46.983414097+10:00 stderr F                  ^^^^^^^^^^^^^^^^
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client.py", line 608, in _request
2024-10-06T01:30:46.983414097+10:00 stderr F     await resp.start(conn)
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 971, in start
2024-10-06T01:30:46.983414097+10:00 stderr F     with self._timer:
2024-10-06T01:30:46.983414097+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/helpers.py", line 735, in __exit__
2024-10-06T01:30:46.983414097+10:00 stderr F     raise asyncio.TimeoutError from None
2024-10-06T01:30:46.983414097+10:00 stderr F TimeoutError

It retried every 5 minutes for 5 times with the same result, then giving this:

2024-10-06T02:17:11.984961721+10:00 stderr F 2024-10-05 16:17:11 [   ERROR   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Download failed after 5 attempts, abandoning event 67013c77018cda03e401338e:
2024-10-06T02:17:11.985304205+10:00 stderr F 2024-10-05 16:17:11 [  WARNING  ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Event failed download attempt 2
2024-10-06T02:17:11.985304205+10:00 stderr F Traceback (most recent call last):
2024-10-06T02:17:11.985304205+10:00 stderr F   File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader.py", line 145, in start
2024-10-06T02:17:11.985304205+10:00 stderr F     assert video is not None
2024-10-06T02:17:11.985304205+10:00 stderr F            ^^^^^^^^^^^^^^^^^
2024-10-06T02:17:11.985304205+10:00 stderr F AssertionError

Five hours later it "re-discovered" the missing event, and started the cycle again:

2024-10-06T07:06:37.012147272+10:00 stderr F 2024-10-05 21:06:37 [   DEBUG   ] unifi_protect_backup.missing_event_checker :  Running check for missing events...
2024-10-06T07:06:51.865179640+10:00 stderr F 2024-10-05 21:06:51 [  WARNING  ] unifi_protect_backup.missing_event_checker :   Found missing events, adding to backup queue
2024-10-06T07:06:51.868633995+10:00 stderr F 2024-10-05 21:06:51 [   INFO    ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Downloading event: 67013c77018cda03e401338e
2024-10-06T07:06:51.868672164+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Remaining Download Queue: 0
2024-10-06T07:06:51.868721803+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Video Download Buffer: 0.0B/1.5GiB
2024-10-06T07:06:51.868774743+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Camera: Patio Camera
2024-10-06T07:06:51.868814782+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Type: smartDetectZone (person)
2024-10-06T07:06:51.868873731+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Start: 2024-10-05T23-17-41 (1728134261.005)
2024-10-06T07:06:51.868929420+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    End: 2024-10-05T23-17-59 (1728134279.616)
2024-10-06T07:06:51.868970109+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Duration: 18.611s
2024-10-06T07:06:51.869026278+10:00 stderr F 2024-10-05 21:06:51 [   DEBUG   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]    Downloading video...
2024-10-06T07:11:51.872153993+10:00 stderr F 2024-10-05 21:11:51 [   DEBUG   ] unifi_protect_backup.missing_event_checker :  Running check for missing events...
2024-10-06T07:11:51.979580672+10:00 stderr F 2024-10-05 21:11:51 [  WARNING  ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]      Failed download attempt 1, retying in 1s
2024-10-06T07:11:51.979580672+10:00 stderr F Traceback (most recent call last):
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader.py", line 184, in _download
2024-10-06T07:11:51.979580672+10:00 stderr F     video = await self._protect.get_camera_video(event.camera_id, event.start, event.end)
2024-10-06T07:11:51.979580672+10:00 stderr F             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1411, in get_camera_video
2024-10-06T07:11:51.979580672+10:00 stderr F     return await self.export_camera_video(
2024-10-06T07:11:51.979580672+10:00 stderr F            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 1333, in export_camera_video
2024-10-06T07:11:51.979580672+10:00 stderr F     return await self.api_request_raw(
2024-10-06T07:11:51.979580672+10:00 stderr F            ^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/api.py", line 239, in api_request_raw
2024-10-06T07:11:51.979580672+10:00 stderr F     response = await self._os.request(
2024-10-06T07:11:51.979580672+10:00 stderr F                ^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/pyunifiprotect/session.py", line 378, in request
2024-10-06T07:11:51.979580672+10:00 stderr F     response = await req_context.__aenter__()  # noqa: PLC2801
2024-10-06T07:11:51.979580672+10:00 stderr F                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client.py", line 1197, in __aenter__
2024-10-06T07:11:51.979580672+10:00 stderr F     self._resp = await self._coro
2024-10-06T07:11:51.979580672+10:00 stderr F                  ^^^^^^^^^^^^^^^^
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client.py", line 608, in _request
2024-10-06T07:11:51.979580672+10:00 stderr F     await resp.start(conn)
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 971, in start
2024-10-06T07:11:51.979580672+10:00 stderr F     with self._timer:
2024-10-06T07:11:51.979580672+10:00 stderr F   File "/usr/lib/python3.12/site-packages/aiohttp/helpers.py", line 735, in __exit__
2024-10-06T07:11:51.979580672+10:00 stderr F     raise asyncio.TimeoutError from None
2024-10-06T07:11:51.979580672+10:00 stderr F TimeoutError

...again doing 5 attempts, an dfailing:

2024-10-06T07:32:00.982206998+10:00 stderr F 2024-10-05 21:32:00 [   ERROR   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Download failed after 5 attempts, abandoning event 67013c77018cda03e401338e:
2024-10-06T07:32:00.982598591+10:00 stderr F 2024-10-05 21:32:00 [  WARNING  ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Event failed download attempt 3
2024-10-06T07:32:00.982598591+10:00 stderr F Traceback (most recent call last):
2024-10-06T07:32:00.982598591+10:00 stderr F   File "/usr/lib/python3.12/site-packages/unifi_protect_backup/downloader.py", line 145, in start
2024-10-06T07:32:00.982598591+10:00 stderr F     assert video is not None
2024-10-06T07:32:00.982598591+10:00 stderr F            ^^^^^^^^^^^^^^^^^
2024-10-06T07:32:00.982598591+10:00 stderr F AssertionError

We are now up to the 7th attempt of 5 attempts:

2024-10-06T11:07:20.981481756+10:00 stderr F TimeoutError
2024-10-06T11:07:21.982828476+10:00 stderr F 2024-10-06 01:07:21 [   ERROR   ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Download failed after 5 attempts, abandoning event 67013c77018cda03e401338e:
2024-10-06T11:07:21.983163790+10:00 stderr F 2024-10-06 01:07:21 [  WARNING  ] unifi_protect_backup.downloader            : [67013c77018cda03e401338e]  Event failed download attempt 7

How do we make it actually GIVE UP on this clip? How many goes will it continue to do?

Comment too: the logging refers to a batch of 5 attempts as "download failed after 5 attempts" and then seems to do batches of those, with each batch also being referred to as a "download attempt". Am I reading that correctly? If so, perhaps referring to them as "Event failed download set 7" may be better?

What I Did

see comments above.

@ep1cman
Copy link
Owner

ep1cman commented Oct 6, 2024

The way it works is as follows

  • The downloader will attempt to download a file, it will try to do this up to 5 times in quick succession. The purpose of this is to work around temporary glitches, often caused by too much load on the NVR. If all of these fail, the event is discarded from the queue
  • The missing event checker will re-add the discarded events to the queue each time it runs.
  • If an event is discarded 10 times, it gets marked in the database to be permanently ignored and it will never be marked as missing by the missing event checker again

@Swallowtail23
Copy link
Author

Got it, thanks

@Swallowtail23
Copy link
Author

Swallowtail23 commented Dec 8, 2024

Hmm, something odd here, this one doesn't want to die:

2024-12-07T20:12:11.005405657+10:00 stderr F 2024-12-07 10:12:11 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T23:33:42.004659166+10:00 stderr F 2024-12-07 13:33:42 [   INFO    ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Downloading event: 67013ca3016ada03e40133c0
2024-12-07T23:33:42.004704196+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Remaining Download Queue: 16
2024-12-07T23:33:42.004756495+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Video Download Buffer: 0.0B/1.5GiB
2024-12-07T23:33:42.004814024+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Camera: Patio Camera
2024-12-07T23:33:42.004858013+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Type: smartDetectZone (person)
2024-12-07T23:33:42.004931082+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Start: 2024-10-05T23-18-24 (1728134304.984)
2024-12-07T23:33:42.004984401+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    End: 2024-10-05T23-18-41 (1728134321.761)
2024-12-07T23:33:42.005025771+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Duration: 16.777s
2024-12-07T23:33:42.005083450+10:00 stderr F 2024-12-07 13:33:42 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Downloading video...
2024-12-07T23:38:43.005867528+10:00 stderr F 2024-12-07 13:38:43 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 1, retying in 1s
2024-12-07T23:43:45.007421149+10:00 stderr F 2024-12-07 13:43:45 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 2, retying in 1s
2024-12-07T23:48:47.004011924+10:00 stderr F 2024-12-07 13:48:47 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 3, retying in 1s
2024-12-07T23:53:49.006608928+10:00 stderr F 2024-12-07 13:53:49 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 4, retying in 1s
2024-12-07T23:58:51.004616700+10:00 stderr F 2024-12-07 13:58:51 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 5, retying in 1s
2024-12-07T23:58:52.006253261+10:00 stderr F 2024-12-07 13:58:52 [   ERROR   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Download failed after 5 attempts, abandoning event 67013ca3016ada03e40133c0:
2024-12-07T23:58:52.006579396+10:00 stderr F 2024-12-07 13:58:52 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T03:20:13.005706949+10:00 stderr F 2024-12-07 17:20:13 [   INFO    ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Downloading event: 67013ca3016ada03e40133c0
2024-12-08T03:20:13.005751579+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Remaining Download Queue: 7
2024-12-08T03:20:13.005803178+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Video Download Buffer: 0.0B/1.5GiB
2024-12-08T03:20:13.005857637+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Camera: Patio Camera
2024-12-08T03:20:13.005913566+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Type: smartDetectZone (person)
2024-12-08T03:20:13.005973655+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Start: 2024-10-05T23-18-24 (1728134304.984)
2024-12-08T03:20:13.006024194+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    End: 2024-10-05T23-18-41 (1728134321.761)
2024-12-08T03:20:13.006066773+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Duration: 16.777s
2024-12-08T03:20:13.006126362+10:00 stderr F 2024-12-07 17:20:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Downloading video...
2024-12-08T03:25:14.003455230+10:00 stderr F 2024-12-07 17:25:14 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 1, retying in 1s
2024-12-08T03:30:16.006757861+10:00 stderr F 2024-12-07 17:30:16 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 2, retying in 1s
2024-12-08T03:35:18.005501194+10:00 stderr F 2024-12-07 17:35:18 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 3, retying in 1s
2024-12-08T03:40:20.005883121+10:00 stderr F 2024-12-07 17:40:20 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 4, retying in 1s
2024-12-08T03:45:22.004102204+10:00 stderr F 2024-12-07 17:45:22 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 5, retying in 1s
2024-12-08T03:45:23.005852305+10:00 stderr F 2024-12-07 17:45:23 [   ERROR   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Download failed after 5 attempts, abandoning event 67013ca3016ada03e40133c0:
2024-12-08T03:45:23.006192940+10:00 stderr F 2024-12-07 17:45:23 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T07:06:43.005619193+10:00 stderr F 2024-12-07 21:06:43 [   INFO    ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Downloading event: 67013ca3016ada03e40133c0
2024-12-08T07:06:43.005664962+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Remaining Download Queue: 7
2024-12-08T07:06:43.005719201+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Video Download Buffer: 0.0B/1.5GiB
2024-12-08T07:06:43.005775540+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Camera: Patio Camera
2024-12-08T07:06:43.005818740+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Type: smartDetectZone (person)
2024-12-08T07:06:43.005888479+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Start: 2024-10-05T23-18-24 (1728134304.984)
2024-12-08T07:06:43.005940218+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    End: 2024-10-05T23-18-41 (1728134321.761)
2024-12-08T07:06:43.005981527+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Duration: 16.777s
2024-12-08T07:06:43.006038556+10:00 stderr F 2024-12-07 21:06:43 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Downloading video...
2024-12-08T07:11:44.003851689+10:00 stderr F 2024-12-07 21:11:44 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 1, retying in 1s
2024-12-08T07:16:46.005978451+10:00 stderr F 2024-12-07 21:16:46 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 2, retying in 1s
2024-12-08T07:21:48.007977246+10:00 stderr F 2024-12-07 21:21:48 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 3, retying in 1s
2024-12-08T07:26:50.009121800+10:00 stderr F 2024-12-07 21:26:50 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 4, retying in 1s
2024-12-08T07:31:52.004740324+10:00 stderr F 2024-12-07 21:31:52 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 5, retying in 1s
2024-12-08T07:31:53.005402725+10:00 stderr F 2024-12-07 21:31:53 [   ERROR   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Download failed after 5 attempts, abandoning event 67013ca3016ada03e40133c0:
2024-12-08T07:31:53.005741530+10:00 stderr F 2024-12-07 21:31:53 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T10:53:13.005631050+10:00 stderr F 2024-12-08 00:53:13 [   INFO    ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Downloading event: 67013ca3016ada03e40133c0
2024-12-08T10:53:13.005677120+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Remaining Download Queue: 30
2024-12-08T10:53:13.005731079+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Video Download Buffer: 0.0B/1.5GiB
2024-12-08T10:53:13.005788318+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Camera: Patio Camera
2024-12-08T10:53:13.005832827+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Type: smartDetectZone (person)
2024-12-08T10:53:13.005902516+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Start: 2024-10-05T23-18-24 (1728134304.984)
2024-12-08T10:53:13.005953785+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    End: 2024-10-05T23-18-41 (1728134321.761)
2024-12-08T10:53:13.005995475+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Duration: 16.777s
2024-12-08T10:53:13.006054054+10:00 stderr F 2024-12-08 00:53:13 [   DEBUG   ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]    Downloading video...
2024-12-08T10:58:14.005131009+10:00 stderr F 2024-12-08 00:58:14 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 1, retying in 1s
2024-12-08T11:03:16.004047226+10:00 stderr F 2024-12-08 01:03:16 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 2, retying in 1s
2024-12-08T11:08:18.003885378+10:00 stderr F 2024-12-08 01:08:18 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 3, retying in 1s
2024-12-08T11:13:20.005036619+10:00 stderr F 2024-12-08 01:13:20 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]      Failed download attempt 4, retying in 1s

This is an extract from the log filtered on the event ID. Note how it keeps doing the 5 x times, but it's not incrementing the total discard attempts, it just keeps repeating:
Event failed download attempt 1

@Swallowtail23
Copy link
Author

If I grep for this event failing:

[root@emp90 log]# cat upb-0.11.0.log | grep 67013ca3016ada03e40133c0 | grep "Event failed download attempt"
2024-12-01T01:31:12.006133333+10:00 stderr F 2024-11-30 15:31:12 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-01T17:36:51.005379777+10:00 stderr F 2024-12-01 07:36:51 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-01T20:36:34.006422957+10:00 stderr F 2024-12-01 10:36:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-02T06:34:18.004900571+10:00 stderr F 2024-12-01 20:34:18 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 2
2024-12-02T10:20:56.009354806+10:00 stderr F 2024-12-02 00:20:56 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-02T14:07:26.008385348+10:00 stderr F 2024-12-02 04:07:26 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 2
2024-12-02T17:53:57.006263003+10:00 stderr F 2024-12-02 07:53:57 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 3
2024-12-02T21:40:28.005203218+10:00 stderr F 2024-12-02 11:40:28 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T01:27:03.007024264+10:00 stderr F 2024-12-02 15:27:03 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T05:13:34.006615396+10:00 stderr F 2024-12-02 19:13:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T09:00:04.005985053+10:00 stderr F 2024-12-02 23:00:04 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T12:46:34.006520226+10:00 stderr F 2024-12-03 02:46:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T16:33:04.009434886+10:00 stderr F 2024-12-03 06:33:04 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-03T20:19:40.006939360+10:00 stderr F 2024-12-03 10:19:40 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T00:06:11.007270600+10:00 stderr F 2024-12-03 14:06:11 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T03:52:42.006225890+10:00 stderr F 2024-12-03 17:52:42 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T07:39:12.009063345+10:00 stderr F 2024-12-03 21:39:12 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T11:25:43.028584936+10:00 stderr F 2024-12-04 01:25:43 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T15:12:14.009400125+10:00 stderr F 2024-12-04 05:12:14 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T18:58:47.009829458+10:00 stderr F 2024-12-04 08:58:47 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-04T22:45:19.010119708+10:00 stderr F 2024-12-04 12:45:19 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T02:31:49.009529557+10:00 stderr F 2024-12-04 16:31:49 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T06:18:20.007679294+10:00 stderr F 2024-12-04 20:18:20 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T10:04:50.004524526+10:00 stderr F 2024-12-05 00:04:50 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T13:51:21.009276072+10:00 stderr F 2024-12-05 03:51:21 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T17:37:55.006593287+10:00 stderr F 2024-12-05 07:37:55 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-05T21:24:26.005754471+10:00 stderr F 2024-12-05 11:24:26 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T01:11:00.007528983+10:00 stderr F 2024-12-05 15:11:00 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T04:57:30.005517526+10:00 stderr F 2024-12-05 18:57:30 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T08:44:00.006962709+10:00 stderr F 2024-12-05 22:44:00 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T12:30:34.006393650+10:00 stderr F 2024-12-06 02:30:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T16:17:21.062559915+10:00 stderr F 2024-12-06 06:17:21 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-06T20:03:51.007585953+10:00 stderr F 2024-12-06 10:03:51 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T01:18:46.004548383+10:00 stderr F 2024-12-06 15:18:46 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T05:05:32.006583671+10:00 stderr F 2024-12-06 19:05:32 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 2
2024-12-07T08:52:02.006167047+10:00 stderr F 2024-12-06 22:52:02 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 3
2024-12-07T12:38:32.010548961+10:00 stderr F 2024-12-07 02:38:32 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 4
2024-12-07T16:25:34.009592122+10:00 stderr F 2024-12-07 06:25:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T20:12:11.005405657+10:00 stderr F 2024-12-07 10:12:11 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T23:58:52.006579396+10:00 stderr F 2024-12-07 13:58:52 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T03:45:23.006192940+10:00 stderr F 2024-12-07 17:45:23 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T07:31:53.005741530+10:00 stderr F 2024-12-07 21:31:53 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-08T11:18:23.009103509+10:00 stderr F 2024-12-08 01:18:23 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
[root@emp90 log]# cat upb-0.11.0.log | grep 67013ca3016ada03e40133c0 | grep -c "Event failed download attempt"
43

So there are times it does increase the count (it got up to 4 on one occasion), but it resets and starts again.

In total it has now tried to get this event 215 times.

@Swallowtail23
Copy link
Author

Swallowtail23 commented Dec 8, 2024

This code:

                    if self._failures[event.id] >= 10:
                        self.logger.error(
                            "Event has failed to download 10 times in a row. Permanently ignoring this event"
                        )
                        await self._ignore_event(event)
                    continue

...has not been triggered at all:

[root@emp90 log]# cat upb-0.11.0.log | grep "Event has failed to download"
[root@emp90 log]#

OK, working through this...

The code has this timer:

self._failures = ExpiringDict(60 * 60 * 12)  # Time to live = 12h

So the problem here is that it's not trying the required number of times inside the timer:

2024-12-07T01:18:46.004548383+10:00 stderr F 2024-12-06 15:18:46 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1
2024-12-07T05:05:32.006583671+10:00 stderr F 2024-12-06 19:05:32 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 2
2024-12-07T08:52:02.006167047+10:00 stderr F 2024-12-06 22:52:02 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 3
2024-12-07T12:38:32.010548961+10:00 stderr F 2024-12-07 02:38:32 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 4
2024-12-07T16:25:34.009592122+10:00 stderr F 2024-12-07 06:25:34 [  WARNING  ] unifi_protect_backup.downloader            : [67013ca3016ada03e40133c0]  Event failed download attempt 1

It got to 4 inside that 12 hours, but then resets.

So either the timer needs to be configurable (longer), or the number of retries does, or the speed with which it retries.

As it stands at the moment, this code is going to keep on retrying to get these clips forever, and will never mark them as permanently unobtainable.

@Swallowtail23
Copy link
Author

@ep1cman - any ideas on this?

@Swallowtail23
Copy link
Author

OK.... radio silence all round here.
These missed events keep spitting the same messages, never reaching the required failures within 12h.
In absence of anyone having a way to configure the behaviour and fix the issue, does anyone know how to mark the events manually?

@ep1cman
Copy link
Owner

ep1cman commented Dec 13, 2024

Dude I have a life outside of GitHub. I'm sure you can figure out that December is a busy month for many folks. 5 days is not radio silence, I've been away for a week for my day job with zero time to even look at GitHub. Nagging me and making these sorts of comments gives me no motivation to look into your issue any faster. Please consider the human at the other end, and the fact this is not their job.

If you want to manually ignore an event, edit the sqlite file

@Swallowtail23
Copy link
Author

I apologise @ep1cman Sebastian, no offence was meant.

@ep1cman
Copy link
Owner

ep1cman commented Jan 6, 2025

While agree with your conclusion here, I don't understand how come it took so long for it to retry. The missing event checker is configured to check every 5 minutes. So what should occur is:

  • Get event
  • Attempt to download 5 times
  • Increment failure
  • Missing event checker runs at some point in the next 5 mins, finds missed event and re-adds it to the queue.
  • after 10 failures it is ignored

Assuming the intial 5 download failures take negligible time, this whole process should last no more that 100 minutes, well below 12h.

Are the logs above edited at all? Im surpised to not see the Found missing events, adding to backup queue message in them. 5 Hours is also a very strange interval between the retries

@Swallowtail23
Copy link
Author

The logs were grepped:
[root@emp90 log]# cat upb-0.11.0.log | grep 67013ca3016ada03e40133c0 | grep "Event failed download attempt"
I'll run through and get a full set.

@Swallowtail23
Copy link
Author

upb.txt
Attached an example of an event which took over 2 weeks to perma-fail. It incremented the fail counter 208 times in that duration, finally reaching 10 on day 16. 187 times it didn't get past 1.

Note there were other video events between these, this log file is grepped on the event id 67638d5d02d15003e400e033.

@ep1cman
Copy link
Owner

ep1cman commented Jan 17, 2025

Are you able to provide a non-grepped log? I am interested in seeing when the missing event checker is firing

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants