Bug 516671

Summary: gconf-helper segfaulting at gnome login
Product: [Fedora] Fedora Reporter: Tom London <selinux>
Component: GConfAssignee: Ray Strode [halfline] <rstrode>
Status: CLOSED DUPLICATE QA Contact:
Severity: medium Docs Contact:
Priority: low    
Version: rawhideCC: azelinka, frankly3d, jreiser, lkundrak, lpoetter, sangu.fedora, wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-09-01 17:17:56 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
gzip of core generated by /usr/libexec/pulse/gconf-helper
none
output of valgrind /usr/libexec/pulse/gconf-helper.
none
valgrind output of /usr/libexec/pulse/gconf-helper with segfault none

Description Tom London 2009-08-11 02:11:26 UTC
Description of problem:
I'm noticing this on every gnome login:
SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
gconf-helper[1951]: segfault at 895d0 ip 00000000000895d0 sp 00007fff18cebd08 error 14 in gconf-helper[400000+2000]

Here is some more context from /var/log/messages:
Aug 10 18:59:48 tlondon kernel: [drm] DAC-6: set mode  2a
Aug 10 18:59:48 tlondon seahorse-daemon[1828]: init gpgme version 1.1.8
Aug 10 18:59:49 tlondon kernel: fuse init (API version 7.12)
Aug 10 18:59:51 tlondon rtkit-daemon[1862]: Sucessfully made thread 1860 of process 1860 (/usr/bin/pulseaudio) owned by '500' high priority at nice level -11.
Aug 10 18:59:52 tlondon rtkit-daemon[1862]: Sucessfully made thread 1926 of process 1860 (/usr/bin/pulseaudio) owned by '500' RT at priority 5.
Aug 10 18:59:52 tlondon restorecond: Unable to watch (/home/tbl/public_html/*) No such file or directory
Aug 10 18:59:53 tlondon rtkit-daemon[1862]: Sucessfully made thread 1946 of process 1860 (/usr/bin/pulseaudio) owned by '500' RT at priority 5.
Aug 10 18:59:54 tlondon kernel: gconf-helper[1951]: segfault at 895d0 ip 00000000000895d0 sp 00007fff18cebd08 error 14 in gconf-helper[400000+2000]
Aug 10 18:59:54 tlondon pulseaudio[1860]: module-gconf.c: Unable to read or parse data from client.
Aug 10 18:59:54 tlondon pulseaudio[1860]: module.c: Failed to load  module "module-gconf" (argument: ""): initialization failed.
Aug 10 18:59:54 tlondon kernel: i2c-adapter i2c-2: unable to read EDID block.
Aug 10 18:59:54 tlondon kernel: i915 0000:00:02.0: DVI-D-1: no EDID data
Aug 10 18:59:54 tlondon kernel: i2c-adapter i2c-2: unable to read EDID block.

Some way for me to provide "more useful" information?

Version-Release number of selected component (if applicable):
pulseaudio-libs-glib2-0.9.16-5.test4.fc12.x86_64
pulseaudio-libs-0.9.16-5.test4.fc12.x86_64
pulseaudio-debuginfo-0.9.16-5.test4.fc12.x86_64
pulseaudio-module-x11-0.9.16-5.test4.fc12.x86_64
pulseaudio-utils-0.9.16-5.test4.fc12.x86_64
pulseaudio-0.9.16-5.test4.fc12.x86_64
pulseaudio-module-bluetooth-0.9.16-5.test4.fc12.x86_64
pulseaudio-module-gconf-0.9.16-5.test4.fc12.x86_64


How reproducible:
Every login

Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Lennart Poettering 2009-08-11 18:30:22 UTC
Hmm, interesting. never seen that. Any chance you can get a backtrace of this? Possibly by running /usr/libexec/pulse/gconf-helper directly?

It doesn't segfault here...

Comment 2 Tom London 2009-08-11 19:36:38 UTC
Sure.  I started with "gdb /usr/libexec/pulse/gconf-helper" (and the usual "run").

So far all I see is a "!" printed ....

Are there any arguments to pass to it?

Comment 3 Tom London 2009-08-11 20:22:58 UTC
A bit more:

Looks like this started happening to me on 5 August:

[root@tlondon ~]# grep gconf-helper /var/log/messages
Aug  5 06:41:33 tlondon kernel: gconf-helper[1657]: segfault at 89670 ip 0000000000089670 sp 00007fffd07eea68 error 14 in gconf-helper[400000+2000]
Aug  5 06:51:32 tlondon kernel: gconf-helper[3250]: segfault at 89670 ip 0000000000089670 sp 00007fff44602058 error 14 in gconf-helper[400000+2000]
Aug  5 06:52:20 tlondon kernel: gconf-helper[3607]: segfault at 89670 ip 0000000000089670 sp 00007fff51bad988 error 14 in gconf-helper[400000+2000]
Aug  5 08:57:09 tlondon kernel: gconf-helper[1675]: segfault at 89670 ip 0000000000089670 sp 00007fff73f7c5d8 error 14 in gconf-helper[400000+2000]
Aug  5 14:50:34 tlondon kernel: gconf-helper[9840]: segfault at 89670 ip 0000000000089670 sp 00007fffd93803e8 error 14 in gconf-helper[400000+2000]
Aug  6 06:20:09 tlondon kernel: gconf-helper[1654]: segfault at 89670 ip 0000000000089670 sp 00007fff580703a8 error 14 in gconf-helper[400000+2000]
Aug  6 07:22:58 tlondon kernel: gconf-helper[3673]: segfault at 89670 ip 
<<<<<SNIP>>>>>
Aug 10 15:02:43 tlondon kernel: gconf-helper[1764]: segfault at 895d0 ip 00000000000895d0 sp 00007fff5ad7fa48 error 14 in gconf-helper[400000+2000]
Aug 10 18:59:54 tlondon kernel: gconf-helper[1951]: segfault at 895d0 ip 00000000000895d0 sp 00007fff18cebd08 error 14 in gconf-helper[400000+2000]
Aug 10 19:21:16 tlondon kernel: gconf-helper[1782]: segfault at 895d0 ip 00000000000895d0 sp 00007fff0ebc20e8 error 14 in gconf-helper[400000+2000]
Aug 11 06:49:03 tlondon kernel: gconf-helper[1942]: segfault at 895d0 ip 00000000000895d0 sp 00007fff82e37ed8 error 14 in gconf-helper[400000+2000]
Aug 11 08:54:36 tlondon kernel: gconf-helper[1791]: segfault at 895d0 ip 00000000000895d0 sp 00007fff06d76ee8 error 14 in gconf-helper[400000+2000]
[root@tlondon ~]#

/var/log/messages starts at:

[root@tlondon ~]# head $_
Jul 19 08:10:08 tlondon kernel: imklog 4.2.0, log source = /proc/kmsg started.
Jul 19 08:10:08 tlondon rsyslogd: [origin software="rsyslogd" swVersion="4.2.0" x-pid="814" x-info="http://www.rsyslog.com"] (re)start
Jul 19 08:11:01 tlondon ntpd[1159]: synchronized to 66.250.45.2, stratum 2

Last pulseaudio update:
Aug 05 06:27:21 Updated: pulseaudio-libs-0.9.16-5.test4.fc12.x86_64
Aug 05 06:27:54 Updated: pulseaudio-libs-glib2-0.9.16-5.test4.fc12.x86_64
Aug 05 06:27:55 Updated: pulseaudio-utils-0.9.16-5.test4.fc12.x86_64
Aug 05 06:29:16 Updated: pulseaudio-debuginfo-0.9.16-5.test4.fc12.x86_64
Aug 05 06:30:18 Updated: pulseaudio-0.9.16-5.test4.fc12.x86_64
Aug 05 06:30:19 Updated: pulseaudio-module-bluetooth-0.9.16-5.test4.fc12.x86_64
Aug 05 06:30:25 Updated: pulseaudio-module-gconf-0.9.16-5.test4.fc12.x86_64
Aug 05 06:30:26 Updated: pulseaudio-module-x11-0.9.16-5.test4.fc12.x86_64

The boot where this started is
Aug  5 06:40:53 tlondon kernel: imklog 4.2.0, log source = /proc/kmsg started.
Aug  5 06:40:53 tlondon rsyslogd: [origin software="rsyslogd" swVersion="4.2.0" x-pid="868" x-info="http://www.rsyslog.com"] (re)start
Aug  5 06:40:53 tlondon kernel: Initializing cgroup subsys cpuset
Aug  5 06:40:53 tlondon kernel: Initializing cgroup subsys cpu

Worthwhile to downgrade just pulseaudio-module-gconf and test?

Comment 4 Tom London 2009-08-11 20:28:25 UTC
Nevermind.... would need to downgrade all of pulseaudio back to 0.9.16-4.test4.

Useful to do?

Comment 5 Lennart Poettering 2009-08-11 23:57:29 UTC
the ! is what you actually should be seeing. You get more output if you toggle a few of the settings in paprefs.

Any chance you can get a coredump for this?

Comment 6 Tom London 2009-08-12 00:38:00 UTC
I have 

# allow core dumps
ulimit -c unlimited >/dev/null 2>&1

in my .bashrc, but I'm not getting any core files.....

I'll continue to try to get one, but I'm having no luck just running it manually and letting it "just hang".

I welcome suggestions!

Comment 7 Lennart Poettering 2009-08-12 00:44:08 UTC
hmm, due to chdir("/") in pa the core dump might not be created for perm reasons. Use /proc/sys/kernel/core_pattern to place them in /tmp or so.

Comment 8 Tom London 2009-08-12 04:29:06 UTC
Created attachment 357113 [details]
gzip of core generated by /usr/libexec/pulse/gconf-helper

Didn't know about core_pattern.....  Thanks!

Anyway, I booted up to runlevel 3 and did an "echo /tmp/core >/proc/sys/kernel/core_pattern", and then a "telinit 5".

Got a core:

Core was generated by `/usr/libexec/pulse/gconf-helper'.
Program terminated with signal 11, Segmentation fault.
#0  0x00000000000895d0 in ?? ()
(gdb) where
#0  0x00000000000895d0 in ?? ()
#1  0x00007f893ae64409 in CORBA_ORB_init (argc=0x7fffd5ac2efc, 
    argv=0x7fffd5ac2ee0, orb_identifier=0x7f893e96d9f6 "orbit-local-orb", 
    ev=0x7fffd5ac2eb0) at corba-orb.c:404
#2  0x00007f893e951f63 in gconf_orb_get () at gconf-internals.c:2767
#3  0x00007f893e9520d3 in gconf_get_server (
    start_if_not_found=<value optimized out>, failure_log=0x90ec00)
    at gconf-internals.c:2519
#4  0x00007f893e9522b2 in gconf_activate_server (start_if_not_found=0, 
    error=0x0) at gconf-internals.c:2861
#5  0x00007f893e95fad4 in try_to_contact_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2234
#6  gconf_get_config_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2278
#7  0x00007f893e9605b9 in gconf_engine_connect (conf=0x90e830, 
    start_if_not_found=<value optimized out>, err=0x0) at gconf.c:364
#8  0x00007f893e960c0c in gconf_engine_get_default () at gconf.c:575
#9  0x00007f893e968a54 in gconf_client_get_default () at gconf-client.c:433
#10 0x0000000000401024 in main (argc=<value optimized out>, 
    argv=<value optimized out>) at modules/gconf/gconf-helper.c:104
(gdb) 

Not sure if its helpful, but I attach the core file....

Comment 9 Tom London 2009-08-12 04:47:38 UTC
A bit more:

(gdb) where
#0  0x00000000000895d0 in ?? ()
#1  0x00007f893ae64409 in CORBA_ORB_init (argc=0x7fffd5ac2efc, 
    argv=0x7fffd5ac2ee0, orb_identifier=0x7f893e96d9f6 "orbit-local-orb", 
    ev=0x7fffd5ac2eb0) at corba-orb.c:404
#2  0x00007f893e951f63 in gconf_orb_get () at gconf-internals.c:2767
#3  0x00007f893e9520d3 in gconf_get_server (
    start_if_not_found=<value optimized out>, failure_log=0x90ec00)
    at gconf-internals.c:2519
#4  0x00007f893e9522b2 in gconf_activate_server (start_if_not_found=0, 
    error=0x0) at gconf-internals.c:2861
#5  0x00007f893e95fad4 in try_to_contact_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2234
#6  gconf_get_config_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2278
#7  0x00007f893e9605b9 in gconf_engine_connect (conf=0x90e830, 
    start_if_not_found=<value optimized out>, err=0x0) at gconf.c:364
#8  0x00007f893e960c0c in gconf_engine_get_default () at gconf.c:575
#9  0x00007f893e968a54 in gconf_client_get_default () at gconf-client.c:433
#10 0x0000000000401024 in main (argc=<value optimized out>, 
    argv=<value optimized out>) at modules/gconf/gconf-helper.c:104
(gdb) down
Bottom (innermost) frame selected; you cannot go down.
(gdb) up
#1  0x00007f893ae64409 in CORBA_ORB_init (argc=0x7fffd5ac2efc, 
    argv=0x7fffd5ac2ee0, orb_identifier=0x7f893e96d9f6 "orbit-local-orb", 
    ev=0x7fffd5ac2eb0) at corba-orb.c:404
404		    strstr (orb_identifier, "orbit-local-non-threaded-orb") != NULL)
(gdb) list
399	
400		/* the allocation code uses the bottom bit of any pointer */
401		g_assert (ORBIT_ALIGNOF_CORBA_DOUBLE > 2);
402	
403		if (orb_identifier &&
404		    strstr (orb_identifier, "orbit-local-non-threaded-orb") != NULL)
405			thread_safe = FALSE;
406		else
407			thread_safe = TRUE;
408	
(gdb)

Comment 10 Tom London 2009-08-12 13:16:43 UTC
Here's another one from this morning's login. Believe its the same as the one above....:

Core was generated by `/usr/libexec/pulse/gconf-helper'.
Program terminated with signal 11, Segmentation fault.
#0  0x00000000000895d0 in ?? ()
(gdb) where
#0  0x00000000000895d0 in ?? ()
#1  0x00007f3e4fb45409 in CORBA_ORB_init (argc=0x7fffd3f20bec, 
    argv=0x7fffd3f20bd0, orb_identifier=0x7f3e5364e9f6 "orbit-local-orb", 
    ev=0x7fffd3f20ba0) at corba-orb.c:404
#2  0x00007f3e53632f63 in gconf_orb_get () at gconf-internals.c:2767
#3  0x00007f3e536330d3 in gconf_get_server (
    start_if_not_found=<value optimized out>, failure_log=0x14bcc00)
    at gconf-internals.c:2519
#4  0x00007f3e536332b2 in gconf_activate_server (start_if_not_found=0, 
    error=0x0) at gconf-internals.c:2861
#5  0x00007f3e53640ad4 in try_to_contact_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2234
#6  gconf_get_config_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2278
#7  0x00007f3e536415b9 in gconf_engine_connect (conf=0x14bc830, 
    start_if_not_found=<value optimized out>, err=0x0) at gconf.c:364
#8  0x00007f3e53641c0c in gconf_engine_get_default () at gconf.c:575
#9  0x00007f3e53649a54 in gconf_client_get_default () at gconf-client.c:433
#10 0x0000000000401024 in main (argc=<value optimized out>, 
    argv=<value optimized out>) at modules/gconf/gconf-helper.c:104
(gdb)

Comment 11 Lennart Poettering 2009-08-12 15:44:47 UTC
Hmm, could you make this a full bt? (i.e. "bt full" instead of "bt" in gdb?) Looks like breakage in gconf, reassigning to gconf.

Comment 12 Lennart Poettering 2009-08-12 15:44:51 UTC
*** Bug 517064 has been marked as a duplicate of this bug. ***

Comment 13 Tom London 2009-08-12 16:04:13 UTC
(gdb) bt full
#0  0x00000000000895d0 in ?? ()
No symbol table info available.
#1  0x00007f63c718c409 in CORBA_ORB_init (argc=0x7fff630667bc, 
    argv=0x7fff630667a0, orb_identifier=0x7f63cac959f6 "orbit-local-orb", 
    ev=0x7fff63066770) at corba-orb.c:404
        thread_safe = <value optimized out>
        retval = <value optimized out>
        orb_if = {type = ORBIT_ROT_ORB, 
          destroy = 0x7f63c718c340 <CORBA_ORB_release_fn>}
#2  0x00007f63cac79f63 in gconf_orb_get () at gconf-internals.c:2767
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, 
            _release = 0 '\000'}}
        argc = 1
        argv = {0x7f63cac959f0 "gconf", 0x0}
        __PRETTY_FUNCTION__ = "gconf_orb_get"
#3  0x00007f63cac7a0d3 in gconf_get_server (
    start_if_not_found=<value optimized out>, failure_log=0x1149c00)
    at gconf-internals.c:2519
        server = <value optimized out>
        ior = 0x114ce60 "IOR:010000001600000049444c3a436f6e666967536572766572323a312e30000000030000000054424f500000000101020005000000554e4958000000000a0000006c6f63616c686f7374000000280000002f746d702f6f726269742d74626c2f6c696e"...
        orb = <value optimized out>
---Type <return> to continue, or q <return> to quit---
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, 
            _release = 0 '\000'}}
#4  0x00007f63cac7a2b2 in gconf_activate_server (start_if_not_found=0, 
    error=0x0) at gconf-internals.c:2861
        server = <value optimized out>
        failure_log = 0x1149c00
        ev = {_id = 0x40 <Address 0x40 out of bounds>, _major = 0, _any = {
            _type = 0x0, _value = 0x3000000002, _release = 124 '|'}}
#5  0x00007f63cac87ad4 in try_to_contact_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2234
        ev = can't compute CFA for this frame
(gdb)

Comment 14 Lennart Poettering 2009-08-24 14:11:38 UTC
*** Bug 518978 has been marked as a duplicate of this bug. ***

Comment 15 Lennart Poettering 2009-08-24 14:20:59 UTC
Tom, that bt is somehow cut after stack frame #5. Probably because gdb was broken at the time. Could you get another bt and make sure it goes all theway up to main() please?

Comment 16 Tom London 2009-08-24 15:42:05 UTC
Not sure I can.....

Here is bt from latest core: says "ev = can't compute CFA for this frame" at frame #5

(gdb) bt full
#0  0x00000000000895d0 in ?? ()
No symbol table info available.
#1  0x00007f40988ab409 in CORBA_ORB_init (argc=0x7fffb2fff38c, argv=0x7fffb2fff370, orb_identifier=0x7f409c3bc9f6 "orbit-local-orb", ev=0x7fffb2fff340) at corba-orb.c:404
        thread_safe = <value optimized out>
        retval = <value optimized out>
        orb_if = {type = ORBIT_ROT_ORB, destroy = 0x7f40988ab340 <CORBA_ORB_release_fn>}
#2  0x00007f409c3a0f63 in gconf_orb_get () at gconf-internals.c:2767
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, _release = 0 '\000'}}
        argc = 1
        argv = {0x7f409c3bc9f0 "gconf", 0x0}
        __PRETTY_FUNCTION__ = "gconf_orb_get"
#3  0x00007f409c3a10d3 in gconf_get_server (start_if_not_found=<value optimized out>, failure_log=0x1842c00) at gconf-internals.c:2519
        server = <value optimized out>
        ior = 0x1845e60 "IOR:010000001600000049444c3a436f6e666967536572766572323a312e30000000030000000054424f500000000101020005000000554e4958000000000a0000006c6f63616c686f7374000000280000002f746d702f6f726269742d74626c2f6c696e"...
        orb = <value optimized out>
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, _release = 0 '\000'}}
#4  0x00007f409c3a12b2 in gconf_activate_server (start_if_not_found=0, error=0x0) at gconf-internals.c:2861
        server = <value optimized out>
        failure_log = 0x1842c00
        ev = {_id = 0x40 <Address 0x40 out of bounds>, _major = 0, _any = {_type = 0x0, _value = 0x3000000002, _release = 124 '|'}}
#5  0x00007f409c3aead4 in try_to_contact_server (err=<value optimized out>, start_if_not_found=<value optimized out>) at gconf.c:2234
        ev = can't compute CFA for this frame
(gdb) 

Something else I can do?????

Comment 17 Tom London 2009-08-24 15:45:39 UTC
Sorry... looks like "full" is busting this.

Core was generated by `/usr/libexec/pulse/gconf-helper'.
Program terminated with signal 11, Segmentation fault.
#0  0x00000000000895d0 in ?? ()
(gdb) where
#0  0x00000000000895d0 in ?? ()
#1  0x00007f40988ab409 in CORBA_ORB_init (argc=0x7fffb2fff38c, 
    argv=0x7fffb2fff370, orb_identifier=0x7f409c3bc9f6 "orbit-local-orb", 
    ev=0x7fffb2fff340) at corba-orb.c:404
