Ticket #512 (reopened defect)

Opened 3 years ago

Last modified 18 months ago

module-jack-sink disconnect

Reported by: matth45 Owned by: lennart
Milestone: Component: module-jack-*
Keywords: segfault jackd disconnect zombified Cc: geoffp@…

Description

I am using pulseaudio 0.9.14, the latest release in the Fedora 10 repos, and jackd 0.116.1.

When I use the module-jack-sink module I frequently get a segfault when playing audio through the pulseaudio daemon.

I get the following line in dmesg:

pulseaudio[7224]: segfault at 302d68ef ip 00bc058a sp b271efac error 4 in libjack.so.0.0.28[bb8000+10000]

I cannot successfully attach to the running pulseaudio process with gdb - it slows down too much and breaks the pulseaudio connection to jack. I also cannot force pulseaudio to leave a core file. I have run ulimit -c unlimited, and set /etc/security/limits.conf

*               soft    core            65536

and added the following line in daemon.conf:

rlimit-core = 65536

Please advise how I can get a core file.

I'm attaching my default.pa and daemon.conf files.

With the attached configuration files, I start jackd as:

/usr/bin/jackd -v -R -p128 -dalsa -dhw:0 -r48000 -p2048 -n2 -P -S -o2

I start pulseaudio as:

pulseaudio --log-level=debug

I attempt to play a file:

mplayer -ao pulse /usr/share/sounds/warning.wav

I have also used the alsa plugin, with the same effect:

aplay /usr/share/sounds/warning.wav

I get the following output:

$ pulseaudio --log-level=debug
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
I: caps.c: Dropping root privileges.
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
D: main.c: Started as real root: no, suid root: yes
I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling.
I: main.c: We're in the group 'pulse-rt', allowing real-time scheduling.
I: main.c: RLIMIT_RTPRIO is set to 99, allowing real-time scheduling.
I: main.c: RLIMIT_NICE is set to 40, allowing high-priority scheduling.
I: core-util.c: Successfully gained nice level -11.
D: main.c: Can realtime: yes, can high-priority: yes
I: main.c: Giving up CAP_NICE
D: main.c: Can realtime: yes, can high-priority: yes
I: main.c: This is PulseAudio 0.9.14
D: main.c: Compilation host: i386-redhat-linux-gnu
D: main.c: Compilation CFLAGS: -ggdb -Wall -W -Wextra -pedantic -pipe -Wno-long-long -Wvla -Wno-overlength-strings -Wconversion -Wundef -Wformat -Wlogical-op -Wpacked -Wformat-security -Wmissing-include-dirs -Wformat-nonliteral -Wold-style-definition -Wdeclaration-after-statement -Wfloat-equal -Wmissing-declarations -Wmissing-prototypes -Wstrict-prototypes -Wredundant-decls -Wmissing-noreturn -Wshadow -Wendif-labels -Wpointer-arith -Wcast-align -Wwrite-strings -Wno-unused-parameter -ffast-math
D: main.c: Running on host: Linux i686 2.6.27.19-170.2.35.fc10.i686 #1 SMP Mon Feb 23 13:21:22 EST 2009
I: main.c: Page size is 4096 bytes
D: main.c: Compiled with Valgrind support: no
D: main.c: Running in valgrind mode: no
D: main.c: Optimized build: no
I: main.c: Machine ID is 03915f3e108fe94a48048100463a06ad.
I: main.c: Using runtime directory /home/media/.pulse/03915f3e108fe94a48048100463a06ad:runtime.
I: main.c: Using state directory /home/media/.pulse.
I: main.c: Running in system mode: no
W: pid.c: Stale PID file, overwriting.
I: main.c: Fresh high-resolution timers available! Bon appetit!
D: memblock.c: Using shared memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65496
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-esound-protocol-unix.so': success
I: module.c: Loaded "module-esound-protocol-unix" (index: #0; argument: "").
I: module.c: Loaded "module-native-protocol-unix" (index: #1; argument: "").
I: module.c: Loaded "module-esound-protocol-tcp" (index: #2; argument: "").
I: module.c: Loaded "module-native-protocol-tcp" (index: #3; argument: "").
I: module-stream-restore.c: Sucessfully opened database file '/home/media/.pulse/03915f3e108fe94a48048100463a06ad:stream-volumes.i386-redhat-linux-gnu.gdbm'.
I: module.c: Loaded "module-stream-restore" (index: #4; argument: "").
I: module-device-restore.c: Sucessfully opened database file '/home/media/.pulse/03915f3e108fe94a48048100463a06ad:device-volumes.i386-redhat-linux-gnu.gdbm'.
I: module.c: Loaded "module-device-restore" (index: #5; argument: "").
I: module-default-device-restore.c: Saved default sink 'puff-jack-output' not existant, not restoring default sink setting.
I: module-default-device-restore.c: Saved default source 'puff-jack-output.monitor' not existant, not restoring default source setting.
I: module.c: Loaded "module-default-device-restore" (index: #6; argument: "").
I: module.c: Loaded "module-rescue-streams" (index: #7; argument: "").
D: module-always-sink.c: Autoloading null-sink as no other sinks detected.
I: module-device-restore.c: Restoring volume for sink auto_null.
I: module-device-restore.c: Restoring mute state for sink auto_null.
I: sink.c: Created sink 0 "auto_null" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-device-restore.c: Restoring volume for source auto_null.monitor.
I: module-device-restore.c: Restoring mute state for source auto_null.monitor.
I: source.c: Created source 0 "auto_null.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
D: module-null-sink.c: Thread starting up
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module.c: Loaded "module-null-sink" (index: #8; argument: "sink_name=auto_null").
I: module.c: Loaded "module-always-sink" (index: #9; argument: "").
I: client.c: Created 0 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session2"
D: module-console-kit.c: Added new session /org/freedesktop/ConsoleKit/Session2
I: module.c: Loaded "module-console-kit" (index: #10; argument: "").
I: module.c: Loaded "module-position-event-sounds" (index: #11; argument: "").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-jack-sink.so': success
I: module-jack-sink.c: Successfully connected as 'PulseAudio JACK Sink'
I: module-device-restore.c: Restoring volume for sink puff-jack-output.
I: module-device-restore.c: Restoring mute state for sink puff-jack-output.
I: sink.c: Created sink 1 "puff-jack-output" with sample spec float32le 6ch 48000Hz and channel map front-left,front-right,rear-left,rear-right,front-center,lfe
I: module-device-restore.c: Restoring volume for source puff-jack-output.monitor.
I: module-device-restore.c: Restoring mute state for source puff-jack-output.monitor.
I: source.c: Created source 1 "puff-jack-output.monitor" with sample spec float32le 6ch 48000Hz and channel map front-left,front-right,rear-left,rear-right,front-center,lfe
D: module-jack-sink.c: Thread starting up
I: core-util.c: Successfully enabled SCHED_FIFO scheduling for thread, with priority 5.
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+28
I: module-jack-sink.c: JACK thread starting up.
I: core-util.c: Successfully enabled SCHED_FIFO scheduling for thread, with priority 9.
I: module-always-sink.c: A new sink has been discovered. Unloading null-sink.
I: module.c: Loaded "module-jack-sink" (index: #12; argument: "sink_name=puff-jack-output channels=6 connect=false").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-gconf.so': success
I: module.c: Loaded "module-gconf" (index: #13; argument: "").
I: main.c: Daemon startup complete.
I: module.c: Unloading "module-null-sink" (index: #8).
D: module-rescue-streams.c: No sink inputs to move away.
D: module-rescue-streams.c: No source outputs to move away.
D: core-subscribe.c: Dropped redundant event due to remove event.
D: core-subscribe.c: Dropped redundant event due to remove event.
D: module-null-sink.c: Thread shutting down
I: sink.c: Freeing sink 0 "auto_null"
I: source.c: Freeing source 0 "auto_null.monitor"
I: module.c: Unloaded "module-null-sink" (index: #8).
D: core-subscribe.c: Dropped redundant event due to remove event.
D: module-console-kit.c: dbus: interface=org.freedesktop.DBus, path=/org/freedesktop/DBus, member=NameAcquired
I: client.c: Created 1 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 14, local 14
I: protocol-native.c: Got credentials: uid=500 gid=500 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: yes
I: module-stream-restore.c: Restoring device for stream sink-input-by-application-name:MPlayer.
D: module-stream-restore.c: Not restoring volume for sink input sink-input-by-application-name:MPlayer, because already set.
D: module-stream-restore.c: Not restoring mute state for sink input sink-input-by-application-name:MPlayer, because already set.
D: resampler.c: Channel matrix:
D: resampler.c:        I00   I01 
D: resampler.c:     +------------
D: resampler.c: O00 | 1.000 0.000
D: resampler.c: O01 | 0.000 1.000
D: resampler.c: O02 | 1.000 0.000
D: resampler.c: O03 | 0.000 1.000
D: resampler.c: O04 | 0.500 0.500
D: resampler.c: O05 | 0.000 0.000
I: resampler.c: Using resampler 'speex-float-3'
I: resampler.c: Using float32le as working format.
I: resampler.c: Choosing speex quality setting 3.
D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=24, prebuf=0, minreq=1 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=33554448, tlength=33554448, base=24, prebuf=0, minreq=24 maxrewind=0
I: sink-input.c: Created input 0 "audio stream" on puff-jack-output with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: protocol-native.c: Requested tlength=250.00 ms, minreq=20.00 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
D: memblockq.c: memblockq requested: maxlength=4194304, tlength=44100, base=4, prebuf=44100, minreq=3528 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=44100, base=4, prebuf=44100, minreq=3528 maxrewind=0
I: protocol-native.c: Final latency 460.00 ms = 210.00 ms + 2*20.00 ms + 210.00 ms
W: module-jack-sink.c: JACK error >zombified - calling shutdown handler<
I: module-jack-sink.c: JACK thread shutting down..
D: protocol-native.c: Requesting rewind due to end of underrun.
I: module.c: Unloading "module-jack-sink" (index: #12).
D: module-always-sink.c: Autoloading null-sink as no other sinks detected.
I: module-device-restore.c: Restoring volume for sink auto_null.
I: module-device-restore.c: Restoring mute state for sink auto_null.
I: sink.c: Created sink 2 "auto_null" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: module-device-restore.c: Restoring volume for source auto_null.monitor.
I: module-device-restore.c: Restoring mute state for source auto_null.monitor.
I: source.c: Created source 2 "auto_null.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
D: module-null-sink.c: Thread starting up
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module.c: Loaded "module-null-sink" (index: #14; argument: "sink_name=auto_null").
Segmentation fault

Attachments

daemon.conf (301 bytes) - added by matth45 3 years ago.
daemon.conf configuration file
default.pa (1.0 kB) - added by matth45 3 years ago.
default.pa configuration file
default.2.pa (486 bytes) - added by matth45 3 years ago.
Simplified default.pa (no longer causes segfault, but still disconnects from jackd)
pulseaudio log and backtrace.txt (34.6 kB) - added by geoffp 18 months ago.
Backtrace of the issue, attempt at playing a song in Rhythmbox

Change History

Changed 3 years ago by matth45

daemon.conf configuration file

Changed 3 years ago by matth45

default.pa configuration file

  Changed 3 years ago by matth45

  • keywords jackd disconnect zombified added
  • severity changed from normal to major

Using the attached simplified default.pa configuration file pulseaudio no longer causes a segmentation fault, but it loses its connection to jackd (looking at the debug output above the lost connection seems to be the root cause of the error).

Here is the output for the new default.pa

$ pulseaudio --log-level=debug
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
I: caps.c: Dropping root privileges.
I: caps.c: Limited capabilities successfully to CAP_SYS_NICE.
D: main.c: Started as real root: no, suid root: yes
I: main.c: We're in the group 'pulse-rt', allowing high-priority scheduling.
I: main.c: We're in the group 'pulse-rt', allowing real-time scheduling.
I: main.c: RLIMIT_RTPRIO is set to 99, allowing real-time scheduling.
I: main.c: RLIMIT_NICE is set to 40, allowing high-priority scheduling.
I: core-util.c: Successfully gained nice level -11.
D: main.c: Can realtime: yes, can high-priority: yes
I: main.c: Giving up CAP_NICE
D: main.c: Can realtime: yes, can high-priority: yes
I: main.c: This is PulseAudio 0.9.14
D: main.c: Compilation host: i386-redhat-linux-gnu
D: main.c: Compilation CFLAGS: -ggdb -Wall -W -Wextra -pedantic -pipe -Wno-long-long -Wvla -Wno-overlength-strings -Wconversion -Wundef -Wformat -Wlogical-op -Wpacked -Wformat-security -Wmissing-include-dirs -Wformat-nonliteral -Wold-style-definition -Wdeclaration-after-statement -Wfloat-equal -Wmissing-declarations -Wmissing-prototypes -Wstrict-prototypes -Wredundant-decls -Wmissing-noreturn -Wshadow -Wendif-labels -Wpointer-arith -Wcast-align -Wwrite-strings -Wno-unused-parameter -ffast-math
D: main.c: Running on host: Linux i686 2.6.27.19-170.2.35.fc10.i686 #1 SMP Mon Feb 23 13:21:22 EST 2009
I: main.c: Page size is 4096 bytes
D: main.c: Compiled with Valgrind support: no
D: main.c: Running in valgrind mode: no
D: main.c: Optimized build: no
I: main.c: Machine ID is 03915f3e108fe94a48048100463a06ad.
I: main.c: Using runtime directory /home/media/.pulse/03915f3e108fe94a48048100463a06ad:runtime.
I: main.c: Using state directory /home/media/.pulse.
I: main.c: Running in system mode: no
W: pid.c: Stale PID file, overwriting.
I: main.c: Fresh high-resolution timers available! Bon appetit!
D: memblock.c: Using shared memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65496
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-esound-protocol-unix.so': success
I: module.c: Loaded "module-esound-protocol-unix" (index: #0; argument: "").
I: module.c: Loaded "module-native-protocol-unix" (index: #1; argument: "").
I: module.c: Loaded "module-esound-protocol-tcp" (index: #2; argument: "").
I: module.c: Loaded "module-native-protocol-tcp" (index: #3; argument: "").
I: client.c: Created 0 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session2"
D: module-console-kit.c: Added new session /org/freedesktop/ConsoleKit/Session2
I: module.c: Loaded "module-console-kit" (index: #4; argument: "").
I: module.c: Loaded "module-position-event-sounds" (index: #5; argument: "").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-jack-sink.so': success
I: module-jack-sink.c: Successfully connected as 'PulseAudio JACK Sink'
I: sink.c: Created sink 0 "puff-jack-output" with sample spec float32le 6ch 48000Hz and channel map front-left,front-right,rear-left,rear-right,front-center,lfe
I: source.c: Created source 0 "puff-jack-output.monitor" with sample spec float32le 6ch 48000Hz and channel map front-left,front-right,rear-left,rear-right,front-center,lfe
D: module-jack-sink.c: Thread starting up
I: core-util.c: Successfully enabled SCHED_FIFO scheduling for thread, with priority 5.
D: rtpoll.c: Acquired POSIX realtime signal SIGRTMIN+29
I: module-jack-sink.c: JACK thread starting up.
I: core-util.c: Successfully enabled SCHED_FIFO scheduling for thread, with priority 9.
I: module.c: Loaded "module-jack-sink" (index: #6; argument: "sink_name=puff-jack-output channels=6 connect=false").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9/modules/module-gconf.so': success
I: module.c: Loaded "module-gconf" (index: #7; argument: "").
I: main.c: Daemon startup complete.
D: module-console-kit.c: dbus: interface=org.freedesktop.DBus, path=/org/freedesktop/DBus, member=NameAcquired
I: client.c: Created 1 "Native client (UNIX socket client)"
D: protocol-native.c: Protocol version: remote 14, local 14
I: protocol-native.c: Got credentials: uid=500 gid=500 success=1
D: protocol-native.c: SHM possible: yes
D: protocol-native.c: Negotiated SHM: yes
D: resampler.c: Channel matrix:
D: resampler.c:        I00   I01 
D: resampler.c:     +------------
D: resampler.c: O00 | 1.000 0.000
D: resampler.c: O01 | 0.000 1.000
D: resampler.c: O02 | 1.000 0.000
D: resampler.c: O03 | 0.000 1.000
D: resampler.c: O04 | 0.500 0.500
D: resampler.c: O05 | 0.000 0.000
I: resampler.c: Using resampler 'speex-float-3'
I: resampler.c: Using float32le as working format.
I: resampler.c: Choosing speex quality setting 3.
D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=24, prebuf=0, minreq=1 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=33554448, tlength=33554448, base=24, prebuf=0, minreq=24 maxrewind=0
I: sink-input.c: Created input 0 "audio stream" on puff-jack-output with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: protocol-native.c: Requested tlength=250.00 ms, minreq=20.00 ms
D: protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
D: memblockq.c: memblockq requested: maxlength=4194304, tlength=44100, base=4, prebuf=44100, minreq=3528 maxrewind=0
D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=44100, base=4, prebuf=44100, minreq=3528 maxrewind=0
I: protocol-native.c: Final latency 460.00 ms = 210.00 ms + 2*20.00 ms + 210.00 ms
W: module-jack-sink.c: JACK error >zombified - calling shutdown handler<
I: module-jack-sink.c: JACK thread shutting down..
D: protocol-native.c: Requesting rewind due to end of underrun.
I: module.c: Unloading "module-jack-sink" (index: #6).
I: sink-input.c: Freeing input 0 "audio stream"
D: module-jack-sink.c: Thread shutting down
I: sink.c: Freeing sink 0 "puff-jack-output"
I: source.c: Freeing source 0 "puff-jack-output.monitor"
I: module.c: Unloaded "module-jack-sink" (index: #6).
I: client.c: Freed 1 "MPlayer"
I: protocol-native.c: Connection died.

Changed 3 years ago by matth45

Simplified default.pa (no longer causes segfault, but still disconnects from jackd)

  Changed 3 years ago by matth45

I notice that if I start jackd with a larger period (eg. 4096) as:

/usr/bin/jackd -v -R -p128 -dalsa -dhw:0 -r48000 -p4096 -n2 -P -S -o2

I do not get disconnects. (I do get higher latency). I also get the following messages repeated as long as a client is connected to the pulseaudio daemon:

D: memblock.c: Memory block too large for pool: 98304 > 65536
D: memblock.c: Memory block too large for pool: 98304 > 65536
D: memblock.c: Memory block too large for pool: 98304 > 65536
D: memblock.c: Memory block too large for pool: 98304 > 65536

When I attempt to set shm-size-bytes in daemon.conf much larger that 1024*1024*64 pulseaudio fails to start with the message:

E: shm.c: Assertion 'size <= ((pa_align(1024*1024*64)))' failed at pulsecore/shm.c:93, function pa_shm_create_rw(). Aborting.
Aborted

A period of even 2048 still causes the frequent disconnects as seen above.

  Changed 3 years ago by lennart

  • status changed from new to closed
  • resolution set to duplicate

Please provide a stack trace of the segfault.

http://www.pulseaudio.org/wiki/Community#BugsPatchesTranslations

Duplicate of #472.

  Changed 3 years ago by matth45

  • status changed from closed to reopened
  • resolution duplicate deleted
  • summary changed from module-jack-sink segfault to module-jack-sink disconnect

I have two problems here:

First, I am having the same issue as the OP in #472, in that I cannot get a core file to be generated, and I cannot attach gdb to the process without interrupting the connection to jack. That is why I asked you for advice on getting a backtrace. I understand that one is needed to debug the segfault, I simply cannot give it to you without some input.

Second, I think there are actually two bugs here, and I am no longer interested in the segfault bug. There is a segfault caused when pulseaudio tries to switch from the jack-sink to another sink, and there is the bug that causes pulseaudio to disconnect from jack in the first place. I suggest you use #472 to track the segfault and use this bug to track the disconnect issue, which occurs before the segfault. Please read my description above!

I have changed the title accordingly.

Thanks

  Changed 3 years ago by stack

I've noticed that disabling jack realtime doen the module-jack-* not to disconnect, also the segfault is not happening. This is not a solution nor a workaround, but hopefully a help to the debug.

  Changed 3 years ago by lennart

  • status changed from reopened to closed
  • resolution set to worksforme

There was some breakage in this area in JACK a while ago. I assume that this problem does not exist anymore. If it does feel free to reopen.

Changed 18 months ago by geoffp

Backtrace of the issue, attempt at playing a song in Rhythmbox

follow-up: ↓ 9   Changed 18 months ago by geoffp

  • cc geoffp@… added
  • status changed from closed to reopened
  • resolution worksforme deleted

I still have this, unfortunately. I've attached a log + backtrace. The segfault for me occurs at the first time I play a song with Rhythmbox after starting Jack + Pulse.

  Changed 18 months ago by geoffp

  • pulseaudio 0.9.21-63-gd3efa-dirty
  • jackd version 0.118.0 tmpdir /dev/shm protocol 24

in reply to: ↑ 7   Changed 18 months ago by tanuk

Replying to geoffp:

I still have this, unfortunately. I've attached a log + backtrace. The segfault for me occurs at the first time I play a song with Rhythmbox after starting Jack + Pulse.

I don't see any segfault in that backtrace. Segmentation fault means that a program crashes due to trying to access memory that it doesn't own. In that backtrace pulseaudio didn't crash - you stopped it yourself using ctrl-c.

I assume you're running jackd in the realtime mode. How small buffers are you using in jackd? If they are very small, does increasing the jackd buffer size help? AFAIK the most likely reason for zombification is that the client (in this case pulseaudio) doesn't return from its processing callback fast enough. If you can't use pulseaudio with reasonably small buffers in jackd, then I guess this bug can be left open... It's another matter whether anyone knows how to fix this.

Note: See TracTickets for help on using tickets.