ffmpeg encoder warning: almost fed libavcodec with a frame

[curtis]

Hi @,
I compiled ffmpeg and vlc, but when I ran vlc I received these error messages:

[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)

Can you help there is problem?
Thanks

I compiled ffmpeg and vlc with these parameters:
FFMPEG (version ffmpeg-checkout-2006-12-05):
./configure --enable-mp3lame --enable-xvid --enable-gpl --enable-pp --enable-vorbis --enable-dts --enable-libogg --enable-shared

VLC (version vlc-snapshot-20061207.tar.gz):

./configure --enable-httpd --enable-mad --enable-libdvbpsi --enable-pp --enable-gpl --enable-shared --disable-wxwidgets --enable-optimize-memory --enable-sout --enable-dvbpsi --enable-libmpeg2 --with-dvbpsi=/usr/src/libdvbpsi4-0.1.5 --with-dvbpsi-tree=/usr/src/libdvbpsi4-0.1.5 --enable-ffmpeg --with-ffmpeg-tree=/usr/src/ffmpeg-checkout-2006-12-05 --with-ffmpeg-mp3lame --enable-xvideo --enable-release --enable-static --enable-st --enable-pth --enable-mostly-builtin

More info from vlc:

/usr/local/bin/vlc -vvv udp://@233.10.47.71 --sout '#transcode{vcodec=WMV2,vb=512,scale=1,acodec=mpga,ab=192,channels=2}:duplicate{dst=std{access=http,mux=ts,dst=:5190}'
VLC media player 0.9.0-svn Grishenko
[00000001] main libvlc debug: checking builtin modules
[00000001] main libvlc debug: checking plugin modules
[00000001] main libvlc debug: loading plugins cache file /home/curtis/.vlc/cache/plugins-04041e.dat
[00000001] main libvlc debug: recursively browsing `modules'
[00000001] main libvlc debug: recursively browsing `/usr/local/lib/vlc'
[00000001] main libvlc debug: recursively browsing `plugins'
[00000001] main libvlc debug: module bank initialized, found 190 modules
[00000001] main libvlc debug: opening config file (/home/curtis/.vlc/vlcrc)
[00000001] main libvlc debug: CPU has capabilities 486 586 MMX MMXEXT SSE SSE2 FPU
[00000001] main libvlc debug: looking for memcpy module: 3 candidates
[00000001] main libvlc debug: using memcpy module "memcpymmxext"
[00000266] main stream output debug: stream=`transcode'
[00000267] main private debug: looking for sout stream module: 1 candidate
invalid options (empty)[00000266] main stream output debug: stream=`duplicate'
[00000270] main private debug: looking for sout stream module: 1 candidate
[00000270] stream_out_duplicate private debug: creating 'duplicate'
[00000270] stream_out_duplicate private debug: * adding `std{access=http,mux=ts,dst=:5190}'
[00000266] main stream output debug: stream=`std'
[00000272] main private debug: looking for sout stream module: 1 candidate
[00000272] main private debug: set config option: sout-standard-access to http
[00000272] main private debug: set config option: sout-standard-mux to ts
[00000272] main private debug: set config option: sout-standard-dst to :5190
[00000272] stream_out_standard private debug: creating `http/ts://:5190'
[00000272] stream_out_standard private debug: using `http/ts://:5190'
[00000274] main private debug: looking for sout access module: 1 candidate
[00000274] main private: creating httpd
[00000274] main private debug: net: listening to port 5190
[00000277] main http server debug: thread 1087314864 (httpd host thread) created at priority 0 (network/httpd.c:1153)
[00000274] main private debug: using sout access module "access_output_http"
[00000272] stream_out_standard private debug: access opened
[00000278] main private debug: looking for sout mux module: 1 candidate
[00000278] mux_ts private debug: shaping=200000 pcr=70000 dts_delay=400000
[00000278] main private debug: using sout mux module "mux_ts"
[00000266] main stream output debug: muxer support adding stream at any time
[00000272] stream_out_standard private debug: mux opened
[00000272] main private debug: using sout stream module "stream_out_standard"
[00000270] main private debug: using sout stream module "stream_out_duplicate"
[00000267] main private debug: set config option: sout-transcode-vcodec to WMV2
[00000267] main private debug: set config option: sout-transcode-vb to 512
[00000267] main private debug: set config option: sout-transcode-scale to 1
[00000267] main private debug: set config option: sout-transcode-acodec to mpga
[00000267] main private debug: set config option: sout-transcode-ab to 192
[00000267] main private debug: set config option: sout-transcode-channels to 2
[00000267] stream_out_transcode private debug: codec audio=mpga 0Hz 2 channels 192Kb/s
[00000267] stream_out_transcode private debug: codec video=WMV2 0x0 scaling: 1.000000 512kb/s
[00000267] main private debug: using sout stream module "stream_out_transcode"
[00000265] main input debug: `file/xspf-open:///home/curtis/.vlc/ml.xsp' gives access `file' demux `xspf-open' path `/home/curtis/.vlc/ml.xsp'
[00000265] main input debug: creating access 'file' path='/home/curtis/.vlc/ml.xsp'
[00000280] main access debug: looking for access2 module: 4 candidates
[00000280] access_file access debug: opening file `/home/curtis/.vlc/ml.xsp'
[00000280] main access debug: using access2 module "access_file"
[00000282] main private debug: pre-buffering...
[00000282] main private debug: received first data for our buffer
[00000265] main input debug: creating demux: access='file' demux='xspf-open' path='/home/curtis/.vlc/ml.xsp'
[00000283] main demuxer debug: looking for demux2 module: 1 candidate
[00000283] playlist demuxer debug: using XSPF playlist reader
[00000283] main demuxer debug: using demux2 module "playlist"
[00000265] main input debug: starting in sync mode
[00000265] main input debug: `file/xspf-open:///home/curtis/.vlc/ml.xsp' successfully opened
[00000296] main private debug: looking for xml module: 1 candidate
[00000296] main private debug: using xml module "xtag"
[00000283] playlist demuxer debug: parsed 0 tracks successfully
[00000296] main private debug: removing module "xtag"
[00000265] main input debug: closing input
[00000283] main demuxer debug: removing module "playlist"
[00000280] main access debug: removing module "access_file"
[00000265] main input debug: destroying sout
[00000267] main private debug: destroying chain... (name=transcode)
[00000270] main private debug: destroying chain... (name=duplicate)
[00000270] stream_out_duplicate private debug: closing a duplication
[00000272] main private debug: destroying chain... (name=std)
[00000278] main private debug: removing module "mux_ts"
[00000277] main http server debug: thread 1087314864 joined (network/httpd.c:1209)
[00000277] main http server debug: HTTP host removed
[00000276] main http server debug: no host left, stopping httpd
[00000274] access_output_http private debug: Close
[00000274] main private debug: removing module "access_output_http"
[00000272] main private debug: removing module "stream_out_standard"
[00000272] main private debug: destroying chain done
[00000270] main private debug: removing module "stream_out_duplicate"
[00000270] main private debug: destroying chain done
[00000267] main private debug: removing module "stream_out_transcode"
[00000267] main private debug: destroying chain done
[00000298] main private debug: waiting for thread completion
[00000298] main private debug: thread 1087314864 (preparser) created at priority 0 (playlist/thread.c:87)
[00000299] main private debug: waiting for thread completion
[00000299] main private debug: thread 1101040560 (fetcher) created at priority 0 (playlist/thread.c:113)
[00000264] main playlist debug: waiting for thread completion
[00000264] main playlist debug: thread 1109429168 (playlist) created at priority 0 (playlist/thread.c:123)
[00000300] main interface debug: looking for interface module: 1 candidate
[00000300] main interface debug: using interface module "hotkeys"
[00000300] main interface debug: thread 1117842352 (interface) created at priority 0 (interface/interface.c:237)
[00000302] main interface debug: looking for interface module: 1 candidate
[00000302] main interface debug: using interface module "screensaver"
[00000302] main interface debug: thread 1126239152 (interface) created at priority 0 (interface/interface.c:237)
[00000264] main playlist debug: adding item `udp://@233.10.47.71' ( udp://@233.10.47.71 )
[00000304] main interface debug: looking for interface module: 1 candidate
Remote control interface initialized. Type `help' for help.
[00000304] main interface debug: using interface module "rc"
[00000264] main playlist debug: rebuilding array of current - root Playlist
[00000264] main playlist debug: rebuild done - 1 items, index -1
[00000264] main playlist debug: starting new item
[00000264] main playlist debug: processing request item null node Playlist skip 0
[00000264] main playlist debug: creating new input thread
[00000306] main input debug: waiting for thread completion
[00000306] main input debug: thread 1134681008 (input) created at priority 0 (input/input.c:288)
[00000264] main playlist debug: requesting art for udp://@233.10.47.71
[00000264] main playlist debug: art not found for udp://@233.10.47.71
[00000307] main stream output debug: stream=`transcode'
[00000308] main private debug: looking for sout stream module: 1 candidate
invalid options (empty)[00000307] main stream output debug: stream=`duplicate'
[00000310] main private debug: looking for sout stream module: 1 candidate
[00000310] stream_out_duplicate private debug: creating 'duplicate'
[00000310] stream_out_duplicate private debug: * adding `std{access=http,mux=ts,dst=:5190}'
[00000307] main stream output debug: stream=`std'
[00000311] main private debug: looking for sout stream module: 1 candidate
[00000311] main private debug: set config option: sout-standard-access to http
[00000311] main private debug: set config option: sout-standard-mux to ts
[00000311] main private debug: set config option: sout-standard-dst to :5190
[00000311] stream_out_standard private debug: creating `http/ts://:5190'
[00000311] stream_out_standard private debug: using `http/ts://:5190'
[00000312] main private debug: looking for sout access module: 1 candidate
[00000312] main private: creating httpd
[00000312] main private debug: net: listening to port 5190
[00000314] main http server debug: thread 1143069616 (httpd host thread) created at priority 0 (network/httpd.c:1153)
[00000312] main private debug: using sout access module "access_output_http"
[00000311] stream_out_standard private debug: access opened
[00000315] main private debug: looking for sout mux module: 1 candidate
[00000315] mux_ts private debug: shaping=200000 pcr=70000 dts_delay=400000
[00000315] main private debug: using sout mux module "mux_ts"
[00000307] main stream output debug: muxer support adding stream at any time
[00000311] stream_out_standard private debug: mux opened
[00000311] main private debug: using sout stream module "stream_out_standard"
[00000310] main private debug: using sout stream module "stream_out_duplicate"
[00000308] main private debug: set config option: sout-transcode-vcodec to WMV2
[00000308] main private debug: set config option: sout-transcode-vb to 512
[00000308] main private debug: set config option: sout-transcode-scale to 1
[00000308] main private debug: set config option: sout-transcode-acodec to mpga
[00000308] main private debug: set config option: sout-transcode-ab to 192
[00000308] main private debug: set config option: sout-transcode-channels to 2
[00000308] stream_out_transcode private debug: codec audio=mpga 0Hz 2 channels 192Kb/s
[00000308] stream_out_transcode private debug: codec video=WMV2 0x0 scaling: 1.000000 512kb/s
[00000308] main private debug: using sout stream module "stream_out_transcode"
[00000306] main input debug: `udp://@233.10.47.71' gives access `udp' demux `' path `@233.10.47.71'
[00000306] main input debug: creating demux: access='udp' demux='' path='@233.10.47.71'
[00000316] main demuxer debug: looking for access_demux module: 0 candidates
[00000316] main demuxer warning: no access_demux module matched "udp"
[00000306] main input debug: creating access 'udp' path='@233.10.47.71'
[00000317] main access debug: looking for access2 module: 5 candidates
[00000317] access_udp access debug: opening server=:0 local=233.10.47.71:1234
[00000317] main access debug: net: connecting to '[]:0@[233.10.47.71]:1234'
[00000317] main access debug: IP_ADD_MEMBERSHIP multicast request
[00000317] main access debug: using access2 module "access_udp"
[00000319] main private debug: pre buffering
[00000317] access_udp access debug: detected TS over RTP
[00000317] access_udp access debug: RTP: prebuffered 60 packets
[00000306] main input debug: creating demux: access='udp' demux='ts' path='@233.10.47.71'
[00000320] main demuxer debug: looking for demux2 module: 1 candidate
[00000320] main demuxer debug: using demux2 module "ts"
[00000320] ts demuxer debug: DEMUX_SET_GROUP 0 (nil)
[00000306] main input debug: starting in sync mode
[00000317] access_udp access warning: unimplemented query in control
[00000306] main input debug: `udp://@233.10.47.71' successfully opened
[00000320] ts demuxer debug: pid[402] unknown
[00000320] ts demuxer debug: pid[2162] unknown
[00000320] ts demuxer debug: pid[1842] unknown
[00000320] ts demuxer debug: pid[562] unknown
[00000320] ts demuxer debug: pid[1602] unknown
libdvbpsi error (PSI decoder): TS discontinuity (received 13, expected 0) for PID 0
[00000320] ts demuxer debug: PATCallBack called
[00000320] ts demuxer debug: new PAT ts_id=1 version=1 current_next=1
[00000320] ts demuxer debug: * number=8002 pid=802
libdvbpsi error (PSI decoder): TS discontinuity (received 3, expected 0) for PID 802
[00000320] ts demuxer debug: PMTCallBack called
[00000320] ts demuxer debug: new PMT program number=8002 version=1 pid_pcr=402
[00000320] ts demuxer debug: * descriptor : CA (0x9) SysID 0xd03
[00000320] ts demuxer debug: * es pid=402 type=2 fcc=mpgv
[00000306] main input debug: selecting program id=8002
[00000322] main packetizer debug: looking for packetizer module: 15 candidates
[00000322] main packetizer debug: using packetizer module "packetizer_mpegvideo"
[00000322] main packetizer debug: thread 1158278064 (decoder) created at priority 0 (input/decoder.c:172)
[00000320] ts demuxer debug: * es pid=562 type=3 fcc=mpga
[00000341] main packetizer debug: looking for packetizer module: 15 candidates
[00000341] main packetizer debug: using packetizer module "mpeg_audio"
[00000341] main packetizer debug: thread 1166683056 (decoder) created at priority 0 (input/decoder.c:172)
[00000320] ts demuxer debug: * es pid=1122 type=161 *unknown*
[00000320] ts demuxer debug: * es pid=1282 type=147 *unknown*
[00000320] ts demuxer debug: * es pid=1602 type=3 fcc=mpga
[00000320] ts demuxer debug: * es pid=1842 type=6 dr->i_tag=0x56
[00000320] ts demuxer debug: * EBU Teletext descriptor
[00000320] ts demuxer debug: * es pid=1842 type=6 fcc=telx
[00000320] ts demuxer debug: * es pid=2162 type=6 dr->i_tag=0x45
[00000320] ts demuxer debug: * VBI Data descriptor
[00000320] ts demuxer debug: * es pid=2162 type=6 *unknown*
[00000320] ts demuxer warning: first packet for pid=2162 cc=0xb
[00000320] ts demuxer warning: first packet for pid=402 cc=0xa
[00000320] ts demuxer warning: first packet for pid=1842 cc=0xf
[00000320] ts demuxer warning: first packet for pid=562 cc=0xf
[00000320] ts demuxer warning: first packet for pid=1602 cc=0x7
[00000322] packetizer_mpegvideo packetizer debug: waiting for sequence start
[00000341] mpeg_audio packetizer debug: MPGA channels:2 samplerate:48000 bitrate:192
[00000307] main stream output debug: adding a new input
[00000308] stream_out_transcode private debug: creating audio transcoding from fcc=`mpga' to fcc=`mpga'
[00000344] main decoder debug: looking for decoder module: 18 candidates
[00000344] main decoder debug: using decoder module "mpeg_audio"
[00000345] main encoder debug: looking for encoder module: 4 candidates
[00000345] ffmpeg encoder debug: libavcodec initialized (interface 3348736 )
[00000345] ffmpeg encoder debug: found encoder MPEG Audio layer 1/2
[00000345] main encoder debug: using encoder module "ffmpeg"
[00000361] main private debug: looking for audio filter2 module: 5 candidates
[00000361] mpgatofixed32 private debug: mpga->fl32, bits per sample: 0
[00000361] main private debug: using audio filter2 module "mpgatofixed32"
[00000364] main private debug: looking for audio filter2 module: 5 candidates
[00000364] audio_format private debug: fl32->s16l, bits per sample: 32
[00000364] main private debug: using audio filter2 module "audio_format"
[00000310] stream_out_duplicate private debug: duplicated a new stream codec=mpga (es=562 group=8002)
[00000315] main private debug: adding a new input
[00000315] mux_ts private debug: adding input codec=mpga pid=68
[00000315] mux_ts private debug: - lang=slk
[00000315] mux_ts private debug: new PCR PID is 68
[00000310] stream_out_duplicate private debug: - added for output 0
[00000344] mpeg_audio decoder debug: MPGA channels:2 samplerate:48000 bitrate:192
[00000322] packetizer_mpegvideo packetizer debug: waiting for sequence start
[00000322] packetizer_mpegvideo packetizer debug: size 720x576 fps=25.000
[00000307] main stream output debug: adding a new input
[00000308] stream_out_transcode private debug: creating video transcoding from fcc=`mpgv' to fcc=`WMV2'
[00000372] main decoder debug: looking for decoder module: 18 candidates
[00000372] main decoder debug: using decoder module "libmpeg2"
[00000373] main encoder debug: looking for encoder module: 4 candidates
[00000373] ffmpeg encoder debug: libavcodec already initialized
[00000373] ffmpeg encoder debug: found encoder Windows Media Video 2
[00000373] main encoder debug: using encoder module "ffmpeg"
[00000373] main encoder debug: removing module "ffmpeg"
[00000372] libmpeg2 decoder debug: 720x576 (display 720,576), aspect 576000, sar 16:15, 25.000 fps
[00000374] main private warning: dts != current_pts (-213300)
[00000374] main private warning: vout synchro warning: pts != current_date (-40000)
[00000308] stream_out_transcode private debug: decoder aspect is 576000:432000
[00000308] stream_out_transcode private debug: source pixel aspect is 1.066667:1
[00000308] stream_out_transcode private debug: scaled pixel aspect is 1.064815:1
[00000308] stream_out_transcode private debug: source 720x576, crop 720x576, destination 720x576, padding 720x576
[00000308] stream_out_transcode private debug: encoder aspect is 575000:432000
[00000373] main encoder debug: looking for encoder module: 4 candidates
[00000373] ffmpeg encoder debug: libavcodec already initialized
[00000373] ffmpeg encoder debug: removing common factors from framerate
(wmv2@0x8187400)
[00000373] ffmpeg encoder debug: found encoder Windows Media Video 2
[00000373] main encoder debug: using encoder module "ffmpeg"
[00000310] stream_out_duplicate private debug: duplicated a new stream codec=WMV2 (es=402 group=8002)
[00000315] main private debug: adding a new input
[00000315] mux_ts private debug: adding input codec=WMV2 pid=69
[00000315] mux_ts private debug: new PCR PID is 69
[00000310] stream_out_duplicate private debug: - added for output 0
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)

