After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 753899 - baseparse: push sticky events to downstreams for initial prerolling
baseparse: push sticky events to downstreams for initial prerolling
Status: RESOLVED FIXED
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
1.5.2
Other Linux
: Normal blocker
: 1.13.1
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks: 783842 791584
 
 
Reported: 2015-08-20 23:45 UTC by HoonHee Lee
Modified: 2017-12-13 15:45 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
push sticky events for initial prerolling (1.62 KB, patch)
2015-08-20 23:51 UTC, HoonHee Lee
none Details | Review
Attach original log for gstreamer (868.58 KB, application/gzip)
2015-08-21 12:09 UTC, HoonHee Lee
  Details
matroska-demux: send GAP events for lagging audio and video streams too (2.76 KB, patch)
2015-08-21 13:19 UTC, Tim-Philipp Müller
committed Details | Review
Attach log with sending gap event (1.08 MB, application/gzip)
2015-08-23 23:55 UTC, HoonHee Lee
  Details
baseparse: push sticky events for initial prerolling (2.22 KB, patch)
2015-09-01 13:36 UTC, HoonHee Lee
none Details | Review
push pending caps event for initial prerolling (1.94 KB, patch)
2015-09-02 10:07 UTC, HoonHee Lee
needs-work Details | Review
Negotiate output before GAP event (5.33 KB, patch)
2016-01-22 10:33 UTC, HoonHee Lee
none Details | Review
baseparse: make it to have negotiated output before GAP event (5.42 KB, patch)
2016-01-25 00:03 UTC, HoonHee Lee
none Details | Review
baseparse: make it to have negotiated output before GAP event (6.16 KB, patch)
2016-01-25 07:37 UTC, HoonHee Lee
needs-work Details | Review
baseparse: make it to have negotiated output before GAP event (4.28 KB, patch)
2016-01-28 02:15 UTC, HoonHee Lee
needs-work Details | Review
baseparse: make it to have negotiated output before GAP event (4.59 KB, patch)
2016-01-28 10:46 UTC, HoonHee Lee
committed Details | Review

Description HoonHee Lee 2015-08-20 23:45:26 UTC
I tested following content through "gst-launch-1.0 playbin" in desktop environment.

============================================================
1-Video and 2-Audio
Video
: video/x-h264, level=(string)4, profile=(string)high, codec_data=(buffer)01640028ffe1001967640028acc8501e0089f96100000303e90000bb808f18319601000668e9386cf23c, stream-format=(string)avc, alignment=(string)au, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)24000/1001
Audio
: audio/x-ac3, framed=(boolean)true, channels=(int)6, rate=(int)48000
Audio
: audio/x-ac3, framed=(boolean)true, channels=(int)6, rate=(int)48000
============================================================

Following is construction of decodebin.
===========================================================
filesrc - typefind - mkvdemux - multiqueue -  h264parse - capsfilter - avdec_h264
                                                             ` ac3parse - capsfilter - a52dec
                                                             ` ac3parse - capstilter
===========================================================

Content is not playing.
First buffer of second audio track is feeding after 19 seconds.
Sticky events in such caps is not sending to capsfilter and we can not configure audio decoder for 2nd audio track. After that, we can not finish auto-plugging and complete exposed pads.
Then, overrun has occur by multiqueue and seems to cause problems with the initial prerolling.

As Tim-Philipp Müller's comment, I tried to push sticky events to downstream elements when gap event is received in baseparse.
Then, auto-plugging and initial prerolling is completed and content is playing well.
Comment 1 HoonHee Lee 2015-08-20 23:51:08 UTC
Created attachment 309775 [details] [review]
push sticky events for initial prerolling

