blakeblackshear / frigate

NVR with realtime local object detection for IP cameras
https://frigate.video
MIT License
19.52k stars 1.8k forks source link

[Support]: Unable to keep up with recording segments in cache... #7631

Closed Spectre5 closed 1 year ago

Spectre5 commented 1 year ago

Describe the problem you are having

I'm getting nearly non-stop warnings similar to "WARNING : Unable to keep up with recording segments in cache for camera1. Keeping the 5 most recent segments out of 6 and discarding the rest..." as well as "Discarding a corrupt recording segment: /tmp/cache/camera1-20230830031158.mp4".

Until I get a good and stable setup going, I'm working with only 1 camera (the recommended Loryta IPC-T5442TM-AS with the suggested settings at the bottom of the camera setup page). The storage is entirely local on a NVME drive, so my write speed should be as good as it gets. The camera is hardwired to the same switch as the computed hosting docker.

I'm running Frigate through docker on a dedicated LXC container in proxmox on a Lenovo M910Q (i7-6700T w/ 32GB RAM - the container given 4 cores, 8GB RAM, and 1 GB swap) and the google coral is setup and working well. The System page currently indicates less than 2% of CPU and less than 0.3% of memory for each of ffmpeg, Capture, and Detect (0 skipped). The storage shows 3.5 GB / 65 GB and the memory shows 7.6 MB / 1.05 GB for /dev/shm and 2.6 MB / 1000 MB for /tmp/cache. I list all of this to make it clear the system is not at all taxed and the storage writing should be as fast as it can be (NVMe)

I've tried clearing database and all media files as well as restarting docker (and the host), but the issue comes back within hours.

Version

0.12.1-367d724

Frigate config file

mqtt:
  enabled: True
  host: 192.168.1.10
  port: 1883
  user: REDACTED
  password: REDACTED

ffmpeg:
  hwaccel_args: preset-vaapi

detectors:
  coral:
    type: edgetpu
    device: usb

birdseye:
  enabled: True

snapshots:
  enabled: True
  clean_copy: True
  timestamp: True
  bounding_box: True
  crop: False

record:
  enabled: True
  retain:
    days: 0
  events:
    pre_capture: 5
    post_capture: 5
    retain:
      default: 20

go2rtc:
  streams:
    camera1:
      - rtsp://{FRIGATE_RTSP_USER}:{FRIGATE_RTSP_PASSWORD}@192.168.8.100:554/cam/realmonitor?channel=1&subtype=0
  webrtc:
    candidates:
      - 192.168.8.11:8555
      - stun:8555

detect:
  enabled: True
  width: 1280
  height: 720

cameras:
  camera1:
    ffmpeg:
      output_args:
        record: preset-record-generic-audio-copy
      inputs:
        - path: rtsp://127.0.0.1:8554/camera1
          input_args: preset-rtsp-restream
          roles:
            - record
        - path: rtsp://{FRIGATE_RTSP_USER}:{FRIGATE_RTSP_PASSWORD}@192.168.8.100:554/cam/realmonitor?channel=1&subtype=2
          roles:
            - detect
    best_image_timeout: 20

rtmp:
  enabled: False

ui:
  timezone: America/Los_Angeles

Relevant log output

