Past duration 0.999992 too large

[MysteryX]

Summary of the bug:
How to reproduce:

% ffmpeg -i "Job2_Source.mpg" -vcodec utvideo -an "Job2_Temp.avi"
ffmpeg version N-73361-g03b2b40
built with gcc 4.9.2 (GCC)

Using this input file (MPEG VCD file)
​https://www.spiritualselftransformation.com/files/media-encoder-old.mpg

The conversion to AVI works but is slow and keeps throwing the error "Past duration 0.999992 too large".

Converting with build N-67118-g08e6832 works fine and is about 3x faster.

Here's the full console output.

ffmpeg.exe -i "Job2_Source.mpg" -vcodec utvideo -an "Job1_Temp.avi"
ffmpeg version N-73361-g03b2b40 Copyright (c) 2000-2015 the FFmpeg developers
  built with gcc 4.9.2 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-av
isynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enab
le-iconv --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --
enable-libdcadec --enable-libfreetype --enable-libgme --enable-libgsm --enable-l
ibilbc --enable-libmodplug --enable-libmp3lame --enable-libopencore-amrnb --enab
le-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-librtmp --en
able-libschroedinger --enable-libsoxr --enable-libspeex --enable-libtheora --ena
ble-libtwolame --enable-libvidstab --enable-libvo-aacenc --enable-libvo-amrwbenc
 --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enabl
e-libx264 --enable-libx265 --enable-libxavs --enable-libxvid --enable-lzma --ena
ble-decklink --enable-zlib
  libavutil      54. 27.100 / 54. 27.100
  libavcodec     56. 46.100 / 56. 46.100
  libavformat    56. 40.100 / 56. 40.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5. 19.100 /  5. 19.100
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  2.100 /  1.  2.100
  libpostproc    53.  3.100 / 53.  3.100
Input #0, mpeg, from 'Job2_Source.mpg':
  Duration: 00:04:31.57, start: 0.699856, bitrate: 1394 kb/s
    Stream #0:0[0x1e0]: Video: mpeg1video, yuv420p(tv), 352x288 [SAR 178:163 DAR
 1958:1467], 1152 kb/s, 25 fps, 25 tbr, 90k tbn, 25 tbc
    Stream #0:1[0x1c0]: Audio: mp2, 44100 Hz, stereo, s16p, 224 kb/s
File 'Job1_Temp.avi' already exists. Overwrite ? [y/N] y
Output #0, avi, to 'Job1_Temp.avi':
  Metadata:
    ISFT            : Lavf56.40.100
    Stream #0:0: Video: utvideo (ULY0 / 0x30594C55), yuv420p, 352x288 [SAR 178:1
63 DAR 1958:1467], q=2-31, 200 kb/s, 25 fps, 25 tbn, 25 tbc
    Metadata:
      encoder         : Lavc56.46.100 utvideo
Stream mapping:
  Stream #0:0 -> #0:0 (mpeg1video (native) -> utvideo (native))
Press [q] to stop, [?] for help
Past duration 0.999992 too large
    Last message repeated 63 times
frame=   66 fps=0.0 q=0.0 size=    2137kB time=00:00:02.52 bitrate=6948.2kbits/s
Past duration 0.999992 too large
    Last message repeated 321 times
frame=  388 fps=388 q=0.0 size=   21195kB time=00:00:15.40 bitrate=11274.6kbits/
Past duration 0.999992 too large
    Last message repeated 323 times
frame=  712 fps=475 q=0.0 size=   44169kB time=00:00:28.36 bitrate=12758.5kbits/
Past duration 0.999992 too large
    Last message repeated 326 times
frame= 1039 fps=519 q=0.0 size=   67234kB time=00:00:41.44 bitrate=13291.1kbits/
Past duration 0.999992 too large
    Last message repeated 323 times
frame= 1363 fps=545 q=0.0 size=   92675kB time=00:00:54.40 bitrate=13955.8kbits/
Past duration 0.999992 too large
    Last message repeated 319 times
frame= 1683 fps=561 q=0.0 size=  119482kB time=00:01:07.20 bitrate=14565.5kbits/
Past duration 0.999992 too large
    Last message repeated 319 times
frame= 2003 fps=572 q=0.0 size=  144694kB time=00:01:20.00 bitrate=14816.7kbits/
Past duration 0.999992 too large
    Last message repeated 322 times
frame= 2326 fps=581 q=0.0 size=  171286kB time=00:01:32.92 bitrate=15100.9kbits/
Past duration 0.999992 too large
    Last message repeated 322 times
frame= 2649 fps=588 q=0.0 size=  198910kB time=00:01:45.84 bitrate=15395.6kbits/
Past duration 0.999992 too large
    Last message repeated 324 times
