How to debug ffmpeg reliability for long running rtsp streams

Question

I have a long running ffmpeg background process that "watches" an rtsp stream and takes snapshots every 7 minutes.

It's being run like this

C:\Windows\System32\cmd.exe /c C:\ffmpeg\bin\ffmpeg.exe -nostdin -rtsp_transport tcp -y -timeout 5000000 -i rtsp://someurl -q:v 1 -an -vf fps=0.002381,scale="1280:720" -strftime 1 -f image2 C:\somelocalfolder\%Y-%m-%d_%H-%M-%S.jpg > c:\ffmpeglog.txt 2>&1

This process runs for days but intermittently, for hours at a time, seems to miss taking snapshots, until eventually it starts to take them again - then fail again, etc. The logs at info level are not helpful. I checked the stream during times when it was not taking snapshots and the stream was up. What's happening here? How can I debug this?

Below is an image of succesfull snapshots per hour. There should always be between 8 and 9.

Logs look like this

    ffmpeg version 2022-03-31-git-e301a24fa1-full_build-www.gyan.dev Copyright (c) 2000-2022 the FFmpeg developers
  built with gcc 11.2.0 (Rev7, Built by MSYS2 project)
  configuration: --enable-gpl --enable-version3 --enable-static --disable-w32threads --disable-autodetect --enable-fontconfig --enable-iconv --enable-gnutls --enable-libxml2 --enable-gmp --enable-bzlib --enable-lzma --enable-libsnappy --enable-zlib --enable-librist --enable-libsrt --enable-libssh --enable-libzmq --enable-avisynth --enable-libbluray --enable-libcaca --enable-sdl2 --enable-libdav1d --enable-libdavs2 --enable-libuavs3d --enable-libzvbi --enable-librav1e --enable-libsvtav1 --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs2 --enable-libxvid --enable-libaom --enable-libopenjpeg --enable-libvpx --enable-mediafoundation --enable-libass --enable-frei0r --enable-libfreetype --enable-libfribidi --enable-libvidstab --enable-libvmaf --enable-libzimg --enable-amf --enable-cuda-llvm --enable-cuvid --enable-ffnvcodec --enable-nvdec --enable-nvenc --enable-d3d11va --enable-dxva2 --enable-libmfx --enable-libshaderc --enable-vulkan --enable-libplacebo --enable-opencl --enable-libcdio --enable-libgme --enable-libmodplug --enable-libopenmpt --enable-libopencore-amrwb --enable-libmp3lame --enable-libshine --enable-libtheora --enable-libtwolame --enable-libvo-amrwbenc --enable-libilbc --enable-libgsm --enable-libopencore-amrnb --enable-libopus --enable-libspeex --enable-libvorbis --enable-ladspa --enable-libbs2b --enable-libflite --enable-libmysofa --enable-librubberband --enable-libsoxr --enable-chromaprint
  libavutil      57. 24.101 / 57. 24.101
  libavcodec     59. 25.100 / 59. 25.100
  libavformat    59. 20.101 / 59. 20.101
  libavdevice    59.  6.100 / 59.  6.100
  libavfilter     8. 29.100 /  8. 29.100
  libswscale      6.  6.100 /  6.  6.100
  libswresample   4.  6.100 /  4.  6.100
  libpostproc    56.  5.100 / 56.  5.100
Input #0, rtsp, from 'rtsp://somerul':
  Metadata:
    title           : HIK Media Server V4.21.005
    comment         : HIK Media Server Session Description : standard
  Duration: N/A, start: 0.033000, bitrate: N/A
  Stream #0:0: Video: h264 (High), yuv420p(progressive), 704x576, 30 tbr, 90k tbn
Stream mapping:
  Stream #0:0 -> #0:0 (h264 (native) -> mjpeg (native))
[swscaler @ 000002a1c2c20680] [swscaler @ 000002a1c2c2e0c0] deprecated pixel format used, make sure you did set range correctly
[swscaler @ 000002a1c2c20680] [swscaler @ 000002a1c2c67c40] deprecated pixel format used, make sure you did set range correctly
[swscaler @ 000002a1c2c20680] [swscaler @ 000002a1c2cc6700] deprecated pixel format used, make sure you did set range correctly
Output #0, image2, to 'C:\somelocalfolder\Temp\stream_2\StreamedImages\%Y-%m-%d_%H-%M-%S.jpg':
  Metadata:
    title           : HIK Media Server V4.21.005
    comment         : HIK Media Server Session Description : standard
    encoder         : Lavf59.20.101
  Stream #0:0: Video: mjpeg, yuvj420p(pc, progressive), 1280x720, q=2-31, 200 kb/s, 0.0024 fps, 0.0024 tbn
    Metadata:
      encoder         : Lavc59.25.100 mjpeg
    Side data:
      cpb: bitrate max/min/avg: 0/0/200000 buffer size: 0 vbv_delay: N/A
