ffmpeg exiting when outputting high data rate video to RTMP

masonevans commented 3 years ago

Describe the bug I have two cameras, a Hikvision and an Amcrest. Each camera has a main stream and a substream; the main stream is set to max res at 6/5 fps and the substreams are set to VGA res 6/5 fps (the Hikvision only does 6 fps, not 5).

When I put the RTMP role on the main stream, my logs end up with a bunch of error messages and the RTMP stream is very unstable. When I try to watch the RTMP stream in HA, it will freeze at times corresponding to the error messages in the logs. When I move the RTMP role to the substream I do not have any issues.

From what I can tell by running the generated ffmpeg command directly, the issue doesn't happen if I output to a file instead of an RTMP stream

Version of frigate 0.8.4-5043040

Config file Include your full config file wrapped in triple back ticks.

mqtt:
  host: mqtt.xxxx.xxxx
ffmpeg:
  hwaccel_args:
    - -hwaccel
    - vaapi
    - -hwaccel_device
    - /dev/dri/renderD128
    - -hwaccel_output_format
    - yuv420p
cameras:
  amcrest:
    ffmpeg:
      inputs:
        - path: rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=0
          roles:
            - clips
            - record
            - rtmp
        - path: rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=1
          roles:
            - detect
    width: 704
    height: 480
    fps: 5
    detect:
      enabled: True
    rtmp:
      enabled: True
    clips:
      enabled: True
    snapshots:
      enabled: True
record:
  enabled: True
  retain_days: 14
objects:
  track:
    - person
    - car
    - truck
    - bird
    - cat
    - dog
    - horse
    - sheep
    - cow
    - bear
    - zebra
detectors:
  coral1:
    type: edgetpu
    device: pci

Frigate container logs

ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5571d5f40140] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5571d5f43240] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5571d5f41840] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5571d5f40140] Non-monotonous DTS in output stream 0:0; previous: 0, current: 0; changing to 1. This may result in incorrect timestamps in the output file.
ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5571d5f43240] Non-monotonous DTS in output stream 1:0; previous: 0, current: 0; changing to 1. This may result in incorrect timestamps in the output file.
ffmpeg.amcrest.clips_record_rtmp ERROR   : av_interleaved_write_frame(): Connection reset by peer
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5571d5f41840] Failed to update header with correct duration.
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5571d5f41840] Failed to update header with correct filesize.
ffmpeg.amcrest.clips_record_rtmp ERROR   : Error writing trailer of rtmp://127.0.0.1/live/amcrest: Connection reset by peer
watchdog.amcrest               INFO    : Terminating the existing ffmpeg process...
watchdog.amcrest               INFO    : Waiting for ffmpeg to exit gracefully...
ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5575ab42d700] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : [segment @ 0x5575ab431240] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5575ab433640] 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
ffmpeg.amcrest.clips_record_rtmp ERROR   : av_interleaved_write_frame(): Connection reset by peer
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5575ab433640] Failed to update header with correct duration.
ffmpeg.amcrest.clips_record_rtmp ERROR   : [flv @ 0x5575ab433640] Failed to update header with correct filesize.
ffmpeg.amcrest.clips_record_rtmp ERROR   : Error writing trailer of rtmp://127.0.0.1/live/amcrest: Connection reset by peer
watchdog.amcrest               INFO    : Terminating the existing ffmpeg process...
watchdog.amcrest               INFO    : Waiting for ffmpeg to exit gracefully...

Frigate stats

{
  "amcrest": {
    "camera_fps": 5.1, 
    "capture_pid": 45, 
    "detection_fps": 0.0, 
    "pid": 42, 
    "process_fps": 5.1, 
    "skipped_fps": 0.0
  }, 
  "detection_fps": 0.0, 
  "detectors": {
    "coral1": {
      "detection_start": 0.0, 
      "inference_speed": 10.0, 
      "pid": 39
    }
  }, 
  "service": {
    "storage": {
      "/dev/shm": {
        "free": 2146.7, 
        "mount_type": "tmpfs", 
        "total": 2147.5, 
        "used": 0.8
      }, 
      "/media/frigate/clips": {
        "free": 7325526.1, 
        "mount_type": "ext4", 
        "total": 7937302.4, 
        "used": 211681.4
      }, 
      "/media/frigate/recordings": {
        "free": 7325526.1, 
        "mount_type": "ext4", 
        "total": 7937302.4, 
        "used": 211681.4
      }, 
      "/tmp/cache": {
        "free": 918.6, 
        "mount_type": "tmpfs", 
        "total": 1000.0, 
        "used": 81.4
      }
    }, 
    "uptime": 302, 
    "version": "0.8.4-5043040"
  }
}

