Opened 12 months ago

Last modified 11 months ago

#9081 new defect

Progress reporting regression for content with large frame gaps

Reported by: Zac Owned by:
Priority: important Component: undetermined
Version: git-master Keywords: fps regression
Cc: Blocked By:
Blocking: Reproduced by developer: no
Analyzed by developer: no

Description (last modified by Carl Eugen Hoyos)

Summary of the bug:
I noticed that the "progress" update in the console output no longer refreshes as of ver 4.3.x (I tested in 4.2.0 to confirm the regression) for certain content.

For reference the "status update" I am talking about is this bit of the console output:

frame= 1106 fps=157 q=26.0 size= 1024kB time=00:00:35.06 bitrate= 239.2kbits/s speed=4.97x

The input content has large periods with no frames. The command I am using fixes this my forcing the output framerate to 30. When I do this in v4.2.1 (and prior) the "speed" and "frame" values written to the console continue to update even though the location in the source is not moving forward (during the large gaps). In 4.3.1, it looks like the progress update only occurs when the source location has changed.

Why does this matter? My app does "hang detection" and this triggers a false positive hang. I can always bump my hang detection timer so it is not a huge deal for me but no matter what I can always encounter content which has longer and longer time between frames (think of a slide presentation where an 8 hour long video may have 10 frames).

FWIW I tried on windows and linux builds and got the same result.

How to reproduce:

c:\ffmpegs\ffmpeg-4.2.1-win64-static\ffmpeg-4.2.1-win64-static>ffmpeg -i input.mp4 -an -map 0:v:0  -vf fps=fps=30,scale=1656:1246,yadif=deint=1  -colorspace bt709 -color_primaries bt709 -color_trc bt709  -pix_fmt yuv420p  -c:v libx264 -profile:v main -level:v 4.2 -preset medium -crf 20  -x264-params bframes=0:scenecut=0:aud=1:cabac=0:colormatrix=bt709 -force_key_frames expr:gte(t,n_forced*3)  -b:v 2560000 -maxrate:v 3840000 -bufsize 11520000 -max_muxing_queue_size 9999  d8ba422f4-cbf7-4986-a2b2-acbc004ba739.m4v
ffmpeg version 4.3.1 Copyright (c) 2000-2020 the FFmpeg developers
  built with gcc 10.2.1 (GCC) 20200726
  configuration: --enable-gpl --enable-version3 --enable-sdl2 --enable-fontconfig --enable-gnutls --enable-iconv --enable-libass --enable-libdav1d --enable-libbluray --enable-libfreetype --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libsrt --enable-libtheora --enable-libtwolame --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxml2 --enable-libzimg --enable-lzma --enable-zlib --enable-gmp --enable-libvidstab --enable-libvmaf --enable-libvorbis --enable-libvo-amrwbenc --enable-libmysofa --enable-libspeex --enable-libxvid --enable-libaom --enable-libgsm --enable-librav1e --disable-w32threads --enable-libmfx --enable-ffnvcodec --enable-cuda-llvm --enable-cuvid --enable-d3d11va --enable-nvenc --enable-nvdec --enable-dxva2 --enable-avisynth --enable-libopenmpt --enable-amf
  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
  libswscale      5.  7.100 /  5.  7.100
  libswresample   3.  7.100 /  3.  7.100
  libpostproc    55.  7.100 / 55.  7.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'input.mp4':
  Metadata:
    major_brand     : mp42
    minor_version   : 1
    compatible_brands: isommp41mp42
    creation_time   : 2021-01-20T16:18:49.000000Z
  Duration: 00:27:44.94, start: 0.000000, bitrate: 419 kb/s
    Stream #0:0(und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 247 kb/s (default)
    Metadata:
      creation_time   : 2021-01-20T16:18:49.000000Z
      handler_name    : Core Media Audio
    Stream #0:1(und): Video: h264 (High) (avc1 / 0x31637661), yuvj420p(pc, bt709/bt709/iec61966-2-1), 1440x1920, 169 kb/s, 6.99 fps, 60 tbr, 600 tbn, 1200 tbc (default)
    Metadata:
      rotate          : 270
      creation_time   : 2021-01-20T16:18:49.000000Z
      handler_name    : Core Media Video
    Side data:
      displaymatrix: rotation of 90.00 degrees