#2  0x00007f409c3a0f63 in gconf_orb_get () at gconf-internals.c:2767
#3  0x00007f409c3a10d3 in gconf_get_server (
    start_if_not_found=<value optimized out>, failure_log=0x1842c00)
    at gconf-internals.c:2519
#4  0x00007f409c3a12b2 in gconf_activate_server (start_if_not_found=0, 
    error=0x0) at gconf-internals.c:2861
#5  0x00007f409c3aead4 in try_to_contact_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2234
#6  gconf_get_config_server (err=<value optimized out>, 
    start_if_not_found=<value optimized out>) at gconf.c:2278
#7  0x00007f409c3af5b9 in gconf_engine_connect (conf=0x1842830, 
    start_if_not_found=<value optimized out>, err=0x0) at gconf.c:364
#8  0x00007f409c3afc0c in gconf_engine_get_default () at gconf.c:575
#9  0x00007f409c3b7a54 in gconf_client_get_default () at gconf-client.c:433
#10 0x0000000000401024 in main (argc=<value optimized out>, 
    argv=<value optimized out>) at modules/gconf/gconf-helper.c:104

Comment 18 Lennart Poettering 2009-08-24 15:51:15 UTC
Try upgrading your gdb. Those CFA errors should be fixed in the most recent gdb.

