GNOME Bugzilla – Bug 150779
gconfd-2 aborts with signal 11 20 - 30 minutes after it starts.
Last modified: 2004-12-22 21:47:04 UTC
NOTE: This is the first time I've submitted a bug to gnome. I'd previously been thinking of this as the 'fedora-core-2.90 dev tree' problem with the version of GConfD2 listed below, but I'm not sure and am wondering if anyone else has had this symptom among the folks that really know gnome. *sanity-check* doesn't return any output (-1 or -2). It doesn't matter which application invokes gconfd-2. If this is the wrong place to submit this, sorry and I'd be grateful for any info on that. Description of problem: The gconfd-2 component of the GConf2 package (for the last 3 fc2 development tree versions) has segfaulted ~30 minutes after anything kicks it off. (e.g. Firefox, Any Gnome utility, or gconftool-2 --spawn). I'm using the kde3.3 desktop and all other s/w from the fc290 dev tree. Version-Release number of selected component (if applicable): GConf2-2.7.91.1-1 How reproducible: Always. Regardless of what invokes gconfd-2, it always goes away after 30 minutes, unless a normal shutdown precedes that time period, in which case it normally exits (signal 15). Steps to Reproduce: 1. Start up something built with the gtk2 toolkit, like firefox, or just use gconftool-2 --spawn to invoke gconfd-2. You'll get the following (similar, anyway) output. Aug 20 16:53:59 Kathaldo gconfd (root-8663): starting (version 2.7.91.1), pid 8663 user 'root' Aug 20 16:53:59 Kathaldo gconfd (root-8663): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration source at position 0 Aug 20 16:53:59 Kathaldo gconfd (root-8663): Resolved address "xml:readwrite:/root/.gconf" to a writable configuration source at position 1 Aug 20 16:53:59 Kathaldo gconfd (root-8663): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source at position 2 Then 20-30 minutes later without touching the computer (either way): Aug 20 17:14:59 Kathaldo gconfd (root-8663): Received signal 11, dumping core. Please report a GConf bug. 2. It'll restart if you use gconftool-2 again. 3. .. Actual results: I'm on FC3T1 and getting a signal 11 from gconfd 20 minutes after Firefox kicks it off (using KDE3). GConf2 version: 2.7.90-1. I installed debug-info and attached gdb to it. Should I start a new bugzilla entry for this? This is the backtrace after it segfaults: Program received signal SIGSEGV, Segmentation fault.
+ Trace 49542
Thread 16384 (LWP 1291)
Additional info: This is Fedora 2.90 development tree. I use KDE & all the rest if 100% up to date as of the date of this bug posting. (e.g.) glibc-2.3.3-45
Mickey: does this still happen with latest rawhide? If so could you install the GConf2-debuginfo RPM and get a stack trace - it'll make it much easier to figure out what's going on. Thanks :)
Thanks for the reply, Mark. Yes it's still occurring with the very latest version, and here's what you asked for: GConf2-2.7.91.1-1, GConf2-debuginfo-2.7.91.1-1, GConf2-devel-2.7.91.1-1 are the latest (as of today 25-Aug) versions I can get from the FC2.90 dev tree. A stack trace follows of ~10-15 lines preceeding & ~10-15 lines following the segfault: ---- system log (/var/log/messages) output that relates to the kickoff through segfault of gconfd-2 ------ Aug 25 14:14:51 Kathaldo gconfd (root-28003): starting (version 2.7.91.1), pid 28003 user 'root' Aug 25 14:14:51 Kathaldo gconfd (root-28003): Resolved address "xml:readonly:/etc/gconf/gconf.xml.mandatory" to a read-only configuration source at position 0 Aug 25 14:14:51 Kathaldo gconfd (root-28003): Resolved address "xml:readwrite:/root/.gconf" to a writable configuration source at position 1 Aug 25 14:14:51 Kathaldo gconfd (root-28003): Resolved address "xml:readonly:/etc/gconf/gconf.xml.defaults" to a read-only configuration source at position 2 Aug 25 14:35:51 Kathaldo gconfd (root-28003): Received signal 11, dumping core.Please report a GConf bug. ---------- end of system log. Note the period of time as ~20 minutes this occurrance ---------- ***** ---- strace output using GConf2-debuginfo-2.7.91.1-1 symbols ----- poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 66) = 0 gettimeofday({1093469691, 338777}, NULL) = 0 time(NULL) = 1093469691 time(NULL) = 1093469691 gettimeofday({1093469691, 339225}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 30000) = 0 gettimeofday({1093469721, 330328}, NULL) = 0 gettimeofday({1093469721, 330475}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 8) = 0 gettimeofday({1093469721, 339123}, NULL) = 0 time(NULL) = 1093469721 munmap(0x40503000, 48800) = 0 time(NULL) = 1093469721 mkdir("/root/.gconfd", 0700) = -1 EEXIST (File exists) open("/root/.gconfd/saved_state.tmp", O_WRONLY|O_CREAT|O_TRUNC, 0700) = 13 write(13, "CLIENTADD \"IOR:01d6ffbf170000004"..., 617) = 617 close(13) = 0 stat64("/root/.gconfd/saved_state", {st_mode=S_IFREG|0700, st_size=617, ...}) =0 rename("/root/.gconfd/saved_state", "/root/.gconfd/saved_state.orig") = 0 rename("/root/.gconfd/saved_state.tmp", "/root/.gconfd/saved_state") = 0 unlink("/root/.gconfd/saved_state.orig") = 0 gettimeofday({1093469721, 341539}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 29998) = 0 gettimeofday({1093469751, 329864}, NULL) = 0 gettimeofday({1093469751, 330009}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 9) = 0 gettimeofday({1093469751, 339839}, NULL) = 0 time(NULL) = 1093469751 --- SIGSEGV (Segmentation fault) @ 0 (0) --- time([1093469751]) = 1093469751 open("/etc/localtime", O_RDONLY) = 13 fstat64(13, {st_mode=S_IFREG|0644, st_size=1017, ...}) = 0 close(13) = 0 open("/etc/localtime", O_RDONLY) = 13 fstat64(13, {st_mode=S_IFREG|0644, st_size=1017, ...}) = 0 close(13) = 0 open("/etc/localtime", O_RDONLY) = 13 fstat64(13, {st_mode=S_IFREG|0644, st_size=1017, ...}) = 0 close(13) = 0 rt_sigaction(SIGPIPE, {0x401a85d8, [], 0}, {SIG_IGN}, 8) = 0 send(4, "<11>Aug 25 14:35:51 gconfd (root"..., 101, 0) = 101 rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0 kill(28003, SIGABRT) = 0 --- SIGABRT (Aborted) @ 0 (0) --- Process 28003 detached [ ---- end of strace output ---- By the way: I also tried building GConf2 from SRPMS (of the dev tree) on my system but got the identical results. I did an $rpmbuild --rebuild GC*.src.rpm to test that but the result above is from all RPMS FC originals. Notes: It "appears" to be the case that gconfd-2 is on a ~30 second timer where it does the following steps each interval: -------- gettimeofday({1093469061, 309814}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 29961) = 0 gettimeofday({1093469091, 261009}, NULL) = 0 gettimeofday({1093469091, 261157}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 9) = 0 gettimeofday({1093469091, 270843}, NULL) = 0 gettimeofday({1093469091, 270987}, NULL) = 0 poll([{fd=7, events=POLLIN}, {fd=9, events=POLLIN|POLLPRI}, {fd=11, events=POLLIN|POLLPRI}, {fd=14, events=POLLIN|POLLPRI}], 4, 38) = 0 gettimeofday({1093469091, 328585}, NULL) = 0 time(NULL) = 1093469091 time(NULL) = 1093469091 gettimeofday({1093469091, 329035}, NULL) = 0 poll( ------- This is what it seems to do when there's no input whatsoever from the keyboard or mouse but with some gtk2-built client running that normally would've spawned it. It appears to be polling for something that requires it. It does this until it segfaults as is shown in the strace output above.
Sorry about the confusion - what I really mean was "could you install the glib2-debuginfo RPM and attach gdb to get a backtrace when it crashes?" Thanks
Oops ;) Ok. I installed glib2-debuginfo, spawned gconfd-2, started gdb & attached it to the pid: Here's the result: (gdb) attach 30804 Attaching to process 30804 warning: The current VSYSCALL page code requires an existing execuitable. Use "add-symbol-file-from-memory" to load the VSYSCALL page by hand Reading symbols from /usr/libexec/gconfd-2...Reading symbols from /usr/lib/debug/usr/libexec/gconfd-2.debug...done. Using host libthread_db library "/lib/libthread_db.so.1". done. Reading symbols from /usr/lib/libgconf-2.so.4...Reading symbols from /usr/lib/debug/usr/lib/libgconf-2.so.4.1.0.debug...done. done. Loaded symbols for /usr/lib/libgconf-2.so.4 Reading symbols from /usr/lib/libgobject-2.0.so.0...Reading symbols from /usr/lib/debug/usr/lib/libgobject-2.0.so.0.400.6.debug...done. done. Loaded symbols for /usr/lib/libgobject-2.0.so.0 Reading symbols from /usr/lib/libORBit-2.so.0...done. Loaded symbols for /usr/lib/libORBit-2.so.0 Reading symbols from /lib/libm.so.6...done. Loaded symbols for /lib/libm.so.6 Reading symbols from /usr/lib/libgmodule-2.0.so.0...Reading symbols from /usr/lib/debug/usr/lib/libgmodule-2.0.so.0.400.6.debug...done. done. Loaded symbols for /usr/lib/libgmodule-2.0.so.0 Reading symbols from /lib/libdl.so.2...done. Loaded symbols for /lib/libdl.so.2 Reading symbols from /usr/lib/libgthread-2.0.so.0...Reading symbols from /usr/lib/debug/usr/lib/libgthread-2.0.so.0.400.6.debug...done. done. Loaded symbols for /usr/lib/libgthread-2.0.so.0 Reading symbols from /usr/lib/libglib-2.0.so.0...Reading symbols from /usr/lib/debug/usr/lib/libglib-2.0.so.0.400.6.debug...done. done. Loaded symbols for /usr/lib/libglib-2.0.so.0 Reading symbols from /lib/libpthread.so.0...done. [Thread debugging using libthread_db enabled] [New Thread 16384 (LWP 30804)] Loaded symbols for /lib/libpthread.so.0 Reading symbols from /lib/libc.so.6...done. Loaded symbols for /lib/libc.so.6 Reading symbols from /usr/lib/libpopt.so.0...done. Loaded symbols for /usr/lib/libpopt.so.0 Reading symbols from /lib/ld-linux.so.2...done. Loaded symbols for /lib/ld-linux.so.2 Reading symbols from /lib/libnss_files.so.2...done. Loaded symbols for /lib/libnss_files.so.2 Reading symbols from /usr/lib/GConf/2/libgconfbackend-xml.so...Reading symbols from /usr/lib/debug/usr/lib/GConf/2/libgconfbackend-xml.so.debug...done. done. Loaded symbols for /usr/lib/GConf/2/libgconfbackend-xml.so 0x402985be in poll () from /lib/libc.so.6 (gdb) cont Continuing. Program received signal SIGSEGV, Segmentation fault.
+ Trace 49635
Thread 16384 (LWP 30804)
Hope that's of some use. If you need other symbols loaded, just let me know. Mick
Thanks much, but I can't easily figure out what's going on here without more debugging info. What would be good would be to get a full debug log. You can do this by adding user.debug /tmp/gconf.debug line in /etc/syslog and restarting syslog. The you want to do: $> gconftool-2 --shutdown $> gconftool-2 --spawn attach the /tmp/gconf.debug file once you've reproduced it.
Created attachment 30972 [details] Output of 'user.debug /tmp/gconf.debug' line in syslog.conf. Mark: I'm sure I tried that before and only wound up with the same 3-4 lines of general gconfd output in gconf.debug that were previously in /var/log/messages, but maybe when the symbols are installed it behaves differently: Here's what I've done: 1) edited /etc/syslog.conf, added the line you suggested (user.debug /tmp/gconf.debug) 2) gconftool-2 --shutdown 3) gconftool-2 --spawn 4) attached the output file /tmp/gconf.debug This is the file although I can see it's totally worthless for your purposes. Q: is there some step I've missed in order to get that file to be full of verbose debug output? I tried to find a 'verbose' option on gconftool-2 & gconfd-2 as well as in '$man syslog.conf' but don't see anything. I'd really like to learn the best way to provice info for debug, so I appreciate your patience. I've debugged many programs over time, but getting the type of output you want (in linux) is new to me. Thanks.
Goodness, I forgot the most important part. You want: $> GCONF_DEBUG_OUTPUT=1 gconftool-2 --spawn Sorry about that :/
Created attachment 30978 [details] Another take at gconf.debug with the flag set as described. /tmp/gconf.debug attached when GCONF_DEBUG_OUTPUT=1 set: Ok, have added that and will have another file for you within 20-30 minutes. Should that be an $export GCONF_DEBUG_OUTPUT=1; gconftool-2 --spawn or will the above syntax work? In any case, I tried it both ways & it has *extra* debug info included, so hopefully will be of some use. The 'current debugged run' in gconf.debug starts at ~7:33. Stuff before that didn't have the GCONF_DEBUG_OUTPUT=1 flag set.
Thanks much Mickey, I think its fixed now: 2004-08-30 Mark McLoughlin <mark@skynet.ie> Lots of debugging info from Mickey Stein <yekkim@pacbell.net> narrowed this one down in bug #150779. * gconf/gconfd.c: (drop_old_databases): don't drop the default database here, we do that later. Hangover from the fact that the default database didn't use to be on db_list. Please let me know if you still see the problem with GConf 2.7.92 which should appear soon.
Thanks Mark, I'll post back when 2.7.92 appears. Appreciate it, Mickey
GConf2-2.7.92-1 showed up on redhat in the SRPMS folder, so I built it and installed. That took care of the problem (or I can see no exits, abnormal behaviour, etc). Thanks a million for all the work, Mick