Dear Tim-Philipp Müller
As you know, test content is stored in your FTP server.
Comment 2 HoonHee Lee 2015-08-20 23:51:40 UTC
Dear All
Please review and check my patch.
Comment 3 Olivier Crête 2015-08-20 23:53:29 UTC
I wonder if GstPad shouldn't forward sticky events on GAP events like it does on buffers?
Comment 4 HoonHee Lee 2015-08-21 00:01:45 UTC
Dear Olivier Crête
Sticky events in such caps is not forwarding to downstream elements when I get a gap event in baseparse.
Please refer below patch in funnel element.
=>  https://bugzilla.gnome.org/show_bug.cgi?id=738202
I think it would be helpful to understand what I mean.
Comment 5 Nicolas Dufresne (ndufresne) 2015-08-21 00:21:14 UTC
I think we are all understanding what you mean. It's normal to ask if a patch to gstpad.c would make more sense then patching all the elements.
Comment 6 HoonHee Lee 2015-08-21 00:29:19 UTC
Thanks Nicolas Dufresne
I will check it in terms of gstpad.c
Comment 7 Sebastian Dröge (slomo) 2015-08-21 06:59:03 UTC
GstPad should forward sticky events (if any are pending) whenever a serialized downstream event is received, this would include all sticky events and also the GAP event.
Comment 8 Sebastian Dröge (slomo) 2015-08-21 07:05:18 UTC
That would be check_sticky() from gstpad.c, which is used e.g. in gst_pad_push_event() for srcpads. So not sure what exactly your patch is fixing :)

All sticky events should be in the baseparse pending events lists *or* stored on the srcpad already. Then when pushing all the pending events on the srcpad, all stored sticky events should already be pushed, following by all pending events, followed by the GAP event. If there are any events on the sinkpad, that are not in the pending events list and not stored on the srcpad already, this seems like a bug in baseparse's event delaying code (the pending_events stuff).
Comment 9 HoonHee Lee 2015-08-21 12:09:21 UTC
Created attachment 309810 [details]
Attach original log for gstreamer
Comment 10 HoonHee Lee 2015-08-21 12:13:56 UTC
Dear Sebastian and All.
Thanks for your reply.

Anyway I uploaded log for gstreamer with following level.
=> --gst-debug="5,decodebin:6,multiqueue:6,ac3parse:6,capsfilter:6"
This log is not containing about pushing gap event from mkvdemux.

In advance, refer to attached log.
Then, I will upload new log for containing to push gap event from mkvdemux.
It would be more helpful to discuss this issue.
Comment 11 Tim-Philipp Müller 2015-08-21 12:19:31 UTC
What seems to be happening is that baseparse receives the GAP event, then goes on to push any pending events, and then forwards the GAP event immediately. However, no CAPS event is ever pushed, and this also results in a sticky event warning.
Comment 12 Sebastian Dröge (slomo) 2015-08-21 12:23:43 UTC
Then it should probably make up caps like audio/videodecoder are doing now :)
Comment 13 HoonHee Lee 2015-08-21 12:36:09 UTC
Dear Tim and Sebastian
I reviewed the attached log.
ac3parse1 for 2nd audio track receive following events.
Also, it receive caps event.
==========================================
hoonheelee@EXID:~/work/gstreamer$ cat nemo_ng_prerolling.log | grep "have event type " | grep "ac3parse1"
0:00:00.201209273  4956 0x7feaa811f140 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:src> have event type reconfigure event: 0x7feaa4037470, time 99:99:99.999999999, seq-num 193, (NULL)
0:00:00.204107304  4956 0x7feaa811f140 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:src> have event type reconfigure event: 0x7feaa4037200, time 99:99:99.999999999, seq-num 201, (NULL)
0:00:00.204240326  4956 0x7feaa811f140 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:src> have event type reconfigure event: 0x7feaa4037470, time 99:99:99.999999999, seq-num 204, (NULL)
0:00:00.253076841  4956 0x7feaa402ed90 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:sink> have event type stream-start event: 0x7feaa4037400, time 99:99:99.999999999, seq-num 151, GstEventStreamStart, stream-id=(string)01060e07da2388c91522133d20f4f9dc7b5586be8191f49acb7f89a68a55ea98/2239632770, flags=(GstStreamFlags)GST_STREAM_FLAG_NONE, group-id=(uint)1;
0:00:00.253668788  4956 0x7feaa402ed90 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:sink> have event type caps event: 0x7feaa4037350, time 99:99:99.999999999, seq-num 152, GstEventCaps, caps=(GstCaps)"audio/x-ac3\,\ framed\=\(boolean\)true\,\ channels\=\(int\)6\,\ rate\=\(int\)48000";
0:00:00.254385199  4956 0x7feaa402ed90 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:sink> have event type segment event: 0x7feaa4037470, time 99:99:99.999999999, seq-num 207, GstEventSegment, segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, base=(guint64)0, offset=(guint64)0, start=(guint64)0, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0, duration=(guint64)6053984000000;";
===============================================

