Capture with error msg: Application provided invalid, non monotonically increasing

[Jean-Pierre]

Summary of the bug: I try to capture from a S-VHS player and Dazzle DVC100, audio directly connected from the player to the input line of the integrated audio card.

When I run the command I get the following pattern:
-Error message in red
Application provided invalid, non monotonically increasing dts to muxer in stream 0:
Then a frame is dropped
Then I get a lot of warning messages in yellow
Past duration 0.xxxxxx too large
where 0.xxxxxx increase from 0.6xxxx to 0.9xxxx
Then stop

To test more accurately, I removed the tape from the player and got a blue, still image with the program number wrote in white. This still image is very stable, no static.

When I run the command to capture the still image I get the above pattern at regular time.
See the first log

Then I removed the last part of the command
-aspect 4:3 -f sdl "Dazzle output"
I get the above pattern WITHOUT the error message in red but still with the warning and frame drop.
See the second log

When I remove all related to audio (input / output) the error is still present.

How to reproduce:
./ffmpeg -report -f pulse -ar 44100 -ac 2 -channel_layout stereo -thread_queue_size 512 -itsoffset -0.20 -i alsa_input.pci-0000_00_14.2.analog-stereo -f v4l2 -ts mono2abs -channel 1 -video_size 720x576 -pix_fmt yuyv422 -thread_queue_size 512 -i /dev/video0 -c:v ffv1 -level 3 -aspect 4:3 -pix_fmt yuv422p -c:a pcm_s16le /Store3/Test/t_date +%Y%m%d_%H%M.mkv -aspect 4:3 -f sdl "Dazzle output"

[Jean-Pierre]

Full command

[Jean-Pierre]

Command without sdl

[Jean-Pierre]

More tests

I did 12 tests with the CL

./ffmpeg -debug 1 -f v4l2 -ts mono2abs -channel 1 -video_size 720x576 -pix_fmt yuyv422 -thread_queue_size 512 -i /dev/video0 -c:v ffv1 -level 3 -g 1 -aspect 4:3 -pix_fmt yuv422p /Store3/Test/t_date +%Y%m%d_%H%M.mkv -aspect 4:3 -f sdl "Dazzle output"

I always get the same pattern:
One first red error message
Few seconds correct
Around 60 yellow warning messages
Few seconds correct, a bit longer than the previous
A second red error message

I wrote down:
1- The value at the end of the first red error message
Application provided invalid, non monotonically increasing dts to muxer in stream 0: xxx >= xxx

2 & 3- The offset and the pts at the message
Starting new cluster at offset xxxxxxxx bytes, pts xxxxx
just after the first yellow warning message
Past duration 0.xxx too large

4- The value at the end of the second red error message
Application provided invalid, non monotonically increasing dts to muxer in stream 0: xxx >= xxx

Test|First error|Too large @bytes|Too large @pts|Second error
*-|..1 .. |..... 2 .......|.... 3 ...|.. 4
1 | 192 | 51808270 | 10760 | 570
2 | 183 | 50130991 | 10400 | 561
3 | 219 | 56954209 | 11800 | 597
4 | 192 | 51911648 | 10760 | 570
5 | 161 | 45894575 | 9520 | 539
6 | 204 | 54028812 | 11200 | 582
7 | 213 | 55996679 | 11600 | 591
8 | 176 | 48726442 | 10080 | 554
9 | 197 | 52595957 | 10920 | 575
10| 224 | 58047439 | 12000 | 602
11| 179 | 19117311 | 10200 | 557
12| 223 | 58023111 | 12000 | 601

If you subtract the value of the 1st error to the value of the 2nd error you always get 378.
All the values are proportional and start around the same time.
This is not a random error but a predictable error => bug.

Hope this will help

[Carl Eugen Hoyos]

So audio recording is not necessary to reproduce the issue?

[Jean-Pierre]

As you can see, not at all necessary

More tests here
​http://ffmpeg.org/pipermail/ffmpeg-user/2015-September/028426.html

[Jean-Pierre]

I did the same previous test with the last ffmpeg update.
Same error, same drops.

Could you let me know were you are on the search of this bug?
Could you let me know whether it will be fix or not?
Could you let me know any delay it will take?

Thanks

./ffmpeg -debug 1 -f v4l2 -ts mono2abs -channel 1 -video_size 720x576 -pix_fmt yuyv422 -thread_queue_size 512 -i /dev/video0 -c:v ffv1 -level 3 -g 1 -aspect 4:3 -pix_fmt yuv422p /Store3/Test/t_date+%Y%m%d_%H%M.mkv -aspect 4:3 -f sdl "Dazzle output"
ffmpeg version N-76232-gabae43a Copyright (c) 2000-2015 the FFmpeg developers

