[Libav-user] Async Video and Audio after cutting an AVI into pieces

Roman Fietze roman.fietze at telemotive.de
Fri Apr 4 12:14:13 CEST 2014


Dear List Members,

I would like to find the reason for the following problem, probably to
even fix it in the ffmpeg/libav sources with your help.

The steps are (for details like parameters see below):

- record an RTSP stream from an AXIS P7214 (H264+AAC), e.g. 60 s long

- cut it into pieces using ffmpag with -ss and -t

- play it using ffplay

Everything looks good except the last step. Playing the cut video from
step 2 using mplayer works fine, playing it using ffplay gives me very
slow video, but audio has the correct speed. I get the same bad result
when I use my own little test program to stream the camera data and
cut the video plus audio right away. Playing the uncut file from the
first step works fine.

I can see the warnings about the non oncreasing timestamps, but I
cannot (yet) figure out where to look. Any pointer where to start
debugging would be very helpful. Probably the first step would be to
add some debug info inside ffmpeg.c where the packets are read, scaled
and written.

The debug output of the three steps are following here, always makred
with the proper numer:

--- snippety snip, step 1 ------------
ffmpeg version N-62122-g16509d3 Copyright (c) 2000-2014 the FFmpeg developers
  built on Apr  4 2014 08:41:56 with gcc 4.8 (SUSE Linux)
  configuration: 
  libavutil      52. 73.100 / 52. 73.100
  libavcodec     55. 56.107 / 55. 56.107
  libavformat    55. 36.101 / 55. 36.101
  libavdevice    55. 11.100 / 55. 11.100
  libavfilter     4.  3.100 /  4.  3.100
  libswscale      2.  6.100 /  2.  6.100
  libswresample   0. 18.100 /  0. 18.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument 'debug'.
Reading option '-i' ... matched as input file with argument 'rtsp://192.168.0.90/axis-media/media.amp'.
Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '-c:a' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '-y' ... matched as option 'y' (overwrite output files) with argument '1'.
Reading option '-t' ... matched as option 't' (record or transcode "duration" seconds of audio/video) with argument '60'.
Reading option 'ffmpeg.avi' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument debug.
Applying option y (overwrite output files) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input file rtsp://192.168.0.90/axis-media/media.amp.
Successfully parsed a group of options.
Opening an input file: rtsp://192.168.0.90/axis-media/media.amp.
[rtsp @ 0x1ce2a20] SDP:
v=0
o=- 1396609211548433 1396609211548433 IN IP4 192.168.0.90
s=Media Presentation
e=NONE
b=AS:50032
t=0 0
a=control:*
a=range:npt=0.000000-
m=video 0 RTP/AVP 96
c=IN IP4 0.0.0.0
b=AS:50000
a=framerate:15.0
a=transform:1,0,0;0,1,0;0,0,1
a=control:trackID=1
a=rtpmap:96 H264/90000
a=fmtp:96 packetization-mode=1; profile-level-id=4D0029; sprop-parameter-sets=Z00AKeKQFgJNgScFAQXh4kRU,aO48gA==
m=audio 0 RTP/AVP 97
c=IN IP4 0.0.0.0
b=AS:32
a=control:trackID=2
a=rtpmap:97 mpeg4-generic/16000/1
a=fmtp:97 streamtype=5; profile-level-id=15; mode=AAC-hbr; config=1408; sizeLength=13; indexLength=3; indexDeltaLength=3; profile=1; bitrate=32000;
[rtsp @ 0x1ce2a20] video codec set to: h264
[NULL @ 0x1ce5620] RTP Packetization Mode: 1
[NULL @ 0x1ce5620] RTP Profile IDC: 4d Profile IOP: 0 Level: 29
[NULL @ 0x1ce5620] Extradata set to 0x1ce5bc0 (size: 30)!
[rtsp @ 0x1ce2a20] audio codec set to: aac
[rtsp @ 0x1ce2a20] audio samplerate set to: 16000
[rtsp @ 0x1ce2a20] audio channels set to: 1
[udp @ 0x1ce8b60] end receive buffer size reported is 131072
[udp @ 0x1cf8e60] end receive buffer size reported is 131072
[udp @ 0x1d09420] end receive buffer size reported is 131072
[udp @ 0x1d094a0] end receive buffer size reported is 131072
[rtsp @ 0x1ce2a20] hello state=0
[rtsp @ 0x1ce2a20] All info found
rfps: 24.666667 0.016341
rfps: 24.750000 0.009187
    Last message repeated 1 times
