[vlc-devel] EsOutDecodersStopBuffering screws up timestamps when transcoding

[David Flynn]

Hi,

While trying to solve an issue with timestamps, i've discoverd that time
briefly jumps bacwards when transcoding and input_clock_ChangeSystemOrigin
gets called within EsOutDecodersStopBuffering.

Here is a brief example:

vlc -vvv file/rawvid://bbb-360p24.i420 :rawvid-height=360 \
 :rawvid-width=640 :rawvid-chroma=I420 :rawvid-fps=24 \
 --sout '#standard{access=file,mux=raw,dst=/dev/null}'

I've liberally sprinkled a few msg_Dbg()s around:

(Sorry, paste.videolan.org is dead)
[0x816e510] main input debug: starting in sync mode
[0x816e510] main input debug: `file/rawvid://bbb-360p24.i420' successfully opened
[0x81878a0] rawvid demux debug: PCR: 1
[0x816e510] main input debug: Buffering 0%
[0x81885b8] rawvideo packetizer debug: incoming set pts:1
[0x80cd0b0] main stream output debug: adding a new sout input (sout_input:0x81884a0)
[0x8171cc0] main mux debug: adding a new input
[0x8171cc0] mux_dummy mux debug: adding input
[0x80cd0b0] main stream output debug: got buffer: pts:170867726591 dts:170867726591
[0x81885b8] main packetizer debug: switching to async mode
[0x816e510] main input debug: control type=1
[0x81878a0] rawvid demux debug: PCR: 41667
[0x816e510] main input debug: Buffering 13%
[0x81885b8] rawvideo packetizer debug: incoming set pts:41667
[0x80cd0b0] main stream output debug: got buffer: pts:170867768257 dts:170867768257
[0x81878a0] rawvid demux debug: PCR: 83334
[0x816e510] main input debug: Buffering 27%
[0x81885b8] rawvideo packetizer debug: incoming set pts:83334
[0x80cd0b0] main stream output debug: got buffer: pts:170867809924 dts:170867809924
[0x81878a0] rawvid demux debug: PCR: 125001
[0x816e510] main input debug: Buffering 41%
[0x81885b8] rawvideo packetizer debug: incoming set pts:125001
[0x80cd0b0] main stream output debug: got buffer: pts:170867851591 dts:170867851591
[0x81878a0] rawvid demux debug: PCR: 166667
[0x816e510] main input debug: Buffering 55%
[0x81885b8] rawvideo packetizer debug: incoming set pts:166667
[0x80cd0b0] main stream output debug: got buffer: pts:170867893257 dts:170867893257
[0x81878a0] rawvid demux debug: PCR: 208334
[0x816e510] main input debug: Buffering 69%
[0x81885b8] rawvideo packetizer debug: incoming set pts:208334
[0x80cd0b0] main stream output debug: got buffer: pts:170867934924 dts:170867934924
[0x81878a0] rawvid demux debug: PCR: 250001
[0x816e510] main input debug: Buffering 83%
[0x81885b8] rawvideo packetizer debug: incoming set pts:250001
[0x80cd0b0] main stream output debug: got buffer: pts:170867976591 dts:170867976591
[0x81878a0] rawvid demux debug: PCR: 291667
[0x816e510] main input debug: Buffering 97%
[0x81885b8] rawvideo packetizer debug: incoming set pts:291667
A ===> [0x80cd0b0] main stream output debug: got buffer: pts:170868018257 dts:170868018257
[0x81878a0] rawvid demux debug: PCR: 333334
[0x816e510] main input debug: Stream buffering done (333 ms in 39 ms)
[0x816e510] main input debug: Decoder buffering done in 0 ms
[0x81885b8] rawvideo packetizer debug: incoming set pts:333334
B ===> [0x80cd0b0] main stream output debug: got buffer: pts:170867809163 dts:170867809163
[0x81878a0] rawvid demux debug: PCR: 375001
[0x81885b8] rawvideo packetizer debug: incoming set pts:375001
[0x80cd0b0] main stream output debug: got buffer: pts:170867850830 dts:170867850830

Note that (B) now comes before (A).  This is unfortunate, since it
screws up everything downstream related to timestamps; ie, it isn't
possible to produce a correct stream.

If people wish to test it, the above example is avaliable with:

$ git checkout -b test-df-insanity origin/master
$ git pull git://repo.or.cz/vlc/davidf-public.git df-rawvid

(Contains two patches, one to make rawvid actually do timestamps
accurately [I'll submit this shortly for review], and another that
adds msg_Dbg()s as above).

It looks like the issue is to do with:
input_clock_ChangeSystemOrigin( p_sys->p_pgrm->p_clock, i_ts_delay - i_buffering_duration );

(if i remove that line, the clock doesn't become skewed)

This issue doesn't seem to occur when not transcoding (ie playback)

NB, /dev/zero works just as well as bbb-360p24.i420

Any thoughts?

..david