Created attachment 127210 [details] [review]
debug mutex failure

It's not a glib issue. Pulseaudio doesn't use glib. The problem is that pthread_mutex_init() fails in an unexpected way.

I attached a patch that prints a bit more information when the failure happens.

I applied the patch and reiinstalled (in version 9.0).  I ran

pulseaudio --help
and 
pulsaudio --start

Both aborted with:

E: [pulseaudio] mutex-posix.c: Assertion 'pthread_mutex_lock(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:90, function pa_mutex_lock(). Aborting.

Here's the backtrace from the core dump:

Program terminated with signal SIGABRT, Aborted.
#0  0x00002b33134fb979 in raise () from /lib64/libc.so.6

Thread 1 (Thread 0x2b330e285c00 (LWP 32450)):
#0  0x00002b33134fb979 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00002b33134fd088 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00002b330ed31fc2 in pa_mutex_lock (m=m@entry=0x1c75b70)
    at pulsecore/mutex-posix.c:94
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#3  0x00002b330ed1c5fa in pa_once_begin (
    control=control@entry=0x2b330ef5ec50 <_once.4859>) at pulsecore/once.c:44
        m = 0x1c75b70
#4  0x00002b330ed0e0d0 in pa_init_i18n () at pulsecore/i18n.c:30
        _once = {mutex = {ptr = {value = 29842288}}, done = {value = 0}}
#5  0x0000000000405b5c in main (argc=2, argv=0x7ffe13d77d58)
    at daemon/main.c:473
        c = 0x0
        buf = 0x0
        conf = 0x0
        mainloop = 0x0
        s = <optimized out>
        r = 0
        retval = 1
        d = 0
        valid_pid_file = false
        ltdl_init = false
        n_fds = 0
        passed_fds = 0x1c4b0b0
        e = <optimized out>
        daemon_pipe = {-1, -1}
        daemon_pipe2 = {-1, -1}
        autospawn_fd = -1
        autospawn_locked = false
        server_lookup = 0x0
        lookup_service_bus = 0x0
        server_bus = 0x0
        start_server = <optimized out>
        __func__ = "main"
        __PRETTY_FUNCTION__ = "main"

Ok, the assertion is different than before. This is not caused by the patch, maybe older pulseaudio versions crashed differently?

Are you sure that the patching was successful and you're running the patched version of pulseaudio? The line number in the new assertion matches unpatched code.

Anyway, I'll attach another patch that will show what error pthread_mutex_lock() returns. It also fixes a bug in the first patch that I made yesterday. This second patch is meant to be applied on top of the first patch.

Created attachment 127236 [details] [review]
second patch