2023-08-28 11:49:20.808788198  [INFO] Starting Frigate...
2023-08-28 11:49:21.892684348  [2023-08-28 11:49:21] frigate.app                    INFO    : Starting Frigate (0.12.1-367d724)
<SNIP>
2023-08-28 11:49:24.691521789  [2023-08-28 11:49:22] frigate.detectors.plugins.edgetpu_tfl INFO    : Attempting to load TPU as usb
2023-08-28 11:49:24.696250146  [2023-08-28 11:49:24] frigate.detectors.plugins.edgetpu_tfl INFO    : TPU found
2023-08-29 00:47:14.502495421  [2023-08-29 00:47:14] frigate.record                 WARNING : Discarding a corrupt recording segment: /tmp/cache/camera1-20230829004649.mp4
2023-08-29 00:47:24.446258089  [2023-08-29 00:47:24] frigate.record                 WARNING : Unable to keep up with recording segments in cache for camera1. Keeping the 5 most recent segments out of 6 and discarding the rest...
<SNIP - last 2 messages both repeated many times>
2023-08-30 03:32:47.994172171  [2023-08-30 03:32:47] watchdog.camera1               ERROR   : No new recording segments were created for camera1 in the last 120s. restarting the ffmpeg record process...
2023-08-30 03:32:47.994351282  [2023-08-30 03:32:47] watchdog.camera1               INFO    : Terminating the existing ffmpeg process...
2023-08-30 03:32:47.994420967  [2023-08-30 03:32:47] watchdog.camera1               INFO    : Waiting for ffmpeg to exit gracefully...
2023-08-30 03:32:49.471213505  [2023-08-30 03:32:49] frigate.record                 WARNING : Discarding a corrupt recording segment: /tmp/cache/camera1-20230830033047.mp4
2023-08-30 11:54:57.704503095  [2023-08-30 11:54:57] frigate.watchdog               INFO    : Detection appears to be stuck. Restarting detection process...
2023-08-30 11:54:57.704605936  [2023-08-30 11:54:57] root                           INFO    : Waiting for detection process to exit gracefully...
2023-08-30 11:55:27.717073254  [2023-08-30 11:55:27] root                           INFO    : Detection process didnt exit. Force killing...
2023-08-30 11:55:27.723019250  [2023-08-30 11:55:27] root                           INFO    : Detection process has exited...
2023-08-30 11:55:27.733247074  [2023-08-30 11:55:27] detector.coral                 INFO    : Starting detection process: 178903
2023-08-30 11:55:30.378047755  [2023-08-30 11:55:27] frigate.detectors.plugins.edgetpu_tfl INFO    : Attempting to load TPU as usb
2023-08-30 11:55:30.383796119  [2023-08-30 11:55:30] frigate.detectors.plugins.edgetpu_tfl INFO    : TPU found

FFprobe output from your camera

$ ffprobe 192.168.8.100
ffprobe version 5.1.2-3ubuntu1 Copyright (c) 2007-2022 the FFmpeg developers
  built with gcc 12 (Ubuntu 12.2.0-14ubuntu2)
  configuration: --prefix=/usr --extra-version=3ubuntu1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libdav1d --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libglslang --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librabbitmq --enable-librist --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --disable-sndio --enable-libjxl --enable-pocketsphinx --enable-librsvg --enable-libmfx --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libx264 --enable-libplacebo --enable-librav1e --enable-shared
  libavutil      57. 28.100 / 57. 28.100
  libavcodec     59. 37.100 / 59. 37.100
  libavformat    59. 27.100 / 59. 27.100
  libavdevice    59.  7.100 / 59.  7.100
  libavfilter     8. 44.100 /  8. 44.100
  libswscale      6.  7.100 /  6.  7.100
  libswresample   4.  7.100 /  4.  7.100
  libpostproc    56.  6.100 / 56.  6.100
192.168.8.100: No such file or directory

Frigate stats

