Crashes on gst_bus_add_watch

Duzy Chan geek at duzy.info
Mon Feb 4 01:25:10 PST 2013


And I'm thinking that do I need to manually close the socket fd created by
a tcpserversink? It looks like it's not always closed on changing the
element state from ready to null.

static gboolean
gst_multi_handle_sink_stop (GstBaseSink * bsink)
{
  GstMultiHandleSinkClass *mhclass;
  GstBuffer *buf;
  gint i;
  GstMultiHandleSink *mhsink = GST_MULTI_HANDLE_SINK (bsink);

  mhclass = GST_MULTI_HANDLE_SINK_GET_CLASS (mhsink);

  if (!GST_OBJECT_FLAG_IS_SET (bsink, GST_MULTI_HANDLE_SINK_OPEN))
    return TRUE;

  mhsink->running = FALSE;

  mhclass->stop_pre (mhsink);

  if (mhsink->thread) {
    GST_DEBUG_OBJECT (mhsink, "joining thread");
    g_thread_join (mhsink->thread);
    GST_DEBUG_OBJECT (mhsink, "joined thread");
    mhsink->thread = NULL;
  }

  /* free the clients */
  mhclass->clear (GST_MULTI_HANDLE_SINK (mhsink));

  if (mhsink->streamheader) {
    g_slist_foreach (mhsink->streamheader, (GFunc) gst_mini_object_unref,
NULL);
    g_slist_free (mhsink->streamheader);
    mhsink->streamheader = NULL;
  }

  if (mhclass->*close*)
    mhclass->*close* (mhsink);

  mhclass->stop_post (mhsink);

  /* remove all queued buffers */
  if (mhsink->bufqueue) {
    GST_DEBUG_OBJECT (mhsink, "Emptying bufqueue with %d buffers",
        mhsink->bufqueue->len);
    for (i = mhsink->bufqueue->len - 1; i >= 0; --i) {
      buf = g_array_index (mhsink->bufqueue, GstBuffer *, i);
      GST_LOG_OBJECT (mhsink, "Removing buffer %p (%d) with refcount %d",
buf,
          i, GST_MINI_OBJECT_REFCOUNT (buf));
      gst_buffer_unref (buf);
      mhsink->bufqueue = g_array_remove_index (mhsink->bufqueue, i);
    }
    /* freeing the array is done in _finalize */
  }
  GST_OBJECT_FLAG_UNSET (mhsink, GST_MULTI_HANDLE_SINK_OPEN);

  return TRUE;
}



On Mon, Feb 4, 2013 at 4:45 PM, Duzy Chan <geek at duzy.info> wrote:

> And the gst_bus_add_watch issue still occurs, I didn't fix that:
>
> (gst-switch-srv:31051): GStreamer-CRITICAL **: *gst_poll_get_read_gpollfd*:
> assertion `set != NULL' failed
> (gst-switch-srv:31051): GStreamer-CRITICAL **: *gst_bus_create_watch*:
> assertion `bus->priv->poll != NULL' failed
> (gst-switch-srv:31051): GLib-CRITICAL **: *g_source_set_callback*:
> assertion `source != NULL' failed
>
>
> And the stack looks like:
>
> #0  *g_source_attach* (source=source at entry=0x0, context=0x0) at
> gmain.c:1154
> #1  0x00007ffff7b1e258 in *gst_bus_add_watch_full_unlocked*(notify=<optimized out>, user_data=0x706800, func=0x405b60
> <gst_worker_message>, priority=<optimized out>, bus=<optimized out>) at
> gstbus.c:867
> #2  *gst_bus_add_watch_full_unlocked* (bus=<optimized out>,
> priority=<optimized out>, func=0x405b60 <gst_worker_message>,
> user_data=0x706800, notify=<optimized out>) at gstbus.c:846
> #3  0x00007ffff7b1e397 in *gst_bus_add_watch_full* (bus=0x227cb80,
> priority=priority at entry=0, func=func at entry=0x405b60 <gst_worker_message>,
> user_data=user_data at entry=0x706800, notify=notify at entry=0x0) at
> gstbus.c:916
> #4  0x00007ffff7b1e3c0 in *gst_bus_add_watch* (bus=<optimized out>,
> func=func at entry=0x405b60 <gst_worker_message>, user_data=user_data at entry=0x706800)
> at gstbus.c:948
> #5  0x0000000000405303 in *gst_worker_prepare_unsafe* (worker=worker at entry=0x706800)
> at gstworker.c:621
> #6  0x00000000004055a0 in *gst_worker_reset* (worker=0x706800) at
> gstworker.c:705
> #7  0x000000000040c138 in *gst_composite_apply_parameters*(composite=composite at entry=0x706800)
> at gstcomposite.c:320
> #8  0x000000000040c608 in *gst_composite_commit_transition*(composite=0x706800) at gstcomposite.c:497
> #9  *gst_composite_null* (composite=0x706800) at gstcomposite.c:583
> #10 0x0000000000406369 in *gst_worker_state_ready_to_null*(worker=0x706800) at gstworker.c:438
> #11 *gst_worker_pipeline_state_changed* (statechange=<optimized out>,
> worker=0x706800) at gstworker.c:472
> #12 *gst_worker_message* (bus=<optimized out>, message=0x2278530,
> worker=0x706800) at gstworker.c:542
> #13 0x00007ffff7b1dc67 in *gst_bus_source_dispatch* (source=source at entry=0x22575e0,
> callback=0x405b60 <gst_worker_message>, user_data=0x706800) at gstbus.c:773
> #14 0x00007ffff7252ee5 in *g_main_dispatch* (context=0x62a0f0) at
> gmain.c:3054
> #15 *g_main_context_dispatch* (context=context at entry=0x62a0f0) at
> gmain.c:3630
> #16 0x00007ffff7253228 in *g_main_context_iterate* (context=0x62a0f0,
> block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>) at
> gmain.c:3701
> #17 0x00007ffff725369a in *g_main_loop_run* (loop=0x706760) at
> gmain.c:3895
> #18 0x00000000004044e0 in *gst_switch_server_run* (srv=0x708000) at
> gstswitchserver.c:1095
> #19 *main* (argc=1, argv=0x7fffffffe578) at gstswitchserver.c:1119
>
>
> On Mon, Feb 4, 2013 at 10:18 AM, Duzy Chan <geek at duzy.info> wrote:
>
>> And things in *gst_multi_socket_sink_start_pre* are now attracting my
>> attentions, because this is where *g_main_context_new* was called. And *
>> GWakup* is like to be used only in *GMainContext*.
>>
>> static gboolean
>> gst_multi_socket_sink_start_pre (GstMultiHandleSink * mhsink)
>> {
>>   GstMultiSocketSink *mssink = GST_MULTI_SOCKET_SINK (mhsink);
>>   GstMultiHandleSinkClass *mhsinkclass =
>>       GST_MULTI_HANDLE_SINK_GET_CLASS (mhsink);
>>   GList *clients;
>>
>>   GST_INFO_OBJECT (mssink, "starting");
>>
>>   mssink->main_context = *g_main_context_new* ();
>>
>>   CLIENTS_LOCK (mhsink);
>>   for (clients = mhsink->clients; clients; clients = clients->next) {
>>     GstSocketClient *client = clients->data;
>>     GstMultiHandleClient *mhclient = (GstMultiHandleClient *) client;
>>
>>     if (client->source)
>>       continue;
>>     mhsinkclass->hash_adding (mhsink, mhclient);
>>   }
>>   CLIENTS_UNLOCK (mhsink);
>>
>>   return TRUE;
>> }
>>
>>
>> And here is g_main_context_new looks like:
>>
>> GMainContext *
>> g_main_context_new (void)
>> {
>>   static gsize initialised;
>>   GMainContext *context;
>>
>>   if (g_once_init_enter (&initialised))
>>     {
>> #ifdef G_MAIN_POLL_DEBUG
>>       if (getenv ("G_MAIN_POLL_DEBUG") != NULL)
>>         _g_main_poll_debug = TRUE;
>> #endif
>>
>>       g_once_init_leave (&initialised, TRUE);
>>     }
>>
>>   context = g_new0 (GMainContext, 1);
>>
>>   g_mutex_init (&context->mutex);
>>   g_cond_init (&context->cond);
>>
>>   context->owner = NULL;
>>   context->waiters = NULL;
>>
>>   context->ref_count = 1;
>>
>>   context->next_id = 1;
>>
>>   context->source_list = NULL;
>>
>>   context->poll_func = g_poll;
>>
>>   context->cached_poll_array = NULL;
>>   context->cached_poll_array_size = 0;
>>
>>   context->pending_dispatches = g_ptr_array_new ();
>>
>>   context->time_is_fresh = FALSE;
>>
>>   context->wakeup = *g_wakeup_new* ();
>>   g_wakeup_get_pollfd (context->wakeup, &context->wake_up_rec);
>>   g_main_context_add_poll_unlocked (context, 0, &context->wake_up_rec);
>>
>>   G_LOCK (main_context_list);
>>   main_context_list = g_slist_append (main_context_list, context);
>>
>> #ifdef G_MAIN_POLL_DEBUG
>>   if (_g_main_poll_debug)
>>     g_print ("created context=%p\n", context);
>> #endif
>>
>>   G_UNLOCK (main_context_list);
>>
>>   return context;
>> }
>>
>>
>>
>>
>> On Mon, Feb 4, 2013 at 2:21 AM, Duzy Chan <geek at duzy.info> wrote:
>>
>>> Honestly I'm not very sure about the real cause. I think it might have
>>> failed to request some resources. I added many locks for many situation (my
>>> latest code is at https://github.com/duzy/gst-switch), and changed a
>>> method of log messages, refactored my code a lot, and *
>>> gst_bus_create_watch* issue seems gone. But I'm now confronting another
>>> issue, complaining:
>>>
>>> (gst-switch-srv:1709): GLib-ERROR **: *Creating pipes for GWakeup: Too
>>> many open files*
>>>
>>> This is happened almost 100% percent, by running the a test for nearly 2
>>> minutes. And this test was trying to make request to *gst-switch-srv*indirectly to recreate the pipelines repeatedly and very fast (I spawned
>>> three threads in the test for making the requests to the server, and it
>>> will at least recreate three pipelines in a request).
>>>
>>> Everything looks fine, except for the *too-many-open-files* error. And
>>> this time my stack looks like this (the latest changes):
>>>
>>> *bt*
>>> #0  *g_logv* (log_domain=0x7ffff72d11ae "GLib",
>>> log_level=G_LOG_LEVEL_ERROR, format=<optimized out>, args=args at entry=0x7fffffffddb8)
>>> at /build/buildd/glib2.0-2.34.1/./glib/gmessages.c:974
>>> #1  0x00007ffff7297e42 in *g_log* (log_domain=log_domain at entry=0x7ffff72d11ae
>>> "GLib", log_level=log_level at entry=G_LOG_LEVEL_ERROR, format=format at entry=0x7ffff7323030
>>> "Creating pipes for GWakeup: %s\n") at
>>> /build/buildd/glib2.0-2.34.1/./glib/gmessages.c:1003
>>> #2  0x00007ffff72cd113 in *g_wakeup_new* () at
>>> /build/buildd/glib2.0-2.34.1/./glib/gwakeup.c:163
>>> #3  0x00007ffff728ed47 in *g_main_context_new* () at
>>> /build/buildd/glib2.0-2.34.1/./glib/gmain.c:590
>>> #4  0x00007fffd1cb1071 in *gst_multi_socket_sink_start_pre*(mhsink=0x23564d0) at gstmultisocketsink.c:1005
>>> #5  0x00007fffd1cacc50 in *gst_multi_handle_sink_start*(bsink=0x23564d0) at gstmultihandlesink.c:2112
>>> #6  *gst_multi_handle_sink_change_state* (element=0x23564d0,
>>> transition=<optimized out>) at gstmultihandlesink.c:2205
>>> #7  0x00007ffff7b2e28c in *gst_element_change_state*(element=element at entry=0x23564d0,
>>> transition=<optimized out>) at gstelement.c:2594
>>> #8  0x00007ffff7b2ec61 in *gst_element_set_state_func*(element=0x23564d0, state=GST_STATE_READY) at gstelement.c:2550
>>> #9  0x00007ffff7b16579 in *gst_bin_element_set_state*(next=GST_STATE_READY, current=GST_STATE_NULL, start_time=0, base_time=0,
>>> element=0x23564d0, bin=0x217f1b0) at gstbin.c:2308
>>> #10 *gst_bin_change_state_func* (element=0x217f1b0,
>>> transition=GST_STATE_CHANGE_NULL_TO_READY) at gstbin.c:2610
>>> #11 0x00007ffff7b2e28c in *gst_element_change_state*(element=element at entry=0x217f1b0,
>>> transition=<optimized out>) at gstelement.c:2594
>>> #12 0x00007ffff7b2ec61 in *gst_element_set_state_func*(element=0x217f1b0, state=GST_STATE_READY) at gstelement.c:2550
>>> #13 0x0000000000405961 in *gst_worker_start* (worker=0x62f0f0) at
>>> gstworker.c:236
>>> #14 0x000000000040bc30 in *gst_composite_close_transition*(composite=0x706800) at gstcomposite.c:513
>>> #15 *gst_composite_alive* (composite=0x706800) at gstcomposite.c:565
>>> #16 0x00000000004063ca in *gst_worker_state_paused_to_playing*(worker=0x706800) at gstworker.c:412
>>> #17 *gst_worker_pipeline_state_changed* (statechange=<optimized out>,
>>> worker=0x706800) at gstworker.c:463
>>> #18 *gst_worker_message* (bus=<optimized out>, message=0x7fffd80138a0,
>>> worker=0x706800) at gstworker.c:542
>>> #19 0x00007ffff7b1dc67 in *gst_bus_source_dispatch* (source=source at entry=0x23614f0,
>>> callback=0x405b40 <gst_worker_message>, user_data=0x706800) at gstbus.c:773
>>> #20 0x00007ffff7290ab5 in *g_main_dispatch* (context=0x61f2d0) at
>>> /build/buildd/glib2.0-2.34.1/./glib/gmain.c:2715
>>> #21 *g_main_context_dispatch* (context=context at entry=0x61f2d0) at
>>> /build/buildd/glib2.0-2.34.1/./glib/gmain.c:3219
>>> #22 0x00007ffff7290de8 in *g_main_context_iterate* (context=0x61f2d0,
>>> block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>)
>>> at /build/buildd/glib2.0-2.34.1/./glib/gmain.c:3290
>>> #23 0x00007ffff72911e2 in *g_main_loop_run* (loop=0x706760) at
>>> /build/buildd/glib2.0-2.34.1/./glib/gmain.c:3484
>>> #24 0x00000000004044c0 in *gst_switch_server_run* (srv=0x708000) at
>>> gstswitchserver.c:1095
>>> #25 *main* (argc=1, argv=0x7fffffffe578) at gstswitchserver.c:1119
>>>
>>> The top several call frames are almost 100% percent path. And the key
>>> location of my client code is at:
>>>
>>> https://github.com/duzy/gst-switch/blob/switch/tools/gstworker.c#L681
>>>
>>> Which is doing recreation of three pipelines. I've been tracking on it
>>> for some days, but not yet have found the exact cause point. But I'm very
>>> sure that those leaked file descriptors are all of "unix socket" class, and
>>> should be created by *g_unix_open_pipe*. E.g. those already opened
>>> files (part, total 1024):
>>>
>>> ....
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 750 -> socket:[2418126]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 751 -> socket:[2418138]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 752 -> socket:[2418139]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 753 -> socket:[2418140]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 754 -> socket:[2417418]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 755 -> socket:[2417357]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 756 -> socket:[2417358]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 757 -> socket:[2415573]
>>>   lrwx------ 1 duzy duzy 64 Feb  4 01:46 758 -> socket:[2415574]
>>> ....
>>>
>>> I'm now think that if my previous issue was actually not solved, and
>>> that's actually very much related to too-many-open-files issue. Say:
>>>
>>> GStreamer-CRITICAL **: gst_poll_get_read_gpollfd: assertion `set !=
>>> NULL' failed
>>> GStreamer-CRITICAL **: gst_bus_create_watch: assertion `bus->priv->poll
>>> != NULL' failed
>>> GLib-CRITICAL **: g_source_set_callback: assertion `source != NULL'
>>> failed
>>>
>>>
>>> Hope you would have some ideas.
>>>
>>> Best Regards
>>> Duzy Chan
>>>
>>>
>>>
>>> On Sat, Jan 26, 2013 at 7:50 PM, Tim-Philipp Müller <t.i.m at zen.co.uk>wrote:
>>>
>>>> On Sat, 2013-01-26 at 08:08 +0800, Duzy Chan wrote:
>>>>
>>>> > Problem solved. Thanks all.
>>>>
>>>> So what was the problem/solution? Something in your code?
>>>>
>>>>  Cheers
>>>>   -Tim
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> gstreamer-devel mailing list
>>>> gstreamer-devel at lists.freedesktop.org
>>>> http://lists.freedesktop.org/mailman/listinfo/gstreamer-devel
>>>>
>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/gstreamer-devel/attachments/20130204/c7793b6a/attachment-0001.html>


More information about the gstreamer-devel mailing list