built with gcc 5.1.1 (GCC) 20150618 (Red Hat 5.1.1-4)
configuration: --enable-libpulse --enable-gpl --enable-libx264
libavutil 55. 4.100 / 55. 4.100
libavcodec 57. 9.100 / 57. 9.100
libavformat 57. 10.101 / 57. 10.101
libavdevice 57. 0.100 / 57. 0.100
libavfilter 6. 13.100 / 6. 13.100
libswscale 4. 0.100 / 4. 0.100
libswresample 2. 0.100 / 2. 0.100
libpostproc 54. 0.100 / 54. 0.100

[Jean-Pierre]

I did a new test on another computer with Stella 6,7 (Centos remix)

When I run the above without -ts mono2abs option, CL I get the same pattern as above.
When I run the exact above CL, I get immediate error message and frame drops.

Hope this will help.
Is there someone to have a look please?
Many thanks

./ffmpeg -debug 1 -f v4l2 -ts mono2abs -channel 1 -video_size 720x576 -pix_fmt yuyv422 -thread_queue_size 512 -i /dev/video0 -c:v libx264 -vf setfield=tff -preset slow -qp 0 -x264opts tff=1 -aspect 4:3 -pix_fmt yuv422p ../Test/t_date +%Y%m%d_%H%M.mkv -aspect 4:3 -f sdl "Dazzle output"
ffmpeg version N-76481-g6f1ddc7 Copyright (c) 2000-2015 the FFmpeg developers

built with gcc 4.4.7 (GCC) 20120313 (Red Hat 4.4.7-16)
configuration: --enable-libpulse --enable-gpl --enable-libx264 --enable-sdl
libavutil 55. 5.100 / 55. 5.100
libavcodec 57. 15.100 / 57. 15.100
libavformat 57. 14.100 / 57. 14.100
libavdevice 57. 0.100 / 57. 0.100
libavfilter 6. 14.101 / 6. 14.101
libswscale 4. 0.100 / 4. 0.100
libswresample 2. 0.100 / 2. 0.100
libpostproc 54. 0.100 / 54. 0.100

matched as AVOption 'debug' with argument '1'.

Reading option '-f' ... matched as option 'f' (force format) with argument 'v4l2'.
Reading option '-ts' ... matched as AVOption 'ts' with argument 'mono2abs'.
Reading option '-channel' ... matched as AVOption 'channel' with argument '1'.
Reading option '-video_size' ... matched as AVOption 'video_size' with argument '720x576'.
Reading option '-pix_fmt' ... matched as option 'pix_fmt' (set pixel format) with argument 'yuyv422'.
Reading option '-thread_queue_size' ... matched as option 'thread_queue_size' (set the maximum number of queued packets from the demuxer) with argument '512'.
Reading option '-i' ... matched as input file with argument '/dev/video0'.
Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'libx264'.
Reading option '-vf' ... matched as option 'vf' (set video filters) with argument 'setfield=tff'.
Reading option '-preset' ... matched as AVOption 'preset' with argument 'slow'.
Reading option '-qp' ... matched as AVOption 'qp' with argument '0'.
Reading option '-x264opts' ... matched as AVOption 'x264opts' with argument 'tff=1'.
Reading option '-aspect' ... matched as option 'aspect' (set aspect ratio (4:3, 16:9 or 1.3333, 1.7777)) with argument '4:3'.
Reading option '-pix_fmt' ... matched as option 'pix_fmt' (set pixel format) with argument 'yuv422p'.
Reading option '../Test/t_20151108_1237.mkv' ... matched as output file.
Reading option '-aspect' ... matched as option 'aspect' (set aspect ratio (4:3, 16:9 or 1.3333, 1.7777)) with argument '4:3'.
Reading option '-f' ... matched as option 'f' (force format) with argument 'sdl'.
Reading option 'Dazzle output' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Successfully parsed a group of options.
Parsing a group of options: input file /dev/video0.
Applying option f (force format) with argument v4l2.
Applying option pix_fmt (set pixel format) with argument yuyv422.
Applying option thread_queue_size (set the maximum number of queued packets from the demuxer) with argument 512.
Successfully parsed a group of options.
Opening an input file: /dev/video0.
[video4linux2,v4l2 @ 0x3811a20] fd:3 capabilities:5020041
[video4linux2,v4l2 @ 0x3811a20] Selecting input_channel: 1
[video4linux2,v4l2 @ 0x3811a20] Current input_channel: 1, input_name: S-Video, input_std: ffffff
[video4linux2,v4l2 @ 0x3811a20] The V4L2 driver is using the interlaced mode
[video4linux2,v4l2 @ 0x3811a20] Current standard: PAL, id: ff, frameperiod: 1/25
[video4linux2,v4l2 @ 0x3811a20] Detected monotonic timestamps, converting
[video4linux2,v4l2 @ 0x3811a20] All info found
Input #0, video4linux2,v4l2, from '/dev/video0':

