Opened 7 years ago

Last modified 13 months ago

#6037 open defect

mkv muxing not broken

Reported by: q3cpma Owned by:
Priority: important Component: avformat
Version: git-master Keywords: regression
Cc: v0qiu24elio.ldb63qpfmjrkkiv9el@gmail.com, zagser168@yandex.ru, mail@himbeer.me, hasezoey Blocked By:
Blocking: Reproduced by developer: yes
Analyzed by developer: no

Description

Summary of the bug:
Muxing two working files (AC3 stream + DVD sub stream and a freshly encoded ffv1 stream) into a mkv produces a broken file: seeking around can break (mute) audio.
Reproducible with both mpv and ffplay (example: seek to around 5.5s).

It seem like http://ffmpeg.gusari.org/viewtopic.php?f=11&t=2713 is related.

On the longer sample, I also get:
-Audio being muted without having to seek
-"Starting new cluster due to timestamp" matroska warnings during mux
-"[mkv] Too many packets in the demuxer packet queues" errors in mpv

How to reproduce:

ffmpeg -y -i 20s.mkv -i ffv1.mkv -map 0:a:1 -map 0:s -map 1:v -c copy out.mkv >ffmpeg.log 2>&1
ffmpeg version 3.2.2 Copyright (c) 2000-2016 the FFmpeg developers
  built with gcc 4.9.3 (Gentoo 4.9.3 p1.5, pie-0.6.4)
  configuration: --prefix=/usr --libdir=/usr/lib64 --shlibdir=/usr/lib64 --docdir=/usr/share/doc/ffmpeg-3.2.2/html --mandir=/usr/share/man --enable-shared --cc=x86_64-pc-linux-gnu-gcc --cxx=x86_64-pc-linux-gnu-g++ --ar=x86_64-pc-linux-gnu-ar --optflags='-O2 -march=native -mprefer-avx128 -mvzeroupper -pipe' --disable-static --enable-avfilter --enable-avresample --disable-stripping --enable-nonfree --disable-indev=v4l2 --disable-outdev=v4l2 --disable-indev=oss --disable-indev=jack --disable-outdev=oss --enable-bzlib --disable-runtime-cpudetect --disable-debug --disable-gcrypt --disable-gnutls --disable-gmp --enable-gpl --enable-hardcoded-tables --enable-iconv --disable-lzma --enable-network --enable-openssl --enable-postproc --disable-libsmbclient --enable-ffplay --enable-sdl2 --disable-vaapi --disable-vdpau --enable-xlib --disable-libxcb --disable-libxcb-shm --disable-libxcb-xfixes --enable-zlib --disable-libcdio --disable-libiec61883 --disable-libdc1394 --disable-libcaca --disable-openal --enable-opengl --disable-libv4l2 --disable-libpulse --disable-libopencore-amrwb --disable-libopencore-amrnb --disable-libfdk-aac --disable-libopenjpeg --enable-libbluray --disable-libcelt --disable-libgme --disable-libgsm --disable-mmal --disable-libmodplug --enable-libopus --disable-libilbc --disable-librtmp --disable-libssh --disable-libschroedinger --disable-libspeex --enable-libvorbis --enable-libvpx --disable-libzvbi --disable-libbs2b --disable-chromaprint --disable-libebur128 --disable-libflite --disable-frei0r --disable-libfribidi --disable-fontconfig --disable-ladspa --enable-libass --disable-libfreetype --disable-librubberband --enable-libzimg --disable-libsoxr --enable-pthreads --disable-libvo-amrwbenc --enable-libmp3lame --disable-libkvazaar --disable-nvenc --disable-libopenh264 --disable-libsnappy --disable-libtheora --disable-libtwolame --disable-libwavpack --disable-libwebp --enable-libx264 --enable-libx265 --disable-libxvid --enable-x11grab --disable-amd3dnow --disable-amd3dnowext --disable-avx2 --cpu=host --disable-doc --disable-htmlpages --enable-manpages
  libavutil      55. 34.100 / 55. 34.100
  libavcodec     57. 64.101 / 57. 64.101
  libavformat    57. 56.100 / 57. 56.100
  libavdevice    57.  1.100 / 57.  1.100
  libavfilter     6. 65.100 /  6. 65.100
  libavresample   3.  1.  0 /  3.  1.  0
  libswscale      4.  2.100 /  4.  2.100
  libswresample   2.  3.100 /  2.  3.100
  libpostproc    54.  1.100 / 54.  1.100