Hmm, but the other back trace is probably good enough. THis is really a weird issue, as the bug is triggered in strstr() where we look for a static const string in a static const string. That this fails is really really surprising.

Would probably make sense to valgrind this. But last time I checked vg was even more broken in rawhide than gdb. Sigh.

Comment 19 Tom London 2009-08-24 16:05:39 UTC
Hmmm, I'm running gdb-6.8.50.20090818-4.fc12.x86_64.  Believe that is the latest koji gdb.

I'm willing to valgrind and filter a bit....

Any special instructions on starting gconf-helper?

Comment 20 Tom London 2009-08-24 16:10:31 UTC
Created attachment 358477 [details]
output of valgrind /usr/libexec/pulse/gconf-helper.  

Output of "trivial valgrind".

I just ran valgrind until I saw the "!", and then hit ctrl-C.

It doesn't segfault when I run it from a window.....

Comment 21 Tom London 2009-08-24 17:43:37 UTC
Created attachment 358493 [details]
valgrind output of /usr/libexec/pulse/gconf-helper with segfault

OK, I think I have a valgrind output when it segfaults (full output attached):

==1830== Use of uninitialised value of size 8
==1830==    at 0x4C2736C: memcpy (mc_replace_strmem.c:482)
==1830==    by 0x50C21CE: g_strdup (string3.h:52)
==1830==    by 0x4E3C0A2: gconf_get_server (gconf-internals.c:2494)
==1830==    by 0x4E3C2B1: gconf_activate_server (gconf-internals.c:2861)
==1830==    by 0x4E49AD3: gconf_get_config_server (gconf.c:2234)
==1830==    by 0x4E4A5B8: gconf_engine_connect (gconf.c:364)
==1830==    by 0x4E4AC0B: gconf_engine_get_default (gconf.c:575)
==1830==    by 0x4E52A53: gconf_client_get_default (gconf-client.c:433)
==1830==    by 0x401023: main (gconf-helper.c:104)
==1830== 
==1830== Conditional jump or move depends on uninitialised value(s)
==1830==    at 0x4C2737A: memcpy (mc_replace_strmem.c:482)
==1830==    by 0x50C21CE: g_strdup (string3.h:52)
==1830==    by 0x4E3C0A2: gconf_get_server (gconf-internals.c:2494)
==1830==    by 0x4E3C2B1: gconf_activate_server (gconf-internals.c:2861)
==1830==    by 0x4E49AD3: gconf_get_config_server (gconf.c:2234)
==1830==    by 0x4E4A5B8: gconf_engine_connect (gconf.c:364)
==1830==    by 0x4E4AC0B: gconf_engine_get_default (gconf.c:575)
==1830==    by 0x4E52A53: gconf_client_get_default (gconf-client.c:433)
==1830==    by 0x401023: main (gconf-helper.c:104)
==1830== 
==1830== Jump to the invalid address stated on the next line
==1830==    at 0x895D0: ???
==1830==    by 0x4E3C0D300000006: ???
==1830==  Address 0x895d0 is not stack'd, malloc'd or (recently) free'd
==1830== 
==1830== 
==1830== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==1830==  Bad permissions for mapped region at address 0x895D0
==1830==    at 0x895D0: ???
==1830==    by 0x4E3C0D300000006: ???

