hlssink: does not always adhere to the segment target duration

Submitted by Baldur Gislason

Link to original bug (#719785)

Description

It seems that the force-key-unit events emitted by hlssink are being ignored by the upstream in some cases. This depends on the source file.
Executing the pipe:
gst-launch-1.0 -v --gst-debug=mpegtsmux:4,hlssink:4,x264enc:4 filesrc location=klovn_1500.mp4 ! decodebin ! queue ! x264enc ! mpegtsmux ! hlssink target-duration=10
result:
http://pastebin.com/UTae4KXK

The interesting messages are:
0:00:02.083604323 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:07.800000000 wanted 0:00:10.000000000
0:00:02.083781840 21359 0xc0e8f0 INFO x264enc gstx264enc.c:1902:gst_x264_enc_encode_frame:<x264enc0> Forcing key frame
0:00:02.093407736 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:08.000000000 wanted 0:00:10.000000000

And a few seconds later:
0:00:02.975715319 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:09.800000000 wanted 0:00:10.000000000
0:00:02.998043430 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:09.880000000 wanted 0:00:10.000000000
0:00:02.998910966 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:806:mpegtsmux_sink_event:<mpegtsmux0> have downstream force-key-unit event on pad sink_65, seqnum 263, running-time 0:00:10.000000000 count 1
0:00:02.998932445 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:810:mpegtsmux_sink_event:<mpegtsmux0> skipping downstream force key unit event as an upstream force key unit is already queued
0:00:02.998955341 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:09.920000000 wanted 0:00:10.000000000
0:00:03.000188674 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:10.000000000 wanted 0:00:10.000000000
0:00:03.000215625 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:943:check_pending_key_unit_event: pending force key unit, waiting for keyframe
0:00:03.010917966 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:09.960000000 wanted 0:00:10.000000000
0:00:03.046916732 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:10.080000000 wanted 0:00:10.000000000
0:00:03.046973034 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:943:check_pending_key_unit_event: pending force key unit, waiting for keyframe

And more seconds later:
0:00:04.253965353 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:943:check_pending_key_unit_event: pending force key unit, waiting for keyframe
0:00:04.264080154 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:12.800000000 wanted 0:00:10.000000000
0:00:04.264115620 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:943:check_pending_key_unit_event: pending force key unit, waiting for keyframe
0:00:04.264906283 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:12.920000000 wanted 0:00:10.000000000
0:00:04.264959113 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:1092:mpegtsmux_collected_buffer:<mpegtsmux0> pushing downstream force-key-unit event 234 0:00:12.920000000 count 1
0:00:04.264977565 21359 0xc0e8f0 INFO hlssink gsthlssink.c:530:gst_hls_sink_ghost_event_probe:<hlssink0> event: custom-downstream

0:00:04.264993943 21359 0xc0e8f0 INFO hlssink gsthlssink.c:562:gst_hls_sink_ghost_event_probe:<hlssink0> setting index 1
0:00:04.265520688 21359 0xc0e8f0 INFO hlssink gsthlssink.c:358:gst_hls_sink_handle_message:<hlssink0> COUNT 1
0:00:04.275804950 21359 0xc0e8f0 INFO hlssink gsthlssink.c:588:schedule_next_key_unit:<hlssink0> sending upstream force-key-unit, index 2 now 0:00:12.920000000 target 0:00:22.920000000
0:00:04.275849188 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:862:mpegtsmux_src_event:<mpegtsmux0> received upstream force-key-unit event, seqnum 266 running_time 0:00:22.920000000 all_headers 1 count 2
0:00:04.275869467 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:883:mpegtsmux_src_event:<mpegtsmux0> forwarding to sink_65
0:00:04.275885087 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:885:mpegtsmux_src_event:<mpegtsmux0> result 1
0:00:04.278922057 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:13.080000000 wanted 0:00:22.920000000
0:00:04.279804278 21359 0xc0e8f0 INFO mpegtsmux mpegtsmux.c:937:check_pending_key_unit_event: now 0:00:13.000000000 wanted 0:00:22.920000000

Version: 1.x