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

Can frigate recover from this? (Unable to create clip for .... There were no cache files for this event) #1406

Closed
rhatguy opened this issue Jul 19, 2021 · 12 comments
Labels

Comments

@rhatguy
Copy link

rhatguy commented Jul 19, 2021

I have frigate running on an RPi4 with an externally powered USB hub and a SSD for clips. I have 4 reolink cams (4 wired and 1 wireless). From time to time I'll notice that frigate sends me a notification (through home assistant) that a person was detected on a particular camera, but there is no event for it and no clip inside frigate. Previously I've just restarted frigate and everything has started back working so I've just chalked it up to some weirdness with my reolink cameras, but today I investigated and noticed something odd. Upon checking the frigate web gui all 5 of my cameras have up to date timestamps indicating they're still streaming just fine, but no events were created when I came home today, and I also got a notification of someone at my front door with no picture attached. I noticed that no events have been created for some time inside frigate even though I know they've been happening.

Completely ignoring WHY what I describe below is happening, my first thought was, how can I detect that /tmp/cache files are not being updated and trigger a restart of frigate. It seems like a cache file being older than a few minutes or maybe an hour is a dead giveaway that something is wrong. Is there anything inside frigate that should be catching this type of issue and/or automatically restarting the frigate processes for that camera? Any recommendations on how to detect these "dead" cameras and restart them automatically?

  1. Frigate is throwing regular events stating that there were no cache files for an event.
    frigate.events WARNING : Unable to create clip for driveway_cam and event 1626706592.809362-wqhv92. There were no cache files for this event.
    frigate.events WARNING : Unable to create clip for driveway_cam and event 1626706655.222137-82ikf4. There were no cache files for this event.
    frigate.events WARNING : Unable to create clip for driveway_cam and event 1626706656.498177-6a8upy. There were no cache files for this event.
    frigate.events WARNING : Unable to create clip for driveway_cam and event 1626706685.919663-8bpxs0. There were no cache files for this event.
    frigate.events WARNING : Unable to create clip for driveway_cam and event 1626706686.17994-o9otj2. There were no cache files for this event.
    frigate.events WARNING : Unable to create clip for garage_cam and event 1626706691.75816-qedh2y. There were no cache files for this event.

  2. The capture processes are still running inside the docker container.
    root@5f7a72846d53:/opt/frigate# ps -ef | egrep -i ffmpeg
    root 63 45 0 Jul12 ? 00:04:14 ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.75/bcs/channel0_main.bcs?channel=0&stream=0&user=xxxxx&password=xxxxxxx -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/front_door_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/front_door_cam
    root 69 46 4 Jul12 ? 07:19:36 ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.76/bcs/channel0_main.bcs?channel=0&stream=0&user=xxxxx&password=xxxxxxx -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/garage_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/garage_cam
    root 76 54 0 Jul12 ? 00:04:20 ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.74/bcs/channel0_main.bcs?channel=0&stream=0&user=xxxxx&password=xxxxxxx -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/back_porch_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/back_porch_cam
    root 2689 53 3 Jul18 ? 00:37:12 ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtsp://xxxxx:xxxxxx@backyard_cam.travisandliz.com:554/h264Preview_01_main -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/backyard_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/backyard_cam
    root 9367 53 2 Jul18 ? 00:43:56 ffmpeg -analyzeduration 1000M -probesize 1000M -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtsp://xxxxx:xxxxxxx@backyard_cam.travisandliz.com:554/h264Preview_01_sub -r 4 -f rawvideo -pix_fmt yuv420p pipe:
    root 9382 46 2 Jul18 ? 00:47:06 ffmpeg -analyzeduration 1000M -probesize 1000M -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.76/bcs/channel0_sub.bcs?channel=0&stream=0&user=xxxxx&password=xxxxx -r 4 -f rawvideo -pix_fmt yuv420p pipe:
    root 9384 49 2 Jul18 ? 00:55:03 ffmpeg -analyzeduration 1000M -probesize 1000M -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.77/bcs/channel0_sub.bcs?channel=0&stream=0&user=xxxxx&password=xxxxx -r 4 -f rawvideo -pix_fmt yuv420p pipe:
    root 12877 54 2 02:01 ? 00:15:22 ffmpeg -analyzeduration 1000M -probesize 1000M -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.74/bcs/channel0_sub.bcs?channel=0&stream=0&user=xxxxx&password=xxxxx -r 4 -f rawvideo -pix_fmt yuv420p pipe:
    root 12887 45 2 02:01 ? 00:15:26 ffmpeg -analyzeduration 1000M -probesize 1000M -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.75/bcs/channel0_sub.bcs?channel=0&stream=0&user=xxxxx&password=xxxxx -r 4 -f rawvideo -pix_fmt yuv420p pipe:
    root 20714 49 0 Jul17 ? 00:20:06 ffmpeg -hide_banner -loglevel warning -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -fflags nobuffer -use_wallclock_as_timestamps 1 -flags low_delay -strict experimental -i rtmp://10.1.1.77/bcs/channel0_main.bcs?channel=0&stream=0&user=xxxxx&password=xxxxx -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/driveway_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/driveway_cam

  3. No new files are being created inside /tmp/cache inside docker for 4 of the cameras while 1 is still working.
    root@5f7a72846d53:/tmp/cache# ls -l
    total 117572
    -rw-r--r-- 1 root root 6291504 Jul 12 02:00 back_porch_cam-20210712015956.mp4
    -rw-r--r-- 1 root root 10486957 Jul 19 17:36 backyard_cam-20210719173619.mp4
    -rw-r--r-- 1 root root 10488757 Jul 19 17:36 backyard_cam-20210719173629.mp4
    -rw-r--r-- 1 root root 10490212 Jul 19 17:36 backyard_cam-20210719173639.mp4
    -rw-r--r-- 1 root root 10489060 Jul 19 17:36 backyard_cam-20210719173649.mp4
    -rw-r--r-- 1 root root 10488895 Jul 19 17:37 backyard_cam-20210719173659.mp4
    -rw-r--r-- 1 root root 10490167 Jul 19 17:37 backyard_cam-20210719173709.mp4
    -rw-r--r-- 1 root root 10489975 Jul 19 17:37 backyard_cam-20210719173719.mp4
    -rw-r--r-- 1 root root 10487480 Jul 19 17:37 backyard_cam-20210719173729.mp4
    -rw-r--r-- 1 root root 10488510 Jul 19 17:37 backyard_cam-20210719173739.mp4
    -rw-r--r-- 1 root root 8126512 Jul 19 17:37 backyard_cam-20210719173749.mp4
    -rw-r--r-- 1 root root 8126512 Jul 18 02:00 driveway_cam-20210718015953.mp4
    -rw-r--r-- 1 root root 2883632 Jul 12 02:00 front_door_cam-20210712020008.mp4
    -rw-r--r-- 1 root root 524336 Jul 18 02:00 garage_cam-20210718020008.mp4
    root@5f7a72846d53:/tmp/cache# df -h /tmp/cache
    Filesystem Size Used Avail Use% Mounted on
    tmpfs 954M 113M 842M 12% /tmp/cache