Input #0, matroska,webm, from '20s.mkv':
  Metadata:
    title           : Gunsmith Cats
    ENCODER         : Lavf57.56.100
  Duration: 00:00:20.16, start: 0.016000, bitrate: 7009 kb/s
    Chapter #0:0: start 0.064000, end 20.000000
    Metadata:
      title           : 0 1
    Stream #0:0(eng): Audio: ac3, 48000 Hz, stereo, fltp, 224 kb/s (default)
    Metadata:
      title           : Stereo
      BPS-eng         : 224000
      DURATION-eng    : 00:29:17.152000000
      NUMBER_OF_FRAMES-eng: 54911
      NUMBER_OF_BYTES-eng: 49200256
      SOURCE_ID-eng   : 0180BD
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:20.016000000
    Stream #0:1(jpn): Audio: ac3, 48000 Hz, stereo, fltp, 224 kb/s
    Metadata:
      title           : Stereo
      BPS-eng         : 224000
      DURATION-eng    : 00:29:13.728000000
      NUMBER_OF_FRAMES-eng: 54804
      NUMBER_OF_BYTES-eng: 49104384
      SOURCE_ID-eng   : 0181BD
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:20.027000000
    Stream #0:2(eng): Video: mpeg2video (Main), yuv420p(tv, top first), 720x576 [SAR 16:15 DAR 4:3], 25 fps, 25 tbr, 1k tbn, 50 tbc
    Metadata:
      BPS-eng         : 6522010
      DURATION-eng    : 00:29:17.200000000
      NUMBER_OF_FRAMES-eng: 43930
      NUMBER_OF_BYTES-eng: 1432559524
      SOURCE_ID-eng   : 0100E0
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:20.160000000
    Stream #0:3(eng): Subtitle: dvd_subtitle, 720x576 (default)
    Metadata:
      BPS-eng         : 5142
      DURATION-eng    : 00:28:42.315200000
      NUMBER_OF_FRAMES-eng: 371
      NUMBER_OF_BYTES-eng: 1107152
      SOURCE_ID-eng   : 0120BD
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:00.000000000
Input #1, matroska,webm, from 'ffv1.mkv':
  Metadata:
    ENCODER         : Lavf57.56.100
  Duration: 00:00:20.00, start: 0.000000, bitrate: 57823 kb/s
    Stream #1:0: Video: ffv1 (FFV1 / 0x31564646), yuv420p(progressive), 744x568, 50 fps, 50 tbr, 1k tbn, 1k tbc (default)
    Metadata:
      ENCODER         : Lavc57.64.101 ffv1
      DURATION        : 00:00:20.000000000
Output #0, matroska, to 'out.mkv':
  Metadata:
    title           : Gunsmith Cats
    encoder         : Lavf57.56.100
    Chapter #0:0: start 0.048000, end 19.984000
    Metadata:
      title           : 0 1
    Stream #0:0(jpn): Audio: ac3 ([0] [0][0] / 0x2000), 48000 Hz, stereo, 224 kb/s
    Metadata:
      title           : Stereo
      BPS-eng         : 224000
      DURATION-eng    : 00:29:13.728000000
      NUMBER_OF_FRAMES-eng: 54804
      NUMBER_OF_BYTES-eng: 49104384
      SOURCE_ID-eng   : 0181BD
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:20.027000000
    Stream #0:1(eng): Subtitle: dvd_subtitle, 720x576 (default)
    Metadata:
      BPS-eng         : 5142
      DURATION-eng    : 00:28:42.315200000
      NUMBER_OF_FRAMES-eng: 371
      NUMBER_OF_BYTES-eng: 1107152
      SOURCE_ID-eng   : 0120BD
      _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
      DURATION        : 00:00:00.000000000
    Stream #0:2: Video: ffv1 (FFV1 / 0x31564646), yuv420p(progressive), 744x568, q=2-31, 50 fps, 50 tbr, 1k tbn, 1k tbc (default)
    Metadata:
      ENCODER         : Lavc57.64.101 ffv1
      DURATION        : 00:00:20.000000000
Stream mapping:
  Stream #0:1 -> #0:0 (copy)
  Stream #0:3 -> #0:1 (copy)
  Stream #1:0 -> #0:2 (copy)
Press [q] to stop, [?] for help
frame= 1000 fps=0.0 q=-1.0 Lsize=  141718kB time=00:00:19.98 bitrate=58102.8kbits/s speed=37.7x    
video:141160kB audio:540kB subtitle:0kB other streams:0kB global headers:1kB muxing overhead: 0.012737%

Files
20s.mkv: https://files.catbox.moe/4bdv0o.mkv
ffv1.mkv: https://files.catbox.moe/zp0brx.mkv (or you can convert 20s.mkv to ffv1.mkv)
out.mkv: ask if you can't reproduce

Attachments (2)

framehash.txt (88.9 KB ) - added by mkver 6 years ago.
The unmodified output of framehash.
ffmpeg-20180920-225448.log (961.5 KB ) - added by mkver 6 years ago.
The unmodified report.

Download all attachments as: .zip

Change History (18)

comment:1 by Carl Eugen Hoyos, 7 years ago

Do you think this is a regression?
Is the issue reproducible with current FFmpeg?

Last edited 7 years ago by Carl Eugen Hoyos (previous) (diff)

comment:2 by Carl Eugen Hoyos, 7 years ago

Priority: importantnormal

comment:3 by q3cpma, 7 years ago

Yes, I tried with the Van Sickle git build. Also, mkvtoolnix (9.6.0) produces a valid result.

comment:4 by Carl Eugen Hoyos, 7 years ago

Could you explain how I can reproduce the issue?
I downloaded the two samples, used your exact command line and played the output file with ffplay: No matter how often I seek, sound always plays fine.

comment:5 by q3cpma, 7 years ago

I gave an example because of size of the sample. Seek around 5.5s and there's no sound.

comment:6 by q3cpma, 7 years ago

This is actually exactly like the link said.

