video sync errors and missing stream after clipping h264 files

[Stewart Andreason]

Summary of the bug:
If I re-encode a file with h264, any later attempts to clip/trim/resize that file result in various sync errors or even a missing video stream.

How to reproduce:
After starting with a raw camera file, after I process it by resizing
and/or cropping etc, using the h264 codec, When I later try to use that
output file as an input file for further processing, (like to trim
the length and starting time) it gives an error and drops the video stream, or it gets the video way out of sync.
Looks like the same bug, with different starting times specified.

I suspect a problem with tbc and tbn, watch the input and output values.
Step 1, resize only:

> ffmpeg -v 9 -loglevel 99 -i 20150204_1037_beaverDam7_rec_5472.MOV -c:v h264 -s 640x360 -c:a copy 20150204_1037_beaverDam7_rec_5472-360p.mov >& ffmpeg-5472-test1.log

ffmpeg version N-69557-gb119945 Copyright (c) 2000-2015 the FFmpeg developers
  built with gcc 4.9.1 (GCC)
  configuration: --enable-gpl --enable-libx264 --disable-doc --disable-htmlpages --disable-podpages --disable-ffserver --disable-network --enable-libfreetype --enable-libfontconfig --enable-shared
  libavutil      54. 18.100 / 54. 18.100
  libavcodec     56. 21.102 / 56. 21.102
  libavformat    56. 19.100 / 56. 19.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5.  9.103 /  5.  9.103
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  1.100 /  1.  1.100
  libpostproc    53.  3.100 / 53.  3.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-i' ... matched as input file with argument '20150204_1037_beaverDam7_rec_5472.MOV'.
Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'h264'.
Reading option '-s' ... matched as option 's' (set frame size (WxH or abbreviation)) with argument '640x360'.
Reading option '-c:a' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '20150204_1037_beaverDam7_rec_5472-360p.mov' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Successfully parsed a group of options.
Parsing a group of options: input file 20150204_1037_beaverDam7_rec_5472.MOV.
Successfully parsed a group of options.
Opening an input file: 20150204_1037_beaverDam7_rec_5472.MOV.
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Format mov,mp4,m4a,3gp,3g2,mj2 probed with size=2048 and score=100
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] ISO: File Type Major Brand: qt  
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Before avformat_find_stream_info() pos: 55287099 bytes read:73011 seeks:2
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] All info found
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] After avformat_find_stream_info() pos: 2656256 bytes read:2466043 seeks:4 frames:31
Guessed Channel Layout for  Input Stream #0.1 : mono
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '20150204_1037_beaverDam7_rec_5472.MOV':
  Metadata:
    major_brand     : qt  
    minor_version   : 0
    compatible_brands: qt  
    creation_time   : 2015-02-04 10:37:32
    original_format : DVR-CD
    original_format-eng: DVR-CD
    comment         : HDDVR-Mobius
    comment-eng     : HDDVR-Mobius
  Duration: 00:00:24.00, start: 0.000000, bitrate: 18429 kb/s
    Stream #0:0(eng), 30, 1/30000: Video: h264 (High) (avc1 / 0x31637661), yuv420p(left), 1920x1080 (1920x1088), 1/60000, 17662 kb/s, 30 fps, 30 tbr, 30k tbn, 60k tbc (default)
    Metadata:
      creation_time   : 2015-02-04 10:37:32
      handler_name    : DataHandler
      encoder         : h264
    Stream #0:1(eng), 1, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, 1 channels, s16, 512 kb/s (default)
    Metadata:
      creation_time   : 2015-02-04 10:37:32
      handler_name    : DataHandler