@mitchross
Copy link
Contributor

#1388

@rhatguy
Copy link
Author

rhatguy commented Jul 20, 2021

This looks like a different issue to me. In #1388 clips are being created. If you look at the output from my "ls -l", only my backyard_cam is producing current timestamped files in /tmp/cache. Given that I'm still able to see all 5 cameras updating in the frigate UI, the ffmpeg processes are still pulling data from the cameras. A simple restart of frigate brings all 5 cameras back online. I'm asking if there is a way frigate can detect if no files are currently being created in /tmp/cache and if so bounce the ffmpeg processes to try to get them working again.

@mitchross
Copy link
Contributor

Did you also see #788

@rhatguy
Copy link
Author

rhatguy commented Jul 22, 2021

I have looked at #788. This seems to be related to increasing capture time, which I haven't done. My issue is the creation of the files in /tmp/cache is completely stopped, but only for certain cameras.

To go back to my original question though...regardless of how one gets into this situation (whether because of something described in the previously mentioned issues or some other reason), is there some way to have frigate automatically restart the affected processes if files in /tmp/cache are stale? I don't think there is ever a reason why a file in /tmp/cache should be days old as shown in my logs above. My thought is if we find a cache file that is X days/hours/minutes old, we should restart those processes. I'm thinking about creating a cron job that just restarts the entire container if it ever finds a file older than 1 hour in /tmp/cache.

@blakeblackshear
Copy link
Owner

Just to make sure I am following this, the ffmpeg process that creates clips in the cache directory sometimes stops writing segments, but doesn't actually exit. Is that correct? I think this is a known issue with the reolink cameras and rtmp. Is there a reason you arent using the recommended input args for reolink cameras?

The -rw_timeout 5000000 is supposed to tell ffmpeg to error for this.

@rhatguy
Copy link
Author

rhatguy commented Jul 23, 2021

