progress not shown correctly when embedding srt files

[jonas]

Summary of the bug:
I am trying to transcode fairly long video files (400+ minutes) and also embed srt files.

As soon as one srt input is mapped to the output, the progress during transcoding snaps to the srt timestamps, i.e. if the first subtitle appears after 15 minutes, the progress would show 15 Minutes as the current time, even though the ffmpeg has not transcoded enough frames for that. Initially a very fast speed is shown, which then decreases, as the transcoded frames reach the actual time. After that time is reached, it will snap to the next time in the srt file. This makes estimating the processing speed cumbersome.As far as I can tell, the output file does not have any issues.

How to reproduce:

ffmpeg -f lavfi -i nullsrc=s=1920x1080:d=300  -i test.srt -map 0 -map 1 -c:s mov_text test2.mp4
ffmpeg version git-2020-02-11-f15007a 

output from
ffmpeg -v 9 -loglevel 99 -f lavfi -i nullsrc=s=1920x1080:d=300 -i test.srt

ffmpeg started on 2020-02-15 at 19:05:44
Report written to "ffmpeg-20200215-190544.log"
Log level: 99
Command line:
./ffmpeg -v 9 -loglevel 99 -f lavfi -i "nullsrc=s=1920x1080:d=300" -i test.srt -report
ffmpeg version git-2020-02-11-f15007a Copyright (c) 2000-2020 the FFmpeg developers
  built with Apple clang version 11.0.0 (clang-1100.0.33.8)
  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-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-libvorbis --enable-libvo-amrwbenc --enable-libmysofa --enable-libspeex --enable-libxvid --enable-libaom --enable-appkit --enable-avfoundation --enable-coreimage --enable-audiotoolbox
  libavutil      56. 39.100 / 56. 39.100
  libavcodec     58. 68.102 / 58. 68.102
  libavformat    58. 38.100 / 58. 38.100
  libavdevice    58.  9.103 / 58.  9.103
  libavfilter     7. 75.100 /  7. 75.100
  libswscale      5.  6.100 /  5.  6.100
  libswresample   3.  6.100 /  3.  6.100
  libpostproc    55.  6.100 / 55.  6.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-f' ... matched as option 'f' (force format) with argument 'lavfi'.
Reading option '-i' ... matched as input url with argument 'nullsrc=s=1920x1080:d=300'.
Reading option '-i' ... matched as input url with argument 'test.srt'.
Reading option '-report' ... matched as option 'report' (generate a report) with argument '1'.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Applying option loglevel (set logging level) with argument 99.
Applying option report (generate a report) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input url nullsrc=s=1920x1080:d=300.
Applying option f (force format) with argument lavfi.
Successfully parsed a group of options.
Opening an input file: nullsrc=s=1920x1080:d=300.
detected 4 logical cores
[Parsed_nullsrc_0 @ 0x7ffafb403ec0] Setting 's' to value '1920x1080'
[Parsed_nullsrc_0 @ 0x7ffafb403ec0] Setting 'd' to value '300'
[Parsed_nullsrc_0 @ 0x7ffafb403ec0] size:1920x1080 rate:25/1 duration:300.000000 sar:1/1
[AVFilterGraph @ 0x7ffafb520e80] query_formats: 2 queried, 1 merged, 0 already done, 0 delayed
[lavfi @ 0x7ffafc001200] All info found
[lavfi @ 0x7ffafc001200] stream 0: start_time: 0.000 duration: -368934881474191040.000
[lavfi @ 0x7ffafc001200] format: start_time: 0.000 duration: -9223372036854.775 (estimate from bit rate) bitrate=0 kb/s
Input #0, lavfi, from 'nullsrc=s=1920x1080:d=300':
  Duration: N/A, start: 0.000000, bitrate: N/A
    Stream #0:0, 1, 1/25: Video: rawvideo, 1 reference frame (I420 / 0x30323449), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 0/1, 25 tbr, 25 tbn, 25 tbc
Successfully opened the file.
Parsing a group of options: input url test.srt.
Successfully parsed a group of options.
Opening an input file: test.srt.
[NULL @ 0x7ffafc00c200] Opening 'test.srt' for reading
[file @ 0x7ffafb520d80] Setting default whitelist 'file,crypto,data'
Probing srt score:100 size:2048
[srt @ 0x7ffafc00c200] Format srt probed with size=2048 and score=100
[srt @ 0x7ffafc00c200] Before avformat_find_stream_info() pos: 12632 bytes read:12632 seeks:0 nb_streams:1
[srt @ 0x7ffafc00c200] All info found
[srt @ 0x7ffafc00c200] stream 0: start_time: -9223372036854776.000 duration: -9223372036854776.000
[srt @ 0x7ffafc00c200] format: start_time: -9223372036854.775 duration: -9223372036854.775 (estimate from bit rate) bitrate=0 kb/s
[srt @ 0x7ffafc00c200] After avformat_find_stream_info() pos: 12632 bytes read:12632 seeks:0 frames:0
Input #1, srt, from 'test.srt':
  Duration: N/A, bitrate: N/A
    Stream #1:0, 0, 1/1000: Subtitle: subrip
Successfully opened the file.
At least one output file must be specified
[AVIOContext @ 0x7ffafb521480] Statistics: 12632 bytes read, 0 seeks

[jonas]

test srt file to reproduce the bug