Crashes on gst_bus_add_watch

Duzy Chan geek at duzy.info
Mon Feb 4 01:37:54 PST 2013


I think what I was thinking is right, the tcpserversink is not closing the
FDs it allocated, I need to free those socket FD by myself, according to
the comment docs in gstmultihandlesink.c:

 * Clients can be removed from multihandlesink by emitting the
#GstMultiHandleSink::remove signal. For
 * each descriptor removed, the #GstMultiHandleSink::client-removed signal
will be called. The
 * #GstMultiHandleSink::client-removed signal can also be fired when
multihandlesink decides that a
 * client is not active anymore or, depending on the value of the
 * #GstMultiHandleSink:recover-policy property, if the client is reading
too slowly.
 * In all cases, multihandlesink will never close a file descriptor itself.
 * The user of multihandlesink is responsible for closing all file
descriptors.
 * This can for example be done in response to the
#GstMultiHandleSink::client-fd-removed signal.
 * Note that multihandlesink still has a reference to the file descriptor
when the
 * #GstMultiHandleSink::client-removed signal is emitted, so that
"get-stats" can be performed on
 * the descriptor; it is therefore not safe to close the file descriptor in
 * the #GstMultiHandleSink::client-removed signal handler, and you should
use the
 * #GstMultiHandleSink::client-fd-removed signal to safely close the fd.

I'm going to try to close the FD by myself, and see if it fixes my issue.



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

> 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/bb15b04c/attachment-0001.html>


More information about the gstreamer-devel mailing list