{"camera1":{"camera_fps":5.1,"capture_pid":433,"detection_enabled":1,"detection_fps":2.7,"ffmpeg_pid":439,"pid":430,"process_fps":5.1,"skipped_fps":0.0},"cpu_usages":{"%Cpu(s):":{"cpu":"id,","mem":"0.1"},"1":{"cpu":"0.0","mem":"0.0"},"111":{"cpu":"1.7","mem":"0.7"},"118":{"cpu":"0.0","mem":"0.0"},"134":{"cpu":"0.0","mem":"0.0"},"135":{"cpu":"0.0","mem":"0.0"},"136":{"cpu":"0.0","mem":"0.0"},"144":{"cpu":"0.0","mem":"0.0"},"148853":{"cpu":"0.7","mem":"0.1"},"15":{"cpu":"0.0","mem":"0.0"},"155":{"cpu":"0.0","mem":"0.0"},"16":{"cpu":"0.0","mem":"0.0"},"167":{"cpu":"0.0","mem":"0.0"},"172":{"cpu":"0.0","mem":"0.0"},"173":{"cpu":"0.0","mem":"0.1"},"178903":{"cpu":"1.7","mem":"0.5"},"181080":{"cpu":"0.0","mem":"0.0"},"181124":{"cpu":"0.3","mem":"0.0"},"181131":{"cpu":"0.0","mem":"0.0"},"24":{"cpu":"0.0","mem":"0.0"},"25":{"cpu":"0.0","mem":"0.0"},"26":{"cpu":"0.0","mem":"0.0"},"27":{"cpu":"0.0","mem":"0.0"},"28":{"cpu":"0.0","mem":"0.0"},"29":{"cpu":"0.0","mem":"0.0"},"30":{"cpu":"0.0","mem":"0.0"},"31":{"cpu":"0.0","mem":"0.0"},"32":{"cpu":"0.0","mem":"0.0"},"41":{"cpu":"0.0","mem":"0.0"},"417":{"cpu":"0.0","mem":"0.2"},"42":{"cpu":"0.0","mem":"0.0"},"423":{"cpu":"0.0","mem":"0.0"},"426":{"cpu":"0.7","mem":"0.3"},"430":{"cpu":"3.3","mem":"0.3"},"433":{"cpu":"1.0","mem":"0.3"},"435":{"cpu":"0.0","mem":"0.1"},"438":{"cpu":"0.0","mem":"0.1"},"439":{"cpu":"1.7","mem":"0.2"},"79":{"cpu":"0.0","mem":"0.0"},"81":{"cpu":"0.0","mem":"0.0"},"82":{"cpu":"0.0","mem":"0.0"},"89":{"cpu":"2.0","mem":"0.1"},"96":{"cpu":"0.0","mem":"0.0"},"MiB":{"cpu":"25840.7","mem":"avail"},"PID":{"cpu":"%CPU","mem":"%MEM"},"Tasks:":{"cpu":"stopped,","mem":"0"},"top":{"cpu":"users,","mem":"load"}},"detection_fps":2.7,"detectors":{"coral":{"detection_start":0.0,"inference_speed":8.05,"pid":178903}},"gpu_usages":{"intel-vaapi":{"gpu":"0.35 %","mem":"- %"}},"service":{"last_updated":1693423643,"latest_version":"0.12.1","storage":{"/dev/shm":{"free":1066.1,"mount_type":"tmpfs","total":1073.7,"used":7.7},"/media/frigate/clips":{"free":60026.1,"mount_type":"ext4","total":67049.7,"used":3570.8},"/media/frigate/recordings":{"free":60026.1,"mount_type":"ext4","total":67049.7,"used":3570.8},"/tmp/cache":{"free":994.9,"mount_type":"tmpfs","total":1000.0,"used":5.1}},"temperatures":{},"uptime":175081,"version":"0.12.1-367d724"}}

Operating system

Proxmox

Install method

Docker Compose (in LXC Container)

Coral version

USB

Network connection

Wired

Camera make and model

Loryta IPC-T5442TM-AS

Any other information that may be helpful

I assume it is unrelated, but I am also running the Home Assistant Integration as well as the proxy addon.

The go2rtc log contains the following:

