Opened 4 months ago

#6632 new defect

Two ffmpeg instances record with (and without) lags

Reported by: Gnitry Owned by:
Priority: normal Component: ffmpeg
Version: unspecified Keywords: ffmpeg novus rtp C# service
Cc: Blocked By:
Blocking: Reproduced by developer: no
Analyzed by developer: no

Description

I have and RTP video broadcast stream (using NOVUS – H.264 / MPEG-4 HD/SD Broadcast Encoder). And I have a Windows Server 2012 (Intel Xeon E5-2690, 128Gb RAM) with service which is recording this stream to file (using lastest FFmpeg, calling it as external process). Every 2-5 minutes recording stops and starts again to a new file.

From time to time there are significant (and not) lags in video. At most these lags are at the beginning file, sometimes in the center/end. Regarding log there are missed packets.

It could be network problems, but:

I ran manually from console in parallel another instance of ffmpeg and started to record the same broadcast stream with segmentation by time. And in this case recording is very good (missed packets 1..5 very very rarely), no lags. At moments, when the first ffmpeg records the second ffmpeg has no problems.

What could be the reason of this behavior? Two ffmpeg instances run in parallel and read the same udp input, but the first misses packets when the second feels good. No memory problems, no hdd problems, no CPU overload. I also tried to set highest priority of the first ffmpeg process, but it didn't help. The only difference between them I see is that first ffmpeg is run from service, and the second is run from from local administrator. To be honest, I used vlc as recorder before, but it had the same problems too... And I can surely say that video stream is ok, because it is played in VLC player 24h/day on another PC without lags...

That is how I run ffmpeg from windows service (C#):


 _process = new Process();
    var startInfo = new ProcessStartInfo(@"ffmpeg\ffmpeg.exe");
    startInfo.UseShellExecute = false;
    startInfo.RedirectStandardInput = true;
    startInfo.Arguments = "-loglevel debug -y -ss 1 -i \"" + _url + "\" -vcodec copy -y -an \"" + _outputFileName + "\"";
    startInfo.CreateNoWindow = true;

Command to record video automatically from windows service:


ffmpeg.exe -loglevel debug -y -ss 1 -i "rtp://225.1.1.1:1024" -vcodec copy -y -an "Session-021221.ts"

Command to record video manually.


 D:\ffmpeg\ffmpeg -i "rtp://225.1.1.1:1024" -vcodec copy -an -f segment -strftime 1 -segment_time 300 "novus-%Y-%m-%d_%H-%M-%S.ts"

This is part of the log of one of the broken recordings (some other full logs are attached):

    ...
    2017.09.01 18R:22:56.171  frame=  172 fps= 45 q=-1.0 size=    2816kB time=00:00:03.45 bitrate=6674.9kbits/s speed=0.909x    
    2017.09.01 18R:22:56.174  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:22:56.686      Last message repeated 26 times
    2017.09.01 18R:22:56.687  frame=  199 fps= 46 q=-1.0 size=    3072kB time=00:00:03.99 bitrate=6297.7kbits/s speed=0.926x    
    2017.09.01 18R:23:04.554  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:04.571      Last message repeated 26 times
    2017.09.01 18R:23:04.571  frame=  226 fps= 47 q=-1.0 size=    3584kB time=00:00:04.53 bitrate=6472.7kbits/s speed=0.939x    
    2017.09.01 18R:23:04.571  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:04.572      Last message repeated 26 times
    2017.09.01 18R:23:04.572  frame=  253 fps= 47 q=-1.0 size=    4096kB time=00:00:05.07 bitrate=6610.4kbits/s speed=0.948x    
    2017.09.01 18R:23:04.572  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:04.572  frame=  254 fps= 21 q=-1.0 size=    4096kB time=00:00:05.09 bitrate=6584.5kbits/s speed=0.418x    
    2017.09.01 18R:23:04.572  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:04.655      Last message repeated 5 times
    2017.09.01 18R:23:04.684  [rtp @ 0000000000a3a9a0] max delay reached. need to consume packet
    2017.09.01 18R:23:04.684  [rtp @ 0000000000a3a9a0] RTP: missed 4147 packets
    2017.09.01 18R:23:04.685  [rtp @ 0000000000a3a9a0] RTP: PT=21: bad cseq a237 expected=9204
    2017.09.01 18R:23:04.685  [rtp @ 0000000000a3a9a0] max delay reached. need to consume packet
    2017.09.01 18R:23:04.685  [rtp @ 0000000000a3a9a0] RTP: missed 4148 packets
    2017.09.01 18R:23:04.685  [rtp @ 0000000000a3a9a0] Continuity check failed for pid 256 expected 8 got 15
    2017.09.01 18R:23:04.686  [rtp @ 0000000000a3a9a0] Continuity check failed for pid 272 expected 10 got 15
    2017.09.01 18R:23:04.686  [rtp @ 0000000000a3a9a0] Continuity check failed for pid 32 expected 13 got 4
    2017.09.01 18R:23:04.686  [rtp @ 0000000000a3a9a0] Continuity check failed for pid 0 expected 14 got 6
    2017.09.01 18R:23:04.767  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:05.255      Last message repeated 25 times
    2017.09.01 18R:23:05.256  frame=  286 fps= 22 q=-1.0 size=    4608kB time=00:00:12.51 bitrate=3016.0kbits/s speed=0.971x    
    2017.09.01 18R:23:05.257  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:05.77      Last message repeated 26 times
    2017.09.01 18R:23:05.77  frame=  313 fps= 23 q=-1.0 size=    5120kB time=00:00:13.05 bitrate=3212.5kbits/s speed=0.974x    
    2017.09.01 18R:23:05.773  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:06.287      Last message repeated 26 times
    2017.09.01 18R:23:06.288  frame=  340 fps= 24 q=-1.0 size=    5376kB time=00:00:13.59 bitrate=3239.2kbits/s speed=0.977x    
    2017.09.01 18R:23:06.29  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:06.803      Last message repeated 26 times
    2017.09.01 18R:23:06.804  frame=  367 fps= 25 q=-1.0 size=    5888kB time=00:00:14.13 bitrate=3412.2kbits/s speed=0.979x    
    2017.09.01 18R:23:06.808  [NULL @ 0000000000a89ee0] ct_type:0 pic_struct:0
    2017.09.01 18R:23:07.324      Last message repeated 26 times
    2017.09.01 18R:23:07.324  frame=  394 fps= 26 q=-1.0 size=    6144kB time=00:00:14.67 bitrate=3429.5kbits/s speed=0.981x   
    ...


Some full logs:

https://pastebin.com/dl/e74KE5H3
https://pastebin.com/dl/H6GUbD22

Attachments (2)

SessionN659906@17-42.log (117.2 KB) - added by Gnitry 4 months ago.
SessionN659929@18-22.log (61.3 KB) - added by Gnitry 4 months ago.

Download all attachments as: .zip

Change History (2)

Changed 4 months ago by Gnitry

Changed 4 months ago by Gnitry

Note: See TracTickets for help on using tickets.