FFprobe from your camera

Run the following command and paste output below

$ docker exec -it frigate bash
root@60bef3b4366e:/opt/frigate# ffprobe "rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=0"
ffprobe version 4.3.1 Copyright (c) 2007-2020 the FFmpeg developers
  built with gcc 9 (Ubuntu 9.3.0-17ubuntu1~20.04)
  configuration: --disable-debug --disable-doc --disable-ffplay --enable-shared --enable-avresample --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-gpl --enable-libfreetype --enable-libvidstab --enable-libmfx --enable-libmp3lame --enable-libopus --enable-libtheora --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libxcb --enable-libx265 --enable-libxvid --enable-libx264 --enable-nonfree --enable-openssl --enable-libfdk_aac --enable-postproc --enable-small --enable-version3 --enable-libzmq --extra-libs=-ldl --prefix=/opt/ffmpeg --enable-libopenjpeg --enable-libkvazaar --enable-libaom --extra-libs=-lpthread --enable-vaapi --extra-cflags=-I/opt/ffmpeg/include --extra-ldflags=-L/opt/ffmpeg/lib
  libavutil      56. 51.100 / 56. 51.100
  libavcodec     58. 91.100 / 58. 91.100
  libavformat    58. 45.100 / 58. 45.100
  libavdevice    58. 10.100 / 58. 10.100
  libavfilter     7. 85.100 /  7. 85.100
  libavresample   4.  0.  0 /  4.  0.  0
  libswscale      5.  7.100 /  5.  7.100
  libswresample   3.  7.100 /  3.  7.100
  libpostproc    55.  7.100 / 55.  7.100
Input #0, rtsp, from 'rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=0':
  Metadata:
    title           : Media Server
  Duration: N/A, start: 0.200000, bitrate: N/A
    Stream #0:0: Video: h264, yuv420p(progressive), 3840x2160, 100 tbr, 90k tbn, 180k tbc

Screenshots If applicable, add screenshots to help explain your problem.

Computer Hardware

OS: NixOS 21.05
Install method: Docker Compose
Virtualization: None - bare metal OS on i5-8400 w/8GB RAM
Coral Version: PCIe
Network Setup: Cameras hardwired to a UniFi Flex switch, switch & server both hardwired to UniFi Dream Machine Pro

Camera Info:

Manufacturer: Amcrest
Model: FCM-IP8M-T2499EW28MM
Resolution: 3840x2160
FPS: 10

Additional context

I ran the ffmpeg command directly in the docker container and am able to reproduce the error, although it doesn't happen as frequently as when Frigate is running (maybe because I didn't start a second stream like Frigate does with the detect stream?)

# ffmpeg -hide_banner -loglevel verbose -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -rtsp_transport tcp -stimeout 5000000 -use_wallclock_as_timestamps 1 -i "rtsp://xxx:xxx@xxxx:554/cam/realmonitor?channel=1&subtype=0" -f segment -segment_time 60 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /media/frigate/recordings/amcrest-%Y%m%d%H%M%S.mp4 -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/amcrest-%Y%m%d%H%M%S.mp4 -c copy -f flv rtmp://127.0.0.1/live/amcrest

....

[flv @ 0x558aba466400] Failed to update header with correct duration.
[flv @ 0x558aba466400] Failed to update header with correct filesize.
Error writing trailer of rtmp://127.0.0.1/live/amcrest: Connection reset by peer
frame= 3102 fps= 10 q=-1.0 Lq=-1.0 q=-1.0 size=N/A time=00:05:10.08 bitrate=N/A speed=1.01x
video:951217kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
Input file #0 (rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=0):
  Input stream #0:0 (video): 3102 packets read (324682120 bytes);
  Total: 3102 packets (324682120 bytes) demuxed
Output file #0 (/media/frigate/recordings/amcrest-%Y%m%d%H%M%S.mp4):
  Output stream #0:0 (video): 3102 packets muxed (324682120 bytes);
  Total: 3102 packets (324682120 bytes) muxed