Stream mapping:
  Stream #0:1 -> #0:0 (h264 (native) -> h264 (libx264))
Press [q] to stop, [?] for help
[swscaler @ 00000203a4821a00] deprecated pixel format used, make sure you did set range correctly
[libx264 @ 00000203a0601340] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
[libx264 @ 00000203a0601340] profile Main, level 4.2, 4:2:0, 8-bit
[libx264 @ 00000203a0601340] 264 - core 161 - H.264/MPEG-4 AVC codec - Copyleft 2003-2020 - http://www.videolan.org/x264.html - options: cabac=0 ref=3 deblock=1:0:0 analyse=0x1:0x111 me=hex subme=7 psy=1 psy_rd=1.00:0.00 mixed_ref=1 me_range=16 chroma_me=1 trellis=1 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=-2 threads=12 lookahead_threads=2 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=0 weightp=2 keyint=250 keyint_min=25 scenecut=0 intra_refresh=0 rc_lookahead=40 rc=crf mbtree=1 crf=20.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 vbv_maxrate=3840 vbv_bufsize=11520 crf_max=0.0 nal_hrd=none filler=0 ip_ratio=1.40 aq=1:1.00
Output #0, ipod, to 'd8ba422f4-cbf7-4986-a2b2-acbc004ba739.m4v':
  Metadata:
    major_brand     : mp42
    minor_version   : 1
    compatible_brands: isommp41mp42
    encoder         : Lavf58.45.100
    Stream #0:0(und): Video: h264 (libx264) (avc1 / 0x31637661), yuv420p(bt709), 1656x1246, q=-1--1, 2560 kb/s, 30 fps, 15360 tbn, 30 tbc (default)
    Metadata:
      encoder         : Lavc58.91.100 libx264
      creation_time   : 2021-01-20T16:18:49.000000Z
      handler_name    : Core Media Video
    Side data:
      cpb: bitrate max/min/avg: 3840000/0/2560000 buffer size: 11520000 vbv_delay: N/A
      displaymatrix: rotation of -0.00 degrees
[out_0_0 @ 00000203a471f1c0] 100 buffers queued in out_0_0, something may be wrong.peed=2.47x
frame=  290 fps=113 q=26.0 size=       0kB time=00:00:07.86 bitrate=   0.0kbits/s speed=3.06x

Notes:
I used this version
https://github.com/BtbN/FFmpeg-Builds/releases/tag/autobuild-2021-01-26-12-37 (I tried many prior 4.3.1 vernos too)

I would submit my input.mp4 file which repros it but it has customer content so I cannot. I have probably two dozen other files (all with large gaps between the video frames) but I have not got approval to share externally.

Attachments (2)

output.zip (1.5 MB ) - added by Zac 12 months ago.
ffmpeg -i input.mp4 -an -map 0:v:0 -vf fps=fps=30,scale=1656:1246,yadif=deint=1 -colorspace bt709 -color_primaries bt709 -color_trc bt709 -pix_fmt yuv420p -c:v libx264 -profile:v main -level:v 4.2 -preset medium -crf 20 -x264-params bframes=0:scenecut=0:aud=1:cabac=0:colormatrix=bt709 -force_key_frames expr:gte(t,n_forced*3) -b:v 2560000 -maxrate:v 3840000 -bufsize 11520000 -max_muxing_queue_size 9999 d8ba422f4-cbf7-4986-a2b2-acbc004ba739.m4v -v 9 -loglevel 99
repro.jpg (181.4 KB ) - added by Zac 12 months ago.
io stats

Download all attachments as: .zip