rfps: 24.833333 0.004079
    Last message repeated 1 times
rfps: 24.916667 0.001017
    Last message repeated 1 times
rfps: 25.000000 0.000000
rfps: 25.083333 0.001029
    Last message repeated 1 times
rfps: 25.166667 0.004103
    Last message repeated 1 times
rfps: 25.250000 0.009223
    Last message repeated 1 times
rfps: 25.333333 0.016389
rfps: 49.666667 0.016318
rfps: 49.750000 0.009170
    Last message repeated 1 times
rfps: 49.833333 0.004068
    Last message repeated 1 times
rfps: 49.916667 0.001011
    Last message repeated 1 times
rfps: 50.000000 0.000000
rfps: 50.083333 0.001035
    Last message repeated 1 times
rfps: 50.166667 0.004115
    Last message repeated 1 times
rfps: 50.250000 0.009241
    Last message repeated 1 times
rfps: 50.333333 0.016412
Input #0, rtsp, from 'rtsp://192.168.0.90/axis-media/media.amp':
  Metadata:
    title           : Media Presentation
  Duration: N/A, start: 0.061563, bitrate: N/A
    Stream #0:0, 28, 1/90000: Video: h264 (Main), yuvj420p(pc, bt470bg), 704x576 [SAR 12:11 DAR 4:3], 1/180000, 25 tbr, 90k tbn, 180k tbc
    Stream #0:1, 29, 1/16000: Audio: aac, 16000 Hz, mono, fltp
Successfully opened the file.
Parsing a group of options: output file ffmpeg.avi.
Applying option c:v (codec name) with argument copy.
Applying option c:a (codec name) with argument copy.
Applying option t (record or transcode "duration" seconds of audio/video) with argument 60.
Successfully parsed a group of options.
Opening an output file: ffmpeg.avi.
Successfully opened the file.
Output #0, avi, to 'ffmpeg.avi':
  Metadata:
    INAM            : Media Presentation
    ISFT            : Lavf55.36.101
    Stream #0:0, 0, 1/600: Video: h264 (H264 / 0x34363248), yuvj420p, 704x576 [SAR 12:11 DAR 4:3], 1/90000, q=2-31, 600 tbn, 90k tbc
    Stream #0:1, 0, 8/125: Audio: aac ([255][0][0][0] / 0x00FF), 16000 Hz, mono
Stream mapping:
  Stream #0:0 -> #0:0 (copy)
  Stream #0:1 -> #0:1 (copy)
