Sink elements hangs for a while

[iron_guitarist1987]

Hello all,

I created a custom sink element that prints out the data received. When I run my pipeline, it hangs for a minute or two, and then it starts printing the data. The is the debug info I get before it hangs. Any ideas on what I should do?

0:00:04.028382000 15485      0x22924a0 DEBUG               basesink gstbasesink.c:2267:gst_base_sink_wait_preroll:<cobjsink0> continue after preroll
0:00:04.028431000 15485      0x22924a0 DEBUG               basesink gstbasesink.c:2559:gst_base_sink_do_sync:<cobjsink0> possibly waiting for clock to                                                        reach 0:01:59.504382370, adjusted 0:01:59.504382370
0:00:04.028489000 15485      0x22924a0 LOG                 basesink gstbasesink.c:2183:gst_base_sink_wait_clock:<cobjsink0> time 0:01:59.504382370, bas                                                       e_time 6:33:56.936747532
0:00:04.028504000 15485      0x22924a0 DEBUG              GST_CLOCK gstclock.c:195:gst_clock_entry_new:<GstSystemClock> created entry 0x2921400, time 6:35                                                       :56.441129902
0:00:04.028742000 15485      0x22924a0 DEBUG              GST_CLOCK gstclock.c:489:gst_clock_id_wait:<GstSystemClock> waiting on clock entry 0x2921400
0:00:04.028950000 15485      0x22924a0 DEBUG              GST_CLOCK gstclock.c:955:gst_clock_get_internal_time:<GstSystemClock> internal time 6:33:56.9644                                                       75532
0:00:04.029013000 15485      0x22924a0 DEBUG              GST_CLOCK gstclock.c:1000:gst_clock_get_time:<GstSystemClock> adjusted time 6:33:56.964475532
0:00:04.029061000 15485      0x22924a0 DEBUG              GST_CLOCK gstsystemclock.c:598:gst_system_clock_id_wait_jitter_unlocked: entry 0x2921400 time 6:                                                       35:56.441129902 now 6:33:56.964475532 diff (time-now) 119476654370
0:00:04.029121000 15485      0x22924a0 DEBUG               GST_POLL gstpoll.c:1224:gst_poll_wait: timeout :0:01:59.476654370


Thank you.

[Tim-Philipp Müller-2]

On Thu, 2012-10-04 at 13:12 -0700, iron_guitarist1987 wrote:

> I created a custom sink element that prints out the data received. When I
> run my pipeline, it hangs for a minute or two, and then it starts printing
> the data. The is the debug info I get before it hangs. Any ideas on what I
> should do?
> (snip)

It looks like the upstream elements tell it to wait for ~2 minutes.

Perhaps you could show us what the incoming new segment event and the
fist few buffer timestamps are, with:

 gst-launch-0.10 -v ....  ! fakesink | grep -i -e chain -e event

Cheers
 -Tim

_______________________________________________
gstreamer-devel mailing list
[hidden email]
http://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[iron_guitarist1987]

This is what I got:

/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event   ******* E (type: 102, GstEventNewsegment, update=(boolean)false, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, start=(gint64)7347441722222, stop=(gint64)7407127180074, position=(gint64)0;) 0x5adf2c0"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event   ******* E (type: 102, GstEventNewsegment, update=(boolean)false, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, start=(gint64)7347441722222, stop=(gint64)7407127180074, position=(gint64)0;) 0x5adf2c0"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event   ******* E (type: 102, GstEventNewsegment, update=(boolean)false, rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME, start=(gint64)7347441722222, stop=(gint64)7407127180074, position=(gint64)0;) 0x5adf2c0"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.575188888, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1c80"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.608555555, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1b80"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.641922222, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1a80"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.675288888, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd2e20"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.708655555, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd2610"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.742022222, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd3ca0"
/GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain   ******* < ( 1016 bytes, timestamp: 2:02:27.775388888, duration: none, offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1390"
...

[Jan Schmidt-6]

Is this with GStreamer 0.10 or 1.0? I'm guessing 0.10 based on the
behaviour. In 0.10, those extra NewSegment events will be causing your
problem - you need to figure out where they're coming from.

There are 3 new segment events arriving before the data - and the first
two represent ~ 59 seconds each of empty space before the real segment
begins, which is where your 119.37 seconds of waiting comes from.

J.

On Fri, 2012-10-05 at 08:43 -0700, iron_guitarist1987 wrote:

> This is what I got:
>
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event  
> ******* E (type: 102, GstEventNewsegment, update=(boolean)false,
> rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
> start=(gint64)7347441722222, stop=(gint64)7407127180074,
> position=(gint64)0;) 0x5adf2c0"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event  
> ******* E (type: 102, GstEventNewsegment, update=(boolean)false,
> rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
> start=(gint64)7347441722222, stop=(gint64)7407127180074,
> position=(gint64)0;) 0x5adf2c0"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "event  
> ******* E (type: 102, GstEventNewsegment, update=(boolean)false,
> rate=(double)1, applied-rate=(double)1, format=(GstFormat)GST_FORMAT_TIME,
> start=(gint64)7347441722222, stop=(gint64)7407127180074,
> position=(gint64)0;) 0x5adf2c0"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.575188888, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1c80"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.608555555, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1b80"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.641922222, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1a80"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.675288888, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd2e20"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.708655555, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd2610"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.742022222, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd3ca0"
> /GstPipeline:pipeline0/GstFakeSink:fakesink0: last-message = "chain  
> ******* < ( 1016 bytes, timestamp: 2:02:27.775388888, duration: none,
> offset: -1, offset_end: -1, flags: 256 delta_unit ) 0x5cd1390"
> ...
>
>
>
>

--
Jan Schmidt <[hidden email]>

_______________________________________________
gstreamer-devel mailing list
[hidden email]
http://lists.freedesktop.org/mailman/listinfo/gstreamer-devel

[iron_guitarist1987]

Thank you for your answer. I am using 0.10. How could I either eliminate the new segments, or the waiting time in the segments?

[iron_guitarist1987]

I tried adding the following function to my element:

static gboolean
gst_customsink_sink_event (GstPad *pad, GstEvent *event)
{
  gboolean ret;
  gboolean update;
  gdouble rate;
  GstFormat format;
  gint64 start, stop, time;
  GstCustomsink *customsink;
 
  customsink = GST_CUSTOMSINK (pad);
 
  switch (GST_EVENT_TYPE (event)) {
    case GST_EVENT_NEWSEGMENT:
     
      gst_event_parse_new_segment (event, &update, &rate, &format, &start, &stop, &time);
     
      g_print("Start time = %llu\n", start);
      g_print("Stop time = %llu\n", stop);
      event = gst_event_new_new_segment (update, rate, GST_FORMAT_TIME, start, start+1, time);
       
      ret = gst_pad_push_event (customsink->sinkpad, event);
      break;
     
  }
 
  gst_object_unref (customsink);
  return TRUE;
}

I get the following output and it still hangs. Any suggestions?

  Setting pipeline to PAUSED ...
  Pipeline is PREROLLING ...
  Pipeline is PREROLLED ...
  Setting pipeline to PLAYING ...
  Start time = 7347441722222
  Stop time = 7407127180074
  Start time = 7347441722222
  Stop time = 7407127180074

  (gst-launch-0.10:5702): GStreamer-CRITICAL **:
  Trying to dispose element vpefobjsink0, but it is in PAUSED instead of the NULL state.
  You need to explicitly set elements to the NULL state before
  dropping the final reference, to allow them to clean up.
  This problem may also be caused by a refcounting bug in the
  application or some element.

[iron_guitarist1987]

Anyone know what can I add to my gst_customsink_sink_event in order to skip these "wait" events?

Thanks.

[iron_guitarist1987]

I still haven't been able to solve this. Does anyone have any ideas?