Change History (9)

by Zac, 12 months ago

Attachment: output.zip added

ffmpeg -i input.mp4 -an -map 0:v:0 -vf fps=fps=30,scale=1656:1246,yadif=deint=1 -colorspace bt709 -color_primaries bt709 -color_trc bt709 -pix_fmt yuv420p -c:v libx264 -profile:v main -level:v 4.2 -preset medium -crf 20 -x264-params bframes=0:scenecut=0:aud=1:cabac=0:colormatrix=bt709 -force_key_frames expr:gte(t,n_forced*3) -b:v 2560000 -maxrate:v 3840000 -bufsize 11520000 -max_muxing_queue_size 9999 d8ba422f4-cbf7-4986-a2b2-acbc004ba739.m4v -v 9 -loglevel 99

comment:1 by Carl Eugen Hoyos, 12 months ago

Keywords: regression added; progres removed

Is the issue you see reproducible with current FFmpeg gut head, the only version supported on this bug tracker?
If you cannot provide an input file that allows to reproduce the issue, please run git bisect to find the change introducing the regression.

by Zac, 12 months ago

Attachment: repro.jpg added

io stats

comment:2 by Zac, 12 months ago

cehoyos, thanks for looking at this quickly

Yes. This reproduces with master. I used the 20210127 build from https://johnvansickle.com/ffmpeg/builds/ffmpeg-git-amd64-static.tar.xz.

I am still getting approval from our customer to share the actual file that reproduces the issue. I *hope* to be able to send it.

I found something else which points to what may be an actual root of the issue. I noticed that if I execute the repro command (See bottom of this post for command) from an ec2 instance, the machine goes unresponsive. It all ssh connections are "hung" and no new ones are even collected. Host level metrics fortunately continue to populate which allows me to see that as of 4.3.1.20200831, the read IO is off the charts! See the attached image. There are almost a million readops per minute and 40GB of reads per minute! Note: CPU and write are all nominal so those are not the bottleneck. Last note: The input file is 83MB.

My guess is that we are doing crazy seeking behavior to try to handle this content!

repro command
:./ffmpeg -y -hide_banner -i /root/veros/repro.mp4 -vn -map 0:a:0 -ac 2 -c:a aac -profile:a aac_low -b:a 248750 -maxrate:a 373125 -max_muxing_queue_size 9999 /host/panopto/scratch/1/ec9533d8-13fb-40f1-aa2b-acc2002563fe.m4a -an -map 0:v:0 -vf fps=fps=30,scale=1656:1246,yadif=deint=1 -colorspace bt709 -color_primaries bt709 -color_trc bt709 -pix_fmt yuv420p -c:v libx264 -profile:v main -level:v 4.2 -preset medium -crf 20 -x264-params bframes=0:scenecut=0:aud=1:cabac=0:colormatrix=bt709 -b:v 2560000 -maxrate:v 3840000 -bufsize 11520000 -max_muxing_queue_size 9999 /host/panopto/scratch/1/cb704e72-a038-4eb6-8e5f-acc200256400.m4v)

comment:3 by Zac, 11 months ago

@cehoyos

I received word back from the person who has been creating the "repro content." Before they provide their permission to share the content here they wanted the following Qs answered:
-- How long will the repro file be retained by ffmpeg? Is there a period when it will be deleted (I can manage content lifecycle on the storage server if need be)
-- Who will have access to the repro content? Can we restrict to a specific developer or set of developers? If need be, I can work with specific developers and hand them expiring URLs.

Thanks!
-Zac

comment:4 by Carl Eugen Hoyos, 11 months ago

Forever / everybody

comment:5 by Carl Eugen Hoyos, 11 months ago

Please run git bisect to find the change introducing the issue you see.

comment:6 by Zac, 11 months ago

Good news! I found a customer who let me share the file! That is presumably far more useful.
Sadly, the upload.ffmpeg.org ftp server keeps timing out so I can't repro it. Instead, I plopped the files up on my own s3 bucket for folks to access:

