#8109 closed defect (fixed)
Long loading delay for VfW codecs in Matroska
| Reported by: | Austin | Owned by: | |
|---|---|---|---|
| Priority: | normal | Component: | avformat |
| Version: | git-master | Keywords: | mkv |
| Cc: | Blocked By: | ||
| Blocking: | Reproduced by developer: | yes | |
| Analyzed by developer: | yes |
Description
Greetings,
I notice a very long loading/parsing delay (20+ seconds) in what appears to be the Matroska decoder when referencing MKV video files that are longer than 30 minutes in length.
Steps to reproduce:
1) Create one hour video files for testing using the attached 640x360 image (~8 GB each):
ffmpeg -loop true -i "MKVTest_640x360.bmp" -t 3600 -c:v utvideo -an -sn -dn -f avi -y "MKVTest.avi"
ffmpeg -loop true -i "MKVTest_640x360.bmp" -t 3600 -c:v utvideo -an -sn -dn -f mov -y "MKVTest.mov"
ffmpeg -loop true -i "MKVTest_640x360.bmp" -t 3600 -c:v utvideo -an -sn -dn -f matroska -write_crc32 false -y "MKVTest.mkv"
2) Stream copy a section of video that is 50 minutes into the test files:
ffmpeg -ss 00:50:00.000 -i "MKVTest.avi" -t 1 -c copy -y "LoadAndSeek.avi"
ffmpeg -ss 00:50:00.000 -i "MKVTest.mov" -t 1 -c copy -y "LoadAndSeek.mov"
ffmpeg -ss 00:50:00.000 -i "MKVTest.mkv" -t 1 -c copy -y "LoadAndSeek.mkv"
Output Observations:
The AVI and MOV files are able to stream copy instantly. The MKV file stalls for 20 seconds before transcoding begins.
Other Observations:
HuffYUV and MagicYUV are also affected by slow Matroska loading and playback. FFmpeg appears to be creating a MOV file wrapped by Matroska when using Video for Windows lossless codecs. If those codecs are written directly to a MOV file, load and playback are instant. Adding the Matroska wrapper is what appears to slow things down. My assumption is that the Matroska decoder in ffmpeg is the problem because non-ffmpeg media players like MPC-BE are able to instantly play back and seek the MKV file generated by ffmpeg. This suggests the ffmpeg encoder and Matroska file format are performing as expected, and the problem is contained to the ffmpeg decoder.
Why this bug is significant:
For video editors that are built on top of ffmpeg (like Shotcut and Kdenlive), the long loading time ripples up to the editor and makes opening a project take a very long time. Playback and seeking are extremely slow for videos longer than 30 minutes, meaning the MKV format is unusable for editing biking videos, wedding event capture, surveillance video, etc.
Matroska is an important format because it retains color space and color range metadata for lossless VfW codecs. AVI retains neither, and MOV doesn't have an official color range flag. I'm not aware of any alternative containers for VfW codecs that capture all color metadata, so getting ffmpeg to decode Matroska at the same speed as MPC-BE or a native MOV file would be of great benefit to the libre video editing world. The lossless VfW codecs are popular for proxy editing due to their speed and color accuracy.
Thank you in advance for anything you can find.
-Austin
Uncut console output is as follows:
ffmpeg version N-94664-g0821bc4eee Copyright (c) 2000-2019 the FFmpeg developers
built with gcc 9.1.1 (GCC) 20190807
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-libmfx --enable-amf --enable-ffnvcodec --enable-cuvid --enable-d3d11va --enable-nvenc --enable-nvdec --enable-dxva2 --enable-avisynth --enable-libopenmpt
libavutil 56. 33.100 / 56. 33.100
libavcodec 58. 55.101 / 58. 55.101
libavformat 58. 31.104 / 58. 31.104
libavdevice 58. 9.100 / 58. 9.100
libavfilter 7. 58.101 / 7. 58.101
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 '-ss' ... matched as option 'ss' (set the start time offset) with argument '00:50:00.000'.
Reading option '-i' ... matched as input url with argument 'MKVTest.mkv'.
Reading option '-t' ... matched as option 't' (record or transcode "duration" seconds of audio/video) with argument '1'.
Reading option '-c' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '-y' ... matched as option 'y' (overwrite output files) with argument '1'.
Reading option 'LoadAndSeek.mkv' ... matched as output url.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Applying option y (overwrite output files) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input url MKVTest.mkv.
Applying option ss (set the start time offset) with argument 00:50:00.000.
Successfully parsed a group of options.
Opening an input file: MKVTest.mkv.
[NULL @ 0000000000460840] Opening 'MKVTest.mkv' for reading
[file @ 0000000000462100] Setting default whitelist 'file,crypto'
Probing matroska,webm score:100 size:2048
Probing mp3 score:1 size:2048
[matroska,webm @ 0000000000460840] Format matroska,webm probed with size=2048 and score=100
st:0 removing common factor 1000000 from timebase
[matroska,webm @ 0000000000460840] Before avformat_find_stream_info() pos: 697 bytes read:32768 seeks:0 nb_streams:1
[matroska,webm @ 0000000000460840] parser not found for codec utvideo, packets or times may be invalid.
[utvideo @ 000000000046a4c0] Encoder version 1.0.0.240
[utvideo @ 000000000046a4c0] Original format 118
[utvideo @ 000000000046a4c0] Encoding parameters 02000001
[matroska,webm @ 0000000000460840] parser not found for codec utvideo, packets or times may be invalid.
[matroska,webm @ 0000000000460840] All info found
[matroska,webm @ 0000000000460840] stream 0: start_time: 0.000 duration: -9223372036854776.000
[matroska,webm @ 0000000000460840] format: start_time: 0.000 duration: 3600.000 bitrate=18374 kb/s
[matroska,webm @ 0000000000460840] After avformat_find_stream_info() pos: 92543 bytes read:92543 seeks:0 frames:1
Input #0, matroska,webm, from 'MKVTest.mkv':
Metadata:
ENCODER : Lavf58.29.100
Duration: 01:00:00.00, start: 0.000000, bitrate: 18374 kb/s
Stream #0:0, 1, 1/1000: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360, 0/1, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.54.100 utvideo
DURATION : 01:00:00.000000000
Successfully opened the file.
Parsing a group of options: output url LoadAndSeek.mkv.
Applying option t (record or transcode "duration" seconds of audio/video) with argument 1.
Applying option c (codec name) with argument copy.
Successfully parsed a group of options.
Opening an output file: LoadAndSeek.mkv.
[file @ 000000000301be00] Setting default whitelist 'file,crypto'
Successfully opened the file.
[matroska @ 000000000288b400] get_metadata_duration returned: 3600000000
[matroska @ 000000000288b400] Write early duration from recording time = 1000
Output #0, matroska, to 'LoadAndSeek.mkv':
Metadata:
encoder : Lavf58.31.104
Stream #0:0, 0, 1/1000: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360 (0x0), 0/1, q=2-31, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.54.100 utvideo
DURATION : 01:00:00.000000000
Stream mapping:
Press [q] to stop, ? for help
cur_dts is invalid st:0 (0) [init:1 i_done:0 finish:0] (this is harmless if it occurs once at the start per stream)
[matroska @ 000000000288b400] Writing block of size 91832 with pts 0, dts 0, duration 40 at relative offset 9 in cluster at offset 711. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 92567 bytes, pts 40, dts 40
[matroska @ 000000000288b400] Writing block of size 91832 with pts 40, dts 40, duration 40 at relative offset 9 in cluster at offset 92567. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 184423 bytes, pts 80, dts 80
[matroska @ 000000000288b400] Writing block of size 91832 with pts 80, dts 80, duration 40 at relative offset 9 in cluster at offset 184423. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 276279 bytes, pts 120, dts 120
[matroska @ 000000000288b400] Writing block of size 91832 with pts 120, dts 120, duration 40 at relative offset 9 in cluster at offset 276279. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 368135 bytes, pts 160, dts 160
[matroska @ 000000000288b400] Writing block of size 91832 with pts 160, dts 160, duration 40 at relative offset 9 in cluster at offset 368135. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 459991 bytes, pts 200, dts 200
[matroska @ 000000000288b400] Writing block of size 91832 with pts 200, dts 200, duration 40 at relative offset 9 in cluster at offset 459991. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 551847 bytes, pts 240, dts 240
[matroska @ 000000000288b400] Writing block of size 91832 with pts 240, dts 240, duration 40 at relative offset 9 in cluster at offset 551847. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 643703 bytes, pts 280, dts 280
[matroska @ 000000000288b400] Writing block of size 91832 with pts 280, dts 280, duration 40 at relative offset 10 in cluster at offset 643703. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 735560 bytes, pts 320, dts 320
[matroska @ 000000000288b400] Writing block of size 91832 with pts 320, dts 320, duration 40 at relative offset 10 in cluster at offset 735560. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 827417 bytes, pts 360, dts 360
[matroska @ 000000000288b400] Writing block of size 91832 with pts 360, dts 360, duration 40 at relative offset 10 in cluster at offset 827417. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 919274 bytes, pts 400, dts 400
[matroska @ 000000000288b400] Writing block of size 91832 with pts 400, dts 400, duration 40 at relative offset 10 in cluster at offset 919274. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1011131 bytes, pts 440, dts 440
[matroska @ 000000000288b400] Writing block of size 91832 with pts 440, dts 440, duration 40 at relative offset 10 in cluster at offset 1011131. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1102988 bytes, pts 480, dts 480
[matroska @ 000000000288b400] Writing block of size 91832 with pts 480, dts 480, duration 40 at relative offset 10 in cluster at offset 1102988. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1194845 bytes, pts 520, dts 520
[matroska @ 000000000288b400] Writing block of size 91832 with pts 520, dts 520, duration 40 at relative offset 10 in cluster at offset 1194845. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1286702 bytes, pts 560, dts 560
[matroska @ 000000000288b400] Writing block of size 91832 with pts 560, dts 560, duration 40 at relative offset 10 in cluster at offset 1286702. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1378559 bytes, pts 600, dts 600
[matroska @ 000000000288b400] Writing block of size 91832 with pts 600, dts 600, duration 40 at relative offset 10 in cluster at offset 1378559. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1470416 bytes, pts 640, dts 640
[matroska @ 000000000288b400] Writing block of size 91832 with pts 640, dts 640, duration 40 at relative offset 10 in cluster at offset 1470416. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1562273 bytes, pts 680, dts 680
[matroska @ 000000000288b400] Writing block of size 91832 with pts 680, dts 680, duration 40 at relative offset 10 in cluster at offset 1562273. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1654130 bytes, pts 720, dts 720
[matroska @ 000000000288b400] Writing block of size 91832 with pts 720, dts 720, duration 40 at relative offset 10 in cluster at offset 1654130. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1745987 bytes, pts 760, dts 760
[matroska @ 000000000288b400] Writing block of size 91832 with pts 760, dts 760, duration 40 at relative offset 10 in cluster at offset 1745987. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1837844 bytes, pts 800, dts 800
[matroska @ 000000000288b400] Writing block of size 91832 with pts 800, dts 800, duration 40 at relative offset 10 in cluster at offset 1837844. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 1929701 bytes, pts 840, dts 840
[matroska @ 000000000288b400] Writing block of size 91832 with pts 840, dts 840, duration 40 at relative offset 10 in cluster at offset 1929701. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 2021558 bytes, pts 880, dts 880
[matroska @ 000000000288b400] Writing block of size 91832 with pts 880, dts 880, duration 40 at relative offset 10 in cluster at offset 2021558. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 2113415 bytes, pts 920, dts 920
[matroska @ 000000000288b400] Writing block of size 91832 with pts 920, dts 920, duration 40 at relative offset 10 in cluster at offset 2113415. TrackNumber 1, keyframe 1
[matroska @ 000000000288b400] Starting new cluster at offset 2205272 bytes, pts 960, dts 960
[matroska @ 000000000288b400] Writing block of size 91832 with pts 960, dts 960, duration 40 at relative offset 10 in cluster at offset 2205272. TrackNumber 1, keyframe 1
No more output streams to write to, finishing.
[matroska @ 000000000288b400] end duration = 1000
[matroska @ 000000000288b400] stream 0 end duration = 1000
frame= 25 fps=0.0 q=-1.0 Lsize= 2244kB time=00:00:00.96 bitrate=19126.8kbits/s speed=96.1x
video:2242kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.078753%
Input file #0 (MKVTest.mkv):
Input stream #0:0 (video): 26 packets read (2387632 bytes);
Total: 26 packets (2387632 bytes) demuxed
Output file #0 (LoadAndSeek.mkv):
Output stream #0:0 (video): 25 packets muxed (2295800 bytes);
Total: 25 packets (2295800 bytes) muxed
0 frames successfully decoded, 0 decoding errors
[AVIOContext @ 000000000288f180] Statistics: 8 seeks, 31 writeouts
[AVIOContext @ 000000000046a380] Statistics: 4412112 bytes read, 3 seeks
Attachments (1)
Change History (11)
by , 5 years ago
| Attachment: | MKVTest_640x360.bmp added |
|---|
comment:1 by , 5 years ago
| Resolution: | → worksforme |
|---|---|
| Status: | new → closed |
I cannot reproduce any measurable delay (disk cache cleared):
$ ffmpeg -loglevel verbose -benchmark -ss 00:50:00.000 -i MKVTest.mkv -t 1 -c copy LoadAndSeek.mkv
ffmpeg version N-94680-gffd65c8862 Copyright (c) 2000-2019 the FFmpeg developers
built with gcc 9 (SUSE Linux)
configuration: --enable-gpl --enable-gnutls --enable-libxml2 --enable-libx264 --enable-libx265 --enable-libvpx --enable-libaom
libavutil 56. 33.100 / 56. 33.100
libavcodec 58. 55.102 / 58. 55.102
libavformat 58. 31.104 / 58. 31.104
libavdevice 58. 9.100 / 58. 9.100
libavfilter 7. 58.101 / 7. 58.101
libswscale 5. 6.100 / 5. 6.100
libswresample 3. 6.100 / 3. 6.100
libpostproc 55. 6.100 / 55. 6.100
[matroska,webm @ 0x215bc80] parser not found for codec utvideo, packets or times may be invalid.
Last message repeated 1 times
Input #0, matroska,webm, from 'MKVTest.mkv':
Metadata:
ENCODER : Lavf58.31.104
Duration: 01:00:00.00, start: 0.000000, bitrate: 18374 kb/s
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.55.102 utvideo
DURATION : 01:00:00.000000000
Output #0, matroska, to 'LoadAndSeek.mkv':
Metadata:
encoder : Lavf58.31.104
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360 (0x0), q=2-31, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.55.102 utvideo
DURATION : 01:00:00.000000000
Stream mapping:
Stream #0:0 -> #0:0 (copy)
Press [q] to stop, [?] for help
No more output streams to write to, finishing.
frame= 25 fps=0.0 q=-1.0 Lsize= 2244kB time=00:00:00.96 bitrate=19126.8kbits/s speed=18.8x
video:2242kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.078753%
Input file #0 (MKVTest.mkv):
Input stream #0:0 (video): 26 packets read (2387632 bytes);
Total: 26 packets (2387632 bytes) demuxed
Output file #0 (LoadAndSeek.mkv):
Output stream #0:0 (video): 25 packets muxed (2295800 bytes);
Total: 25 packets (2295800 bytes) muxed
bench: utime=0.004s stime=0.007s rtime=0.051s
bench: maxrss=22704kB
[AVIOContext @ 0x242f900] Statistics: 8 seeks, 31 writeouts
[AVIOContext @ 0x2164b80] Statistics: 4412112 bytes read, 3 seeks
comment:2 by , 5 years ago
| Reproduced by developer: | set |
|---|---|
| Resolution: | worksforme |
| Status: | closed → reopened |
I can reproduce some delay, but not 20+ seconds. This is on Windows, same as the ticket's reporter.
The -benchmark option doesn't reflect it, only the external time tool does.
$ time ./ffmpeg -loglevel verbose -benchmark -ss 00:50:00.000 -i /d/MKVTest.mkv -c:v copy -t 1 -f matroska -y NUL
ffmpeg version N-94715-ga12b629ae1 Copyright (c) 2000-2019 the FFmpeg developers
built with gcc 9.2.0 (Rev1, Built by MSYS2 project)
configuration: --enable-gpl --enable-nonfree --enable-libxml2 --enable-libaom --enable-libdav1d --enable-libfdk-aac --enable-libmp3lame --enable-libopus --enable-libvorbis --enable-libvpx --enable-libx264 --enable-libx265 --enable-libwebp --enable-libzimg --cpu=haswell --extra-cflags='-D_WIN32_WINNT=0x0A00' --cc='ccache gcc' --disable-avx512 --samples=../samples --prefix=/mingw64
libavutil 56. 34.100 / 56. 34.100
libavcodec 58. 56.101 / 58. 56.101
libavformat 58. 31.104 / 58. 31.104
libavdevice 58. 9.100 / 58. 9.100
libavfilter 7. 58.102 / 7. 58.102
libswscale 5. 6.100 / 5. 6.100
libswresample 3. 6.100 / 3. 6.100
libpostproc 55. 6.100 / 55. 6.100
[matroska,webm @ 0000000003a68120] parser not found for codec utvideo, packets or times may be invalid.
Last message repeated 1 times
Input #0, matroska,webm, from 'D:/MKVTest.mkv':
Metadata:
ENCODER : Lavf58.31.104
Duration: 01:00:00.00, start: 0.000000, bitrate: 18374 kb/s
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.56.101 utvideo
DURATION : 01:00:00.000000000
Output #0, matroska, to 'NUL':
Metadata:
encoder : Lavf58.31.104
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360 (0x0), q=2-31, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.56.101 utvideo
DURATION : 01:00:00.000000000
Stream mapping:
Stream #0:0 -> #0:0 (copy)
Press [q] to stop, [?] for help
No more output streams to write to, finishing.
frame= 25 fps=0.0 q=-1.0 Lsize= 2244kB time=00:00:00.96 bitrate=19126.8kbits/s speed= 235x
video:2242kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.078753%
Input file #0 (D:/MKVTest.mkv):
Input stream #0:0 (video): 26 packets read (2387632 bytes);
Total: 26 packets (2387632 bytes) demuxed
Output file #0 (NUL):
Output stream #0:0 (video): 25 packets muxed (2295800 bytes);
Total: 25 packets (2295800 bytes) muxed
bench: utime=0.000s stime=0.000s rtime=0.004s
bench: maxrss=31844kB
[AVIOContext @ 0000000004070ec0] Statistics: 8 seeks, 31 writeouts
[AVIOContext @ 0000000003a692e0] Statistics: 4412112 bytes read, 3 seeks
real 0m4.607s
user 0m0.000s
sys 0m0.000s
comment:3 by , 5 years ago
I cannot reproduce on Linux:
$ time ffmpeg -loglevel verbose -benchmark -ss 00:50:00.000 -i MKVTest.mkv -t 1 -c copy LoadAndSeek.mkv
ffmpeg version N-94754-gef43a4d6b3 Copyright (c) 2000-2019 the FFmpeg developers
built with gcc 9 (SUSE Linux)
configuration: --enable-gpl --enable-gnutls --enable-libxml2 --enable-libx264 --enable-libx265 --enable-libvpx --enable-libaom
libavutil 56. 34.100 / 56. 34.100
libavcodec 58. 56.101 / 58. 56.101
libavformat 58. 32.104 / 58. 32.104
libavdevice 58. 9.100 / 58. 9.100
libavfilter 7. 58.102 / 7. 58.102
libswscale 5. 6.100 / 5. 6.100
libswresample 3. 6.100 / 3. 6.100
libpostproc 55. 6.100 / 55. 6.100
[matroska,webm @ 0x2b96c80] parser not found for codec utvideo, packets or times may be invalid.
Last message repeated 1 times
Input #0, matroska,webm, from 'MKVTest.mkv':
Metadata:
ENCODER : Lavf58.31.104
Duration: 01:00:00.00, start: 0.000000, bitrate: 18374 kb/s
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.55.102 utvideo
DURATION : 01:00:00.000000000
Output #0, matroska, to 'LoadAndSeek.mkv':
Metadata:
encoder : Lavf58.32.104
Stream #0:0: Video: utvideo, 1 reference frame (ULRG / 0x47524C55), gbrp, 640x360 (0x0), q=2-31, 25 fps, 25 tbr, 1k tbn, 1k tbc (default)
Metadata:
ENCODER : Lavc58.55.102 utvideo
DURATION : 01:00:00.000000000
Stream mapping:
Stream #0:0 -> #0:0 (copy)
Press [q] to stop, [?] for help
No more output streams to write to, finishing.
frame= 25 fps=0.0 q=-1.0 Lsize= 2244kB time=00:00:00.96 bitrate=19126.8kbits/s speed=3.92x
video:2242kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.078753%
Input file #0 (MKVTest.mkv):
Input stream #0:0 (video): 26 packets read (2387632 bytes);
Total: 26 packets (2387632 bytes) demuxed
Output file #0 (LoadAndSeek.mkv):
Output stream #0:0 (video): 25 packets muxed (2295800 bytes);
Total: 25 packets (2295800 bytes) muxed
bench: utime=0.010s stime=0.001s rtime=0.245s
bench: maxrss=22440kB
[AVIOContext @ 0x2e6a900] Statistics: 8 seeks, 31 writeouts
[AVIOContext @ 0x2b9fb80] Statistics: 4412112 bytes read, 3 seeks
real 0m0.738s
user 0m0.068s
sys 0m0.017s
comment:4 by , 5 years ago
Thank you for investigating so quickly! This is encouraging.
Even if the delay is only 4 seconds (Windows only apparently), this still causes a Kdenlive or Shotcut video editing project with 30 long clips to take an extra two minutes to load. My multi-cam projects in particular bump into this issue.
I should have added that the older and slower the hardware, the longer the MKV parsing appears to take by an exponential amount. The computer that took 20+ seconds is a dual-socket 16-thread 2.4GHz Xeon E5530 from ten years ago running Windows 7. It is not fast by today's standards, but it still works great for video editing if using 640x360 proxies. Unfortunately, I can't get proxies to use full-range YUV video without a flag from a Matroska container, hence this ticket. But even on my old hardware, the AVI and MOV files are still instant in all usage scenarios whereas MKV is not. MKV is somewhat improved on my faster hardware with Windows 10, but still never instant. Perhaps my older hardware is missing a CPU instruction set that optimizes things?
comment:5 by , 5 years ago
| Analyzed by developer: | set |
|---|
The file has 90000 cue entries and parsing them involves reallocating an array for the entries. And Windows seems to be bad at this if the array gets big (does it always copy?). Here are timings for the calls to av_realloc_array in ebml_parse (notice that these numbers also include the allocations of the single MatroskaIndexPos (that don't get reallocated lateron)):
55880 decicycles in realloc, 16 runs, 0 skips 35677 decicycles in realloc, 32 runs, 0 skips 25478 decicycles in realloc, 63 runs, 1 skips 17347 decicycles in realloc, 127 runs, 1 skips 16525 decicycles in realloc, 252 runs, 4 skips 15753 decicycles in realloc, 505 runs, 7 skips 18281 decicycles in realloc, 1013 runs, 11 skips 27369 decicycles in realloc, 2036 runs, 12 skips 46154 decicycles in realloc, 4077 runs, 19 skips 93221 decicycles in realloc, 8152 runs, 40 skips 163832 decicycles in realloc, 16311 runs, 73 skips 222335 decicycles in realloc, 32677 runs, 91 skips 383875 decicycles in realloc, 65417 runs, 119 skips 731573 decicycles in realloc, 130667 runs, 405 skips
It's even more insane if one does not discard outlier:
46876 decicycles in realloc, 16 runs, 31958 decicycles in realloc, 32 runs, 24342 decicycles in realloc, 64 runs, 15159 decicycles in realloc, 128 runs, 12448 decicycles in realloc, 256 runs, 11096 decicycles in realloc, 512 runs, 12053 decicycles in realloc, 1024 runs, 15506 decicycles in realloc, 2048 runs, 27108 decicycles in realloc, 4096 runs, 50788 decicycles in realloc, 8192 runs, 91929 decicycles in realloc, 16384 runs, 181616 decicycles in realloc, 32768 runs, 379396 decicycles in realloc, 65536 runs, 880554 decicycles in realloc, 131072 runs,
comment:6 by , 5 years ago
Thank you so much, mkver. I found two articles stating that realloc() on Windows is "much more likely" to copy data than Linux and Mac for the same workload:
https://blog.kowalczyk.info/article/2be/realloc-on-Windows-vs-Linux.html
https://stackoverflow.com/questions/27627707/how-to-get-a-page-table-savvy-realloc-on-windows
The Microsoft documentation seems to suggest that realloc() is just a wrapper to malloc() although I can't tell if that's only the case of a null pointer passed in:
https://docs.microsoft.com/en-us/cpp/c-runtime-library/reference/realloc?view=vs-2019
Is there anything I can do to help?
comment:7 by , 5 years ago
| Component: | undetermined → avformat |
|---|---|
| Keywords: | mkv added |
comment:8 by , 5 years ago
| Resolution: | → fixed |
|---|---|
| Status: | reopened → closed |
Should be fixed in 3b3150c45f1ebb3635e55e76b63439d8d62de85f
Thanks to mkver who analyzed and found the source of the problem.
comment:9 by , 5 years ago
Absolutely incredible. Thank you everyone. I don't know what inspired James to resurrect a closed ticket, but I'm glad he did. This fix is a game changer for proxy work in Shotcut.
comment:10 by , 5 years ago
I'm following up to say that the fix has resolved all issues I encountered in the ticket description. I just tested the 20190909-9d1e98a nightly build from Zeranoe and the load time for MKV is now instant just like AVI and MOV. Shotcut loads a video editing project much faster too. Thank you everyone so much for resolving this issue. Matroska just went from unusable to preferred when it comes to long videos on Windows. Also, the turtle-speed memory bus on my ten year old hardware explains why realloc() took so much longer to grow than the developers' PCs.
Yellow text on green background, totally generic, just for sake of example