Duration: N/A, start: -1401006899.683493, bitrate: 165888 kb/s

Stream #0:0, 1, 1/1000000: Video: rawvideo, 1 reference frame (YUY2 / 0x32595559), yuyv422, 720x576, 1/1000000, 165888 kb/s, 25 fps, 25 tbr, 1000k tbn, 1000k tbc

Successfully opened the file.
Parsing a group of options: output file ../Test/t_20151108_1237.mkv.
Applying option c:v (codec name) with argument libx264.
Applying option vf (set video filters) with argument setfield=tff.
Applying option aspect (set aspect ratio (4:3, 16:9 or 1.3333, 1.7777)) with argument 4:3.
Applying option pix_fmt (set pixel format) with argument yuv422p.
Successfully parsed a group of options.
Opening an output file: ../Test/t_20151108_1237.mkv.
Successfully opened the file.
Parsing a group of options: output file Dazzle output.
Applying option aspect (set aspect ratio (4:3, 16:9 or 1.3333, 1.7777)) with argument 4:3.
Applying option f (force format) with argument sdl.
Successfully parsed a group of options.
Opening an output file: Dazzle output.
Successfully opened the file.
detected 2 logical cores
[Parsed_setfield_0 @ 0x38171e0] Setting 'mode' to value 'tff'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'video_size' to value '720x576'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'pix_fmt' to value '1'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'time_base' to value '1/1000000'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'pixel_aspect' to value '0/1'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'sws_param' to value 'flags=2'
[graph 0 input from stream 0:0 @ 0x3817040] Setting 'frame_rate' to value '25/1'
[graph 0 input from stream 0:0 @ 0x3817040] w:720 h:576 pixfmt:yuyv422 tb:1/1000000 fr:25/1 sar:0/1 sws_param:flags=2
[format @ 0x3817e40] compat: called with args=[yuv422p]
[format @ 0x3817e40] Setting 'pix_fmts' to value 'yuv422p'
[auto-inserted scaler 0 @ 0x3816160] Setting 'flags' to value 'bicubic'
[auto-inserted scaler 0 @ 0x3816160] w:iw h:ih flags:'bicubic' interl:0
[format @ 0x3817e40] auto-inserting filter 'auto-inserted scaler 0' between the filter 'Parsed_setfield_0' and the filter 'format'
[AVFilterGraph @ 0x3817d40] query_formats: 4 queried, 2 merged, 1 already done, 0 delayed
[auto-inserted scaler 0 @ 0x3816160] w:720 h:576 fmt:yuyv422 sar:0/1 -> w:720 h:576 fmt:yuv422p sar:0/1 flags:0x4
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'video_size' to value '720x576'
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'pix_fmt' to value '1'
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'time_base' to value '1/1000000'
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'pixel_aspect' to value '0/1'
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'sws_param' to value 'flags=2'
[graph 1 input from stream 0:0 @ 0x382f740] Setting 'frame_rate' to value '25/1'
[graph 1 input from stream 0:0 @ 0x382f740] w:720 h:576 pixfmt:yuyv422 tb:1/1000000 fr:25/1 sar:0/1 sws_param:flags=2
[AVFilterGraph @ 0x3816f80] query_formats: 3 queried, 2 merged, 0 already done, 0 delayed
[libx264 @ 0x3815280] interlace + weightp is not implemented
[libx264 @ 0x3815280] using mv_range_thread = 88
[libx264 @ 0x3815280] using SAR=16/15
[libx264 @ 0x3815280] using cpu capabilities: MMX2 SSE2Slow SlowCTZ
[libx264 @ 0x3815280] profile High 4:4:4 Predictive, level 3.0, 4:2:2 8-bit
[libx264 @ 0x3815280] 264 - core 142 r2438 af8e768 - H.264/MPEG-4 AVC codec - Copyleft 2003-2014 - ​http://www.videolan.org/x264.html - options: cabac=1 ref=5 deblock=1:0:0 analyse=0x1:0x111 me=umh subme=8 psy=0 mixed_ref=1 me_range=16 chroma_me=1 trellis=0 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=0 chroma_qp_offset=0 threads=3 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=tff bluray_compat=0 constrained_intra=0 bframes=0 weightp=0 keyint=250 keyint_min=25 scenecut=40 intra_refresh=0 rc=cqp mbtree=0 qp=0
[sdl @ 0x38203c0] w:720 h:576 fmt:yuyv422 -> w:720 h:540
Output #0, matroska, to '../Test/t_20151108_1237.mkv':

