Bug 103528

Summary:	[abrt] Crash when switching profiles (headset -> speakers)
Product:	PulseAudio	Reporter:	Raman Gupta <rocketraman>
Component:	daemon	Assignee:	pulseaudio-bugs
Status:	RESOLVED FIXED	QA Contact:	pulseaudio-bugs
Severity:	normal
Priority:	medium	CC:	lennart
Version:	unspecified
Hardware:	x86-64 (AMD64)
OS:	All
Whiteboard:
i915 platform:		i915 features:
Bug Depends on:
Bug Blocks:	102546
Attachments:	pactl list just before crash command 0001-echo-cancel-ignore-remaining-canceller-messages-afte.patch

Description Raman Gupta 2017-10-31 17:09:57 UTC

(Filing a new bug as requested by @Tanu Kaskinen @ https://bugs.freedesktop.org/show_bug.cgi?id=93443#c28).

PA 11.1 on Fedora 26 (pulseaudio-11.1-2.fc26.src.rpm)

I can reproduce a crash reliably by restarting Chrome (Stable 62, 64-bit), playing a YouTube video, and then switching profiles from headset to speakers. The command that causes the crash is:

pactl set-card-profile alsa_card.pci-0000_00_1b.0 output:analog-surround-40+input:analog-stereo

This causes the crash.

At this point Chrome continues to output audio correctly, but loses access to the mic. Subsequent switches between headset and speakers work fine, but Chrome's access to the mic remains broken.

Once Chrome is restarted mic access is restored, but the crash can easily be reproduced again.

Another interesting thing is that a switch in the opposite direction -- from speakers to headset -- does not cause a crash.

I will attach the output of `pactl list` just before the set-card-profile command, as well as the abrt data which contains the back-trace.

Comment 1 Raman Gupta 2017-10-31 17:10:33 UTC

Created attachment 135189 [details]
pactl list just before crash command

Comment 2 Tanu Kaskinen 2017-11-02 10:40:12 UTC

Thanks! I'm marking this as a release blocker.

You forgot to attach the abrt data, by the way.

Comment 3 Raman Gupta 2017-11-03 07:35:26 UTC

Tanu, for some reason the coredump generated by abrt is always truncated:

BFD: Warning: /var/spool/abrt/ccpp-2017-11-03-02:59:39.422477-24210/coredump is truncated: expected core file size >= 4670910464, found: 2147483648.

When I try to reproduce the problem by running pulseaudio under gdb so I can get 
a backtrace, so far I have been unable to reproduce it -- though interestingly, if Zoiper with echo cancelling module is running, the actual switch doesn't work, there is no crash -- if Zoiper is not running then the switch (usually) works perfectly.

Will report back with a backtrace if I can get one.

Comment 4 Raman Gupta 2017-11-03 22:21:42 UTC

Abrt seems to be truncating the coredump at the 2gb boundary. Not sure why the pulseaudio coredump should be so large in the first place, but I'll look into it.

Comment 5 Raman Gupta 2017-11-08 00:13:45 UTC

Here is the backtrace:

(gdb) bt
#0  0x00005555559ba140 in ?? ()
#1  0x00007ffff7b973f6 in pa_object_cast (o=0x555555992560) at pulsecore/object.h:62
#2  pa_source_assert_ref (o=0x555555992560) at pulsecore/source.h:254
#3  pa_source_set_volume (s=0x555555992560, volume=volume@entry=0x7fffffffcb20, send_msg=send_msg@entry=true, save=save@entry=false) at pulsecore/source.c:1605
#4  0x00007fffa4f4a131 in canceller_process_msg_cb (o=<optimized out>, code=<optimized out>, userdata=0x5555, offset=<optimized out>, chunk=<optimized out>) at modules/echo-cancel/module-echo-cancel.c:1565
#5  0x00007ffff7b995d3 in asyncmsgq_read_cb (api=0x55555576cb28, e=<optimized out>, fd=<optimized out>, events=<optimized out>, userdata=<optimized out>) at pulsecore/thread-mq.c:69
#6  0x00007ffff78fe888 in dispatch_pollfds (m=0x55555576cad0) at pulse/mainloop.c:655
#7  pa_mainloop_dispatch (m=m@entry=0x55555576cad0) at pulse/mainloop.c:898
#8  0x00007ffff78fec5e in pa_mainloop_iterate (m=0x55555576cad0, block=<optimized out>, retval=0x7fffffffcd38) at pulse/mainloop.c:929
#9  0x00007ffff78fece0 in pa_mainloop_run (m=0x55555576cad0, retval=0x7fffffffcd38) at pulse/mainloop.c:944
#10 0x000055555555b33e in main (argc=<optimized out>, argv=<optimized out>) at daemon/main.c:1142
(gdb) 
#0  0x00005555559ba140 in ?? ()
#1  0x00007ffff7b973f6 in pa_object_cast (o=0x555555992560) at pulsecore/object.h:62
#2  pa_source_assert_ref (o=0x555555992560) at pulsecore/source.h:254
#3  pa_source_set_volume (s=0x555555992560, volume=volume@entry=0x7fffffffcb20, send_msg=send_msg@entry=true, save=save@entry=false) at pulsecore/source.c:1605
#4  0x00007fffa4f4a131 in canceller_process_msg_cb (o=<optimized out>, code=<optimized out>, userdata=0x5555, offset=<optimized out>, chunk=<optimized out>) at modules/echo-cancel/module-echo-cancel.c:1565
#5  0x00007ffff7b995d3 in asyncmsgq_read_cb (api=0x55555576cb28, e=<optimized out>, fd=<optimized out>, events=<optimized out>, userdata=<optimized out>) at pulsecore/thread-mq.c:69
#6  0x00007ffff78fe888 in dispatch_pollfds (m=0x55555576cad0) at pulse/mainloop.c:655
#7  pa_mainloop_dispatch (m=m@entry=0x55555576cad0) at pulse/mainloop.c:898
#8  0x00007ffff78fec5e in pa_mainloop_iterate (m=0x55555576cad0, block=<optimized out>, retval=0x7fffffffcd38) at pulse/mainloop.c:929
#9  0x00007ffff78fece0 in pa_mainloop_run (m=0x55555576cad0, retval=0x7fffffffcd38) at pulse/mainloop.c:944
#10 0x000055555555b33e in main (argc=<optimized out>, argv=<optimized out>) at daemon/main.c:1142
(gdb) 
#0  0x00005555559ba140 in ?? ()
#1  0x00007ffff7b973f6 in pa_object_cast (o=0x555555992560) at pulsecore/object.h:62
#2  pa_source_assert_ref (o=0x555555992560) at pulsecore/source.h:254
#3  pa_source_set_volume (s=0x555555992560, volume=volume@entry=0x7fffffffcb20, send_msg=send_msg@entry=true, save=save@entry=false) at pulsecore/source.c:1605
#4  0x00007fffa4f4a131 in canceller_process_msg_cb (o=<optimized out>, code=<optimized out>, userdata=0x5555, offset=<optimized out>, chunk=<optimized out>) at modules/echo-cancel/module-echo-cancel.c:1565
#5  0x00007ffff7b995d3 in asyncmsgq_read_cb (api=0x55555576cb28, e=<optimized out>, fd=<optimized out>, events=<optimized out>, userdata=<optimized out>) at pulsecore/thread-mq.c:69
#6  0x00007ffff78fe888 in dispatch_pollfds (m=0x55555576cad0) at pulse/mainloop.c:655
#7  pa_mainloop_dispatch (m=m@entry=0x55555576cad0) at pulse/mainloop.c:898
#8  0x00007ffff78fec5e in pa_mainloop_iterate (m=0x55555576cad0, block=<optimized out>, retval=0x7fffffffcd38) at pulse/mainloop.c:929
#9  0x00007ffff78fece0 in pa_mainloop_run (m=0x55555576cad0, retval=0x7fffffffcd38) at pulse/mainloop.c:944
#10 0x000055555555b33e in main (argc=<optimized out>, argv=<optimized out>) at daemon/main.c:1142
(gdb) 
#0  0x00005555559ba140 in ?? ()
#1  0x00007ffff7b973f6 in pa_object_cast (o=0x555555992560) at pulsecore/object.h:62
#2  pa_source_assert_ref (o=0x555555992560) at pulsecore/source.h:254
#3  pa_source_set_volume (s=0x555555992560, volume=volume@entry=0x7fffffffcb20, send_msg=send_msg@entry=true, save=save@entry=false) at pulsecore/source.c:1605
#4  0x00007fffa4f4a131 in canceller_process_msg_cb (o=<optimized out>, code=<optimized out>, userdata=0x5555, offset=<optimized out>, chunk=<optimized out>) at modules/echo-cancel/module-echo-cancel.c:1565
#5  0x00007ffff7b995d3 in asyncmsgq_read_cb (api=0x55555576cb28, e=<optimized out>, fd=<optimized out>, events=<optimized out>, userdata=<optimized out>) at pulsecore/thread-mq.c:69
#6  0x00007ffff78fe888 in dispatch_pollfds (m=0x55555576cad0) at pulse/mainloop.c:655
#7  pa_mainloop_dispatch (m=m@entry=0x55555576cad0) at pulse/mainloop.c:898
#8  0x00007ffff78fec5e in pa_mainloop_iterate (m=0x55555576cad0, block=<optimized out>, retval=0x7fffffffcd38) at pulse/mainloop.c:929
#9  0x00007ffff78fece0 in pa_mainloop_run (m=0x55555576cad0, retval=0x7fffffffcd38) at pulse/mainloop.c:944
#10 0x000055555555b33e in main (argc=<optimized out>, argv=<optimized out>) at daemon/main.c:1142

Comment 6 Tanu Kaskinen 2017-11-08 14:11:38 UTC

It looks like u->source is being accessed after it has been freed. I found out one possible reason for that. I'll attach a patch, can you test it? I didn't try reproducing the crash myself yet, because setting up things takes some effort.

Comment 7 Tanu Kaskinen 2017-11-08 14:12:36 UTC

Created attachment 135300 [details] [review]
0001-echo-cancel-ignore-remaining-canceller-messages-afte.patch

Comment 8 Raman Gupta 2017-11-08 18:33:29 UTC

I've tested the patch on top of pulseaudio-11.1-5.fc26 which is in Fedora updates-testing.

So far I am unable to reproduce the crash, and everything is working great -- audio is switching between headset and speakers just as it should!

Comment 9 Tanu Kaskinen 2017-11-09 12:13:33 UTC

Great! Thanks for testing. I submitted the patch to the mailing list:
https://patchwork.freedesktop.org/patch/187359/

Comment 10 Tanu Kaskinen 2017-11-21 13:20:13 UTC

The fix is now in master.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.