It came to my mind that one possible problem with libpthread is that pulseaudio may be linked against libpthread-stubs (as the name suggests, it's a crippled version of libpthread). What does "ldd /usr/bin/pulseaudio | grep pthread" print?

Thanks for the reply.

Your hunch was correct:

ldd `which pulseaudio` | grep pthread
	libpthread-stubs.so.0 => /usr/lib64/libpthread-stubs.so.0 (0x00002b8033b44000)
	libpthread.so.0 => /lib64/libpthread.so.0 (0x00002b803636a000)

which is odd

ls -l /lib64/*pthread*
-rwxr-xr-x 1 root root 134893 Jan 28  2015 /lib64/libpthread-2.17.so*
lrwxrwxrwx 1 root root     18 Jan 28  2015 /lib64/libpthread.so.0 -> libpthread-2.17.so*

ls -l /usr/lib64/libpthread*
-rw-r--r-- 1 root root 382370 Jan 28  2015 /usr/lib64/libpthread.a
-rw-r--r-- 1 root root   1748 Jan 28  2015 /usr/lib64/libpthread_nonshared.a
-rw-r--r-- 1 root root 401612 Sep 15  2013 /usr/lib64/libpthread_p.a
-rw-r--r-- 1 root root    222 Jan 28  2015 /usr/lib64/libpthread.so
-rw-r--r-- 1 root root   1532 Oct  2 14:50 /usr/lib64/libpthread-stubs.a
-rwxr-xr-x 1 root root    976 Oct  2 14:50 /usr/lib64/libpthread-stubs.la*
lrwxrwxrwx 1 root root     25 Oct  2 14:50 /usr/lib64/libpthread-stubs.so -> libpthread-stubs.so.0.0.0*
lrwxrwxrwx 1 root root     25 Oct  2 14:50 /usr/lib64/libpthread-stubs.so.0 -> libpthread-stubs.so.0.0.0*
-rwxr-xr-x 1 root root   4200 Oct  2 14:50 /usr/lib64/libpthread-stubs.so.0.0.0*

Note the big difference in date/time for the libpthread-stubs and libpthread-2.17.so files

I also reapplied both patches to a clean source tree--both seemed to have appied properly (no errors were reported).    Running

pulseaudo --start 

generates a massive core file;  here are the initial parts:

Core was generated by `pulseaudio --start'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
71	    if (pa_once_begin(control)) {

Thread 1 (Thread 0x2b2f9c093c00 (LWP 1980)):
#0  pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#1  0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#2  cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#3  pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#4  0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#5  0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#6  0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#7  0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#8  cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#9  pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#10 0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#11 0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#12 0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#13 0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#14 cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#15 pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#16 0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#17 0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#18 0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#19 0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#20 cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#21 pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#22 0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#23 0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#24 0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#25 0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#26 cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#27 pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#28 0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#29 0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#30 0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#31 0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#32 cstrerror_tls_get () at pulsecore/core-error.c:39
No locals.
#33 pa_cstrerror (errnum=22) at pulsecore/core-error.c:49
        original = 0x0
        translated = <optimized out>
        errbuf = '\000' <repeats 112 times>, "\200\313֜/+\000\000\200\357\320\000\000\000\000"
        __func__ = "pa_cstrerror"
#34 0x00002b2f9cb3ff87 in pa_mutex_lock (m=m@entry=0xd0ef80)
    at pulsecore/mutex-posix.c:100
        r = <optimized out>
        __func__ = "pa_mutex_lock"
        __PRETTY_FUNCTION__ = "pa_mutex_lock"
#35 0x00002b2f9cb2a5fa in pa_once_begin (
    control=0x2b2f9cd6cb80 <cstrerror_tls>) at pulsecore/once.c:44
        m = 0xd0ef80
#36 0x00002b2f9cb2a75b in pa_run_once (control=0x2b2f9cd6cb80 <cstrerror_tls>, 
    func=0x2b2f9cb12010 <cstrerror_tls_init>) at pulsecore/once.c:71
        __func__ = "pa_run_once"
        __PRETTY_FUNCTION__ = "pa_run_once"
#37 0x00002b2f9cb12056 in cstrerror_tls_obj () at pulsecore/core-error.c:39
No locals.
#38 cstrerror_tls_get () at pulsecore/core-error.c:39

Ok, the patch caused an infinite loop, since the function that was supposed to translate the pthread_mutex_lock() error code to a string uses pthread_mutex_lock() too...

Anyway, I think it's safe to assume that libpthread-stubs is the culprit here. I don't know how exactly it gets pulled in. I think it's related to libxcb. Maybe any program that uses libxcb will get linked to libpthread-stubs. You could build pulseaudio without X11 support, and you won't lose much functionality if you do that, but this won't solve the problems with all other applications.

It's possible to use libxcb also without libpthread-stubs.so.0 being installed, but I don't have exact instructions for how to do that. I know that Debian used to have a package that installed the libpthread-stubs library, but nowadays it doesn't. The libpthread-stubs0-dev package still exists, but at least on Intel architectures it doesn't contain anything else than a pkg-config file.

I agree, libpthread-stubs is the problem.   Unfortunatley, my version of libxcb needs pthread-stubs.
I tried the following:

1.  A locally built X including libxcb and pthread-stubs.   PA fails

2.  A locally built libxcb and the distribution's pthread-stubs.  PA fails

3.  A locally built pulseaudio with --disable-x11.  PA fails, 

pulseaudio --start
E: [pulseaudio] main.c: Daemon startup failed.

ldd `which pulseaudio` | grep thread
	libpthread.so.0 => /lib64/libpthread.so.0 (0x00002b7f16dea000)

To get more log messages, try running pulseaudio in a terminal without the --start parameter (--start makes pulseaudio start in the background). Also, -vv will increase the logging level to maximum.

Created attachment 127310 [details]
pulseaudio -vv

The output log from running pulseaudio -vv

E: [pulseaudio] module-console-kit.c: GetSessionsForUnixUser() call failed: org.freedesktop.DBus.Error.Spawn.ChildExited: Launch helper exited with unknown return code 1

It looks like ConsoleKit isn't running, and dbus-daemon fails to start it. Maybe it's not installed at all?

It seems that we don't have a configuration option for disabling module-console-kit, so if you don't use ConsoleKit, you have to remove the module from default.pa (I don't know where you installed pulseaudio, so the file is under /usr/local/etc or something else depending on the configure parameters).

I couldn't find a flag to turn off ConsoleKit but was able to get rid of it in the configuration file as you suggested.  This fixes pulseaudio, but there are still plenty of similar probles with important parts of gnome. I'm going to track down the ConsoleKit issue.

Thanks for your help.

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/42.