I got this by moving /usr/libexec/pulse/gconf-helper to gconf-helper.bin, and creating a "shim" gconf-helper:

#!/bin/bash

echo "$*" >/tmp/gconf-helper-args.$$
valgrind --log-file=/tmp/gconf-helper-valgrind.$$ /usr/libexec/pulse/gconf-helper.bin $*

Does this help?

Comment 22 Ray Strode [halfline] 2009-08-24 20:34:31 UTC
So the relevant code is here:

http://git.gnome.org/cgit/gconf/tree/gconf/gconf-internals.c#n2485

(2485 in master is 2494):

        ior = NULL;
        if (!dbus_message_get_args (reply, &bus_error, DBUS_TYPE_STRING,
                                    &ior, DBUS_TYPE_INVALID)) {
                if (failure_log)
                    g_string_append_printf (failure_log,
                                            _("daemon gave erroneous reply: %s"),
                                            bus_error.message);
                dbus_error_free (&bus_error);
                return NULL;
        }

        ior = g_strdup (ior);


It's not at all clear to me why that'd be a problem...

Comment 23 Ray Strode [halfline] 2009-08-24 20:43:03 UTC
it's also disconcerting that the first message you see in attach 358493 is:

==2471== 
==2471== Invalid read of size 8
==2471==    at 0x81C0EBA: __GI_strcmp (strcmp.S:100)
==2471==    by 0x816EF21: set_binding_values (bindtextdom.c:124)
==2471==    by 0x816F2B4: bind_textdomain_codeset (bindtextdom.c:360)
==2471==    by 0x4E3BC83: _gconf_init_i18n (gconf-internals.c:2940)
==2471==    by 0x4E4AB0C: gconf_engine_blank (gconf.c:235)
==2471==    by 0x4E4ABF1: gconf_engine_get_default (gconf.c:565)
==2471==    by 0x4E52A53: gconf_client_get_default (gconf-client.c:433)
==2471==    by 0x401023: main (gconf-helper.c:104)
==2471==  Address 0xa060368 is 24 bytes inside a block of size 31 alloc'd
==2471==    at 0x4C25E5D: malloc (vg_replace_malloc.c:195)
==2471==    by 0x816F0B8: set_binding_values (bindtextdom.c:230)
==2471==    by 0x816F2D4: bindtextdomain (bindtextdom.c:349)
==2471==    by 0x4E3BC70: _gconf_init_i18n (gconf-internals.c:2938)
==2471==    by 0x4E4AB0C: gconf_engine_blank (gconf.c:235)
==2471==    by 0x4E4ABF1: gconf_engine_get_default (gconf.c:565)
==2471==    by 0x4E52A53: gconf_client_get_default (gconf-client.c:433)
==2471==    by 0x401023: main (gconf-helper.c:104)
==2471== 