Successfully opened the file.
Parsing a group of options: output file 20150204_1037_beaverDam7_rec_5472-360p.mov.
Applying option c:v (codec name) with argument h264.
Applying option s (set frame size (WxH or abbreviation)) with argument 640x360.
Applying option c:a (codec name) with argument copy.
Successfully parsed a group of options.
Opening an output file: 20150204_1037_beaverDam7_rec_5472-360p.mov.
Matched encoder 'libx264' for codec 'h264'.
Successfully opened the file.
detected 1 logical cores
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'video_size' to value '1920x1080'
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'pix_fmt' to value '0'
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'time_base' to value '1/30000'
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'pixel_aspect' to value '0/1'
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'sws_param' to value 'flags=2'
[graph 0 input from stream 0:0 @ 0x8087400] Setting 'frame_rate' to value '30/1'
[graph 0 input from stream 0:0 @ 0x8087400] w:1920 h:1080 pixfmt:yuv420p tb:1/30000 fr:30/1 sar:0/1 sws_param:flags=2
[scaler for output stream 0:0 @ 0x8086fe0] Setting 'w' to value '640'
[scaler for output stream 0:0 @ 0x8086fe0] Setting 'h' to value '360'
[scaler for output stream 0:0 @ 0x8086fe0] Setting 'flags' to value '0x4'
[scaler for output stream 0:0 @ 0x8086fe0] w:640 h:360 flags:'0x4' interl:0
[format @ 0x808eb80] compat: called with args=[yuv420p|yuvj420p|yuv422p|yuvj422p|yuv444p|yuvj444p|nv12|nv16]
[format @ 0x808eb80] Setting 'pix_fmts' to value 'yuv420p|yuvj420p|yuv422p|yuvj422p|yuv444p|yuvj444p|nv12|nv16'
[AVFilterGraph @ 0x81b75a0] query_formats: 5 queried, 4 merged, 0 already done, 0 delayed
[scaler for output stream 0:0 @ 0x8086fe0] w:1920 h:1080 fmt:yuv420p sar:0/1 -> w:640 h:360 fmt:yuv420p sar:0/1 flags:0x4
[libx264 @ 0x80a7360] using cpu capabilities: MMX2 SSE SlowCTZ
[libx264 @ 0x80a7360] profile High, level 3.0
[libx264 @ 0x80a7360] 264 - core 142 r2479 dd79a61 - H.264/MPEG-4 AVC codec - Copyleft 2003-2014 - http://www.videolan.org/x264.html - options: cabac=1 ref=3 deblock=1:0:0 analyse=0x3:0x113 me=hex subme=7 psy=1 psy_rd=1.00:0.00 mixed_ref=1 me_range=16 chroma_me=1 trellis=1 8x8dct=1 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=-2 threads=1 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=3 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=2 keyint=250 keyint_min=25 scenecut=40 intra_refresh=0 rc_lookahead=40 rc=crf mbtree=1 crf=23.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 aq=1:1.00
Output #0, mov, to '20150204_1037_beaverDam7_rec_5472-360p.mov':
  Metadata:
    major_brand     : qt  
    minor_version   : 0
    compatible_brands: qt  
    comment-eng     : HDDVR-Mobius
    original_format : DVR-CD
    original_format-eng: DVR-CD
    comment         : HDDVR-Mobius
    encoder         : Lavf56.19.100
    Stream #0:0(eng), 0, 1/15360: Video: h264 (libx264) (avc1 / 0x31637661), yuv420p(left), 640x360, 1/30, q=-1--1, 30 fps, 15360 tbn, 30 tbc (default)
    Metadata:
      creation_time   : 2015-02-04 10:37:32
      handler_name    : DataHandler
      encoder         : Lavc56.21.102 libx264
    Stream #0:1(eng), 0, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, 512 kb/s (default)
    Metadata:
      creation_time   : 2015-02-04 10:37:32
      handler_name    : DataHandler
Stream mapping:
  Stream #0:0 -> #0:0 (h264 (native) -> h264 (libx264))
  Stream #0:1 -> #0:1 (copy)
Press [q] to stop, [?] for help
Cliping frame in rate conversion by 0.000008
frame=    7 fps=0.0 q=0.0 size=       0kB time=00:00:00.00 bitrate=N/A    
frame=   18 fps= 17 q=0.0 size=       0kB time=00:00:00.00 bitrate=N/A    
frame=   29 fps= 18 q=0.0 size=       0kB time=00:00:00.00 bitrate=N/A    
frame=   38 fps= 18 q=0.0 size=       0kB time=00:00:01.00 bitrate=   0.3kbits/s    
[libx264 @ 0x80a7360] frame=   0 QP=24.25 NAL=3 Slice:I Poc:0   I:920  P:0    SKIP:0    size=23082 bytes
[libx264 @ 0x80a7360] frame=   1 QP=24.49 NAL=2 Slice:P Poc:6   I:30   P:716  SKIP:174  size=7996 bytes
frame=   43 fps= 15 q=29.0 size=      31kB time=00:00:01.00 bitrate= 254.4kbits/s    
[libx264 @ 0x80a7360] frame=   2 QP=29.63 NAL=2 Slice:B Poc:4   I:0    P:513  SKIP:385  size=1381 bytes
[libx264 @ 0x80a7360] frame=   3 QP=27.53 NAL=0 Slice:B Poc:2   I:2    P:556  SKIP:340  size=1388 bytes
[libx264 @ 0x80a7360] frame=   4 QP=23.87 NAL=2 Slice:P Poc:10  I:23   P:756  SKIP:141  size=7939 bytes
[libx264 @ 0x80a7360] frame=   5 QP=27.40 NAL=0 Slice:B Poc:8   I:0    P:534  SKIP:375  size=1325 bytes
frame=   47 fps= 14 q=29.0 size=      51kB time=00:00:01.00 bitrate= 416.2kbits/s    
[libx264 @ 0x80a7360] frame=   6 QP=23.42 NAL=2 Slice:P Poc:16  I:106  P:718  SKIP:96   size=8376 bytes