[xtophe]

increase the input buffer. --udp-caching ....

So that vlc can keep up if the network is a bit late

[curtis]

I used --udp-caching=30000 and tried another numbers. But same errors and nothing to watch.
Then I used video codec mpgv everything ok.
But I have to use WMV2 codec.

Run vlc with:
/usr/local/bin/vlc -vvv udp://@233.10.47.71 --udp-caching=30000 --sout '#transcode{vcodec=WMV2,vb=512,scale=1,acodec=mp3,ab=64,channels=2,audio-sync}:duplicate{dst=std{access=mmsh,mux=asfh,dst=:5190}'


[00000310] stream_out_duplicate private debug: duplicated a new stream codec=WMV2 (es=402 group=8002)
[00000315] main private debug: adding a new input
[00000315] mux_asf private debug: adding input
[00000310] stream_out_duplicate private debug: - added for output 0
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000308] stream_out_transcode private debug: drift is too high, resetting master sync
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000373] ffmpeg encoder warning: almost fed libavcodec with a frame in the past (current: -9223372036854775808, last: 0)
[00000315] main private warning: late buffer for mux input (15401)

Thanks

[rost]

Hi,

I encountered this as well. The problem is a cast of AV_NOPTS_VALUE in modules/codec/ffmpeg/encoder.c in line 842 (version 0.8.6a). I posted a patch for vlc-trunk on vlc-devel yesterday.

As a workaround you might consider replacing line 842
if ( frame.pts != (signed int) AV_NOPTS_VALUE && frame.pts != 0 )

with
if ( frame.pts != AV_NOPTS_VALUE && frame.pts != 0 )

and recompile.

I haven't done this for 0.8.6a but it worked for me in vlc-0.9.0-svn

Regards,
Robert