fronzbot/blinkpy

Save recent clips local - Error when multiple videos

d4icon opened this issue · 4 comments

Describe the bug
When the camera records several videos in a row in a short period of time, if I call save_recent_clips too soon, it does not download all the videos, only the first one recorded.

That is to say, to reproduce the error you have to:

1º - I record video.
2º - I call blink_update
2023-03-28 14:57:58.149 INFO (SyncWorker_5) [blinkpy.camera] 'Input' has 1 clips available for download.
3rd - I call save_recent_clips:
2023-03-28 14:58:08.700 INFO (SyncWorker_9) [blinkpy.camera] Saved 1 of 1 recent clips from 'Entrada' to directory /config/tmp/.

Immediately another video is recorded:
3rd another video is recorded
4th I call blink_update
2023-03-28 14:58:55.745 INFO (SyncWorker_11) [blinkpy.sync_module] Found 1 new clip(s) in local storage manifest id=809
5º - save_recent_clips: ->And now I get this message:
2023-03-28 14:58:55.824 INFO (SyncWorker_11) [blinkpy.sync_module] No new local storage videos since last manifest read at 2023-03-28 14:57:47.633854+02:00.

And I lose the video forever (well not entering the application, of course).
But the plugin doesn't detect it anymore.

On the other hand if I wait long enough without calling blink_update, and then call save_recent_clips, it works.

The problem is that I need it to work the other way, since I have an automation so that when my mobile receives the Amazon blink notification, it forces the "blink_update" in HA and then use save_recent_clips to download the video as quickly as possible.

Log Output/Additional Information

