[FFmpeg-trac] #6037(avformat:open): mkv muxing broken
FFmpeg
trac at avcodec.org
Fri Sep 21 02:28:08 EEST 2018
#6037: mkv muxing broken
------------------------------------+------------------------------------
Reporter: q3cpma | Owner:
Type: defect | Status: open
Priority: important | Component: avformat
Version: git-master | Resolution:
Keywords: regression | Blocked By:
Blocking: | Reproduced by developer: 1
Analyzed by developer: 0 |
------------------------------------+------------------------------------
Changes (by mkver):
* keywords: mkv regression => regression
Comment:
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).
2. 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
}}}
3. The url in the OP doesn't work anymore, but it's available via
[https://web.archive.org/web/20171015142920/http://ffmpeg.gusari.org/viewtopic.php?f=11&t=2713
archive.org]. It's not very enlightning.
4. 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.
--
Ticket URL: <https://trac.ffmpeg.org/ticket/6037#comment:10>
FFmpeg <https://ffmpeg.org>
FFmpeg issue tracker
More information about the FFmpeg-trac
mailing list