avenc_mjpeg does not play well with appsrc do-timestamp=true
Submitted by Francois Gouget
Link to original bug (#753257)
Description
Spice (http://www.spice-space.org/) provides access to remote desktops, particularly in virtualized environments. One of the features is the auto-detection and reencoding of videos to limit bandwidth and ensure smooth playback over the network. Currently it uses an internal MJPEG encoder and I'm adding GStreamer support so more options are available.
The pipeline is:
appsrc format=2 do-timestamp=true ! videoconvert ! avenc_mjpeg ! appsink
The problem is avenc_mjpeg quickly locks up with the following message:
0:00:00.845940069 23436 0x7f5318649800 ERROR libav :0:: Error, Invalid timestamp=12, last=12
The issue is that the frame rate is not really constant as it depends on the delays occurring in the virtual machine's media player and in Spice, and also that we only have an estimate of the fps. So the DTS and PTS timestamps appsrc puts on the buffers are not evenly spaced. Actually I'm not entirely sure why they are even set since we set the format to GST_FORMAT_BYTES.
In the above case we had an estimated fps of 18, and the following buffer timestamps:
002513154 -> 0.0450 -> 0
071591170 -> 1.2870 -> 1
118313226 -> 2.1294 -> 2
165181751 -> 2.9718 -> 3
245834444 -> 4.4244 -> 4
332598247 -> 5.9850 -> 6
371301628 -> 6.6834 -> 7
418700233 -> 7.5366 -> 8
506639922 -> 9.1188 -> 9
544309390 -> 9.7974 -> 10
591892626 -> 10.6524 -> 11
639620343 -> 11.5128 -> 12
677606008 -> 12.1968 -> 12
vp8enc and x264enc have no problem with the timestamps produced by appsrc so I'd expect avenc_mjpeg to work with them too.
Bug 724103 looks similar but it has not seen a resolution so far.
Here are the relevant GStreamer traces:
0:00:00.168343602 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.002513154, dts 0:00:00.002513154, dur 99:99:99.999999999, size 2536960, offset 1, offset_end 18446744073709551615, flags 0x0
0:00:00.235083367 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.071591170, dts 0:00:00.071591170, dur 99:99:99.999999999, size 2536960, offset 2, offset_end 18446744073709551615, flags 0x0
0:00:00.281803710 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.118313226, dts 0:00:00.118313226, dur 99:99:99.999999999, size 2536960, offset 3, offset_end 18446744073709551615, flags 0x0
0:00:00.331504042 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.165181751, dts 0:00:00.165181751, dur 99:99:99.999999999, size 2536960, offset 4, offset_end 18446744073709551615, flags 0x0
0:00:00.409095156 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.245834444, dts 0:00:00.245834444, dur 99:99:99.999999999, size 2536960, offset 5, offset_end 18446744073709551615, flags 0x0
0:00:00.497658441 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.332598247, dts 0:00:00.332598247, dur 99:99:99.999999999, size 2536960, offset 6, offset_end 18446744073709551615, flags 0x0
0:00:00.534940768 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.371301628, dts 0:00:00.371301628, dur 99:99:99.999999999, size 2536960, offset 7, offset_end 18446744073709551615, flags 0x0
0:00:00.582394393 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.418700233, dts 0:00:00.418700233, dur 99:99:99.999999999, size 2536960, offset 8, offset_end 18446744073709551615, flags 0x0
0:00:00.670202868 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.506639922, dts 0:00:00.506639922, dur 99:99:99.999999999, size 2536960, offset 9, offset_end 18446744073709551615, flags 0x0
0:00:00.707709735 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.544309390, dts 0:00:00.544309390, dur 99:99:99.999999999, size 2536960, offset 10, offset_end 18446744073709551615, flags 0x0
0:00:00.756213906 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.591892626, dts 0:00:00.591892626, dur 99:99:99.999999999, size 2536960, offset 11, offset_end 18446744073709551615, flags 0x0
0:00:00.803863082 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.639620343, dts 0:00:00.639620343, dur 99:99:99.999999999, size 2536960, offset 12, offset_end 18446744073709551615, flags 0x0
0:00:00.845885669 23436 0x7f5318649800 LOG GST_SCHEDULING gstpad.c:3828:gst_pad_chain_data_unchecked:encoder:sink calling chainfunction &gst_video_encoder_chain with buffer buffer: 0x7f531864f730, pts 0:00:00.677606008, dts 0:00:00.677606008, dur 99:99:99.999999999, size 2536960, offset 13, offset_end 18446744073709551615, flags 0x0
0:00:00.845940069 23436 0x7f5318649800 ERROR libav :0:: Error, Invalid timestamp=12, last=12
0:00:00.845960574 23436 0x7f5318649800 ERROR libav gstavvidenc.c:675:gst_ffmpegvidenc_handle_frame:<encoder>
avenc_mjpeg: failed to encode buffer
0:00:00.845970442 23436 0x7f5318649800 DEBUG videoencoder gstvideoencoder.c:1902:gst_video_encoder_finish_frame:<encoder>
skipping frame 0:00:00.677606008
Version: 1.6.0