Your understanding is correct. I've been having issues with reliability and with the "stuttering" that has been mentioned on other threads across my 5 reolink cameras (4 * RLC410-5MP and 1 * RLC410W). I don't see the type of issues when I watch the streams with VLC, so my assumption is there is something that ffmpeg is doing differently, so I started playing with the FFMPEG args. Initially, I was using the recommended args, but I had basically removed everything and started from scratch. The rw_timeout was one value I had removed. After reading up on it, I've re-added it back and will continue to test. From the docs it seems like it should fix the issue I described above.

Below is what I've got currently for ffmpeg args, and I'm using the rtmp streams from my reolinks. I get it that these cameras are problematic (trust me), but I've used them with the reolink software as well as with blue iris and have never had as many issues with them just stopping gathering video. I'm trying to figure out what ffmpeg options can increase stability and/or eliminate the stuttering. So far the below options seem to provide a much smoother video than the default options in frigate. Its hard to say about stability yet, but overall I feel like these options (now including the rw_timeout) have been more stable.

I'd love it if some other users with reolinks might try these options and see if they eliminate your stuttering if you have it.

ffmpeg:
global_args: -hide_banner -loglevel warning
input_args:
- -fflags
- +genpts+discardcorrupt+nobuffer
- -analyzeduration
- 1000M
- -probesize
- 1000M
- -rw_timeout
- "5000000"
output_args:
clips: -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy
hwaccel_args: -c:v h264_v4l2m2m

@salleq
Copy link

salleq commented Jul 25, 2021

Initially when I tried these settings I couldn't get the stream working at all, but I guess I had something wrong - even after fixing whatever was wrong, it didn't seem that there was any help for the stuttering of video (and audio working really erratically, muting and unmuting all the time is the best way to describe it) when opened with VLC player. Note that the audio issue isn't prevalent when viewing the clips on Frigate, which I find a bit weird!

But right now it seems both my Reolinks are working close to perfect. I have a RLC-520 and a RLC-410-5MP. The former has 24/7 recording on right now for testing and the latter does not - it doesn't seem to matter anyway. I'll also paste my config for one of my cameras (the ffmpeg settings are identical), but with filtering etc. redacted. Now that I'm typing this I noticed my config isn't exactly the same as yours but I have some parts from #896 as well. But hey - it seems working, and Frigate also recovered from a Reolink reboot unlike in #896 so 🤷‍♂️

I believe analyzeduration and/or probesize could be what make some diference here as I don't have rw_timeout set right now.

 frontyard:
    ffmpeg:
      input_args:
        - -avoid_negative_ts
        - make_zero
        - -fflags
        - nobuffer+genpts+discardcorrupt
        - -flags
        - low_delay
        - -strict
        - experimental
        - -analyzeduration
        - 1000M
        - -probesize
        - 1000M
      inputs:
        - path:  rtmp://reolink/bcs/channel0_main.bcs?channel=0&stream=0&user=admin&password=password
          roles:
            - clips         
            - detect
      output_args: 
          clips: -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy
    width: 2560
    height: 1920
    fps: 5

@rhatguy
Copy link
Author

rhatguy commented Jul 28, 2021

After adding the rw_timeout back in I noticed this had happened again today. The ffmpeg processes for my front_door_camera were still running

root@7c8848bfd715:/tmp/cache# ps -ef | egrep -i ffmpeg | egrep -v grep | egrep -i "front|75"
root 13778 43 1 Jul25 ? 00:51:20 ffmpeg -hide_banner -loglevel warning -c:v h264_v4l2m2m -fflags +genpts+discardcorrupt+nobuffer -analyzeduration 1000M -probesize 1000M -rw_timeout 5000000 -i rtmp://10.1.1.75/bcs/channel0_sub.bcs?channel=0&stream=0&user=username&password=password -r 4 -f rawvideo -pix_fmt yuv420p pipe:
root 19559 43 4 Jul25 ? 02:20:51 ffmpeg -hide_banner -loglevel warning -c:v h264_v4l2m2m -fflags +genpts+discardcorrupt+nobuffer -analyzeduration 1000M -probesize 1000M -rw_timeout 5000000 -i rtmp://10.1.1.75/bcs/channel0_main.bcs?channel=0&stream=0&user=username&password=password -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy /tmp/cache/front_door_cam-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/front_door_cam

But hadn't captured any data for days

root@7c8848bfd715:/tmp/cache# ls -ltr /tmp/cache
.
-rw-r--r-- 1 root root 1835056 Jul 27 11:10 back_porch_cam-20210727111026.mp4
-rw-r--r-- 1 root root 9699376 Jul 27 11:10 backyard_cam-20210727111019.mp4
-rw-r--r-- 1 root root 2883632 Jul 27 11:10 driveway_cam-20210727111024.mp4
-rw-r--r-- 1 root root 3407920 Jul 27 11:10 garage_cam-20210727111024.mp4
-rw-r--r-- 1 root root 9699376 Jul 25 15:22 front_door_cam-20210725152227.mp4