2023-08-28 11:49:20.799330004  [INFO] Preparing go2rtc config...
2023-08-28 11:49:21.010583218  [INFO] Not injecting WebRTC candidates into go2rtc config as it has been set manually
2023-08-28 11:49:21.033088633  [INFO] Starting go2rtc...
2023-08-28 11:49:21.105964786  11:49:21.105 INF go2rtc version 1.2.0 linux/amd64
2023-08-28 11:49:21.106190541  11:49:21.106 INF [api] listen addr=:1984
2023-08-28 11:49:21.106299098  11:49:21.106 INF [rtsp] listen addr=:8554
2023-08-28 11:49:21.106467598  11:49:21.106 INF [srtp] listen addr=:8443
2023-08-28 11:49:21.106599039  11:49:21.106 INF [webrtc] listen addr=:8555
2023-08-28 11:49:30.799194769  [INFO] Starting go2rtc healthcheck service...
2023-08-29 00:47:02.220924157  00:47:02.220 WRN github.com/AlexxIT/go2rtc/cmd/streams/producer.go:133 > error="read tcp 172.22.0.2:52110->192.168.8.100:554: i/o timeout" url=rtsp://REDACTED:REDACTED@192.168.8.100:554/cam/realmonitor?channel=1&subtype=0
2023-08-29 02:23:40.491406086  02:23:40.491 WRN github.com/AlexxIT/go2rtc/cmd/streams/producer.go:133 > error="read tcp 172.22.0.2:37206->192.168.8.100:554: i/o timeout" url=rtsp://REDACTED:REDACTED@192.168.8.100:554/cam/realmonitor?channel=1&subtype=0
2023-08-29 03:05:38.715933366  03:05:38.715 WRN github.com/AlexxIT/go2rtc/cmd/streams/producer.go:133 > error="read tcp 172.22.0.2:42896->192.168.8.100:554: i/o timeout" url=rtsp://REDACTED:REDACTED@192.168.8.100:554/cam/realmonitor?channel=1&subtype=0

I've also tried to adjust the configuration to NOT use go2rtc. In this case, I get different errors in the frigate.log file:

<SNIP>
2023-08-27 21:14:48.311218042  [2023-08-27 21:14:48] ffmpeg.camera1.record          ERROR   : [segment @ 0x56548fc67840] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly
2023-08-27 21:14:48.311338232  [2023-08-27 21:14:48] ffmpeg.camera1.record          ERROR   : [segment @ 0x56548fc67840] Non-monotonous DTS in output stream 0:0; previous: 2390007, current: 2390007; changing to 2390008. This may result in incorrect timestamps in the output file.
<SNIP>
2023-08-27 21:14:48.322257615  [2023-08-27 21:14:48] ffmpeg.camera1.record          ERROR   : rtsp://*:*@192.168.8.100:554/cam/realmonitor?channel=1&subtype=0: Connection timed out
2023-08-27 21:14:48.322259680  [2023-08-27 21:14:48] watchdog.camera1               INFO    : Terminating the existing ffmpeg process...
2023-08-27 21:14:48.322261567  [2023-08-27 21:14:48] watchdog.camera1               INFO    : Waiting for ffmpeg to exit gracefully...
2023-08-27 21:15:04.077449260  [2023-08-27 21:15:04] frigate.record                 ERROR   : Error occurred when attempting to maintain recording cache
2023-08-27 21:15:04.077452687  [2023-08-27 21:15:04] frigate.record                 ERROR   : list index out of range
2023-08-27 21:15:08.322422121  [2023-08-27 21:15:08] watchdog.camera1               INFO    : No frames received from camera1 in 20 seconds. Exiting ffmpeg...
2023-08-27 21:15:08.322902025  [2023-08-27 21:15:08] watchdog.camera1               INFO    : Waiting for ffmpeg to exit gracefully...
2023-08-27 21:15:08.507735255  [2023-08-27 21:15:08] frigate.video                  ERROR   : camera1: Unable to read frames from ffmpeg process.
2023-08-27 21:15:08.508242881  [2023-08-27 21:15:08] frigate.video                  ERROR   : camera1: ffmpeg process is not running. exiting capture thread...
2023-08-27 21:15:09.005247486  [2023-08-27 21:15:09] frigate.record                 ERROR   : Error occurred when attempting to maintain recording cache
2023-08-27 21:15:09.005324300  [2023-08-27 21:15:09] frigate.record                 ERROR   : list index out of range
2023-08-27 21:15:14.005192755  [2023-08-27 21:15:14] frigate.record                 ERROR   : Error occurred when attempting to maintain recording cache
2023-08-27 21:15:14.005271530  [2023-08-27 21:15:14] frigate.record                 ERROR   : list index out of range
2023-08-27 21:15:18.510175602  [2023-08-27 21:15:18] watchdog.camera1               ERROR   : Ffmpeg process crashed unexpectedly for camera1.
2023-08-27 21:15:18.514767154  [2023-08-27 21:15:18] watchdog.camera1               ERROR   : The following ffmpeg logs include the last 100 lines prior to exit.
2023-08-27 21:15:18.515043204  [2023-08-27 21:15:18] ffmpeg.camera1.detect          ERROR   : rtsp://*:*@192.168.8.100:554/cam/realmonitor?channel=1&subtype=2: Connection timed out
2023-08-27 21:15:19.005706299  [2023-08-27 21:15:19] frigate.record                 ERROR   : Error occurred when attempting to maintain recording cache
2023-08-27 21:15:19.005800259  [2023-08-27 21:15:19] frigate.record                 ERROR   : list index out of range
2023-08-27 22:26:08.694330164  [2023-08-27 22:26:08] ffmpeg.camera1.record          ERROR   : [segment @ 0x5612884b25c0] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly
<SNIP>
NickM-27 commented 1 year ago

