ffmpeg 1FPS extraction call spits out infinite ima

Question

This is one of the oddest things I've ever seen while using ffmpeg.

This is the scenario - we are getting video footage from a IONODE ION-E100 encoder, the footage is encoded in h264. I can view the footage fine in VLC, and I can copy it over to another video using ffmpeg and -c:v copy. The issue arises when I try and extract one FPS from the movie using the following command:

ffmpeg -i testmovie.mp4 -r 1 -vf 640:-2 -q:v 18 -loglevel error /tmp/tmp/extraction_%04d.jpeg

What this should do is go through the movie and extract one frame per second, then dump the frames to the files /tmp/tmp/extraction_0001.jpeg, /tmp/tmp/extraction_0002.jpeg, ..., /tmp/tmp/extraction_000X.jpeg. It should end when it reaches the end of the video.

Now the odd thing that happens when I run this command is that it will run in a tight loop, writing tens or hundreds of thousands of images to the disk until the disk is full at which point the command fails. All of the extracted images are the exact same as one another.

Here is the ffmpeg stats output on the video

ffmpeg version 3.2.2 Copyright (c) 2000-2016 the FFmpeg developers
  built with Apple LLVM version 8.0.0 (clang-800.0.42.1)
  configuration: --prefix=/usr/local/Cellar/ffmpeg/3.2.2 --enable-shared --enable-pthreads --enable-gpl --enable-version3 --enable-hardcoded-tables --enable-avresample --cc=clang --host-cflags= --host-ldflags= --enable-libmp3lame --enable-libx264 --enable-libxvid --enable-opencl --disable-lzma --enable-vda
  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, mov,mp4,m4a,3gp,3g2,mj2, from '/Users/john/ionode/test2.mp4':
  Metadata:
    major_brand     : isom
    minor_version   : 512
    compatible_brands: isomiso2avc1mp41
    title           : /videoinput_1:0/h264_1/media.stm
    encoder         : Lavf57.56.100
  Duration: 00:00:16.52, start: -9791.427750, bitrate: 2165 kb/s
    Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 2119 kb/s, 25 fps, 25 tbr, 12800 tbn, 50 tbc (default)
    Metadata:
      handler_name    : VideoHandler
    Stream #0:1(und): Audio: aac (LC) (mp4a / 0x6134706D), 8000 Hz, mono, fltp, 236 kb/s (default)
    Metadata:
      handler_name    : SoundHandler

(notice the start: -9791.427750 value, what is this?)

Here are the encoding details on the footage:

{
    "programs": [

    ],
    "streams": [
        {
            "index": 0,
            "codec_name": "h264",
            "codec_long_name": "H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10",
            "profile": "High",
            "codec_type": "video",
            "codec_time_base": "1/50",
            "codec_tag_string": "avc1",
            "codec_tag": "0x31637661",
            "width": 1920,
            "height": 1080,
            "coded_width": 1920,
            "coded_height": 1080,
            "has_b_frames": 2,
            "sample_aspect_ratio": "1:1",
            "display_aspect_ratio": "16:9",
            "pix_fmt": "yuv420p",
            "level": 40,
            "chroma_location": "left",
            "refs": 1,
            "is_avc": "true",
            "nal_length_size": "4",
            "r_frame_rate": "25/1",
            "avg_frame_rate": "25/1",
            "time_base": "1/12800",
            "start_pts": 0,
            "start_time": "0.000000",
            "duration_ts": 211456,
            "duration": "16.520000",
            "bit_rate": "2119813",
            "bits_per_raw_sample": "8",
            "nb_frames": "413",
            "disposition": {
                "default": 1,
                "dub": 0,
                "original": 0,
                "comment": 0,
                "lyrics": 0,
                "karaoke": 0,
                "forced": 0,
                "hearing_impaired": 0,
                "visual_impaired": 0,
                "clean_effects": 0,
                "attached_pic": 0,
                "timed_thumbnails": 0
            },
            "tags": {
                "language": "und",
                "handler_name": "VideoHandler"
            }
        }
    ]
}

Here a link to the sample video to use: http://s000.tinyupload.com/?file_id=03169189167771012515 (it's a 5MB video file)

The only clues I have as to what is actually going on is the error output from the command that grabs the video from the encoder:

[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823640, current: -630275919; changing to -629823639. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823639, current: -630274895; changing to -629823638. This may result in incorrect timestamps in the output file.
frame=  124 fps= 21 q=28.0 size=      41kB time=00:00:02.60 bitrate= 128.8kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823638, current: -630273871; changing to -629823637. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823637, current: -630272847; changing to -629823636. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823636, current: -630271824; changing to -629823635. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823635, current: -630270800; changing to -629823634. This may result in incorrect timestamps in the output file.
frame=  124 fps= 19 q=28.0 size=      43kB time=00:00:02.60 bitrate= 137.0kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823634, current: -630269776; changing to -629823633. This may result in incorrect timestamps in the output file.
[aac @ 0x7faa1a832000] Queue input is backward in time
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823633, current: -630268752; changing to -629823632. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823632, current: -630267728; changing to -629823631. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823631, current: -630513833; changing to -629823630. This may result in incorrect timestamps in the output file.
frame=  124 fps= 18 q=28.0 size=      46kB time=00:00:02.60 bitrate= 145.4kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823630, current: -630512810; changing to -629823629. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823629, current: -630511786; changing to -629823628. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823628, current: -630510762; changing to -629823627. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823627, current: -630509738; changing to -629823626. This may result in incorrect timestamps in the output file.
frame=  124 fps= 17 q=28.0 size=      49kB time=00:00:02.60 bitrate= 153.6kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823626, current: -630508714; changing to -629823625. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823625, current: -630507690; changing to -629823624. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823624, current: -630506667; changing to -629823623. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823623, current: -630505643; changing to -629823622. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823622, current: -630504619; changing to -629823621. This may result in incorrect timestamps in the output file.
frame=  124 fps= 16 q=28.0 size=      52kB time=00:00:02.60 bitrate= 163.5kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823621, current: -630503595; changing to -629823620. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823620, current: -630502571; changing to -629823619. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823619, current: -630501548; changing to -629823618. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823618, current: -630500524; changing to -629823617. This may result in incorrect timestamps in the output file.
frame=  124 fps= 15 q=28.0 size=      54kB time=00:00:02.60 bitrate= 171.4kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823617, current: -630499500; changing to -629823616. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823616, current: -630498476; changing to -629823615. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823615, current: -630497452; changing to -629823614. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823614, current: -630496428; changing to -629823613. This may result in incorrect timestamps in the output file.
frame=  124 fps= 14 q=28.0 size=      57kB time=00:00:02.60 bitrate= 179.3kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823613, current: -630495405; changing to -629823612. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823612, current: -630494381; changing to -629823611. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823611, current: -630493357; changing to -629823610. This may result in incorrect timestamps in the output file.
frame=  124 fps= 13 q=28.0 size=      59kB time=00:00:02.60 bitrate= 185.6kbits/s dup=26 drop=4 spee[aac @ 0x7faa1a832000] Queue input is backward in time
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823610, current: -630492333; changing to -629823609. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823609, current: -630491309; changing to -629823608. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823608, current: -630736398; changing to -629823607. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823607, current: -630735375; changing to -629823606. This may result in incorrect timestamps in the output file.
frame=  124 fps= 12 q=28.0 size=      61kB time=00:00:02.60 bitrate= 193.5kbits/s dup=26 drop=4 spee[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823606, current: -630734351; changing to -629823605. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823605, current: -630733327; changing to -629823604. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823604, current: -630732303; changing to -629823603. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823603, current: -630731279; changing to -629823602. This may result in incorrect timestamps in the output file.
[mp4 @ 0x7faa1a83ba00] Non-monotonous DTS in output stream 0:1; previous: -629823602, current: -630730256; changing to -629823601. This may result in incorrect timestamps in the output file.
frame=  124 fps= 12 q=-1.0 Lsize=     507kB time=00:00:04.84 bitrate= 858.7kbits/s dup=26 drop=4 speed=0.453x

So my question is, why does this video break ffmpeg? Why does ffmpeg get caught up in a tight loop extracting images without ever making any progres towards the end of the video?

Answer 1

The sample video has a weird audio stream (single packet - negative timestamp).

Use

ffmpeg -i test.mp4 -vf scale=640:-2 -r 1 -vsync 2 -q:v 18 extraction_%04d.jpeg

By default, ffmpeg assumes constant frame-rate for image sequence output. It tracks the output time and counts the frames in each interval to satisfy CFR output. Clearly, the weird timestamps in your sample breaks that process. vsync 2 sets it to VFR output, which stops ffmpeg from duplicating frames.