ffmpeg -i 20s.mkv -map 0:v:0 -c:v ffv1 ffv1.mkv
ffmpeg -i 20s.mkv -i ffv1.mkv -map 0:a -map 0:s -map 1:v -c copy out.mkv

ffmpeg -i 20s.mkv -c:a copy -c:s copy -c:v ffv1 out2.mkv

out.mkv fails while out2.mkv works; when the operation is fundamentally the same.

comment:7 by Carl Eugen Hoyos, 7 years ago

Keywords: regression added
Priority: normalimportant
Reproduced by developer: set
Status: newopen
Version: unspecifiedgit-master

Regression since 3adb5f8d / d9ae1031
Note that ticket #429 to which this is related was not reproducible with 6a4cc509.

comment:8 by q3cpma, 7 years ago

Hello, is there any progress on this? Maybe the title or something should be
changed since the problem isn't mkv muxing by itself, but using multiple sources
instead of one. The URL I gave in the OP is clearer than me.

comment:9 by Jacob, 6 years ago

Cc: v0qiu24elio.ldb63qpfmjrkkiv9el@gmail.com added

comment:10 by mkver, 6 years ago

Keywords: mkv removed
  1. This is similar to #7064; but it is not a duplicate (this issue happens because the second input file isn't read at all until the first file has been completely read because no subtitle packet has been found in the first; in #7064 the problem is that the external subtitle files are immediately available and increase the length of the muxing queue beyond what is permitted by max_interleave_delta, forcing output of packets which results in suboptimal interleavement).
  1. It has indeed nothing to do with mkv muxing; the problem can also be seen with e.g the framehash muxer alone. Here is a shortened output of the framehash muxer:
    #format: frame checksums
    #version: 2
    #hash: CRC32
    #extradata 1,                             511, 9407c384
    #extradata 2,                              42, 4829db1c
    #software: Lavf58.18.101
    #tb 0: 1/1000
    #media_type 0: audio
    #codec_id 0: ac3
    #sample_rate 0: 48000
    #channel_layout 0: 3
    #channel_layout_name 0: stereo
    #tb 1: 1/1000
    #media_type 1: subtitle
    #codec_id 1: dvd_subtitle
    #tb 2: 1/1000
    #media_type 2: video
    #codec_id 2: ffv1
    #dimensions 2: 744x568
    #sar 2: 0/1
    #stream#, dts,        pts, duration,     size, hash
    0,        267,        267,       32,      896, f2ce4992
    0,        299,        299,       32,      896, ae4abb67
    [lots of packets of stream 0 have been omitted for brevity]
    0,       9931,       9931,       32,      896, 13f1a1b7
    0,       9963,       9963,       32,      896, 3e390181
    2,          0,          0,       20,    75412, 4600c046
    2,         20,         20,       20,    74212, 5e1954cc
    [lots of packets for stream 2 have been omitted for brevity]
    2,       9940,       9940,       20,   143795, e9cfa8da
    2,       9960,       9960,       20,   142924, c40a903d
    2,       9980,       9980,       20,   141799, 24fb458b
    0,       9995,       9995,       32,      896, 89d4328d
    2,      10000,      10000,       20,   144622, 1896e461
    2,      10020,      10020,       20,   143099, bb8f163a
    0,      10027,      10027,       32,      896, 149a35dc
    2,      10040,      10040,       20,   141916, 585549ce
    0,      10059,      10059,       32,      896, 67fbd58f
    2,      10060,      10060,       20,   139443, 92874ab2
    2,      10080,      10080,       20,   144065, 10cdd223
    [lots of properly interleaved packets from stream 0 and stream 2 have been omitted here]
    0,      19883,      19883,       32,      896, a7802545
    2,      19900,      19900,       20,   139140, 4c1f37a7
    0,      19915,      19915,       32,      896, 3439c136
    2,      19920,      19920,       20,   138486, 82f79651
    2,      19940,      19940,       20,   137346, b4ccc6ea
    0,      19947,      19947,       32,      896, 0fadf9ce
    2,      19960,      19960,       20,   138097, 6568ef7e
    0,      19979,      19979,       32,      896, b6962970
    2,      19980,      19980,       20,   138755, f381514e
    
  1. The url in the OP doesn't work anymore, but it's available via archive.org. It's not very enlightning.
  1. The subtitle track from file 20s.mkv that is to be merged doesn't contain any packets. Here is what happens because of that:
    ffmpeg started on 2018-09-20 at 22:54:48
    Report written to "ffmpeg-20180920-225448.log"
    Command line:
    ffmpeg -y -debug_ts -i 20s.mkv -i ffv1.mkv -map 0:a:1 -map 0:s -map 1:v -report -loglevel trace -c copy -f framehash -hash crc32 out3.txt
    ffmpeg version N-91990-g49c67e79ca Copyright (c) 2000-2018 the FFmpeg developers
      built with gcc 8.2.1 (GCC) 20180813
      configuration: --disable-static --enable-shared --enable-gpl --enable-version3 --enable-sdl2 --enable-fontconfig --enable-gnutls --enable-iconv --enable-libass --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
      libavutil      56. 19.101 / 56. 19.101
      libavcodec     58. 30.100 / 58. 30.100
      libavformat    58. 18.101 / 58. 18.101
      libavdevice    58.  4.103 / 58.  4.103
      libavfilter     7. 32.100 /  7. 32.100
      libswscale      5.  2.100 /  5.  2.100
      libswresample   3.  2.100 /  3.  2.100
      libpostproc    55.  2.100 / 55.  2.100
    Splitting the commandline.
    Reading option '-y' ... matched as option 'y' (overwrite output files) with argument '1'.
    Reading option '-debug_ts' ... matched as option 'debug_ts' (print timestamp debugging info) with argument '1'.
    Reading option '-i' ... matched as input url with argument '20s.mkv'.
    Reading option '-i' ... matched as input url with argument 'ffv1.mkv'.
    Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:a:1'.
    Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '0:s'.
    Reading option '-map' ... matched as option 'map' (set input stream mapping) with argument '1:v'.
    Reading option '-report' ... matched as option 'report' (generate a report) with argument '1'.
    Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument 'trace'.
    Reading option '-c' ... matched as option 'c' (codec name) with argument 'copy'.
    Reading option '-f' ... matched as option 'f' (force format) with argument 'framehash'.
    Reading option '-hash' ... matched as AVOption 'hash' with argument 'crc32'.
    Reading option 'out3.txt' ... matched as output url.
    Finished splitting the commandline.
    Parsing a group of options: global .
    Applying option y (overwrite output files) with argument 1.
    Applying option debug_ts (print timestamp debugging info) with argument 1.
    Applying option report (generate a report) with argument 1.
    Applying option loglevel (set logging level) with argument trace.
    Successfully parsed a group of options.
    Parsing a group of options: input url 20s.mkv.
    Successfully parsed a group of options.
    Opening an input file: 20s.mkv.
    [NULL @ 0000000000509dc0] Opening '20s.mkv' for reading
    [file @ 000000000050a500] Setting default whitelist 'file,crypto'
    [matroska,webm @ 0000000000509dc0] Format matroska,webm probed with size=2048 and score=100
    st:0 removing common factor 1000000 from timebase
    st:1 removing common factor 1000000 from timebase
    st:2 removing common factor 1000000 from timebase
    st:3 removing common factor 1000000 from timebase
    [matroska,webm @ 0000000000509dc0] Before avformat_find_stream_info() pos: 3589 bytes read:32768 seeks:0 nb_streams:4
    [dvdsub @ 0000000000523780] palette: 0x000000 0x1f1f1f 0xffffff 0xe63f07 0x7e7e7e 0xbebebe 0x14bef3 0xea12eb 0xfaff1a 0x000070 0x067506 0x731f03 0x095f78 0x750975 0x7c950b 0xffffff
    [mpeg2video @ 0000000000522980] Format yuv420p chosen by get_format().
    [matroska,webm @ 0000000000509dc0] All info found
    [matroska,webm @ 0000000000509dc0] After avformat_find_stream_info() pos: 426257 bytes read:436295 seeks:0 frames:19
    Input #0, matroska,webm, from '20s.mkv':
      Metadata:
        title           : Gunsmith Cats
        ENCODER         : Lavf57.56.100
      Duration: 00:00:20.16, start: 0.016000, bitrate: 7009 kb/s
        Chapter #0:0: start 0.064000, end 20.000000
        Metadata:
          title           : 0 1
        Stream #0:0(eng), 9, 1/1000: Audio: ac3, 48000 Hz, stereo, fltp, 224 kb/s (default)
        Metadata:
          title           : Stereo
          BPS-eng         : 224000
          DURATION-eng    : 00:29:17.152000000
          NUMBER_OF_FRAMES-eng: 54911
          NUMBER_OF_BYTES-eng: 49200256
          SOURCE_ID-eng   : 0180BD
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:20.016000000
        Stream #0:1(jpn), 1, 1/1000: Audio: ac3, 48000 Hz, stereo, fltp, 224 kb/s
        Metadata:
          title           : Stereo
          BPS-eng         : 224000
          DURATION-eng    : 00:29:13.728000000
          NUMBER_OF_FRAMES-eng: 54804
          NUMBER_OF_BYTES-eng: 49104384
          SOURCE_ID-eng   : 0181BD
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:20.027000000
        Stream #0:2(eng), 9, 1/1000: Video: mpeg2video (Main), 1 reference frame, yuv420p(tv, top first, left), 720x576 [SAR 16:15 DAR 4:3], 0/1, 25 fps, 25 tbr, 1k tbn, 50 tbc
        Metadata:
          BPS-eng         : 6522010
          DURATION-eng    : 00:29:17.200000000
          NUMBER_OF_FRAMES-eng: 43930
          NUMBER_OF_BYTES-eng: 1432559524
          SOURCE_ID-eng   : 0100E0
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:20.160000000
        Stream #0:3(eng), 0, 1/1000: Subtitle: dvd_subtitle, 720x576 (default)
        Metadata:
          BPS-eng         : 5142
          DURATION-eng    : 00:28:42.315200000
          NUMBER_OF_FRAMES-eng: 371
          NUMBER_OF_BYTES-eng: 1107152
          SOURCE_ID-eng   : 0120BD
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:00.000000000
    Successfully opened the file.
    Parsing a group of options: input url ffv1.mkv.
    Successfully parsed a group of options.
    Opening an input file: ffv1.mkv.
    [NULL @ 000000000056c040] Opening 'ffv1.mkv' for reading
    [file @ 000000000051f180] Setting default whitelist 'file,crypto'
    [matroska,webm @ 000000000056c040] Format matroska,webm probed with size=2048 and score=100
    st:0 removing common factor 1000000 from timebase
    [matroska,webm @ 000000000056c040] Before avformat_find_stream_info() pos: 767 bytes read:32768 seeks:0 nb_streams:1
    [matroska,webm @ 000000000056c040] parser not found for codec ffv1, packets or times may be invalid.
    [matroska,webm @ 000000000056c040] parser not found for codec ffv1, packets or times may be invalid.
    [matroska,webm @ 000000000056c040] All info found
    [matroska,webm @ 000000000056c040] After avformat_find_stream_info() pos: 76204 bytes read:76204 seeks:0 frames:1
    Input #1, matroska,webm, from 'ffv1.mkv':
      Metadata:
        ENCODER         : Lavf57.56.100
      Duration: 00:00:20.00, start: 0.000000, bitrate: 57823 kb/s
        Stream #1:0, 1, 1/1000: Video: ffv1, 1 reference frame (FFV1 / 0x31564646), yuv420p(progressive), 744x568, 0/1, 50 fps, 50 tbr, 1k tbn, 1k tbc (default)
        Metadata:
          ENCODER         : Lavc57.64.101 ffv1
          DURATION        : 00:00:20.000000000
    Successfully opened the file.
    Parsing a group of options: output url out3.txt.
    Applying option map (set input stream mapping) with argument 0:a:1.
    Applying option map (set input stream mapping) with argument 0:s.
    Applying option map (set input stream mapping) with argument 1:v.
    Applying option c (codec name) with argument copy.
    Applying option f (force format) with argument framehash.
    Successfully parsed a group of options.
    Opening an output file: out3.txt.
    [file @ 000000000051f840] Setting default whitelist 'file,crypto'
    Successfully opened the file.
    Output #0, framehash, to 'out3.txt':
      Metadata:
        title           : Gunsmith Cats
        encoder         : Lavf58.18.101
        Chapter #0:0: start 0.048000, end 19.984000
        Metadata:
          title           : 0 1
        Stream #0:0(jpn), 0, 1/1000: Audio: ac3, 48000 Hz, stereo, fltp, 224 kb/s
        Metadata:
          title           : Stereo
          BPS-eng         : 224000
          DURATION-eng    : 00:29:13.728000000
          NUMBER_OF_FRAMES-eng: 54804
          NUMBER_OF_BYTES-eng: 49104384
          SOURCE_ID-eng   : 0181BD
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:20.027000000
        Stream #0:1(eng), 0, 1/1000: Subtitle: dvd_subtitle, 720x576 (default)
        Metadata:
          BPS-eng         : 5142
          DURATION-eng    : 00:28:42.315200000
          NUMBER_OF_FRAMES-eng: 371
          NUMBER_OF_BYTES-eng: 1107152
          SOURCE_ID-eng   : 0120BD
          _STATISTICS_WRITING_APP-eng: MakeMKV v1.10.3 linux(x64-release)
          _STATISTICS_WRITING_DATE_UTC-eng: 2016-12-21 10:56:43
          _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
          DURATION        : 00:00:00.000000000
        Stream #0:2, 0, 1/1000: Video: ffv1, 1 reference frame (FFV1 / 0x31564646), yuv420p(progressive), 744x568 (0x0), 0/1, q=2-31, 50 fps, 50 tbr, 1k tbn, 1k tbc (default)
        Metadata:
          ENCODER         : Lavc57.64.101 ffv1
          DURATION        : 00:00:20.000000000
    Stream mapping:
      Stream #0:1 -> #0:0 (copy)
      Stream #0:3 -> #0:1 (copy)
      Stream #1:0 -> #0:2 (copy)
    Press [q] to stop, [?] for help
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:NOPTS next_dts_time:NOPTS next_pts:NOPTS next_pts_time:NOPTS pkt_pts:283 pkt_pts_time:0.283 pkt_dts:283 pkt_dts_time:0.283 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:267 pkt_pts_time:0.267 pkt_dts:267 pkt_dts_time:0.267 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:267 pkt_pts_time:0.267 pkt_dts:267 pkt_dts_time:0.267 size:896
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:267000 next_dts_time:0.267 next_pts:267000 next_pts_time:0.267 pkt_pts:315 pkt_pts_time:0.315 pkt_dts:315 pkt_dts_time:0.315 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:299 pkt_pts_time:0.299 pkt_dts:299 pkt_dts_time:0.299 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:299 pkt_pts_time:0.299 pkt_dts:299 pkt_dts_time:0.299 size:896
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:299000 next_dts_time:0.299 next_pts:299000 next_pts_time:0.299 pkt_pts:347 pkt_pts_time:0.347 pkt_dts:347 pkt_dts_time:0.347 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:331 pkt_pts_time:0.331 pkt_dts:331 pkt_dts_time:0.331 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:331 pkt_pts_time:0.331 pkt_dts:331 pkt_dts_time:0.331 size:896
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:331000 next_dts_time:0.331 next_pts:331000 next_pts_time:0.331 pkt_pts:379 pkt_pts_time:0.379 pkt_dts:379 pkt_dts_time:0.379 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:363 pkt_pts_time:0.363 pkt_dts:363 pkt_dts_time:0.363 off:-16000 off_time:-0.016
    
    [Lots of the same omitted]
    
    muxer <- type:audio pkt_pts:10219 pkt_pts_time:10.219 pkt_dts:10219 pkt_dts_time:10.219 size:896
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:10219000 next_dts_time:10.219 next_pts:10219000 next_pts_time:10.219 pkt_pts:10267 pkt_pts_time:10.267 pkt_dts:10267 pkt_dts_time:10.267 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:10251 pkt_pts_time:10.251 pkt_dts:10251 pkt_dts_time:10.251 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:10251 pkt_pts_time:10.251 pkt_dts:10251 pkt_dts_time:10.251 size:896
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:10251000 next_dts_time:10.251 next_pts:10251000 next_pts_time:10.251 pkt_pts:10299 pkt_pts_time:10.299 pkt_dts:10299 pkt_dts_time:10.299 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:10283 pkt_pts_time:10.283 pkt_dts:10283 pkt_dts_time:10.283 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:10283 pkt_pts_time:10.283 pkt_dts:10283 pkt_dts_time:10.283 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:10283000 next_dts_time:10.283 next_pts:10283000 next_pts_time:10.283 pkt_pts:10331 pkt_pts_time:10.331 pkt_dts:10331 pkt_dts_time:10.331 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:10315 pkt_pts_time:10.315 pkt_dts:10315 pkt_dts_time:10.315 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:10315 pkt_pts_time:10.315 pkt_dts:10315 pkt_dts_time:10.315 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:10315000 next_dts_time:10.315 next_pts:10315000 next_pts_time:10.315 pkt_pts:10363 pkt_pts_time:10.363 pkt_dts:10363 pkt_dts_time:10.363 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:10347 pkt_pts_time:10.347 pkt_dts:10347 pkt_dts_time:10.347 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:10347 pkt_pts_time:10.347 pkt_dts:10347 pkt_dts_time:10.347 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    
    [Lots of the same omitted]
    
    muxer <- type:audio pkt_pts:19915 pkt_pts_time:19.915 pkt_dts:19915 pkt_dts_time:19.915 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:19915000 next_dts_time:19.915 next_pts:19915000 next_pts_time:19.915 pkt_pts:19963 pkt_pts_time:19.963 pkt_dts:19963 pkt_dts_time:19.963 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:19947 pkt_pts_time:19.947 pkt_dts:19947 pkt_dts_time:19.947 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:19947 pkt_pts_time:19.947 pkt_dts:19947 pkt_dts_time:19.947 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:1 type:audio next_dts:19947000 next_dts_time:19.947 next_pts:19947000 next_pts_time:19.947 pkt_pts:19995 pkt_pts_time:19.995 pkt_dts:19995 pkt_dts_time:19.995 off:-16000 off_time:-0.016
    demuxer+ffmpeg -> ist_index:1 type:audio pkt_pts:19979 pkt_pts_time:19.979 pkt_dts:19979 pkt_dts_time:19.979 off:-16000 off_time:-0.016
    muxer <- type:audio pkt_pts:19979 pkt_pts_time:19.979 pkt_dts:19979 pkt_dts_time:19.979 size:896
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10016000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:NOPTS next_dts_time:NOPTS next_pts:NOPTS next_pts_time:NOPTS pkt_pts:0 pkt_pts_time:0 pkt_dts:0 pkt_dts_time:0 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:0 pkt_pts_time:0 pkt_dts:0 pkt_dts_time:0 off:0 off_time:0
    muxer <- type:video pkt_pts:0 pkt_pts_time:0 pkt_dts:0 pkt_dts_time:0 size:75412
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 19979000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:20000 next_dts_time:0.02 next_pts:20000 next_pts_time:0.02 pkt_pts:20 pkt_pts_time:0.02 pkt_dts:20 pkt_dts_time:0.02 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:20 pkt_pts_time:0.02 pkt_dts:20 pkt_dts_time:0.02 off:0 off_time:0
    muxer <- type:video pkt_pts:20 pkt_pts_time:0.02 pkt_dts:20 pkt_dts_time:0.02 size:74212
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 19959000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:40000 next_dts_time:0.04 next_pts:40000 next_pts_time:0.04 pkt_pts:40 pkt_pts_time:0.04 pkt_dts:40 pkt_dts_time:0.04 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:40 pkt_pts_time:0.04 pkt_dts:40 pkt_dts_time:0.04 off:0 off_time:0
    muxer <- type:video pkt_pts:40 pkt_pts_time:0.04 pkt_dts:40 pkt_dts_time:0.04 size:73261
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 19939000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:60000 next_dts_time:0.06 next_pts:60000 next_pts_time:0.06 pkt_pts:60 pkt_pts_time:0.06 pkt_dts:60 pkt_dts_time:0.06 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:60 pkt_pts_time:0.06 pkt_dts:60 pkt_dts_time:0.06 off:0 off_time:0
    muxer <- type:video pkt_pts:60 pkt_pts_time:0.06 pkt_dts:60 pkt_dts_time:0.06 size:78776
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 19919000 > 10000000: forcing output
    
    [Lots of the same omitted]
    
    demuxer -> ist_index:4 type:video next_dts:9940000 next_dts_time:9.94 next_pts:9940000 next_pts_time:9.94 pkt_pts:9940 pkt_pts_time:9.94 pkt_dts:9940 pkt_dts_time:9.94 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:9940 pkt_pts_time:9.94 pkt_dts:9940 pkt_dts_time:9.94 off:0 off_time:0
    muxer <- type:video pkt_pts:9940 pkt_pts_time:9.94 pkt_dts:9940 pkt_dts_time:9.94 size:143795
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10039000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:9960000 next_dts_time:9.96 next_pts:9960000 next_pts_time:9.96 pkt_pts:9960 pkt_pts_time:9.96 pkt_dts:9960 pkt_dts_time:9.96 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:9960 pkt_pts_time:9.96 pkt_dts:9960 pkt_dts_time:9.96 off:0 off_time:0
    muxer <- type:video pkt_pts:9960 pkt_pts_time:9.96 pkt_dts:9960 pkt_dts_time:9.96 size:142924
    [framehash @ 0000000002299d40] Delay between the first packet and last packet in the muxing queue is 10019000 > 10000000: forcing output
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:9980000 next_dts_time:9.98 next_pts:9980000 next_pts_time:9.98 pkt_pts:9980 pkt_pts_time:9.98 pkt_dts:9980 pkt_dts_time:9.98 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:9980 pkt_pts_time:9.98 pkt_dts:9980 pkt_dts_time:9.98 off:0 off_time:0
    muxer <- type:video pkt_pts:9980 pkt_pts_time:9.98 pkt_dts:9980 pkt_dts_time:9.98 size:141799
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:10000000 next_dts_time:10 next_pts:10000000 next_pts_time:10 pkt_pts:10000 pkt_pts_time:10 pkt_dts:10000 pkt_dts_time:10 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:10000 pkt_pts_time:10 pkt_dts:10000 pkt_dts_time:10 off:0 off_time:0
    muxer <- type:video pkt_pts:10000 pkt_pts_time:10 pkt_dts:10000 pkt_dts_time:10 size:144622
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:10020000 next_dts_time:10.02 next_pts:10020000 next_pts_time:10.02 pkt_pts:10020 pkt_pts_time:10.02 pkt_dts:10020 pkt_dts_time:10.02 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:10020 pkt_pts_time:10.02 pkt_dts:10020 pkt_dts_time:10.02 off:0 off_time:0
    muxer <- type:video pkt_pts:10020 pkt_pts_time:10.02 pkt_dts:10020 pkt_dts_time:10.02 size:143099
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:10040000 next_dts_time:10.04 next_pts:10040000 next_pts_time:10.04 pkt_pts:10040 pkt_pts_time:10.04 pkt_dts:10040 pkt_dts_time:10.04 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:10040 pkt_pts_time:10.04 pkt_dts:10040 pkt_dts_time:10.04 off:0 off_time:0
    muxer <- type:video pkt_pts:10040 pkt_pts_time:10.04 pkt_dts:10040 pkt_dts_time:10.04 size:141916
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:10060000 next_dts_time:10.06 next_pts:10060000 next_pts_time:10.06 pkt_pts:10060 pkt_pts_time:10.06 pkt_dts:10060 pkt_dts_time:10.06 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:10060 pkt_pts_time:10.06 pkt_dts:10060 pkt_dts_time:10.06 off:0 off_time:0
    muxer <- type:video pkt_pts:10060 pkt_pts_time:10.06 pkt_dts:10060 pkt_dts_time:10.06 size:139443
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    
    [Lots of the same omitted]
    
    demuxer -> ist_index:4 type:video next_dts:19960000 next_dts_time:19.96 next_pts:19960000 next_pts_time:19.96 pkt_pts:19960 pkt_pts_time:19.96 pkt_dts:19960 pkt_dts_time:19.96 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:19960 pkt_pts_time:19.96 pkt_dts:19960 pkt_dts_time:19.96 off:0 off_time:0
    muxer <- type:video pkt_pts:19960 pkt_pts_time:19.96 pkt_dts:19960 pkt_dts_time:19.96 size:138097
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    demuxer -> ist_index:4 type:video next_dts:19980000 next_dts_time:19.98 next_pts:19980000 next_pts_time:19.98 pkt_pts:19980 pkt_pts_time:19.98 pkt_dts:19980 pkt_dts_time:19.98 off:0 off_time:0
    demuxer+ffmpeg -> ist_index:4 type:video pkt_pts:19980 pkt_pts_time:19.98 pkt_dts:19980 pkt_dts_time:19.98 off:0 off_time:0
    muxer <- type:video pkt_pts:19980 pkt_pts_time:19.98 pkt_dts:19980 pkt_dts_time:19.98 size:138755
    cur_dts is invalid (this is harmless if it occurs once at the start per stream)
    No more output streams to write to, finishing.
    frame= 1000 fps=697 q=-1.0 Lsize=      89kB time=00:00:19.98 bitrate=  36.5kbits/s speed=13.9x    
    video:141160kB audio:540kB subtitle:0kB other streams:0kB global headers:1kB muxing overhead: unknown
    Input file #0 (20s.mkv):
      Input stream #0:0 (audio): 10 packets read (8960 bytes); 
      Input stream #0:1 (audio): 617 packets read (552832 bytes); 
      Input stream #0:2 (video): 9 packets read (411744 bytes); 
      Input stream #0:3 (subtitle): 0 packets read (0 bytes); 
      Total: 636 packets (973536 bytes) demuxed
    Input file #1 (ffv1.mkv):
      Input stream #1:0 (video): 1000 packets read (144547680 bytes); 
      Total: 1000 packets (144547680 bytes) demuxed
    Output file #0 (out3.txt):
      Output stream #0:0 (audio): 617 packets muxed (552832 bytes); 
      Output stream #0:1 (subtitle): 0 packets muxed (0 bytes); 
      Output stream #0:2 (video): 1000 packets muxed (144547680 bytes); 
      Total: 1617 packets (145100512 bytes) muxed
    0 frames successfully decoded, 0 decoding errors
    [AVIOContext @ 000000000056cf00] Statistics: 0 seeks, 1620 writeouts
    [AVIOContext @ 0000000000512740] Statistics: 17665051 bytes read, 0 seeks
    [AVIOContext @ 000000000056cdc0] Statistics: 144559972 bytes read, 0 seeks
    