frame= 2974 fps=595 q=0.0 size=  225410kB time=00:01:58.84 bitrate=15538.2kbits/
Past duration 0.999992 too large
    Last message repeated 321 times
frame= 3296 fps=599 q=0.0 size=  251311kB time=00:02:11.72 bitrate=15629.6kbits/
Past duration 0.999992 too large
    Last message repeated 321 times
frame= 3618 fps=603 q=0.0 size=  278347kB time=00:02:24.60 bitrate=15769.1kbits/
Past duration 0.999992 too large
    Last message repeated 324 times
frame= 3943 fps=606 q=0.0 size=  306338kB time=00:02:37.60 bitrate=15923.4kbits/
Past duration 0.999992 too large
    Last message repeated 322 times
frame= 4266 fps=609 q=0.0 size=  332256kB time=00:02:50.52 bitrate=15962.0kbits/
Past duration 0.999992 too large
    Last message repeated 322 times
frame= 4589 fps=611 q=0.0 size=  357468kB time=00:03:03.44 bitrate=15963.7kbits/
Past duration 0.999992 too large
    Last message repeated 323 times
frame= 4913 fps=614 q=0.0 size=  381838kB time=00:03:16.40 bitrate=15926.8kbits/
Past duration 0.999992 too large
    Last message repeated 273 times
frame= 5187 fps=610 q=0.0 size=  404312kB time=00:03:27.36 bitrate=15972.8kbits/
Past duration 0.999992 too large
    Last message repeated 326 times
frame= 5514 fps=612 q=0.0 size=  429653kB time=00:03:40.44 bitrate=15966.8kbits/
Past duration 0.999992 too large
    Last message repeated 320 times
frame= 5835 fps=614 q=0.0 size=  456513kB time=00:03:53.28 bitrate=16031.2kbits/
Past duration 0.999992 too large
    Last message repeated 323 times
frame= 6159 fps=615 q=0.0 size=  482825kB time=00:04:06.24 bitrate=16062.8kbits/
Past duration 0.999992 too large
    Last message repeated 323 times
frame= 6483 fps=617 q=0.0 size=  507140kB time=00:04:19.20 bitrate=16028.1kbits/
Past duration 0.999992 too large
    Last message repeated 303 times
frame= 6787 fps=618 q=0.0 Lsize=  527190kB time=00:04:31.48 bitrate=15908.1kbits
/s dup=0 drop=1
video:527025kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxin
g overhead: 0.031253%

[Ganesh Ajjanagadde]

I did a benchmark using the file provided, and nowhere do I notice a "3x" slowdown.

Here are the results using the time command:
N-67118-g08e6832:
ffmpeg -i media-encoder-old.mpg -vcodec utvideo -an media-encoder-old.avi 10.50s user 0.72s system 309% cpu 3.621 total

git-master:
ffmpeg -i media-encoder-old.mpg -vcodec utvideo -an media-encoder-old.avi 10.53s user 0.70s system 329% cpu 3.406 total

Furthermore,
check with hex editor reveals that encoding has not changed, i.e output files are practically identical.
Thus, there is no defect in the output produced.

Note that this past duration thing is a warning,
so if there is any slowdown, it could be due to the I/O for the warning, though I highly doubt that.
This may be disabled easily with e.g -loglevel -quiet.

Could you give more detailed benchmarks in order to substantiate your claim?

[MysteryX]

OK I've done the benchmark. 10 seconds for the old version and 17 seconds for the new version.

Here are the screen captures

Old
​https://mega.co.nz/#!6BBRRIKB!ZqoQGIymi_JCKB85pdVEcmDsaTF_mN0IgRtT_NGF8_8

New
​https://mega.co.nz/#!iBBBWRxK!_4NO7-w7g6bEy20wjO1H60EVzN7fLNy7OA0KUxkidEg

You're right, it's not 3x slowdown :)

[Ganesh Ajjanagadde]

As my comment above indicates, I get nowhere near that level of difference between the two cases with the file you uploaded. Was this test with a new file? If so, please provide the file. Also, it would be helpful if you could try disabling the log as I mentioned above and reporting your results.

[MysteryX]

Interesting. With the original video file, I get 22sec with log and 11 sec with -loglevel quiet

[Ganesh Ajjanagadde]

I guess we can confirm that slowdown is due to the I/O for the warnings.
This issue originates in commit 7b32856011d1859a974b884f76bd17b7a7fdab76.
I do not regard it as a bug; the encoding is identical, and encoding speed is identical
before and after this commit.
The warning is perhaps annoying, but is quite rare and occurs for a reason described in the commit
message. Moreover, it may be easily disabled as I described above.

Unless you can give a solid justification as to why this warning is incorrect,
this ticket should be closed.
For now, I will close it as won't fix; reopen if you find such a justification.