Press [q] to stop, [?] for help
frame=   36 fps=0.0 q=-1.0 size=     123kB time=00:00:02.43 bitrate= 412.9kbits/s    
frame=   44 fps= 42 q=-1.0 size=     138kB time=00:00:02.94 bitrate= 382.8kbits/s    
frame=   52 fps= 33 q=-1.0 size=     172kB time=00:00:03.45 bitrate= 408.5kbits/s    
frame=   59 fps= 28 q=-1.0 size=     196kB time=00:00:03.96 bitrate= 405.6kbits/s    
frame=   67 fps= 26 q=-1.0 size=     252kB time=00:00:04.48 bitrate= 459.9kbits/s    
frame=   75 fps= 24 q=-1.0 size=     295kB time=00:00:04.99 bitrate= 484.2kbits/s    
frame=   83 fps= 23 q=-1.0 size=     335kB time=00:00:05.50 bitrate= 498.1kbits/s    
frame=   90 fps= 22 q=-1.0 size=     363kB time=00:00:06.01 bitrate= 494.7kbits/s    
frame=   98 fps= 21 q=-1.0 size=     421kB time=00:00:06.52 bitrate= 528.5kbits/s    
frame=  106 fps= 21 q=-1.0 size=     456kB time=00:00:07.04 bitrate= 530.2kbits/s    
frame=  113 fps= 20 q=-1.0 size=     488kB time=00:00:07.55 bitrate= 529.5kbits/s    
...
frame=  866 fps= 16 q=-1.0 size=    4948kB time=00:00:57.72 bitrate= 702.2kbits/s    
frame=  874 fps= 16 q=-1.0 size=    4967kB time=00:00:58.24 bitrate= 698.6kbits/s    
frame=  881 fps= 15 q=-1.0 size=    4982kB time=00:00:58.75 bitrate= 694.6kbits/s    
frame=  889 fps= 15 q=-1.0 size=    4999kB time=00:00:59.26 bitrate= 691.0kbits/s    
frame=  896 fps= 15 q=-1.0 size=    5014kB time=00:00:59.77 bitrate= 687.1kbits/s    
No more output streams to write to, finishing.
frame=  901 fps= 15 q=-1.0 Lsize=    5636kB time=00:01:00.03 bitrate= 769.0kbits/s    
video:4532kB audio:228kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 18.394947%
Input file #0 (rtsp://192.168.0.90/axis-media/media.amp):
  Input stream #0:0 (video): 902 packets read (4642256 bytes); 
  Input stream #0:1 (audio): 940 packets read (234163 bytes); 
  Total: 1842 packets (4876419 bytes) demuxed
Output file #0 (ffmpeg.avi):
  Output stream #0:0 (video): 901 packets muxed (4640495 bytes); 
  Output stream #0:1 (audio): 938 packets muxed (233664 bytes); 
  Total: 1839 packets (4874159 bytes) muxed
0 frames successfully decoded, 0 decoding errors
[AVIOContext @ 0x1ce5aa0] Statistics: 10 seeks, 1880 writeouts

--- snippety snip, step 2 ------------
ffmpeg version N-62122-g16509d3 Copyright (c) 2000-2014 the FFmpeg developers
  built on Apr  4 2014 08:41:56 with gcc 4.8 (SUSE Linux)
  configuration: 
  libavutil      52. 73.100 / 52. 73.100
  libavcodec     55. 56.107 / 55. 56.107
  libavformat    55. 36.101 / 55. 36.101
  libavdevice    55. 11.100 / 55. 11.100
  libavfilter     4.  3.100 /  4.  3.100
  libswscale      2.  6.100 /  2.  6.100
  libswresample   0. 18.100 /  0. 18.100
Splitting the commandline.
Reading option '-v' ... matched as option 'v' (set logging level) with argument 'debug'.
Reading option '-i' ... matched as input file with argument 'ffmpeg.avi'.
Reading option '-c:v' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '-c:a' ... matched as option 'c' (codec name) with argument 'copy'.
Reading option '-y' ... matched as option 'y' (overwrite output files) with argument '1'.
Reading option '-ss' ... matched as option 'ss' (set the start time offset) with argument '00:00:00'.
Reading option '-t' ... matched as option 't' (record or transcode "duration" seconds of audio/video) with argument '10'.
Reading option 'ffmpeg00000.avi' ... matched as output file.
Finished splitting the commandline.
Parsing a group of options: global .
Applying option v (set logging level) with argument debug.
Applying option y (overwrite output files) with argument 1.
Successfully parsed a group of options.
Parsing a group of options: input file ffmpeg.avi.
Successfully parsed a group of options.
Opening an input file: ffmpeg.avi.
[avi @ 0x24fda80] Format avi probed with size=2048 and score=100
[avi @ 0x24fe220] use odml:1
[avi @ 0x24fda80] Before avformat_find_stream_info() pos: 10036 bytes read:721504 seeks:4
[avi @ 0x24fda80] All info found
[avi @ 0x24fda80] After avformat_find_stream_info() pos: 134549 bytes read:819808 seeks:4 frames:82
Input #0, avi, from 'ffmpeg.avi':
  Metadata:
    title           : Media Presentation
    encoder         : Lavf55.36.101
  Duration: 00:01:00.03, start: 0.000000, bitrate: 769 kb/s
    Stream #0:0, 41, 1/600: Video: h264 (Main) (H264 / 0x34363248), yuvj420p(pc, bt470bg), 704x576 [SAR 12:11 DAR 4:3], 1/1200, 600 fps, 25 tbr, 600 tbn, 1200 tbc
    Stream #0:1, 41, 8/125: Audio: aac ([255][0][0][0] / 0x00FF), 16000 Hz, mono, fltp