To sum it up:

a) The first input file is read; a few audio packets are demuxed, but no subtitle packet is found. Therefore it continues to read this file until the delay between the first and the last packet in the muxing queue is bigger than 10s. As soon as this happens, a packet of the audio track is output (so that the delay between the first and the last packet in the muxing queue is below 10s again). After that 20s.mkv is read again (probably because no subtitle packet has been found) and a new audio frame is demuxed, making the delay between the first and the last packet in the muxing queue longer than 10s again and forcing the output of another audio packet. This goes on until 20s.mkv has been completely consumed. The last audio packet of the audio track that is to be muxed has a timestamp of 19.995s in the input file, for some reason the demuxer applies an offset of -16ms making it 19.979. Accordingly the last packet to be output at this stage has an (output) timestamp of 9963ms.

b) After a) the muxing queue is almost 10s long and its highest timestamp is 19979ms. Now ffv1.mkv is read. The first packet has a timestamp of 0 and is automatically output because the muxing queue length is longer than 10s after said packet has been added to it. This goes on until the length of the muxing queue is less than 10s (the last video packet whose output is forced has a timestamp of 9960ms; the next timestamp is 9980ms).

c) Then the length of the muxing queue is less than 10s and the rest of the output packets are interleaved properly.

by mkver, 6 years ago