[clipping 90kb of repetitive output]

[libx264 @ 0x80a7360] frame= 701 QP=24.37 NAL=2 Slice:P Poc:404 I:64   P:738  SKIP:118  size=8160 bytes
[libx264 @ 0x80a7360] frame= 702 QP=28.40 NAL=0 Slice:B Poc:402 I:2    P:538  SKIP:331  size=1928 bytes
[libx264 @ 0x80a7360] frame= 703 QP=24.95 NAL=2 Slice:P Poc:408 I:46   P:725  SKIP:149  size=7953 bytes
[libx264 @ 0x80a7360] frame= 704 QP=28.40 NAL=0 Slice:B Poc:406 I:2    P:553  SKIP:318  size=2154 bytes
[libx264 @ 0x80a7360] frame= 705 QP=24.47 NAL=2 Slice:P Poc:412 I:100  P:761  SKIP:59   size=8848 bytes
[libx264 @ 0x80a7360] frame= 706 QP=27.87 NAL=0 Slice:B Poc:410 I:5    P:523  SKIP:339  size=2377 bytes
[libx264 @ 0x80a7360] frame= 707 QP=24.59 NAL=2 Slice:P Poc:416 I:62   P:726  SKIP:132  size=8050 bytes
[libx264 @ 0x80a7360] frame= 708 QP=28.71 NAL=0 Slice:B Poc:414 I:1    P:542  SKIP:326  size=2370 bytes
[libx264 @ 0x80a7360] frame= 709 QP=24.62 NAL=2 Slice:P Poc:420 I:56   P:730  SKIP:134  size=8032 bytes
[libx264 @ 0x80a7360] frame= 710 QP=29.40 NAL=0 Slice:B Poc:418 I:0    P:486  SKIP:378  size=2372 bytes
[libx264 @ 0x80a7360] frame= 711 QP=25.18 NAL=2 Slice:P Poc:424 I:70   P:673  SKIP:177  size=7714 bytes
[libx264 @ 0x80a7360] frame= 712 QP=27.69 NAL=0 Slice:B Poc:422 I:1    P:567  SKIP:315  size=2508 bytes
[libx264 @ 0x80a7360] frame= 713 QP=25.53 NAL=2 Slice:P Poc:428 I:70   P:701  SKIP:149  size=7330 bytes
[libx264 @ 0x80a7360] frame= 714 QP=28.75 NAL=0 Slice:B Poc:426 I:3    P:552  SKIP:319  size=2641 bytes
[libx264 @ 0x80a7360] frame= 715 QP=25.45 NAL=2 Slice:P Poc:432 I:133  P:685  SKIP:102  size=7491 bytes
[libx264 @ 0x80a7360] frame= 716 QP=27.71 NAL=0 Slice:B Poc:430 I:5    P:533  SKIP:334  size=2485 bytes
[libx264 @ 0x80a7360] frame= 717 QP=26.73 NAL=2 Slice:P Poc:436 I:85   P:644  SKIP:191  size=6014 bytes
[libx264 @ 0x80a7360] frame= 718 QP=28.64 NAL=0 Slice:B Poc:434 I:4    P:553  SKIP:324  size=2544 bytes
[libx264 @ 0x80a7360] frame= 719 QP=28.73 NAL=2 Slice:P Poc:438 I:36   P:526  SKIP:358  size=3531 bytes
frame=  720 fps=5.8 q=29.0 Lsize=    6582kB time=00:00:24.00 bitrate=2246.8kbits/s    
video:5066kB audio:1500kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.249506%
Input file #0 (20150204_1037_beaverDam7_rec_5472.MOV):
  Input stream #0:0 (video): 720 packets read (52986380 bytes); 720 frames decoded; 
  Input stream #0:1 (audio): 768 packets read (1536000 bytes); 
  Total: 1488 packets (54522380 bytes) demuxed