Successfully opened the file.
Parsing a group of options: output file ffmpeg00000.avi.
Applying option c:v (codec name) with argument copy.
Applying option c:a (codec name) with argument copy.
Applying option ss (set the start time offset) with argument 00:00:00.
Applying option t (record or transcode "duration" seconds of audio/video) with argument 10.
Successfully parsed a group of options.
Opening an output file: ffmpeg00000.avi.
Successfully opened the file.
Output #0, avi, to 'ffmpeg00000.avi':
  Metadata:
    INAM            : Media Presentation
    ISFT            : Lavf55.36.101
    Stream #0:0, 0, 1/600: Video: h264 (H264 / 0x34363248), yuvj420p, 704x576 [SAR 12:11 DAR 4:3], 1/600, q=2-31, 600 fps, 600 tbn, 600 tbc
    Stream #0:1, 0, 8/125: Audio: aac ([255][0][0][0] / 0x00FF), 16000 Hz, mono
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=  151 fps=0.0 q=-1.0 Lsize=     783kB time=00:00:10.04 bitrate= 638.7kbits/s    
video:592kB audio:38kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 24.354809%
Input file #0 (ffmpeg.avi):
  Input stream #0:0 (video): 152 packets read (611131 bytes); 
  Input stream #0:1 (audio): 158 packets read (39454 bytes); 
  Total: 310 packets (650585 bytes) demuxed
Output file #0 (ffmpeg00000.avi):
  Output stream #0:0 (video): 151 packets muxed (605869 bytes); 
  Output stream #0:1 (audio): 157 packets muxed (39211 bytes); 
  Total: 308 packets (645080 bytes) muxed
0 frames successfully decoded, 0 decoding errors
[AVIOContext @ 0x25eae00] Statistics: 10 seeks, 318 writeouts
[AVIOContext @ 0x2506280] Statistics: 1409632 bytes read, 4 seeks

--- snippety snip, step 3 ------------
ffplay version 2.2 Copyright (c) 2003-2014 the FFmpeg developers
  built on Mar 24 2014 17:15:07 with gcc 4.8 (SUSE Linux)
  configuration: --shlibdir=/usr/lib64 --prefix=/usr --mandir=/usr/share/man --libdir=/usr/lib64 --enable-shared --disable-static --enable-debug --disable-stripping --extra-cflags='-fmessage-length=0 -grecord-gcc-switches -fstack-protector -O2 -Wall -D_FORTIFY_SOURCE=2 -funwind-tables -fasynchronous-unwind-tables -g -fPIC -I/usr/include/gsm' --enable-gpl --enable-x11grab --enable-version3 --enable-pthreads --enable-avfilter --enable-libpulse --enable-libvpx --enable-libopus --enable-libass --enable-libx265 --enable-libmp3lame --enable-libvorbis --enable-libtheora --enable-libspeex --enable-libxvid --enable-libx264 --enable-libschroedinger --enable-libgsm --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-postproc --enable-libdc1394 --enable-librtmp --enable-libfreetype --enable-avresample --enable-libtwolame --enable-libvo-aacenc --enable-gnutls
  libavutil      52. 66.100 / 52. 66.100
  libavcodec     55. 52.102 / 55. 52.102
  libavformat    55. 33.100 / 55. 33.100
  libavdevice    55. 10.100 / 55. 10.100
  libavfilter     4.  2.100 /  4.  2.100
  libavresample   1.  2.  0 /  1.  2.  0
  libswscale      2.  5.102 /  2.  5.102
  libswresample   0. 18.100 /  0. 18.100
  libpostproc    52.  3.100 / 52.  3.100
    nan    :  0.000 fd=   0 aq=    0KB vq=    0KB sq=    0B f=0/0   