--http://cdn-devtest.d.panopto.com/zacesq/ticket/9081/dd_ticket9081.mp4

Enjoy!

comment:7 by Carl Eugen Hoyos, 11 months ago

Component: ffmpegundetermined
Description: modified (diff)
Keywords: fps added
Priority: normalimportant
Summary: Progress reporting regression in 4.3.x for content with large frame gapsProgress reporting regression for content with large frame gaps

Probably a regression since b794df43f3a521985f27d40974316db40b64cc88

I tested with a simplified command line, and the issue I see is not (primarily) a problem with the status line but that my system goes oom:

$ ffmpeg -i ticket9081.mp4 -vf fps=30 -qscale 2 -an out.avi
ffmpeg version N-101060-gbd50e715a9 Copyright (c) 2000-2021 the FFmpeg developers
  built with gcc 10 (SUSE Linux)
  configuration: --enable-gpl
  libavutil      56. 65.100 / 56. 65.100
  libavcodec     58.122.100 / 58.122.100
  libavformat    58. 67.100 / 58. 67.100
  libavdevice    58. 11.103 / 58. 11.103
  libavfilter     7.105.100 /  7.105.100
  libswscale      5.  8.100 /  5.  8.100
  libswresample   3.  8.100 /  3.  8.100
  libpostproc    55.  8.100 / 55.  8.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'ticket9081.mp4':
  Metadata:
    major_brand     : mp42
    minor_version   : 1
    compatible_brands: isommp41mp42
    creation_time   : 2021-02-02T23:52:38.000000Z
  Duration: 00:12:45.87, start: 0.000000, bitrate: 458 kb/s
  Stream #0:0(und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 217 kb/s (default)
    Metadata:
      creation_time   : 2021-02-02T23:52:38.000000Z
      handler_name    : Core Media Audio
      vendor_id       : [0][0][0][0]
  Stream #0:1(und): Video: h264 (High) (avc1 / 0x31637661), yuvj420p(pc, bt709/bt709/iec61966-2-1), 1440x1920, 239 kb/s, 1.95 fps, 60 tbr, 600 tbn, 1200 tbc (default)
    Metadata:
      rotate          : 270
      creation_time   : 2021-02-02T23:52:38.000000Z
      handler_name    : Core Media Video
      vendor_id       : [0][0][0][0]
    Side data:
      displaymatrix: rotation of 90.00 degrees
Please use -q:a or -q:v, -qscale is ambiguous
Stream mapping:
  Stream #0:1 -> #0:0 (h264 (native) -> mpeg4 (native))
Press [q] to stop, [?] for help
[swscaler @ 0x413a5c0] deprecated pixel format used, make sure you did set range correctly
Output #0, avi, to 'out.avi':
  Metadata:
    major_brand     : mp42
    minor_version   : 1
    compatible_brands: isommp41mp42
    ISFT            : Lavf58.67.100
  Stream #0:0(und): Video: mpeg4 (FMP4 / 0x34504D46), yuv420p(tv, bt709/bt709/iec61966-2-1, progressive), 1920x1440, q=2-31, 200 kb/s, 30 fps, 30 tbn (default)
    Metadata:
      encoder         : Lavc58.122.100 mpeg4
      creation_time   : 2021-02-02T23:52:38.000000Z
      handler_name    : Core Media Video
      vendor_id       : [0][0][0][0]
    Side data:
      cpb: bitrate max/min/avg: 0/0/200000 buffer size: 0 vbv_delay: N/A
      displaymatrix: rotation of -0.00 degrees
[out_0_0 @ 0x376bdc0] 100 buffers queued in out_0_0, something may be wrong.ts/s speed= 3.3x       
[out_0_0 @ 0x376bdc0] 1000 buffers queued in out_0_0, something may be wrong.s/s speed=3.31x    
Killed
Note: See TracTickets for help on using tickets.