Crashes on gst_bus_add_watch
Duzy Chan
geek at duzy.info
Tue Feb 5 06:36:08 PST 2013
There're many file descriptor leas in GstBus. All AF_UNIX socket fds,
should be used as message pipe:
==5605== Open AF_UNIX socket 834: <unknown>
==5605== at 0x5D13F8A: socketpair (syscall-template.S:82)
==5605== by 0x4EA2227: gst_poll_new (gstpoll.c:569)
==5605== by 0x4EA22FD: gst_poll_new_timer (gstpoll.c:630)
==5605== by 0x4E6AA84: gst_bus_constructed (gstbus.c:152)
==5605== by 0x54A1122: g_object_newv (gobject.c:1747)
==5605== by 0x4E6B105: gst_bus_new (gstbus.c:286)
==5605== by 0x4E9B6A5: gst_pipeline_init (gstpipeline.c:210)
==5605== by 0x54BBDDE: g_type_create_instance (gtype.c:1912)
==5605== by 0x549F6B7: g_object_constructor (gobject.c:1855)
==5605== by 0x54A0CB0: g_object_newv (gobject.c:1719)
==5605== by 0x4E7D44D: gst_element_factory_create
(gstelementfactory.c:377)
==5605== by 0x4E7D60E: gst_element_factory_make (gstelementfactory.c:446)
==5605== by 0x4EDF184: priv_gst_parse_launch (grammar.y:965)
==5605== by 0x4ED639C: gst_parse_launch_full (gstparse.c:324)
==5605== by 0x405714: gst_worker_create_pipeline (gstworker.c:181)
==5605== by 0x4052B4: gst_worker_prepare_unsafe (gstworker.c:611)
==5605== by 0x40560F: gst_worker_reset (gstworker.c:708)
==5605== by 0x40C847: gst_composite_apply_parameters (gstcomposite.c:320)
==5605== by 0x40CD17: gst_composite_null (gstcomposite.c:540)
==5605== by 0x4063D8: gst_worker_message (gstworker.c:438)
On Mon, Feb 4, 2013 at 7:38 PM, Duzy Chan <geek at duzy.info> wrote:
> Well I tried to manually close the socket FD by *client-socket-removed*signal, but it looks like the signal was never emitted (hoping can some one
> confirm this for me, as I gone through *gstmultisocketsink.c* and *
> gsttcpserversink.c*) because it looks like *client_free* was not called,
> sincerely hoping someone could tell me a bit about this for help:
>
> static void *gst_multi_socket_sink_client_free* (GstMultiHandleSink *
> mhsink,
> GstMultiHandleClient * client)
>
>
> And the other ref is *gst_multi_handle_sink_remove_client_link* in *
> gstmultihandlesink.c*, which do a invocation of *client_free*.
>
> And I'm using gst-plugins-base, at point
> d094ac49cce746425c83f7771a93cc1466a4a6ae.
>
> Regards
> Duzy Chan
>
>
>
>
>
> On Mon, Feb 4, 2013 at 5:37 PM, Duzy Chan <geek at duzy.info> wrote:
>
>> 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/20130205/6cc04da3/attachment-0001.html>
More information about the gstreamer-devel
mailing list