[avi @ 0x1ad0860] Format avi probed with size=2048 and score=100
[avi @ 0x1ad1360] use odml:1
[avi @ 0x1ad0860] non-interleaved AVI
[avi @ 0x1ad0860] Before avformat_find_stream_info() pos: 10036 bytes read:229008 seeks:4
[avi @ 0x1ad0860] Non-increasing DTS in stream 1: packet 3 with DTS 1, packet 4 with DTS 1
[avi @ 0x1ad0860] Non-increasing DTS in stream 1: packet 4 with DTS 1, packet 5 with DTS 1
[avi @ 0x1ad0860] Non-increasing DTS in stream 1: packet 6 with DTS 2, packet 7 with DTS 2
...
[avi @ 0x1ad0860] Non-increasing DTS in stream 1: packet 78 with DTS 25, packet 79 with DTS 25
[avi @ 0x1ad0860] Non-increasing DTS in stream 1: packet 80 with DTS 26, packet 81 with DTS 26
[avi @ 0x1ad0860] max_analyze_duration 5000000 reached at 5056000 microseconds
[avi @ 0x1ad0860] After avformat_find_stream_info() pos: 325818 bytes read:1474192 seeks:35 frames:108
Input #0, avi, from 'ffmpeg00000.avi':
  Metadata:
    title           : Media Presentation
    encoder         : Lavf55.36.101
  Duration: 00:00:09.94, start: 0.000000, bitrate: 645 kb/s
    Stream #0:0, 27, 1/600: Video: h264 (Main) (H264 / 0x34363248), yuvj420p(pc, bt470bg), 704x576 [SAR 12:11 DAR 4:3], 1/1200, 600 fps, 25 tbr, 600 tbn, 1200 tbc
    Stream #0:1, 81, 8/125: Audio: aac ([255][0][0][0] / 0x00FF), 16000 Hz, mono, fltp
detected 8 logical cores
[ffplay_abuffer @ 0x1c4e060] Setting 'sample_rate' to value '16000'
[ffplay_abuffer @ 0x1c4e060] Setting 'sample_fmt' to value 'fltp'
[ffplay_abuffer @ 0x1c4e060] Setting 'channels' to value '1'
[ffplay_abuffer @ 0x1c4e060] Setting 'time_base' to value '1/16000'
[ffplay_abuffer @ 0x1c4e060] Setting 'channel_layout' to value '0x4'
[ffplay_abuffer @ 0x1c4e060] tb:1/16000 samplefmt:fltp samplerate:16000 chlayout:0x4
[ffplay_abuffersink @ 0x1ae2000] auto-inserting filter 'auto-inserted resampler 0' between the filter 'ffplay_abuffer' and the filter 'ffplay_abuffersink'
[AVFilterGraph @ 0x1c5e4a0] query_formats: 2 queried, 0 merged, 3 already done, 0 delayed
[auto-inserted resampler 0 @ 0x1c0cf80] ch:1 chl:mono fmt:fltp r:16000Hz -> ch:1 chl:mono fmt:s16 r:16000Hz
Audio frame changed from rate:16000 ch:1 fmt:fltp layout:mono serial:-1 to rate:16000 ch:1 fmt:fltp layout:mono serial:1
[ffplay_abuffer @ 0x1c4e060] Setting 'sample_rate' to value '16000'
[ffplay_abuffer @ 0x1c4e060] Setting 'sample_fmt' to value 'fltp'
[ffplay_abuffer @ 0x1c4e060] Setting 'channels' to value '1'
[ffplay_abuffer @ 0x1c4e060] Setting 'time_base' to value '1/16000'
[ffplay_abuffer @ 0x1c4e060] Setting 'channel_layout' to value '0x4'
[ffplay_abuffer @ 0x1c4e060] tb:1/16000 samplefmt:fltp samplerate:16000 chlayout:0x4
[ffplay_abuffersink @ 0x1b8a860] auto-inserting filter 'auto-inserted resampler 0' between the filter 'ffplay_abuffer' and the filter 'ffplay_abuffersink'
[AVFilterGraph @ 0x1b6e640] query_formats: 2 queried, 0 merged, 3 already done, 0 delayed
[auto-inserted resampler 0 @ 0x1ae2000] ch:1 chl:mono fmt:fltp r:16000Hz -> ch:1 chl:mono fmt:s16 r:16000Hz
   0.01 A-V:    nan fd=   0 aq=    3KB vq=    0KB sq=    0B f=0/0   
