[gst-devel] ffdec and QoS
Arnout Vandecappelle
arnout at mind.be
Tue Jun 9 19:18:33 CEST 2009
Hoi all,
I've been struggling with QoS events for a while now, and I don't find a way out...
I have a pipeline like this:
souphttpsrc location=... do-timestamp=true ! mpeg4videoparse ! ffdec_mpeg4 ! \
videoscale ! fakesink sync=true qos=true
The ffmpeg decoder element usually buffers one frame internally. Unfortunately, this makes
the sink generate QoS events that causes basetransform to drop frames.
Here is some pruned debug output to indicate the problem:
# A frame is pushed in the decoder, but it is buffered.
0:00:00.752352 ffmpeg gstffmpegdec.c:897:gst_ffmpegdec_get_buffer:<ffdec_mpeg40> getting buffer, apply pts 517907675
0:00:00.754003 ffmpeg gstffmpegdec.c:1600:gst_ffmpegdec_video_frame:<ffdec_mpeg40> after decode: len 10006, have_data 0
0:00:00.754047 ffmpeg gstffmpegdec.c:2099:gst_ffmpegdec_frame:<ffdec_mpeg40> We didn't get a decoded buffer
# 200ms later, the next frame arrives, the previous one is decoded
0:00:00.966332 ffmpeg gstffmpegdec.c:897:gst_ffmpegdec_get_buffer:<ffdec_mpeg40> getting buffer, apply pts 633476686
0:00:00.967236 ffmpeg gstffmpegdec.c:1600:gst_ffmpegdec_video_frame:<ffdec_mpeg40> after decode: len 1512, have_data 288
0:00:00.967269 ffmpeg gstffmpegdec.c:1614:gst_ffmpegdec_video_frame:<ffdec_mpeg40> ts-handler: pts 517907675
0:00:00.969201 GST_QOS gstbasesink.c:2542:gst_base_sink_do_render_stats:<fakesink0> avg_render: 0:00:00.000042465
0:00:00.969219 GST_QOS gstbasesink.c:2346:gst_base_sink_perform_qos:<fakesink0> start: 0:00:00.517907675, entered 0:00:00.850296431, left 0:00:00.850296431, pt:
99:99:99.999999999, duration 0:00:00.000000000,jitter 332388756
0:00:00.969238 GST_QOS gstbasesink.c:2351:gst_base_sink_perform_qos:<fakesink0> avg_duration: 99:99:99.999999999, avg_pt: 99:99:99.999999999, avg_rate: -1
0:00:00.969255 GST_QOS gstbasesink.c:2386:gst_base_sink_perform_qos:<fakesink0> updated: avg_duration: 0:00:00.000000000, avg_pt: 99:99:99.999999999, avg_rate: -1
# no QoS event is sent yet...
# Again 200ms later, the next frame arrives, the previous one is decoded
0:00:01.188664 ffmpeg gstffmpegdec.c:897:gst_ffmpegdec_get_buffer:<ffdec_mpeg40> getting buffer, apply pts 848446910
0:00:01.189441 ffmpeg gstffmpegdec.c:1600:gst_ffmpegdec_video_frame:<ffdec_mpeg40> after decode: len 1339, have_data 288
0:00:01.189483 ffmpeg gstffmpegdec.c:1614:gst_ffmpegdec_video_frame:<ffdec_mpeg40> ts-handler: pts 633476686
0:00:01.189669 GST_QOS gstbasesink.c:2542:gst_base_sink_do_render_stats:<fakesink0> avg_render: 0:00:00.000043914
0:00:01.189684 GST_QOS gstbasesink.c:2346:gst_base_sink_perform_qos:<fakesink0> start: 0:00:00.633476686, entered 0:00:01.070752257, left 0:00:01.070752257, pt:
0:00:00.220455826, duration 0:00:00.000000000,jitter 437275571
0:00:01.189700 GST_QOS gstbasesink.c:2351:gst_base_sink_perform_qos:<fakesink0> avg_duration: 0:00:00.000000000, avg_pt: 99:99:99.999999999, avg_rate: -1
0:00:01.189718 GST_QOS gstbasesink.c:2386:gst_base_sink_perform_qos:<fakesink0> updated: avg_duration: 0:00:00.000000000, avg_pt: 0:00:00.220455826, avg_rate: 0
# Now, a QoS event is sent.
0:00:01.189732 GST_QOS gstbasesink.c:2278:gst_base_sink_send_qos:<fakesink0> qos: proportion: 0.000000, diff 437275571, timestamp 0:00:00.633476686
0:00:01.189759 GST_QOS gstbasetransform.c:2331:gst_base_transform_update_qos:<videoscale0> qos: proportion: 0.000000, diff 437275571, timestamp 0:00:00.633476686
# Again 200ms later, the next frame arrives, the previous one is decoded.
0:00:01.352582 ffmpeg gstffmpegdec.c:1274:gst_ffmpegdec_do_qos:<ffdec_mpeg40> QOS: qostime 0:00:01.070718163, earliest 0:00:01.070752257
0:00:01.352631 ffmpeg gstffmpegdec.c:1331:gst_ffmpegdec_do_qos:<ffdec_mpeg40> QOS: hurry up, diff 34094 >= 0
0:00:01.352676 ffmpeg gstffmpegdec.c:897:gst_ffmpegdec_get_buffer:<ffdec_mpeg40> getting buffer, apply pts 1070718163
0:00:01.353261 ffmpeg gstffmpegdec.c:1600:gst_ffmpegdec_video_frame:<ffdec_mpeg40> after decode: len 1395, have_data 288
0:00:01.353282 ffmpeg gstffmpegdec.c:1614:gst_ffmpegdec_video_frame:<ffdec_mpeg40> ts-handler: pts 848446910
# The timestamp of this frame is earlier than the time that the previous
# one was rendered, so basetransform drops it.
0:00:01.353402 GST_QOS gstbasetransform.c:1862:gst_base_transform_handle_buffer:<videoscale0> skipping transform: qostime 0:00:00.848446910 <= 0:00:01.070752257
# And this story repeats itself.
0:00:01.608276 ffmpeg gstffmpegdec.c:1274:gst_ffmpegdec_do_qos:<ffdec_mpeg40> QOS: qostime 0:00:01.234701170, earliest 0:00:01.070752257
0:00:01.608329 ffmpeg gstffmpegdec.c:1311:gst_ffmpegdec_do_qos:<ffdec_mpeg40> QOS: normal mode 0 < 0.4
0:00:01.608371 ffmpeg gstffmpegdec.c:897:gst_ffmpegdec_get_buffer:<ffdec_mpeg40> getting buffer, apply pts 1234701170
0:00:01.608943 ffmpeg gstffmpegdec.c:1600:gst_ffmpegdec_video_frame:<ffdec_mpeg40> after decode: len 1352, have_data 288
0:00:01.608963 ffmpeg gstffmpegdec.c:1614:gst_ffmpegdec_video_frame:<ffdec_mpeg40> ts-handler: pts 1070718163
0:00:01.609079 GST_QOS gstbasetransform.c:1862:gst_base_transform_handle_buffer:<videoscale0> skipping transform: qostime 0:00:01.070718163 <= 0:00:01.070752257
# The next frame will pass basetransform because we have caught up with the
# previous rendering time
One problem is that the framerate is unknown; with a correct framerate, the
buffers have a duration and this gives a more accurate estimate of the expected
rendering time of the next buffer. However, even so, small differences in
decoding time may still make a buffer seem late (e.g. add 200ms to the first
dropped buffer, above).
The core of the problem, I think, is that the QoS handling doesn't take
into account pipeline latency. It just assumes that throughput = 1/latency
and doesn't seem to take into account that data can be buffered in the
pipeline.
Does anyone have any idea how to solve this? (Except for disabling qos, of
course...)
Regards,
Arnout
--
Arnout Vandecappelle arnout at mind be
Senior Embedded Software Architect +32-16-286540
Essensium/Mind http://www.mind.be
G.Geenslaan 9, 3001 Leuven, Belgium BE 872 984 063 RPR Leuven
LinkedIn profile: http://www.linkedin.com/in/arnoutvandecappelle
GPG fingerprint: D206 D44B 5155 DF98 550D 3F2A 2213 88AA A1C7 C933
More information about the gstreamer-devel
mailing list