Output file #0 (20150204_1037_beaverDam7_rec_5472-360p.mov):
  Output stream #0:0 (video): 720 frames encoded; 720 packets muxed (5187678 bytes); 
  Output stream #0:1 (audio): 768 packets muxed (1536000 bytes); 
  Total: 1488 packets (6723678 bytes) muxed
720 frames successfully decoded, 0 decoding errors
[AVIOContext @ 0x80a9c20] Statistics: 64 seeks, 1539 writeouts
[libx264 @ 0x80a7360] frame I:3     Avg QP:23.41  size: 32721
[libx264 @ 0x80a7360] frame P:379   Avg QP:25.40  size: 11296
[libx264 @ 0x80a7360] frame B:338   Avg QP:29.00  size:  2390
[libx264 @ 0x80a7360] consecutive B-frames: 10.1% 77.8% 12.1%  0.0%
[libx264 @ 0x80a7360] mb I  I16..4:  5.7% 50.0% 44.3%
[libx264 @ 0x80a7360] mb P  I16..4:  1.8%  4.7%  1.8%  P16..4: 36.2% 27.3% 18.8%  0.0%  0.0%    skip: 9.5%
[libx264 @ 0x80a7360] mb B  I16..4:  0.1%  0.2%  0.1%  B16..8: 49.6% 10.5%  3.5%  direct: 2.5%  skip:33.5%  L0:33.0% L1:54.8% BI:12.2%
[libx264 @ 0x80a7360] 8x8 transform intra:56.1% inter:48.3%
[libx264 @ 0x80a7360] coded y,uvDC,uvAC intra: 55.2% 21.5% 1.1% inter: 28.2% 6.3% 0.0%
[libx264 @ 0x80a7360] i16 v,h,dc,p: 29% 27% 18% 26%
[libx264 @ 0x80a7360] i8 v,h,dc,ddl,ddr,vr,hd,vl,hu: 18% 12% 36%  4%  7%  6%  6%  5%  5%
[libx264 @ 0x80a7360] i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 21%  9% 23%  8%  9%  8%  7%  8%  7%
[libx264 @ 0x80a7360] i8c dc,h,v,p: 76% 12% 11%  1%
[libx264 @ 0x80a7360] Weighted P-Frames: Y:11.3% UV:0.3%
[libx264 @ 0x80a7360] ref P L0: 71.2% 20.2%  6.3%  2.2%  0.1%
[libx264 @ 0x80a7360] ref B L0: 95.5%  4.4%  0.1%
[libx264 @ 0x80a7360] ref B L1: 97.6%  2.4%
[libx264 @ 0x80a7360] kb/s:1729.00
[AVIOContext @ 0x808eb00] Statistics: 54633703 bytes read, 26 seeks

Step 2: clip/trim a section of the above file.

> ffmpeg -v 9 -loglevel 99 -i 20150204_1037_beaverDam7_rec_5472-360p.mov -ss 12 -t 8 -c copy 20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov >& ffmpeg-5472-test2.log

ffmpeg version N-69557-gb119945 Copyright (c) 2000-2015 the FFmpeg developers
  built with gcc 4.9.1 (GCC)
  configuration: --enable-gpl --enable-libx264 --disable-doc --disable-htmlpages --disable-podpages --disable-ffserver --disable-network --enable-libfreetype --enable-libfontconfig --enable-shared
  libavutil      54. 18.100 / 54. 18.100
  libavcodec     56. 21.102 / 56. 21.102
  libavformat    56. 19.100 / 56. 19.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5.  9.103 /  5.  9.103
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  1.100 /  1.  1.100
  libpostproc    53.  3.100 / 53.  3.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-i' ... matched as input file with argument '20150204_1037_beaverDam7_rec_5472-360p.mov'.