But, capsfilter2 could not get caps event from ac3parse1 when gap event was forwarding by mkvdemx which is modified locally.
Finally, capsfilter2 could get caps event and complete initial prerolling when caps and gap event were forwarding by mkvdemux.
Comment 14 Tim-Philipp Müller 2015-08-21 13:19:41 UTC
Created attachment 309815 [details] [review]
matroska-demux: send GAP events for lagging audio and video streams too

matroskademux patch for reference.
Comment 15 HoonHee Lee 2015-08-23 23:53:07 UTC
Dear Tim and Sebastian.
I applied above patch for sending gap event in mastroska-demux to my local environment.
I tested it on 1.5.90 version with following level of debug.
=> GST_DEBUG ="5,GST_EVENT:6,GST_PADS:6,decodebin:6,multiqueue:6,ac3parse:6,capsfilter:6"
I confirmed that gap event was sending to downstream in such multiqueue, ac3parse1, capsfilter2, and decodepad3:proxypad4.
But, sticky event in such caps event was not sending to capsfilter2.
Also, stream-start, segment and tag event was sending to downstream in such capsfilter.

===========================================================
0:00:00.332552572 ^[[331m18366^[[00m 0x7f21f411f540 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstevent.c:302:gst_event_new_custom:^[[00m creating new event 0x7f21e8036de0 gap 40966
0:00:00.332559560 ^[[331m18366^[[00m 0x7f21f411f540 ^[[33;01mWARN   ^[[00m ^[[00m       matroskademux matroska-demux.c:2617:gst_matroska_demux_sync_streams:<matroskademux0>^[[00m @@@@@@ type 2
...
0:00:00.332571125 ^[[331m18366^[[00m 0x7f21f411f540 ^[[33;01mWARN   ^[[00m ^[[00m       matroskademux matroska-demux.c:2618:gst_matroska_demux_sync_streams:<matroskademux0>^[[00m @@@@@@ Sending gap event gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
...
0:00:00.333268020 ^[[331m18366^[[00m 0x7f21f411f540 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5121:gst_pad_push_event_unchecked:<matroskademux0:audio_1>^[[00m sending event 0x7f21e8036de0 (gap) to peerpad <multiqueue0:sink_2>
0:00:00.333289477 ^[[331m18366^[[00m 0x7f21f411f540 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<multiqueue0:sink_2>^[[00m have event type gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
...
0:00:00.333321447 ^[[331m18366^[[00m 0x7f21f411f540 ^[[37mDEBUG  ^[[00m ^[[00m          multiqueue gstmultiqueue.c:1823:gst_multi_queue_sink_event:<multiqueue0>^[[00m SingleQueue 2 : Enqueuing event 0x7f21e8036de0 of type gap with id 174
...
0:00:00.333403525 ^[[331m18366^[[00m 0x7f21f411f540 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5129:gst_pad_push_event_unchecked:<matroskademux0:audio_1>^[[00m sent event 0x7f21e8036de0 (gap) to peerpad <multiqueue0:sink_2>, ret ok
...
0:00:00.334208834 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00m          multiqueue gstmultiqueue.c:1276:gst_single_queue_push_one:<multiqueue0>^[[00m SingleQueue 2 : Pushing event 0x7f21e8036de0 of type gap
...
0:00:00.334222415 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5121:gst_pad_push_event_unchecked:<multiqueue0:src_2>^[[00m sending event 0x7f21e8036de0 (gap) to peerpad <ac3parse1:sink>
...
0:00:00.334230225 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:sink>^[[00m have event type gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
...
0:00:00.334246486 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:1093:gst_base_parse_sink_event_default:<ac3parse1>^[[00m handling event 40966, gap
0:00:00.334256186 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:1319:gst_base_parse_sink_event_default:<ac3parse1>^[[00m draining current data due to gap event
0:00:00.334262138 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:4958:store_sticky_event:<ac3parse1:src>^[[00m stored sticky event segment
0:00:00.334267135 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:3745:check_sticky:<ac3parse1:src>^[[00m pushing all sticky events
0:00:00.334271366 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:3678:push_sticky:<ac3parse1:src>^[[00m event stream-start was already received
0:00:00.334276531 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5121:gst_pad_push_event_unchecked:<ac3parse1:src>^[[00m sending event 0x7f21e80370a0 (segment) to peerpad <capsfilter2:sink>
...
0:00:00.334283229 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink>^[[00m have event type segment event: 0x7f21e80370a0, time 99:99:99.999999999, seq-num 208, GstEventSegment, segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, base=(guint64)0, offset=(guint64)0, start=(guint64)0, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0, duration=(guint64)6053984000000;";
0:00:00.334310767 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;34m            GST_CAPS gstpad.c:2557:gst_pad_has_current_caps:<capsfilter2:sink>^[[00m check current pad caps (NULL)
0:00:00.334316180 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00m          capsfilter gstcapsfilter.c:525:gst_capsfilter_sink_event:<capsfilter2>^[[00m Got segment event before caps, queueing
0:00:00.334321066 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5467:gst_pad_send_event_unchecked:<capsfilter2:sink>^[[00m sent event, ret ok
0:00:00.334325897 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:4958:store_sticky_event:<capsfilter2:sink>^[[00m stored sticky event segment
0:00:00.334334412 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5129:gst_pad_push_event_unchecked:<ac3parse1:src>^[[00m sent event 0x7f21e80370a0 (segment) to peerpad <capsfilter2:sink>, ret ok
...
0:00:00.334610766 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5129:gst_pad_push_event_unchecked:<ac3parse1:src>^[[00m sent event 0x7f21e000aee0 (tag) to peerpad <capsfilter2:sink>, ret ok
...
0:00:00.334624088 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:3698:push_sticky:<ac3parse1:src>^[[00m event tag marked received
...
0:00:00.334635030 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:2575:gst_base_parse_drain:<ac3parse1>^[[00m draining
...
0:00:00.334690338 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5121:gst_pad_push_event_unchecked:<ac3parse1:src>^[[00m sending event 0x7f21e8036de0 (gap) to peerpad <capsfilter2:sink>
...
0:00:00.334705975 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink>^[[00m have event type gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
...
0:00:00.334716313 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00m          capsfilter gstcapsfilter.c:534:gst_capsfilter_sink_event:<capsfilter2>^[[00m Forwarding gap event
...
0:00:00.334780544 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<decodepad3:proxypad4>^[[00m have event type gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
0:00:00.334808091 ^[[331m18366^[[00m       0xfb8e30 ^[[37mDEBUG  ^[[00m ^[[00;43m             GST_BUS gstbus.c:789:gst_bus_source_dispatch:<bus1>^[[00m source 0x1194c70 calling dispatch with state-changed message: 0x7f21e0002290, time 99:99:99.999999999, seq-num 267, element 'a52dec0', GstMessageStateChanged, old-state=(GstState)GST_STATE_READY, new-state=(GstState)GST_STATE_PAUSED, pending-state=(GstState)GST_STATE_VOID_PENDING;
0:00:00.334817210 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:2929:gst_pad_event_default:<decodepad3:proxypad4>^[[00m default event handler for event gap event: 0x7f21e8036de0, time 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
0:00:00.334820073 ^[[331m18366^[[00m 0x7f21e8014230 ^[[37mDEBUG  ^[[00m ^[[00;43m             GST_BUS gstbus.c:280:gst_bus_new:<bus12>^[[00m created new bus
0:00:00.334835143 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:2849:gst_pad_forward:<decodepad3:proxypad4>^[[00m calling forward function on pad '':decodepad3
0:00:00.334819438 ^[[331m18366^[[00m 0x7f21e802e450 ^[[37mDEBUG  ^[[00m ^[[00;43m             GST_BUS gstbus.c:344:gst_bus_post:<bus3>^[[00m [msg 0x7f21e0002290] dropped
0:00:00.334845512 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:2894:event_forward_func:<'':decodepad3>^[[00m Reffing and pushing event 0x7f21e8036de0 (gap) to '':decodepad3
...
0:00:00.334992147 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5177:gst_pad_push_event_unchecked:<'':decodepad3>^[[00m Dropping event gap because pad is not linked
0:00:00.334995672 ^[[331m18366^[[00m       0xfb8e30 ^[[37mDEBUG  ^[[00m ^[[00;43m             GST_BUS gstbus.c:892:gst_bus_add_watch_full_unlocked:<bus1>^[[00m New source 0x1194c70 with id 36
0:00:00.334997633 ^[[331m18366^[[00m 0x7f21e802e450 ^[[37mDEBUG  ^[[00m ^[[00m        audiodecoder gstaudiodecoder.c:2200:gst_audio_decoder_sink_eventfunc:<a52dec0>^[[00m received STREAM_START. Clearing taglist
0:00:00.335005853 ^[[331m18366^[[00m 0x7f21e802e990 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5467:gst_pad_send_event_unchecked:<decodepad3:proxypad4>^[[00m sent event, ret error
0:00:00.335016187 ^[[331m18366^[[00m       0xfb8e30 ^[[37mDEBUG  ^[[00m ^[[00;43m             GST_BUS gstbus.c:1152:gst_bus_poll:^[[00m running mainloop 0x11947f0
0:00:00.335029670 ^[[331m18366^[[00m 0x7f21e802e990 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5129:gst_pad_push_event_unchecked:<capsfilter2:src>^[[00m sent event 0x7f21e8036de0 (gap) to peerpad <decodepad3:proxypad4>, ret error
=========================================================

=========================================================
hoonheelee@EXID:~/work/gstreamer$ cat nemo_send_gap.log | grep "have event type" | grep "capsfilter2" | more
0:00:00.252329676 18366 0x7f21f411f540 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:src> have event type reconfigure event: 0x7f21e803
70a0, time 99:99:99.999999999, seq-num 205, (NULL)
0:00:00.286883722 18366 0x7f21e802e990 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink> have event type stream-start event: 0x7f21e8
037030, time 99:99:99.999999999, seq-num 152, GstEventStreamStart, stream-id=(string)01060e07da2388c91522133d20f4f9dc7b5586be8191f49acb7f89a68a55ea98/2239632770, flags=(GstStreamFlags)GST_STREAM_FLAG_NONE,
 group-id=(uint)1;
0:00:00.334283229 18366 0x7f21e802e990 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink> have event type segment event: 0x7f21e80370a
0, time 99:99:99.999999999, seq-num 208, GstEventSegment, segment=(GstSegment)"GstSegment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT
_TIME, base=(guint64)0, offset=(guint64)0, start=(guint64)0, stop=(guint64)18446744073709551615, time=(guint64)0, position=(guint64)0, duration=(guint64)6053984000000;";
0:00:00.334373386 18366 0x7f21e802e990 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink> have event type tag event: 0x7f21e8036ec0, t
ime 99:99:99.999999999, seq-num 154, GstTagList-global, taglist=(taglist)"taglist\,\ title\=\(string\)\"ikyts-\\354\\202\\254\\355\\225\\264\\354\\262\\234\\354\\202\\254-2013-11-03\"\,\ container-format\=
\(string\)Matroska\;";
0:00:00.334510156 18366 0x7f21e802e990 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink> have event type tag event: 0x7f21e000aee0, t
ime 99:99:99.999999999, seq-num 266, GstTagList-stream, taglist=(taglist)"taglist\,\ audio-codec\=\(string\)\"AC-3\\\ audio\"\,\ language-code\=\(string\)ko\;";
0:00:00.334705975 18366 0x7f21e802e990 DEBUG              GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink> have event type gap event: 0x7f21e8036de0, t
ime 99:99:99.999999999, seq-num 262, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
=========================================================

Please check my comment.
Comment 16 HoonHee Lee 2015-08-23 23:55:46 UTC
Created attachment 309899 [details]
Attach log with sending gap event

Please refer attached log. (nemo_send_gap.log.tar.gz)
It is containing to sending gap event.
Comment 17 HoonHee Lee 2015-08-24 00:16:12 UTC
Dear Tim and Sebastian.

I applied following 2 of patches and tested again.
=> push sticky events for initial prerolling
=> matroska-demux: send GAP events for lagging audio and video streams too

Please refer following log.
===================================================
0:00:00.360043063 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<ac3parse1:sink>^[[00m have event type gap event: 0x7fcb54036e00, time 99:99:99.999999999, seq-num 248, GstEventGap, timestamp=(guint64)0, duration=(guint64)8000000;
0:00:00.360053065 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:1106:gst_base_parse_sink_event_default:<ac3parse1>^[[00m handling event 40966, gap
0:00:00.360058086 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:1332:gst_base_parse_sink_event_default:<ac3parse1>^[[00m draining current data due to gap event
0:00:00.360062338 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00m           baseparse gstbaseparse.c:1335:gst_base_parse_sink_event_default:<ac3parse1>^[[00m @@@@@@ Pushing stikcy events to downstream for initial prerolling
0:00:00.360067209 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:4899:store_sticky_event:<ac3parse1:src>^[[00m Removing pending EOS events
0:00:00.360072425 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:4958:store_sticky_event:<ac3parse1:src>^[[00m stored sticky event caps
0:00:00.360077647 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:4964:store_sticky_event:<ac3parse1:src>^[[00m notify caps
0:00:00.360086179 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:3745:check_sticky:<ac3parse1:src>^[[00m pushing all sticky events
0:00:00.360090878 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:3678:push_sticky:<ac3parse1:src>^[[00m event stream-start was already received
0:00:00.360096250 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[33;01mLOG    ^[[00m ^[[00;01;31;41m            GST_PADS gstpad.c:5121:gst_pad_push_event_unchecked:<ac3parse1:src>^[[00m sending event 0x7fcb54036f50 (caps) to peerpad <capsfilter2:sink>
0:00:00.360105987 ^[[334m19155^[[00m 0x7fcb5402ed90 ^[[37mDEBUG  ^[[00m ^[[00;01;34m           GST_EVENT gstpad.c:5398:gst_pad_send_event_unchecked:<capsfilter2:sink>^[[00m have event type caps event: 0x7fcb54036f50, time 99:99:99.999999999, seq-num 152, GstEventCaps, caps=(GstCaps)"audio/x-ac3\,\ framed\=\(boolean\)true\,\ channels\=\(int\)6\,\ rate\=\(int\)48000";
===================================================
Comment 18 Sebastian Dröge (slomo) 2015-08-24 08:19:06 UTC
You need to do GAP event handling like in audio/video decoder base class, see e.g. here: http://cgit.freedesktop.org/gstreamer/gst-plugins-base/tree/gst-libs/gst/video/gstvideodecoder.c#n1270

You basically need to come up with some caps in a clever way before pushing the GAP event if needed. You can't just forward all sticky events from the sinkpad to the srcpad, the caps might be wrong and the other events might be wrong too.
Comment 19 HoonHee Lee 2015-08-25 01:51:29 UTC
Dear Sebastian.
Thanks for your comment and help.
 
I will check it in terms of negotiation of caps event before forwarding gap event.
Then, I will share result with new patch.
Comment 20 HoonHee Lee 2015-09-01 13:36:29 UTC
Created attachment 310416 [details] [review]
baseparse: push sticky events for initial prerolling

Dear All.
Please check and review my patch.
Comment 21 HoonHee Lee 2015-09-01 22:52:44 UTC
I am not sure which is better or proper when gap is received.
One is to sending sticky events to downstream element through gst_pad_sticky_events_foreach () func.
Second is to setting caps to srcpad through gst_pad_set_caps () func.
Third is to insert caps event to pending_events and then pushes it through gst_base_parse_push_pending_events () func.
 
Please check and review my patch.
Comment 22 Sebastian Dröge (slomo) 2015-09-02 07:08:59 UTC
Just copying over all sticky events from the sinkpad to the srcpad is not a good idea, as mentioned above.

You should use the same mechanism that is used for forwarding sticky events (incl. caps) when a buffer is handled. That would be the pending events list
Comment 23 HoonHee Lee 2015-09-02 10:07:03 UTC
Created attachment 310477 [details] [review]
push pending caps event for initial prerolling

Dear All
Thanks for your reply.
 
I modified the code to use pending list.
Please check and review my patch.
Comment 24 Edward Hervey 2016-01-19 15:29:03 UTC
Review of attachment 310477 [details] [review]:

::: libs/gst/base/gstbaseparse.c
@@ +1320,3 @@
       GST_DEBUG_OBJECT (parse, "draining current data due to gap event");
 
+      src_caps = gst_pad_get_current_caps (GST_BASE_PARSE_SRC_PAD (parse));

Instead of constantly doing expensive caps operation, a simpler solution would be to use a boolean to store whether we saw a GAP event before CAPS (and sent something downstream).
Comment 25 Sebastian Dröge (slomo) 2016-01-19 15:41:11 UTC
Look at GstVideoDecoder and GstAudioDecoder for an example implementation of this behaviour btw.
Comment 26 HoonHee Lee 2016-01-22 10:33:12 UTC
Created attachment 319546 [details] [review]
Negotiate output before GAP event

Dear All.
Thanks for your comments and I updated the patch.
To complete initial pre-rolling, ensure we have default output caps before forwarding gap event.
 
Please check and review again.
Comment 27 HoonHee Lee 2016-01-22 22:47:12 UTC
I missed to add bug url to the commit message at the end.
I will update soon.
Comment 28 HoonHee Lee 2016-01-25 00:03:54 UTC
Created attachment 319637 [details] [review]
baseparse: make it to have negotiated output before GAP event

Dear All.
I updated author and bug url in commit message.
  
Please check and review again.
Comment 29 HoonHee Lee 2016-01-25 05:05:19 UTC
I have an issue to test following content.
=> [VOB-C007] MPEG-2PS_MPEG-2 Video_AC3+LPCM_720x480.vob
There is a regression to handle 'audio/x-private1-ac3' format.
I will look into more.
Comment 30 HoonHee Lee 2016-01-25 07:37:08 UTC
Created attachment 319660 [details] [review]
baseparse: make it to have negotiated output before GAP event

Dear All.
Could you kindly check and review this patch?
Comment 31 Sebastian Dröge (slomo) 2016-01-27 12:58:25 UTC
Review of attachment 319660 [details] [review]:

::: libs/gst/base/gstbaseparse.c
@@ +405,3 @@
+
+/**
+ * GST_BASE_PARSE_STREAM_UNLOCK:

Why is this stream lock stuff needed here? GAP, CAPS (and other serialized events) and buffers are guaranteed to be protected by the pad's stream lock already.

@@ +1107,3 @@
+  GstStructure *structure;
+
+  caps = gst_pad_get_allowed_caps (GST_BASE_PARSE_SRC_PAD (parse));

This will return NULL if the srcpad has no peer at this point. It's probably nicer here to use gst_pad_peer_query_caps(). If that returns something you filter it with the source pads template caps, otherwise you just use the source pads template caps.

Note: same bug in GstAudio/VideoDecoder. Want to provide a patch for them? :)

@@ +1423,3 @@
+      /* Ensure we have caps before forwarding the event */
+      GST_BASE_PARSE_STREAM_LOCK (parse);
+      if (!gst_caps_is_fixed (caps)) {

Why? I think you should just check here "if (!gst_pad_has_current_caps())". That's what we care about here

@@ +1430,3 @@
+          parse->priv->pending_events =
+              g_list_append (parse->priv->pending_events,
+              gst_event_new_caps (default_caps));

You're leaking default_caps here.
Comment 32 HoonHee Lee 2016-01-28 02:15:29 UTC
Created attachment 319889 [details] [review]
baseparse: make it to have negotiated output before GAP event

Deal All.
I really appreciate your comment and help.
Please check and review again the patch.
Comment 33 HoonHee Lee 2016-01-28 05:06:33 UTC
Dear Sebastian Dröge
Please check following ticket.
=> https://bugzilla.gnome.org/show_bug.cgi?id=761218
Comment 34 Sebastian Dröge (slomo) 2016-01-28 08:10:50 UTC
Review of attachment 319889 [details] [review]:

::: libs/gst/base/gstbaseparse.c
@@ +1083,3 @@
+
+  filter = gst_pad_get_pad_template_caps (GST_BASE_PARSE_SRC_PAD (parse));
+  peercaps = gst_pad_peer_query_caps (GST_BASE_PARSE_SRC_PAD (parse), filter);

Same comment is in the patch for audio/video decoder here :)

@@ +1399,3 @@
+        } else {
+          GST_ELEMENT_ERROR (parse, STREAM, FORMAT, (NULL),
+              ("Parser output not negotiated before GAP event."));

Here you probably want to unref the event and set it to NULL and set ret to FALSE
Comment 35 HoonHee Lee 2016-01-28 10:46:52 UTC
Created attachment 319913 [details] [review]
baseparse: make it to have negotiated output before GAP event

Dear Sebastian Dröge
Sorry for my misunderstanding.
Please review again.
Comment 36 Sebastian Dröge (slomo) 2016-01-29 09:47:06 UTC
Review of attachment 319913 [details] [review]:

Looks mostly good, I'll just fix up the remaining bits and merge.

::: libs/gst/base/gstbaseparse.c
@@ +893,1 @@
   GST_OBJECT_UNLOCK (parse);

Unneeded whitespace change here

@@ +1061,3 @@
+  gint caps_size;
+
+  GST_LOG ("field [%s:%s]", g_quark_to_string (field_id), value_str);

I would remove the debug output here, it's not object specific and very generic and requires additional allocation/deallocation. Just print the final caps later :)

@@ +1408,3 @@
+              "Store caps event to pending list for initial pre-rolling");
+          parse->priv->pending_events =
+              g_list_append (parse->priv->pending_events,

This has to be prepend, not append
Comment 37 Sebastian Dröge (slomo) 2016-01-29 09:51:29 UTC
commit f90fd86d5fb37e109fbbd2bf1cc346321812fbce
Author: HoonHee Lee <hoonhee.lee@lge.com>
Date:   Mon Jan 25 16:30:04 2016 +0900

    baseparse: Try to generate caps on the srcpad before forwarding GAP event
    
    To configure downstream elements and complete initial pre-rolling,
    ensure we have default output caps before forwarding GAP event.
    
    https://bugzilla.gnome.org/show_bug.cgi?id=753899
Comment 38 Sebastian Dröge (slomo) 2016-01-29 09:51:52 UTC
What's with the matroska patch here? Tim?
Comment 39 Tim-Philipp Müller 2016-02-16 17:21:07 UTC
> What's with the matroska patch here? Tim?

Pushed as well.

I still get this fwiw:
(gst-play-1.0:1157): GStreamer-WARNING **: gstpad.c:5031:store_sticky_event:<ac3parse1:src> Sticky event misordering, got 'segment' before 'caps'

But file plays fine.
Comment 40 Edward Hervey 2017-12-13 09:46:54 UTC
Reopening this bug report because it does introduce a regression. There is no way for subclasses to tell the parent class that it doesn't have enough information to negotiate to at least a compatible format.

For example:
* mpegaudioparse receives "audio/mpeg, mpegversion=1" (without any other fields)
* A gap event comes in
* the base class negotiates to "audio/mpeg, mpegversion=1, layer=1, mpegaudioversion=1, rate=8000, channels=1, parsed=true"
* the caps event get pushed downstream and a decoder gets selected for MP1 (say avdec_mp1float)
* eventually data comes into mpegaudioparse and it negotiates to the *actual* format (mpegaudioversion=3, i.e. mp3)
* the decoder fails to negotiate

While we do want to not delay gap events in parsers, we should only allow this to happen if we do have enough information from upstream caps to negotiate to something which will later be compatible with the actual data stream.

In this case, mpegaudioparse should *not* push caps event if it hasn't at least got a clue as to which mpegaudioversion the stream corresponds to.
Comment 41 Edward Hervey 2017-12-13 15:45:46 UTC
Closing, opened https://bugzilla.gnome.org/show_bug.cgi?id=791584 to track the issue.