when that is just caused by:

bindtextdomain (GETTEXT_PACKAGE, GCONF_LOCALE_DIR);
bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");

Comment 24 John Reiser 2009-08-24 22:33:03 UTC
(In reply to comment #23)
> it's also disconcerting that the first message you see in attach 358493 is:

> ==2471== Invalid read of size 8
> ==2471==    at 0x81C0EBA: __GI_strcmp (strcmp.S:100)
> ==2471==    by 0x816EF21: set_binding_values (bindtextdom.c:124)

> ==2471==  Address 0xa060368 is 24 bytes inside a block of size 31 alloc'd
> ==2471==    at 0x4C25E5D: malloc (vg_replace_malloc.c:195)
> ==2471==    by 0x816F0B8: set_binding_values (bindtextdom.c:230)

> when that is just caused by:
> 
> bindtextdomain (GETTEXT_PACKAGE, GCONF_LOCALE_DIR);
> bind_textdomain_codeset (GETTEXT_PACKAGE, "UTF-8");  

The brand new valgrind-3.5.0 (less than one week old) does not understand the brand new STT_IFUNC symbol type that glibc-2.11 (not yet released; 2.10.90 is now in rawhide) uses to implement processor-specific variants of functions such as strlen, strcmp, etc.  As a result, memcheck does not realize that __GI_strcmp is strcmp and should be replaced by memcheck's internal strcmp.  Thus memcheck analyzes the strcmp that glibc chooses via STT_IFUNC, and reports the speculative over-fetching that __GI_strcmp does.

Comment 25 Lennart Poettering 2009-08-26 01:20:46 UTC
The vg strcmp issue is bug 518247, btw.

The gdb CFA thing is bug 516627. which is supposedly closed with 6.8.50.20090811-2. If it still is broken for you reopen that bug.

Comment 26 Lennart Poettering 2009-08-26 16:03:24 UTC
*** Bug 519325 has been marked as a duplicate of this bug. ***

Comment 27 Tom London 2009-09-01 13:45:27 UTC
koji gdb (gdb-6.8.50.20090818-7.fc12.x86_64.rpm) fixes CFA problem.

Here is output of "bt full":

Core was generated by `/usr/libexec/pulse/gconf-helper'.
Program terminated with signal 11, Segmentation fault.
#0  0x00000000000895f0 in ?? ()
(gdb) set pagination off
(gdb) bt
#0  0x00000000000895f0 in ?? ()
#1  0x00007f802053a409 in CORBA_ORB_init (argc=0x7fff1dd6222c, argv=0x7fff1dd62210, orb_identifier=0x7f8023dbcab6 "orbit-local-orb", ev=0x7fff1dd621e0) at corba-orb.c:404
#2  0x00007f8023da0f63 in gconf_orb_get () at gconf-internals.c:2767
#3  0x00007f8023da10d3 in gconf_get_server (start_if_not_found=<value optimized out>, failure_log=0x8e5c00) at gconf-internals.c:2519
#4  0x00007f8023da12b2 in gconf_activate_server (start_if_not_found=0, error=0x0) at gconf-internals.c:2861
#5  0x00007f8023daeae4 in try_to_contact_server (err=<value optimized out>, start_if_not_found=<value optimized out>) at gconf.c:2241
#6  gconf_get_config_server (err=<value optimized out>, start_if_not_found=<value optimized out>) at gconf.c:2285
#7  0x00007f8023daf5cc in gconf_engine_connect (conf=0x8e5830, start_if_not_found=0, err=0x0) at gconf.c:359
#8  0x00007f8023dafedd in gconf_engine_get_default () at gconf.c:584
#9  0x00007f8023db7b14 in gconf_client_get_default () at gconf-client.c:433
#10 0x0000000000401014 in main (argc=<value optimized out>, argv=<value optimized out>) at modules/gconf/gconf-helper.c:104
(gdb) bt full
#0  0x00000000000895f0 in ?? ()
No symbol table info available.
#1  0x00007f802053a409 in CORBA_ORB_init (argc=0x7fff1dd6222c, argv=0x7fff1dd62210, orb_identifier=0x7f8023dbcab6 "orbit-local-orb", ev=0x7fff1dd621e0) at corba-orb.c:404
        thread_safe = <value optimized out>
        retval = <value optimized out>
        orb_if = {type = ORBIT_ROT_ORB, destroy = 0x7f802053a340 <CORBA_ORB_release_fn>}
#2  0x00007f8023da0f63 in gconf_orb_get () at gconf-internals.c:2767
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, _release = 0 '\000'}}
        argc = 1
        argv = {0x7f8023dbcab0 "gconf", 0x0}
        __PRETTY_FUNCTION__ = "gconf_orb_get"
#3  0x00007f8023da10d3 in gconf_get_server (start_if_not_found=<value optimized out>, failure_log=0x8e5c00) at gconf-internals.c:2519
        server = <value optimized out>
        ior = 0x8e8e60 "IOR:010000001600000049444c3a436f6e666967536572766572323a312e30000000030000000054424f500000000101020005000000554e4958000000000a0000006c6f63616c686f7374000000270000002f746d702f6f726269742d74626c2f6c696e"...
        orb = <value optimized out>
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, _release = 0 '\000'}}
#4  0x00007f8023da12b2 in gconf_activate_server (start_if_not_found=0, error=0x0) at gconf-internals.c:2861
        server = <value optimized out>
        failure_log = 0x8e5c00
        ev = {_id = 0x40 <Address 0x40 out of bounds>, _major = 0, _any = {_type = 0x0, _value = 0x3000000002, _release = 124 '|'}}
#5  0x00007f8023daeae4 in try_to_contact_server (err=<value optimized out>, start_if_not_found=<value optimized out>) at gconf.c:2241
        ev = {_id = 0x0, _major = 13, _any = {_type = 0x770000007c, _value = 0x5b0000006e, _release = 0 '\000'}}
#6  gconf_get_config_server (err=<value optimized out>, start_if_not_found=<value optimized out>) at gconf.c:2285
        __PRETTY_FUNCTION__ = "gconf_get_config_server"
#7  0x00007f8023daf5cc in gconf_engine_connect (conf=0x8e5830, start_if_not_found=0, err=0x0) at gconf.c:359
        cs = <value optimized out>
        db = 0x7fff1dd62570
        tries = 0
        ev = {_id = 0x0, _major = 0, _any = {_type = 0x0, _value = 0x0, _release = 0 '\000'}}
        __PRETTY_FUNCTION__ = "gconf_engine_connect"
#8  0x00007f8023dafedd in gconf_engine_get_default () at gconf.c:584
        conf = 0x8e5830
        source_path = 0x1 <Address 0x1 out of bounds>
        err = 0x0
#9  0x00007f8023db7b14 in gconf_client_get_default () at gconf-client.c:433
        client = <value optimized out>
        engine = <value optimized out>
        __PRETTY_FUNCTION__ = "gconf_client_get_default"
#10 0x0000000000401014 in main (argc=<value optimized out>, argv=<value optimized out>) at modules/gconf/gconf-helper.c:104
        g = <value optimized out>
        client = <value optimized out>
        modules = <value optimized out>
        m = <value optimized out>
(gdb)

Comment 28 Lennart Poettering 2009-09-01 16:50:41 UTC
So, let's summarize the current findings: 

- This thing only happens when gconf-helper is forked off PA, it does not happen when run directly.

- When the strstr() is replaced by a hand-written version (which does not use SSE or anything) the problem goes away

- The strings passed to the strstr() are both const static.

- The code executed before the strstr() is pretty trivial. There's not really much of a chance to fuck up things: http://git.0pointer.de/?p=pulseaudio.git;a=blob;f=src/modules/gconf/gconf-helper.c;h=fbd8cfd83808ef2659814ef4142173d5aa174d68;hb=HEAD#l104

- And valgrind is broken and no help

Comment 29 Lennart Poettering 2009-09-01 17:17:56 UTC
Seems LD_BIND_NOW triggers this issue:

$ LD_BIND_NOW=1 /usr/libexec/pulse/gconf-helper
Segmentation fault

*** This bug has been marked as a duplicate of bug 519226 ***