Video frame changed from size:0x0 format:none serial:-1 to size:704x576 format:yuvj420p serial:1
[ffplay_buffer @ 0x22fbcc0] Setting 'video_size' to value '704x576'
[ffplay_buffer @ 0x22fbcc0] Setting 'pix_fmt' to value '12'
[ffplay_buffer @ 0x22fbcc0] Setting 'time_base' to value '1/600'
[ffplay_buffer @ 0x22fbcc0] Setting 'pixel_aspect' to value '12/11'
[ffplay_buffer @ 0x22fbcc0] Setting 'frame_rate' to value '25/1'
[ffplay_buffer @ 0x22fbcc0] w:704 h:576 pixfmt:yuvj420p tb:1/600 fr:25/1 sar:12/11 sws_param:
[ffplay_crop @ 0x22fca20] Setting 'out_w' to value 'floor(in_w/2)*2'
[ffplay_crop @ 0x22fca20] Setting 'out_h' to value 'floor(in_h/2)*2'
[auto-inserted scaler 0 @ 0x22fd680] Setting 'flags' to value '4'
[auto-inserted scaler 0 @ 0x22fd680] w:iw h:ih flags:'4' interl:0
[ffplay_crop @ 0x22fca20] auto-inserting filter 'auto-inserted scaler 0' between the filter 'ffplay_buffer' and the filter 'ffplay_crop'
[AVFilterGraph @ 0x226d3c0] query_formats: 3 queried, 1 merged, 1 already done, 0 delayed
[swscaler @ 0x22fdd20] deprecated pixel format used, make sure you did set range correctly
[auto-inserted scaler 0 @ 0x22fd680] w:704 h:576 fmt:yuvj420p sar:12/11 -> w:704 h:576 fmt:yuv420p sar:12/11 flags:0x4
[ffplay_crop @ 0x22fca20] w:704 h:576 sar:12/11 -> w:704 h:576 sar:12/11
   0.00 A-V:    nan fd=   0 aq=   13KB vq=    6KB sq=    0B f=0/0   
   0.06 A-V: -0.041 fd=   0 aq=   17KB vq=    6KB sq=    0B f=0/0   
   0.06 A-V: -0.074 fd=   0 aq=   17KB vq=    6KB sq=    0B f=0/0   
   0.10 A-V: -0.121 fd=   0 aq=   18KB vq=    6KB sq=    0B f=0/0   
   0.19 A-V: -0.105 fd=   0 aq=   18KB vq=    6KB sq=    0B f=0/0   
   0.19 A-V: -0.145 fd=   0 aq=   19KB vq=    6KB sq=    0B f=0/0   
   0.22 A-V: -0.194 fd=   0 aq=   19KB vq=    6KB sq=    0B f=0/0   
   0.26 A-V: -0.242 fd=   0 aq=   19KB vq=    6KB sq=    0B f=0/0   
...
   2.90 A-V: -1.641 fd=   0 aq=    5KB vq=   21KB sq=    0B f=0/0   
   2.93 A-V: -1.688 fd=   0 aq=    4KB vq=   20KB sq=    0B f=0/0   
   3.03 A-V: -1.672 fd=   0 aq=    3KB vq=   20KB sq=    0B f=0/0   
[AVIOContext @ 0x1ad15c0] Statistics: 3309200 bytes read, 85 seeks



Roman

-- 
Roman Fietze              Telemotive AG Buero Muehlhausen
Breitwiesen                             73347 Muehlhausen
Tel.: +49 7335 18493-45          http://www.telemotive.de



More information about the Libav-user mailing list