Output file #1 (/tmp/cache/amcrest-%Y%m%d%H%M%S.mp4):
  Output stream #1:0 (video): 3102 packets muxed (324682120 bytes);
  Total: 3102 packets (324682120 bytes) muxed
Output file #2 (rtmp://127.0.0.1/live/amcrest):
  Output stream #2:0 (video): 3102 packets muxed (324682120 bytes);
  Total: 3102 packets (324682120 bytes) muxed
[AVIOContext @ 0x558aba45e5c0] Statistics: 0 seeks, 11592 writeouts
Conversion failed!

I then tried running the same command but sending the stream to disk instead of as an RTMP stream and it does not seem like the issue happens. In fact, I left the below running at the same time as Frigate and my ffmpeg process has run for 30 mins without exiting while Frigate was getting errors about once/minute.

ffmpeg -hide_banner -loglevel verbose -avoid_negative_ts make_zero -fflags +genpts+discardcorrupt -rtsp_transport tcp -stimeout 5000000 -use_wallclock_as_timestamps 1 -i "rtsp://xxx:xxx@xxx:554/cam/realmonitor?channel=1&subtype=0" -f segment -segment_time 60 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /media/frigate/recordings/amcrest-%Y%m%d%H%M%S.mp4 -f segment -segment_time 10 -segment_format mp4 -reset_timestamps 1 -strftime 1 -c copy -an /tmp/cache/amcrest-%Y%m%d%H%M%S.mp4 -c copy -f flv /media/frigate/testing/amcrest-live

Recordings don't seem to have any problem in full res (seems related to the above)
htop shows no stress on the CPU, all six cores are sitting at under 10%
I have plenty of memory on this host (all it does is run Frigate) so I bumped SHM to 2GB
The issue does seem to be related to the amount of data that the cameras are pushing. For example, changing from VBR to CBR or upping the bit rate makes the errors happen more frequently (with max settings the issue occurs more than once/minute). Lowering the resolution of the main stream reduces the frequency of the error.
I can run the full stream through VLC or ffplay without any real problems

blakeblackshear commented 3 years ago

Looks like its specifically struggling to repackage the feed in the flv container. I haven't seen this issue specifically, but I am thinking of replacing nginx for RTMP restreaming with another solution in the future that may resolve this issue.

masonevans commented 3 years ago

I did a bit more testing. The issue is definitely something happening between ffmpeg & nginx/RTMP. I stood up a bare nginx/RTMP server and then ran the ffmpeg RTMP stream directly into it, and was able to reproduce the issue. It seems like it's definitely something in the ffmpeg/RTMP connection as I'm able to reproduce the issue running ffmpeg/nginx on my server with NixOS or my MacOS laptop.

Interestingly, it seems to have some relationship between the bitrate and the iframe rate. 6mbps bitrate works with an iframe every 10 frames but not every 20 frames. 8mbps works with an iframe every 5 frames but not every 10 frames (exact numbers don't seem to be consistent across cameras). I think the inconsistency I was seeing earlier was due to having VBR turned on and the occasional bitrate spike would cause the failure.

@blakeblackshear happy to close this issue if you want, given that it seems to be between ffmpeg & nginx/nginx-rtmp-module and not directly related to Frigate

matthijsvdr commented 3 years ago

@masonevans I have the exact same issue. However I think issue should stay open until its resolved? Even if its not related to the python code its still related on how frigate is released / packaged.

@blakeblackshear what do you think? I also tried the 0.9 rc and it has the same issue.

When running the same camera on a lower resolution everything works fine. (640480 instead of 38402106)

Interestingly, it seems to have some relationship between the bitrate and the iframe rate. 6mbps bitrate works with an iframe every 10 frames but not every 20 frames. 8mbps works with an iframe every 5 frames but not every 10 frames (exact numbers don't seem to be consistent across cameras). I think the inconsistency I was seeing earlier was due to having VBR turned on and the occasional bitrate spike would cause the failure.

I have set my camera's to a constant bitrate of 16384Kbps and it fails directly when RTMP turned on, I can view the RTMP stream in VLC however it will stop about 10 seconds in.

blakeblackshear / frigate

ffmpeg exiting when outputting high data rate video to RTMP #1599