Attachment: framehash.txt added

The unmodified output of framehash.

by mkver, 6 years ago

Attachment: ffmpeg-20180920-225448.log added

The unmodified report.

comment:11 by zagser168, 5 years ago

Cc: zagser168@yandex.ru added

comment:12 by Himbeer, 4 years ago

Cc: mail@himbeer.me added

comment:13 by oscord, 3 years ago

Happy 4th birthday to the broken mux ticket !!!
8P

comment:14 by Elon Musk, 3 years ago

Summary: mkv muxing brokenmkv muxing not broken

comment:15 by oscord, 3 years ago

MKV muxing is "not broken" ? - that is bullshit.
try codec copy in any random combination to mkv destination...

comment:16 by hasezoey, 13 months ago

Cc: hasezoey added

also had just run into this problem by using a input mkv with video and audio stream and replacing that audio with a external track (even if it is literally the same audio stream extracted into its own file), using "-max_interleave_delta 0" fixed it for me

versions:
ffmpeg version n6.0 Copyright (c) 2000-2023 the FFmpeg developers
built with gcc 12.2.1 (GCC) 20230201
configuration: --prefix=/usr --disable-debug --disable-static --disable-stripping --enable-amf --enable-avisynth --enable-cuda-llvm --enable-lto --enable-fontconfig --enable-gmp --enable-gnutls --enable-gpl --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libdav1d --enable-libdrm --enable-libfreetype --enable-libfribidi --enable-libgsm --enable-libiec61883 --enable-libjack --enable-libjxl --enable-libmfx --enable-libmodplug --enable-libmp3lame --enable-libopencore_amrnb --enable-libopencore_amrwb --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librav1e --enable-librsvg --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtheora --enable-libv4l2 --enable-libvidstab --enable-libvmaf --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxcb --enable-libxml2 --enable-libxvid --enable-libzimg --enable-nvdec --enable-nvenc --enable-opencl --enable-opengl --enable-shared --enable-version3 --enable-vulkan
libavutil 58. 2.100 / 58. 2.100
libavcodec 60. 3.100 / 60. 3.100
libavformat 60. 3.100 / 60. 3.100
libavdevice 60. 1.100 / 60. 1.100
libavfilter 9. 3.100 / 9. 3.100
libswscale 7. 1.100 / 7. 1.100
libswresample 4. 10.100 / 4. 10.100
libpostproc 57. 1.100 / 57. 1.100

Note: See TracTickets for help on using tickets.