frame=    1 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A speed=   0x

Update I got some trace logs. The ffmpeg seems to fail silently at some point and stop taking snapshots.

After about 3 million log lines (which is really only a couple of hours in my case) I get the following

rtsp://192.168.15.195:554/streaming/channels/904: Unknown error

But ffmpeg silently continues. Here is a bit more of the log

    [Parsed_fps_0 @ 00000248e7d50e40] Read frame with in pts 1074443040, out pts 28
[Parsed_fps_0 @ 00000248e7d50e40] Dropping frame with pts 28
frame=   28 fps=0.0 q=1.0 size=N/A time=03:08:59.77 bitrate=N/A speed=0.95x    
[rtsp @ 00000248e765cf00] tcp_read_packet:
[h264 @ 00000248e7d59880] nal_unit_type: 1(Coded slice of a non-IDR picture), nal_ref_idc: 3
[rtsp @ 00000248e765cf00] ret=-138 c=24 [$]
rtsp://192.168.15.195:554/streaming/channels/904: Unknown error
[Parsed_fps_0 @ 00000248e7d50e40] Read frame with in pts 1074446100, out pts 28
[Parsed_fps_0 @ 00000248e7d50e40] Dropping frame with pts 28
frame=   28 fps=0.0 q=1.0 size=N/A time=03:08:59.77 bitrate=N/A speed=0.95x    
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=696
[rtsp @ 00000248e765cf00] Sending:
GET_PARAMETER rtsp://192.168.15.195:554/streaming/channels/904 RTSP/1.0

CSeq: 402

User-Agent: Lavf59.20.101

Session: 931848797

Authorization: Digest username="******", realm="709382dda4ccb674edf093d3", nonce="13fca62fc", uri="rtsp://192.168.15.195:554/streaming/channels/904", response="74341df9611f0ac3dc247b402424735b", algorithm="MD5"



--
[NULL @ 00000248e7662640] nal_unit_type: 7(SPS), nal_ref_idc: 3
[NULL @ 00000248e7662640] nal_unit_type: 8(PPS), nal_ref_idc: 3
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=756
[Parsed_fps_0 @ 00000248e7d50e40] Read frame with in pts 1074449070, out pts 28
[Parsed_fps_0 @ 00000248e7d50e40] Dropping frame with pts 28
[Parsed_fps_0 @ 00000248e7d50e40] Read frame with in pts 1074449070, out pts 28
[Parsed_fps_0 @ 00000248e7d50e40] Dropping frame with pts 28
frame=   28 fps=0.0 q=1.0 size=N/A time=03:08:59.77 bitrate=N/A speed=0.949x    
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
frame=   28 fps=0.0 q=1.0 size=N/A time=03:08:59.77 bitrate=N/A speed=0.949x    
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1228
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
[NULL @ 00000248e7662640] reference count 1 overflow
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=804
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=1352
[NULL @ 00000248e7662640] illegal memory management control operation 11
[rtsp @ 00000248e765cf00] tcp_read_packet:
[rtsp @ 00000248e765cf00] ret=1 c=24 [$]
[rtsp @ 00000248e765cf00] id=0 len=836

Basically it appears an issue of ffmpeg silently failing. If it crashed, my software could detect it and I could rerun it, but if it fails silently like this, I need another solution.

user0mdb · Answer

Hi

I suggest you that u use a snapshot approach, there u dont need to have the stream running for long time just for one frame, and let python sleep for the snapshot duration (7 Minutes)

Maybe you are fit with python, here u have a simple script they do the job, with the module pyav

Install latest version of python3 and then install the pyav module with pip

pip install av

import av
import time
import logging

logging.basicConfig(level=logging.INFO)

SECONDS_TO_SLEEP = 60 * 7

def decode_on_frame_and_save_to_disk(url):
    logging.info(f' Try to connect to {url}')
    # Connect to RTSP URL
    video = av.open(url, 'r')
    # Iter over Packages to get an frame
    for packet in video.demux():
        # When frame is decoded
        for frame in packet.decode():
            # Current datetime
            ts = time.strftime("%Y%m%d-%H%M%S")
            # Log file loctaion of file
            logging.info(f' Save Frame frame-{ts}.jpg')
            # Save Frame into JPEG
            frame.to_image().save(f'frame-{ts}.jpg')
            # Close Connection to RTSP Source
            video.close()
            logging.info(f' Closing Connection')
            # Return because we just need one frame
            return

try:
    logging.info(' Start Snapshot Generator')
    while True:
        decode_on_frame_and_save_to_disk('')
        logging.info(f' Awaiting next iteration, sleep for {SECONDS_TO_SLEEP}sec')
        time.sleep(SECONDS_TO_SLEEP)
except Exception as error:
    logging.error(error)

How to debug ffmpeg reliability for long running rtsp streams

1 Answers