Reading option '-ss' ... matched as option 'ss' (set the start time offset) with argument '12'.
Reading option '-t' ... matched as option 't' (record or transcode "duration" seconds of audio/video) with argument '8'.
Reading option '-c' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Successfully parsed a group of options.
Parsing a group of options: input file 20150204_1037_beaverDam7_rec_5472-360p.mov.
Successfully parsed a group of options.
Opening an input file: 20150204_1037_beaverDam7_rec_5472-360p.mov.
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Format mov,mp4,m4a,3gp,3g2,mj2 probed with size=2048 and score=100
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] ISO: File Type Major Brand: qt  
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Before avformat_find_stream_info() pos: 6740454 bytes read:49507 seeks:1
[h264 @ 0x8097220] no picture 
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] All info found
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] After avformat_find_stream_info() pos: 35233 bytes read:115043 seeks:2 frames:4
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '20150204_1037_beaverDam7_rec_5472-360p.mov':
  Metadata:
    major_brand     : qt  
    minor_version   : 512
    compatible_brands: qt  
    encoder         : Lavf56.19.100
    comment         : HDDVR-Mobius
    comment-eng     : HDDVR-Mobius
  Duration: 00:00:24.00, start: 0.000000, bitrate: 2246 kb/s
    Stream #0:0(eng), 3, 1/15360: Video: h264 (High) (avc1 / 0x31637661), yuv420p(left), 640x360 (640x368), 1/60, 1729 kb/s, 30 fps, 30 tbr, 15360 tbn, 60 tbc (default)
    Metadata:
      handler_name    : DataHandler
      encoder         : Lavc56.21.102 libx264
    Stream #0:1(eng), 1, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, s16, 512 kb/s (default)
    Metadata:
      handler_name    : DataHandler
Successfully opened the file.
Parsing a group of options: output file 20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov.
Applying option ss (set the start time offset) with argument 12.
Applying option t (record or transcode "duration" seconds of audio/video) with argument 8.
Applying option c (codec name) with argument copy.
Successfully parsed a group of options.
Opening an output file: 20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov.
Successfully opened the file.
[mov @ 0x816fbe0] timecode: tbc=15360/1 invalid, fallback on 30/1
Output #0, mov, to '20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov':
  Metadata:
    major_brand     : qt  
    minor_version   : 512
    compatible_brands: qt  
    comment-eng     : HDDVR-Mobius
    comment         : HDDVR-Mobius
    encoder         : Lavf56.19.100
    Stream #0:0(eng), 0, 1/15360: Video: h264 (avc1 / 0x31637661), yuv420p(left), 640x360 (0x0), 1/15360, q=2-31, 1729 kb/s, 30 fps, 30 tbr, 15360 tbn, 15360 tbc (default)
    Metadata:
      handler_name    : DataHandler
      encoder         : Lavc56.21.102 libx264
    Stream #0:1(eng), 0, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, 512 kb/s (default)
    Metadata:
      handler_name    : DataHandler
Stream mapping:
  Stream #0:0 -> #0:0 (copy)
  Stream #0:1 -> #0:1 (copy)
Press [q] to stop, [?] for help
No more output streams to write to, finishing.
frame=  102 fps=0.0 q=-1.0 Lsize=    1194kB time=00:00:08.00 bitrate=1222.9kbits/s    
video:691kB audio:500kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.294840%
Input file #0 (20150204_1037_beaverDam7_rec_5472-360p.mov):
  Input stream #0:0 (video): 603 packets read (4613823 bytes); 
  Input stream #0:1 (audio): 641 packets read (1282048 bytes); 
  Total: 1244 packets (5895871 bytes) demuxed
Output file #0 (20150204_1037_beaverDam7_rec_5472-360p_c12t8.mov):
  Output stream #0:0 (video): 102 packets muxed (707304 bytes); 
  Output stream #0:1 (audio): 256 packets muxed (512000 bytes); 
  Total: 358 packets (1219304 bytes) muxed
0 frames successfully decoded, 0 decoding errors
[AVIOContext @ 0x8099ec0] Statistics: 64 seeks, 408 writeouts
[AVIOContext @ 0x808eb00] Statistics: 5947747 bytes read, 2 seeks

This results in a very out of sync video. The time marker starts at 4 seconds, or specifically A: 0.0 V: 4.4
and the video only lasts 4 seconds, as the audio and video arrive at 8 seconds separately. Also the footsteps are clearly out of sync. The video stops while the audio continues to play the correct clip starting and ending points.

Since this did not duplicate my earlier report (Jan22 on ffmpeg-users), I adjust the starting sec to reproduce it.