2023-03-28 14:57:53.292 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v3/accounts/11750/homescreen
2023-03-28 14:57:53.391 DEBUG (SyncWorker_5) [blinkpy.blinkpy] Attempting refresh of blink.sync['DaiconBlink']
2023-03-28 14:57:53.391 DEBUG (SyncWorker_5) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/network/11681/update
2023-03-28 14:57:53.506 DEBUG (SyncWorker_5) [blinkpy.sync_module] Updating local storage manifest
2023-03-28 14:57:53.506 DEBUG (SyncWorker_5) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request
2023-03-28 14:57:53.620 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request/484715690
2023-03-28 14:57:53.702 DEBUG (SyncWorker_5) [blinkpy.sync_module] [retry=1] Retrying in 3 seconds
2023-03-28 14:57:57.364 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request/484715690
2023-03-28 14:57:57.459 INFO (SyncWorker_5) [blinkpy.sync_module] Found 1 new clip(s) in local storage manifest id=809
2023-03-28 14:57:57.461 DEBUG (SyncWorker_5) [blinkpy.sync_module] Checking for new videos
2023-03-28 14:57:57.461 DEBUG (SyncWorker_5) [blinkpy.sync_module] last_refresh = 2023-03-28 14:54:52
2023-03-28 14:57:57.461 DEBUG (SyncWorker_5) [blinkpy.sync_module] interval=1680008032
2023-03-28 14:57:57.461 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/media/changed?since=2023-03-28T12:53:52+0000&page=1
2023-03-28 14:57:57.528 DEBUG (SyncWorker_5) [blinkpy.sync_module] last_manifest_read = 2023-03-28 09:24:56.701217
2023-03-28 14:57:57.528 DEBUG (SyncWorker_5) [blinkpy.sync_module] Manifest ready? True
2023-03-28 14:57:57.529 DEBUG (SyncWorker_5) [blinkpy.sync_module] Processing updated manifest
2023-03-28 14:57:57.529 DEBUG (SyncWorker_5) [blinkpy.sync_module] Checking 'Entrada': clip_time=2023-03-28T12:57:08+00:00, manifest_read=2023-03-28T09:24:56.701217
2023-03-28 14:57:57.529 DEBUG (SyncWorker_5) [blinkpy.sync_module] Found new item in local storage manifest: LocalStorageMediaItem(id=1655407788, camera_name=Entrada, created_at=2023-03-28 12:57:08+00:00, size=1836, manifest_id=809, url_template=/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/$manifest_id/clip/request/$clip_id)
2023-03-28 14:57:57.529 DEBUG (SyncWorker_5) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:57:57.633 DEBUG (SyncWorker_5) [blinkpy.sync_module] Checking 'Entrada': clip_time=2023-03-28T09:24:20+00:00, manifest_read=2023-03-28T09:24:56.701217
2023-03-28 14:57:57.633 INFO (SyncWorker_5) [blinkpy.sync_module] Found 1 new items in local storage manifest since last manifest read at 2023-03-28 11:24:56.701217+02:00.
2023-03-28 14:57:57.633 DEBUG (SyncWorker_5) [blinkpy.sync_module] Updated last_manifest_read to 2023-03-28T12:57:47.633854
2023-03-28 14:57:57.633 DEBUG (SyncWorker_5) [blinkpy.sync_module] Last clip time was 2023-03-28 12:57:08+00:00
2023-03-28 14:57:57.633 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/network/11681/camera/12218/config
2023-03-28 14:57:57.743 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/network/11681/camera/12218/signals
2023-03-28 14:57:57.820 DEBUG (SyncWorker_5) [blinkpy.camera] Found 1 recent clips for Entrada
2023-03-28 14:57:57.820 DEBUG (SyncWorker_5) [blinkpy.camera] Most recent clip for Entrada was created at 2023-03-28T12:57:08+00:00: https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:57:57.820 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v3/media/accounts/11750/networks/11681/catalina/12218/thumbnail/thumbnail.jpg?ts=1679054660&ext=
2023-03-28 14:57:57.970 DEBUG (SyncWorker_5) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:57:58.149 INFO (SyncWorker_5) [blinkpy.camera] 'Entrada' has 1 clips available for download
2023-03-28 14:57:58.149 DEBUG (SyncWorker_5) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:57:58.325 DEBUG (SyncWorker_5) [blinkpy.blinkpy] last_refresh=2023-03-28 14:57:58
2023-03-28 14:58:08.333 DEBUG (SyncWorker_9) [blinkpy.camera] Saving https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788 to /config/tmp/20230328_145708_Entrada.mp4
2023-03-28 14:58:08.333 DEBUG (SyncWorker_9) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:58:08.700 DEBUG (SyncWorker_9) [blinkpy.camera] Removed {'time': '2023-03-28T12:57:08+00:00', 'clip': 'https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788'} from recent clips
2023-03-28 14:58:08.700 INFO (SyncWorker_9) [blinkpy.camera] Saved 1 of 1 recent clips from 'Entrada' to directory /config/tmp/
2023-03-28 14:58:51.666 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v3/accounts/11750/homescreen
2023-03-28 14:58:51.799 DEBUG (SyncWorker_11) [blinkpy.blinkpy] Attempting refresh of blink.sync['DaiconBlink']
2023-03-28 14:58:51.800 DEBUG (SyncWorker_11) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/network/11681/update
2023-03-28 14:58:51.919 DEBUG (SyncWorker_11) [blinkpy.sync_module] Updating local storage manifest
2023-03-28 14:58:51.919 DEBUG (SyncWorker_11) [blinkpy.api] Making POST request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request
2023-03-28 14:58:52.031 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request/484716546
2023-03-28 14:58:52.109 DEBUG (SyncWorker_11) [blinkpy.sync_module] [retry=1] Retrying in 3 seconds
2023-03-28 14:58:55.632 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/request/484716546
2023-03-28 14:58:55.745 INFO (SyncWorker_11) [blinkpy.sync_module] Found 1 new clip(s) in local storage manifest id=809
2023-03-28 14:58:55.745 DEBUG (SyncWorker_11) [blinkpy.sync_module] Checking for new videos
2023-03-28 14:58:55.745 DEBUG (SyncWorker_11) [blinkpy.sync_module] last_refresh = 2023-03-28 14:57:58
2023-03-28 14:58:55.745 DEBUG (SyncWorker_11) [blinkpy.sync_module] interval=1680008218
2023-03-28 14:58:55.745 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/media/changed?since=2023-03-28T12:56:58+0000&page=1
2023-03-28 14:58:55.823 DEBUG (SyncWorker_11) [blinkpy.sync_module] last_manifest_read = 2023-03-28 12:57:47.633854
2023-03-28 14:58:55.823 DEBUG (SyncWorker_11) [blinkpy.sync_module] Manifest ready? True
2023-03-28 14:58:55.823 DEBUG (SyncWorker_11) [blinkpy.sync_module] Processing updated manifest
2023-03-28 14:58:55.824 DEBUG (SyncWorker_11) [blinkpy.sync_module] Checking 'Entrada': clip_time=2023-03-28T12:57:35+00:00, manifest_read=2023-03-28T12:57:47.633854
2023-03-28 14:58:55.824 INFO (SyncWorker_11) [blinkpy.sync_module] No new local storage videos since last manifest read at 2023-03-28 14:57:47.633854+02:00.
2023-03-28 14:58:55.824 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/network/11681/camera/12218/config
2023-03-28 14:58:55.933 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/network/11681/camera/12218/signals
2023-03-28 14:58:56.031 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v3/media/accounts/11750/networks/11681/catalina/12218/thumbnail/thumbnail.jpg?ts=1679054660&ext=
2023-03-28 14:58:56.154 DEBUG (SyncWorker_11) [blinkpy.api] Making GET request to https://rest-e007.immedia-semi.com/api/v1/accounts/11750/networks/11681/sync_modules/15765/local_storage/manifest/809/clip/request/1655407788
2023-03-28 14:58:56.317 DEBUG (SyncWorker_11) [blinkpy.blinkpy] last_refresh=2023-03-28 14:58:56
2023-03-28 14:58:59.039 WARNING (SyncWorker_6) [msmart.device.AC.appliance] Got Null from 192.168.1.46:6444 Version: 3 Count: 0 Spend time: 5.01
2023-03-28 14:59:06.323 INFO (SyncWorker_11) [blinkpy.camera] No recent clips to save for 'Entrada'.

stale commented

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within seven days. Thank you for your contributions.

stale commented

This issue is now being closed due to inactivity.

Could you please provide your script for downloading local files?
I don't get it working...

Sorry didn't see this issue before

The problem is that I need it to work the other way, since I have an automation so that when my mobile receives the Amazon blink notification, it forces the "blink_update" in HA and then use save_recent_clips to download the video as quickly as possible

Yeah pre-0.22.0 there is no way to do what you want without adding appropriate delays between refreshes. Everything is synchronous so if the refresh happens as the clip is still being still being saved, you won't be able to download. This may be fixed with the newer version of blinkpy==0.22.0 but I'm not totally sure. It has been migrated to use pythons asyncio library which also means there's some script updates required if you choose to migrate to this new version (see the README for some examples)

EDIT- if you stick with the non-async version, I've noticed about 5s between a refresh and a call to download videos as being sufficient.