Re: gconfd process eating CPU
- From: Mark McLoughlin <markmc redhat com>
- To: Brian Cameron <Brian Cameron sun com>
- Cc: gconf-list gnome org
- Subject: Re: gconfd process eating CPU
- Date: Fri, 07 Jan 2005 15:28:45 +0000
Hi Brian,
Firstly, you've never mentioned what version of GConf, ORBit2, glib
etc. this is. I see its using liblinc, which means its quite old, but
I've no idea what code to read if I don't know exactly how old.
On Tue, 2005-01-04 at 14:21 -0600, Brian Cameron wrote:
> To get more information, I then ran "truss -fald -u a.out -u ld -u '*::'".
> The "-u a.out" tells truss to report on functions within the binary
> executable
Right, so this stuff is useful and gives an idea of what is going on.
I assume you've snipped the log this short because it just repeats
after this?
Anyway, what's happening is that the main loop seems to have a big
bunch of LincSources, but each source is for a connection that has been
closed by the client. For whatever reason, these sources aren't being
removed as soon as gconfd-2 detects that connection has been closed by
the other end. So, you're talking about a bug in ORBit2 somewhere.
Let me narrate ...
> 4335/1 1: 0.9829 <- libc:_poll() = 13
> 4335/1 1: 0.9831 <- libthread:poll() = 13
> 4335/1 1: 0.9834 <- libglib-2.0:g_main_context_poll() = 0x35e20
> 4335/1 1: 0.9836 -> libglib-2.0:g_main_context_check(0x35e20, 0x7fffffff, 0x2dcc48, 0x1c)
> 4335/1 1: 0.9842 -> liblinc:linc_source_check(0x35dd0, 0xffbfed2f, 0x1, 0x0)
> 4335/1 1: 0.9846 <- liblinc:linc_source_check() = 0
-> here we check a LincSource and find nothing pending
> 4335/1 1: 0.9849 -> libglib-2.0:g_timeout_check(0x38900, 0x3, 0x2, 0x0)
> 4335/1 1: 0.9851 -> libglib-2.0:g_source_get_current_time(0x38900, 0xffbfecc0, 0x0, 0x0)
> 4335/1 1: 0.9854 -> libglib-2.0:g_get_current_time(0x35e9c, 0x0, 0x0, 0x0)
> 4335/1 1: 0.9856 -> libc:gettimeofday(0xffbfebf8, 0x0, 0x0, 0x0)
> 4335/1 1: 0.9859 <- libc:gettimeofday() = 0
> 4335/1 1: 0.9861 <- libglib-2.0:g_get_current_time() = 0x35e9c
> 4335/1 1: 0.9863 <- libglib-2.0:g_source_get_current_time() = 0
> 4335/1 1: 0.9866 <- libglib-2.0:g_timeout_check() = 0
> 4335/1 1: 0.9868 -> libglib-2.0:g_timeout_check(0x38a90, 0x2, 0x1, 0x0)
> 4335/1 1: 0.9870 -> libglib-2.0:g_source_get_current_time(0x38a90, 0xffbfecc0, 0x0, 0x0)
> 4335/1 1: 0.9873 <- libglib-2.0:g_source_get_current_time() = 0
> 4335/1 1: 0.9875 <- libglib-2.0:g_timeout_check() = 0
> 4335/1 1: 0.9877 -> libglib-2.0:g_timeout_check(0x38b78, 0x2, 0x1, 0x0)
> 4335/1 1: 0.9880 -> libglib-2.0:g_source_get_current_time(0x38b78, 0xffbfecc0, 0x0, 0x0)
> 4335/1 1: 0.9882 <- libglib-2.0:g_source_get_current_time() = 0
> 4335/1 1: 0.9885 <- libglib-2.0:g_timeout_check() = 0
-> Here we check a bunch of timeout sources, again nothing pending
> 4335/1 1: 0.9887 -> liblinc:linc_source_check(0x99708, 0x2, 0x1, 0x0)
> 4335/1 1: 0.9890 <- liblinc:linc_source_check() = 1
> 4335/1 1: 0.9892 -> libglib-2.0:g_ptr_array_add(0x32f20, 0x99708, 0x3b, 0x0)
> 4335/1 1: 0.9894 -> libglib-2.0:g_ptr_array_maybe_expand(0x32f20, 0x1, 0x0, 0x0)
> 4335/1 1: 0.9897 <- libglib-2.0:g_ptr_array_maybe_expand() = 0x32f20
> 4335/1 1: 0.9899 <- libglib-2.0:g_ptr_array_add() = 0x32f20
> 4335/1 1: 0.9901 -> liblinc:linc_source_check(0x97d60, 0x4, 0x3, 0x0)
> 4335/1 1: 0.9904 <- liblinc:linc_source_check() = 1
> 4335/1 1: 0.9906 -> libglib-2.0:g_ptr_array_add(0x32f20, 0x97d60, 0x3b, 0x0)
> 4335/1 1: 0.9908 -> libglib-2.0:g_ptr_array_maybe_expand(0x32f20, 0x1, 0x0, 0x0)
> 4335/1 1: 0.9911 <- libglib-2.0:g_ptr_array_maybe_expand() = 0x32f20
> 4335/1 1: 0.9913 <- libglib-2.0:g_ptr_array_add() = 0x32f20
> 4335/1 1: 0.9915 -> liblinc:linc_source_check(0x97f28, 0x4, 0x3, 0x0)
[snip same repeated several times]
-> Here we have a big bunch of sources saying data is pending which
seems odd
> 4335/1 1: 1.0103 <- libglib-2.0:g_timeout_check() = 0
> 4335/1 1: 1.0105 -> liblinc:linc_source_check(0xb5090, 0x2, 0x1, 0x0)
> 4335/1 1: 1.0107 <- liblinc:linc_source_check() = 0
> 4335/1 1: 1.0110 -> liblinc:linc_source_check(0xc7108, 0x3, 0x2, 0x0)
> 4335/1 1: 1.0112 <- liblinc:linc_source_check() = 0
[snip repeated]
-> A number of sources with nothing pending - nothing wrong there
> 4335/1 1: 1.0161 <- libglib-2.0:g_main_context_check() = 1
> 4335/1 1: 1.0163 -> libglib-2.0:g_main_context_dispatch(0x35e20, 0x0, 0x1, 0x0)
> 4335/1 1: 1.0166 -> libglib-2.0:g_main_dispatch(0x35e20, 0x0, 0x0, 0x0)
> 4335/1 1: 1.0169 -> libglib-2.0:g_source_callback_ref(0x986e0, 0x31, 0x0, 0x0)
> 4335/1 1: 1.0171 <- libglib-2.0:g_source_callback_ref() = 0x986e0
> 4335/1 1: 1.0173 -> libglib-2.0:g_source_callback_get(0x986e0, 0x99708, 0xffbfecc8, 0xffbfeccc)
> 4335/1 1: 1.0176 <- libglib-2.0:g_source_callback_get() = 0x986e0
> 4335/1 1: 1.0178 -> liblinc:linc_source_dispatch(0x99708, 0xff1e3768, 0x34900, 0x1000)
-> Now we're dispatching the first source that reported pending data
> 4335/1 1: 1.0185 -> liblinc:linc_connection_io_handler(0x0, 0x1, 0x34900, 0x3b)
> 4335/1 1: 1.0189 -> libgobject-2.0:g_type_check_instance_cast(0x34900, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0191 <- libgobject-2.0:g_type_check_instance_cast() = 0x34900
> 4335/1 1: 1.0194 -> libgobject-2.0:g_object_ref(0x34900, 0x50, 0x0, 0x2)
> 4335/1 1: 1.0196 -> libgobject-2.0:g_type_check_instance_is_a(0x34900, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0199 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0201 <- libgobject-2.0:g_object_ref() = 0x34900
> 4335/1 1: 1.0203 -> liblinc:d_printf(0xff1e5d04, 0xa, 0x3985c, 0x2)
> 4335/1 1: 1.0206 <- liblinc:d_printf() = 0xff1e5d04
> 4335/1 1: 1.0208 -> libORBit-2:giop_connection_handle_input(0x34900, 0xa, 0x3985c, 0x2)
> 4335/1 1: 1.0210 -> libgobject-2.0:g_object_ref(0x34900, 0x0, 0x0, 0x0)
> 4335/1 1: 1.0213 -> libgobject-2.0:g_type_check_instance_is_a(0x34900, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0215 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0217 <- libgobject-2.0:g_object_ref() = 0x34900
> 4335/1 1: 1.0220 -> liblinc:linc_connection_read(0x34900, 0x14418c, 0x0, 0x0)
> 4335/1 1: 1.0222 -> liblinc:d_printf(0xff1e5bb0, 0x0, 0xa, 0x0)
> 4335/1 1: 1.0224 <- liblinc:d_printf() = 0xff1e5bb0
> 4335/1 1: 1.0228 <- liblinc:linc_connection_read() = 0
-> Here we read the connection and find that it returns zero. That
means the other side of the connection has closed. Looking at
recent ORBit code I'd expect linc_connection_state_changed() to
be called and we'd close our side and remove the source
> 4335/1 1: 1.0230 -> libgobject-2.0:g_object_unref(0x34900, 0x14418c, 0x0, 0x0)
> 4335/1 1: 1.0233 -> libgobject-2.0:g_type_check_instance_is_a(0x34900, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0235 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0238 <- libgobject-2.0:g_object_unref() = 0x34900
-> We're unreffing the LincConnection, but there's nothing about
removing the source. This looks like we're just releasing the
ref we took at the start of the function.
> 4335/1 1: 1.0240 <- libORBit-2:giop_connection_handle_input() = 1
> 4335/1 1: 1.0242 -> libgobject-2.0:g_type_check_instance_cast(0x34900, 0x50, 0x3985c, 0xff282c58)
> 4335/1 1: 1.0245 <- libgobject-2.0:g_type_check_instance_cast() = 0x34900
> 4335/1 1: 1.0247 -> libgobject-2.0:g_object_unref(0x34900, 0x50, 0x3985c, 0x2)
> 4335/1 1: 1.0250 -> libgobject-2.0:g_type_check_instance_is_a(0x34900, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0252 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0254 <- libgobject-2.0:g_object_unref() = 0x34900
> 4335/1 1: 1.0256 <- liblinc:linc_source_dispatch() = 1
> 4335/1 1: 1.0259 -> libglib-2.0:g_source_callback_unref(0x986e0, 0x1, 0x34900, 0x12c58)
> 4335/1 1: 1.0261 <- libglib-2.0:g_source_callback_unref() = 0x986e0
> 4335/1 1: 1.0263 -> libglib-2.0:g_source_callback_ref(0x98758, 0x31, 0x34900, 0x12c58)
> 4335/1 1: 1.0266 <- libglib-2.0:g_source_callback_ref() = 0x98758
> 4335/1 1: 1.0268 -> libglib-2.0:g_source_callback_get(0x98758, 0x97d60, 0xffbfecc8, 0xffbfeccc)
> 4335/1 1: 1.0270 <- libglib-2.0:g_source_callback_get() = 0x98758
> 4335/1 1: 1.0272 -> liblinc:linc_source_dispatch(0x97d60, 0xff1e3768, 0x97cc8, 0x1000)
> 4335/1 1: 1.0275 -> liblinc:linc_connection_io_handler(0x0, 0x1, 0x97cc8, 0x3b)
> 4335/1 1: 1.0277 -> libgobject-2.0:g_type_check_instance_cast(0x97cc8, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0289 <- libgobject-2.0:g_type_check_instance_cast() = 0x97cc8
> 4335/1 1: 1.0293 -> libgobject-2.0:g_object_ref(0x97cc8, 0x50, 0x0, 0x2)
> 4335/1 1: 1.0298 -> libgobject-2.0:g_type_check_instance_is_a(0x97cc8, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0301 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0303 <- libgobject-2.0:g_object_ref() = 0x97cc8
> 4335/1 1: 1.0305 -> liblinc:d_printf(0xff1e5d04, 0xd, 0x3985c, 0x2)
> 4335/1 1: 1.0308 <- liblinc:d_printf() = 0xff1e5d04
> 4335/1 1: 1.0310 -> libORBit-2:giop_connection_handle_input(0x97cc8, 0xd, 0x3985c, 0x2)
> 4335/1 1: 1.0313 -> libgobject-2.0:g_object_ref(0x97cc8, 0x0, 0x0, 0x0)
> 4335/1 1: 1.0315 -> libgobject-2.0:g_type_check_instance_is_a(0x97cc8, 0x50, 0x0, 0x0)
> 4335/1 1: 1.0318 <- libgobject-2.0:g_type_check_instance_is_a() = 1
> 4335/1 1: 1.0320 <- libgobject-2.0:g_object_ref() = 0x97cc8
> 4335/1 1: 1.0322 -> liblinc:linc_connection_read(0x97cc8, 0xd45f4, 0x0, 0x0)
> 4335/1 1: 1.0325 -> liblinc:d_printf(0xff1e5bb0, 0x0, 0xd, 0x0)
> 4335/1 1: 1.0327 <- liblinc:d_printf() = 0xff1e5bb0
> 4335/1 1: 1.0329 <- liblinc:linc_connection_read() = 0
-> Same story repeated here
[Snip same thing over and over]
Anyway, that should point you in the right direction to debug the
problem.
Good Luck,
Mark.
[
Date Prev][
Date Next] [
Thread Prev][
Thread Next]
[
Thread Index]
[
Date Index]
[
Author Index]