> ffmpeg -v 9 -loglevel 99 -i 20150204_1037_beaverDam7_rec_5472-360p.mov -ss 3 -t 2 -c copy 20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov >& ffmpeg-5472-test3.log

ffmpeg version N-69557-gb119945 Copyright (c) 2000-2015 the FFmpeg developers
  built with gcc 4.9.1 (GCC)
  configuration: --enable-gpl --enable-libx264 --disable-doc --disable-htmlpages --disable-podpages --disable-ffserver --disable-network --enable-libfreetype --enable-libfontconfig --enable-shared
  libavutil      54. 18.100 / 54. 18.100
  libavcodec     56. 21.102 / 56. 21.102
  libavformat    56. 19.100 / 56. 19.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5.  9.103 /  5.  9.103
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  1.100 /  1.  1.100
  libpostproc    53.  3.100 / 53.  3.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument '9'.
Reading option '-loglevel' ... matched as option 'loglevel' (set logging level) with argument '99'.
Reading option '-i' ... matched as input file with argument '20150204_1037_beaverDam7_rec_5472-360p.mov'.
Reading option '-ss' ... matched as option 'ss' (set the start time offset) with argument '3'.
Reading option '-t' ... matched as option 't' (record or transcode "duration" seconds of audio/video) with argument '2'.
Reading option '-c' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument 9.
Successfully parsed a group of options.
Parsing a group of options: input file 20150204_1037_beaverDam7_rec_5472-360p.mov.
Successfully parsed a group of options.
Opening an input file: 20150204_1037_beaverDam7_rec_5472-360p.mov.
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Format mov,mp4,m4a,3gp,3g2,mj2 probed with size=2048 and score=100
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] ISO: File Type Major Brand: qt  
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] Before avformat_find_stream_info() pos: 6740454 bytes read:49507 seeks:1
[h264 @ 0x8097220] no picture 
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] All info found
[mov,mp4,m4a,3gp,3g2,mj2 @ 0x80969e0] After avformat_find_stream_info() pos: 35233 bytes read:115043 seeks:2 frames:4
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '20150204_1037_beaverDam7_rec_5472-360p.mov':
  Metadata:
    major_brand     : qt  
    minor_version   : 512
    compatible_brands: qt  
    encoder         : Lavf56.19.100
    comment         : HDDVR-Mobius
    comment-eng     : HDDVR-Mobius
  Duration: 00:00:24.00, start: 0.000000, bitrate: 2246 kb/s
    Stream #0:0(eng), 3, 1/15360: Video: h264 (High) (avc1 / 0x31637661), yuv420p(left), 640x360 (640x368), 1/60, 1729 kb/s, 30 fps, 30 tbr, 15360 tbn, 60 tbc (default)
    Metadata:
      handler_name    : DataHandler
      encoder         : Lavc56.21.102 libx264
    Stream #0:1(eng), 1, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, s16, 512 kb/s (default)
    Metadata:
      handler_name    : DataHandler
Successfully opened the file.
Parsing a group of options: output file 20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov.
Applying option ss (set the start time offset) with argument 3.
Applying option t (record or transcode "duration" seconds of audio/video) with argument 2.
Applying option c (codec name) with argument copy.
Successfully parsed a group of options.
Opening an output file: 20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov.
Successfully opened the file.
[mov @ 0x816fbe0] timecode: tbc=15360/1 invalid, fallback on 30/1
Output #0, mov, to '20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov':
  Metadata:
    major_brand     : qt  
    minor_version   : 512
    compatible_brands: qt  
    comment-eng     : HDDVR-Mobius
    comment         : HDDVR-Mobius
    encoder         : Lavf56.19.100
    Stream #0:0(eng), 0, 1/15360: Video: h264 (avc1 / 0x31637661), yuv420p(left), 640x360 (0x0), 1/15360, q=2-31, 1729 kb/s, 30 fps, 30 tbr, 15360 tbn, 15360 tbc (default)
    Metadata:
      handler_name    : DataHandler
      encoder         : Lavc56.21.102 libx264
    Stream #0:1(eng), 0, 1/32000: Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, 512 kb/s (default)
    Metadata:
      handler_name    : DataHandler
Stream mapping:
  Stream #0:0 -> #0:0 (copy)
  Stream #0:1 -> #0:1 (copy)