you're getting a lot of timeouts from the camera & go2rtc, I'd suggest updating to the latest version https://docs.frigate.video/configuration/advanced#custom-go2rtc-version

Spectre5 commented 1 year ago

Thanks, I'll look into the custom go2rtc version. Do you know what might be the cause of this? The system isn't taxed, the camera is brand new, and everything is hardwired (with short CAT 6 cables). Also, at he very end of my long post, I've included some log output without using go2rtc. That log indicates timeouts too, as you've noted, but wouldn't that indicate an issue separate from go2rtc since it wasn't in use there? And that log indicates the follow a number of times as an error: "Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly"

NickM-27 commented 1 year ago

"Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly"

this is a warning, not causing the stream to crash. The stream is crashing because the connection is timing out.

The fact that both subtype=0 and subtype=2 means both streams are timing out from the camera.

Spectre5 commented 1 year ago

Ok, I'll try out the custom go2rtc. Is the instructions different when using docker compose? I don't have a /config directory. I've tried restarted Frigate with that go2rtc executable in the /media directory, /config directory (created it), and next to the docker compose YAML file, but in each case the version reported in the log is still 1.2.0.

NickM-27 commented 1 year ago

you do have a /config directory, it is whatever is mapped to /config in your docker compose. You may have the config file mapped specifically, in which case the docker compose should be edited to map the entire folder instead of just the config file

Spectre5 commented 1 year ago

Gotcha, just realized that now myself. I'll edit the docker compose to map it, try it out today, and report back. Thanks for the help.

NickM-27 commented 1 year ago

I'd also suggest adding

logger:
  logs:
    frigate.record: debug

to the frigate config which will give helpful info on the recordings

Spectre5 commented 1 year ago

Great, the updated go2rtc is active and I've added that debug logging for frigate.record. I'll let it run awhile...

Spectre5 commented 1 year ago

Using a new go2rtc as suggested by @NickM-27 seems to have fixed my issue. Out of curiosity, is there a reason that frigate does not include a newer release of go2rtc (past 1.2.0)?

NickM-27 commented 1 year ago

Out of curiosity, is there a reason that frigate does not include a newer release of go2rtc (past 1.2.0)?

because newer versions weren't out when the current frigate version was released