Metadata:

encoder : Lavf57.14.100
Stream #0:0, 0, 1/1000: Video: h264 (libx264), -1 reference frame (H264 / 0x34363248), yuv422p, 720x576 [SAR 16:15 DAR 4:3], 1/25, q=-1--1, 25 fps, 1k tbn, 25 tbc
Metadata:

encoder : Lavc57.15.100 libx264

Output #1, sdl, to 'Dazzle output':

Metadata:

encoder : Lavf57.14.100
Stream #1:0, 0, 1/25: Video: rawvideo, 1 reference frame (YUY2 / 0x32595559), yuyv422, 720x576 [SAR 16:15 DAR 4:3], 1/25, q=2-31, 200 kb/s, 25 fps, 25 tbn, 25 tbc
Metadata:

encoder : Lavc57.15.100 rawvideo

Stream mapping:

Stream #0:0 -> #0:0 (rawvideo (native) -> h264 (libx264))
Stream #0:0 -> #1:0 (rawvideo (native) -> rawvideo (native))

Press [q] to stop, ? for help
Cliping frame in rate conversion by 0.000008
* dropping frame 1 from stream 0 at ts -55356
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55356 >= -83033
* dropping frame 1 from stream 0 at ts -83033
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55356 >= -96872
* dropping frame 1 from stream 0 at ts -96872
* dropping frame 1 from stream 0 at ts -55353
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55353 >= -83030
* dropping frame 1 from stream 0 at ts -83030
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55353 >= -96869
* dropping frame 1 from stream 0 at ts -96869
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55353 >= -96868
* dropping frame 1 from stream 0 at ts -96868
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: -55353 >= -96867
* dropping frame 1 from stream 0 at ts -96867
* dropping frame 1 from stream 0 at ts -27669
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= 13850
* dropping frame 2 from stream 0 at ts 13850kB time=00:18:27.56 bitrate= 0.0kbits/s dup=0 drop=9
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= 12
* dropping frame 2 from stream 0 at ts 12
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= -13826
* dropping frame 2 from stream 0 at ts -13826
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= -27664
* dropping frame 2 from stream 0 at ts -27664
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= -41503
* dropping frame 2 from stream 0 at ts -41503
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 27688 >= 16
* dropping frame 2 from stream 0 at ts 16
[libx264 @ 0x3815280] frame= 0 QP=0.00 NAL=3 Slice:I Poc:0 I:1620 P:0 SKIP:0 size=156532 bytes
[matroska @ 0x3813f80] Writing block at offset 724, size 157063, pts 0, dts 0, duration 40, keyframe 1
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= 20
* dropping frame 5 from stream 0 at ts 20
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -41497
* dropping frame 5 from stream 0 at ts -41497B time=00:36:55.08 bitrate= 0.6kbits/s dup=0 drop=16
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -13817
* dropping frame 5 from stream 0 at ts -13817
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -55334
* dropping frame 5 from stream 0 at ts -55334
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -27654
* dropping frame 5 from stream 0 at ts -27654
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -13814
* dropping frame 5 from stream 0 at ts -13814
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -55331
* dropping frame 5 from stream 0 at ts -55331
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -83008
* dropping frame 5 from stream 0 at ts -83008
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -96847
* dropping frame 5 from stream 0 at ts -96847
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -110685
* dropping frame 5 from stream 0 at ts -110685
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -69166
* dropping frame 5 from stream 0 at ts -69166
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -41487
* dropping frame 5 from stream 0 at ts -41487
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -83004
* dropping frame 5 from stream 0 at ts -83004
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -166038
* dropping frame 5 from stream 0 at ts -166038
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -152198
* dropping frame 5 from stream 0 at ts -152198
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -69161
* dropping frame 5 from stream 0 at ts -69161
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -69160
* dropping frame 5 from stream 0 at ts -69160
[sdl @ 0x38203c0] Application provided invalid, non monotonically increasing dts to muxer in stream 0: 55376 >= -69159
av_interleaved_write_frame(): Input/output error
No more output streams to write to, finishing.kB time=00:36:55.08 bitrate= 0.6kbits/s dup=0 drop=32
[libx264 @ 0x3815280] frame= 1 QP=0.00 NAL=2 Slice:P Poc:2 I:1130 P:490 SKIP:0 size=184798 bytes
[matroska @ 0x3813f80] Starting new cluster at offset 157797 bytes, pts 1107520dts 1107520
[matroska @ 0x3813f80] Writing block at offset 157814, size 184798, pts 1107520, dts 1107520, duration 40, keyframe 0