Press [q] to stop, [?] for help
No more output streams to write to, finishing.
frame=    0 fps=0.0 q=-1.0 Lsize=     126kB time=00:00:02.00 bitrate= 514.9kbits/s    
video:0kB audio:125kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.573438%
Input file #0 (20150204_1037_beaverDam7_rec_5472-360p.mov):
  Input stream #0:0 (video): 251 packets read (1907581 bytes); 
  Input stream #0:1 (audio): 265 packets read (530432 bytes); 
  Total: 516 packets (2438013 bytes) demuxed
Output file #0 (20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov):
  Output stream #0:0 (video): 0 packets muxed (0 bytes); 
  Output stream #0:1 (audio): 64 packets muxed (128000 bytes); 
  Total: 64 packets (128000 bytes) muxed
0 frames successfully decoded, 0 decoding errors
[AVIOContext @ 0x8099ec0] Statistics: 32 seeks, 89 writeouts
[AVIOContext @ 0x808eb00] Statistics: 2507107 bytes read, 2 seeks

> ffprobe 20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov
ffprobe version N-69557-gb119945 Copyright (c) 2007-2015 the FFmpeg developers
  built with gcc 4.9.1 (GCC)
  configuration: --enable-gpl --enable-libx264 --disable-doc --disable-htmlpages --disable-podpages --disable-ffserver --disable-network --enable-libfreetype --enable-libfontconfig --enable-shared
  libavutil      54. 18.100 / 54. 18.100
  libavcodec     56. 21.102 / 56. 21.102
  libavformat    56. 19.100 / 56. 19.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5.  9.103 /  5.  9.103
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  1.100 /  1.  1.100
  libpostproc    53.  3.100 / 53.  3.100
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '20150204_1037_beaverDam7_rec_5472-360p_c3t2.mov':
  Metadata:
    major_brand     : qt
    minor_version   : 512
    compatible_brands: qt
    encoder         : Lavf56.19.100
    comment         : HDDVR-Mobius
    comment-eng     : HDDVR-Mobius
  Duration: 00:00:02.00, start: 0.000000, bitrate: 514 kb/s
    Stream #0:0(eng): Audio: pcm_s16le (sowt / 0x74776F73), 32000 Hz, mono, s16, 512 kb/s (default)
    Metadata:
      handler_name    : DataHandler

Notice there is no video stream in the test3 output.

Also the tbc don't match. Step 1 wrote the tbc as 30 (default), it becomes 60 (default) at the 2nd stage input, and then 15360 (default) at the last output.
Which tbc is (default)? The meaning of default is lost and confusing.

Error message: tbc=15360/1 invalid seems like perhaps it is confusing tbc and tbn?

Source file 52Mb:
​http://seahorseCorral.org/videos/tests/20150204_1037_beaverDam7_rec_5472.MOV

This seems to be reproducable with any video file I try it on, the problem starts after re-encoding with ffmpeg to h264. Any subsequent attempts at processing (serially) result in bugs.

[compn]

its because you copy audio. try encoding audio as well should fix problem.

[Stewart Andreason]

No that does not solve the problem.

> ffmpeg -i 20150204_1037_beaverDam7_rec_5472.MOV -c:v h264 -s 640x360 -c:a mp2 test2-ea-1.mov
> ffmpeg -i test2-ea-1.mov -ss 12 -t 8 -c copy test2-ea-2.mov

The aud/vid sync goes bad in the second file: test2-ea-2.mov

Even if that solved the problem, it would lose audio quality if I re-encoded the audio. I would end up remapping later the original audio track back in to whatever re-encoded video I made.

[Stewart Andreason]

In the real projects I'm working on, (not just this test video), I also see the bug I'm trying to report.
I finally see a pattern. When a h264 video has larger I-frame intervals, like 2 or 2.5 seconds, if I try to do just the clipping -ss # -t # -c copy (before or apart from any other work, like crop/resize/watermark/etc,) then I see mis-matched aud/vid sync way too often, as I rarely request the video to be cut at exactly the I-frame position.
The same happens after ffmpeg -c:v h264 Any subsequent attempts to clip the video results in messed up aud/vid sync. The key is when the I-frame interval is other than 0.5 or 1.00 second, the usual clipping locations.

Ok I've now worked this through enough times to see this may not be a true bug after all, but a limitation on the I-frame location relative to the desired clipping spots.

Maybe the only realistic improvement would be to add a warning that the first x.x seconds were lost before the first I-frame was found.

[Carl Eugen Hoyos]

Not a regression afaict.