The last few lines of the docker log file show packet mismatches and then finally clips not being created
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] DTS 16594076 < 16594375 out of order
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 48138222 11 1992894671
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 1130753213 131817 1993026488
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 855977705 131817 1993158305
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -1087509866 131817 1993290122
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -1204507006 131817 1993421939
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -1032918522 131817 1993553756
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 1487878207 131817 1993685573
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -501697159 131817 1993817390
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 1669347779 131817 1993949207
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 273122128 131818 1994081025
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -378207414 131818 1994212843
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 588355308 131818 1994344661
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch 12662376 131818 1994476479
ffmpeg.front_door_cam.detect ERROR : [flv @ 0x559d59b5b0] Packet mismatch -1104325017 131818 1994608297
watchdog.front_door_cam INFO : No frames received from front_door_cam in 20 seconds. Exiting ffmpeg...
watchdog.front_door_cam INFO : Waiting for ffmpeg to exit gracefully...
watchdog.front_door_cam INFO : FFmpeg didnt exit. Force killing...
frigate.video INFO : front_door_cam: ffmpeg sent a broken frame. memoryview assignment: lvalue and rvalue have different structures
frigate.video INFO : front_door_cam: ffmpeg sent a broken frame. memoryview assignment: lvalue and rvalue have different structures
frigate.video INFO : front_door_cam: ffmpeg process is not running. exiting capture thread...
frigate.events WARNING : Unable to create clip for front_door_cam and event 1627241782.484642-2802cx. There were no cache files for this event.
frigate.events WARNING : Unable to create clip for front_door_cam and event 1627241800.557333-dvnb7k. There were no cache files for this event.

After a docker-compose down/docker-compose up everything was running successfully again.

Separately I tried setting up a live555ProxyServer to proxy the rtsp streams from my reolink cameras and noticed an interesting log from the proxy server. Apparently Reolink is running a rtsp server from 2013 on their cameras as shown below. Its no wonder the rtsp streams are so unreliable from these cameras. I'm also experimenting with setting up some type of rtmp streaming proxy. Wondering if there a proxy of some type that would be more lenient with the rtmp streams coming from these cameras and feed frigate/ffmpeg a more stable stream.

v=0
o=- 1627192839663369 1 IN IP4 10.1.1.75
s=Session streamed by "preview"
i=h264Preview_01_main
t=0 0
a=tool:LIVE555 Streaming Media v2013.04.08

@blakeblackshear
Copy link
Owner

It would certainly be possible to restart ffmpeg if no segments are detected for a while if absolutely necessary.

@stale
Copy link

stale bot commented Aug 27, 2021

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

@stale stale bot added the stale label Aug 27, 2021
@stale stale bot closed this as completed Aug 30, 2021
@nic0dk
Copy link

nic0dk commented Sep 13, 2021

Separately I tried setting up a live555ProxyServer to proxy the rtsp streams from my reolink cameras and noticed an interesting log from the proxy server. Apparently Reolink is running a rtsp server from 2013 on their cameras as shown below. Its no wonder the rtsp streams are so unreliable from these cameras. I'm also experimenting with setting up some type of rtmp streaming proxy. Wondering if there a proxy of some type that would be more lenient with the rtmp streams coming from these cameras and feed frigate/ffmpeg a more stable stream.

sorry for reopening this case - i just wanted to hear what you end up doing with your Reolink cameras?
running myself RLC420 and 1x RLC520A, all have same problem as yours. also have an old hikvision, but no problem on that at all.

@rhatguy
Copy link
Author

rhatguy commented Sep 14, 2021

This is still happening in my environment. I've tried the rtsp-simple-server as well as been starting to try to play with a neolink based proxy recently. I checked this morning though and multiple of my cams were not recording anymore, so I have by no means solved the problem.

I did have a conversation with reolink support about the exactly old version of the live555 proxy server they are running. The reolink cameras I have at least run a version of the live555 server from 2013.04.08. Obviously there are numerous fixes since then. Reolink support has mentioned that they are working toward updating the live555 server in a subsequent code update, but I'm not exactly holding my breath.

In short, no...my frigate system (with reolink cams) is not exactly stable at the moment. I haven't found a completely working combination that will consistently stream, and not have smearing/tearing. I think frigate is not handling issues in the streams from the cameras well and isn't detecting when ffmpeg dies correctly and restarting it. I'm still trying to play with the various proxy servers in my spare time and trying to find some way of divorcing frigate's ffmpeg directly from the camera steram.

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

No branches or pull requests

5 participants