Bug 104958

Summary: Crash when enabling echo cancellation and also specifying PULSE_PROP="filter.want=echo-cancel media.role=phone"
Product: PulseAudio Reporter: Raman Gupta <rocketraman>
Component: modulesAssignee: pulseaudio-bugs
Status: RESOLVED FIXED QA Contact: pulseaudio-bugs
Severity: normal    
Priority: medium CC: lennart
Version: unspecified   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: i915 features:
Bug Depends on:    
Bug Blocks: 102546    
Attachments: gdb backtrace with symbols
Output of pa
Patch ignore monitor sources

Description Raman Gupta 2018-02-06 00:49:04 UTC
Created attachment 137179 [details]
gdb backtrace with symbols

I am able to consistently reproduce a SEGFAULT on 11.1 (RPM Fedora pulseaudio-11.1-7.fc27.x86_64, with the two echo cancellation patches @ https://patchwork.freedesktop.org/patch/187359/ applied on top.

To do this, I run pulseaudio with the following in /etc/pulse/default.pa:

load-module module-echo-cancel use_master_format=1 aec_method=webrtc aec_args="analog_gain_control=0 digital_gain_control=1 noise_suppression=1" source_name=echoCancel_source sink_name=echoCancel_sink
set-default-source echoCancel_source
set-default-sink echoCancel_sink

and then I run Zoiper as follows:

PULSE_PROP="filter.want=echo-cancel media.role=phone" /opt/Zoiper/zoiper

This then causes a crash in pulseaudio:

Here are the last few lines of the log:

I: [pulseaudio] protocol-native.c: Final latency 50.00 ms = 12.50 ms + 2*12.50 ms + 12.50 ms
D: [alsa-sink-USB Audio] alsa-sink.c: Latency set to 12.50ms
D: [alsa-sink-USB Audio] alsa-sink.c: hwbuf_unused=381600
D: [alsa-sink-USB Audio] alsa-sink.c: setting avail_min=95701
D: [alsa-sink-USB Audio] module-echo-cancel.c: Sink input update max request 4800
D: [alsa-sink-USB Audio] alsa-sink.c: Requesting rewind due to latency change.
D: [alsa-sink-USB Audio] module-echo-cancel.c: Sink input update requested latency 12500
D: [alsa-sink-USB Audio] alsa-sink.c: Requested to rewind 384000 bytes.
D: [alsa-sink-USB Audio] alsa-sink.c: Limited to 9344 bytes.
D: [alsa-sink-USB Audio] alsa-sink.c: before: 2336
D: [alsa-sink-USB Audio] alsa-sink.c: after: 2336
D: [alsa-sink-USB Audio] alsa-sink.c: Rewound 9344 bytes.
D: [alsa-sink-USB Audio] sink.c: Processing rewind...
D: [alsa-sink-USB Audio] sink-input.c: Have to rewind 9344 bytes on render memblockq.
D: [alsa-sink-USB Audio] module-echo-cancel.c: Sink process rewind 0
D: [alsa-sink-USB Audio] sink-input.c: Have to rewind 9344 bytes on render memblockq.
D: [alsa-sink-USB Audio] source.c: Processing rewind...
D: [alsa-source-USB Audio] module-echo-cancel.c: Sink rewind (0)

Thread 1 "pulseaudio" received signal SIGSEGV, Segmentation fault.
0x00007fffcbbf81c1 in find_paired_master (is_sink_input=true, o=0x5555559921a0, filter=0x555555a55810, u=0x5555559c0040) at modules/module-filter-apply.c:204
204                             filter->source_master = so->source->output_from_master->source;


And I have attached the complete backtrace with symbols from `thread apply all bt full`.
Comment 1 Raman Gupta 2018-02-06 00:49:56 UTC
One followup: if the echo cancel module is not added explicitly to default.pa, then there is no crash.
Comment 2 Georg Chini 2018-02-06 07:43:49 UTC
There is no need to load module-echo-cancel explicitly when you specify filter.want. Nevertheless the crash should not happen. Can you please supply a full log? It looks like module-filter-apply tries to use the filter while its master source is moving, but there is not enough of the log to verify. The simple fix might be to return false in find_paired_master() if so->source->output_from_master is NULL, but I need to be sure about the order of events.
Comment 3 Raman Gupta 2018-02-06 08:13:41 UTC
Created attachment 137182 [details]
Output of pa

(In reply to Georg Chini from comment #2)
> There is no need to load module-echo-cancel explicitly when you specify
> filter.want.

Agreed, though I note that the only reason I added loading of the module explicitly was because I there does not appear to be any way to specify parameters to the echo cancel module when using filter.want...

> Nevertheless the crash should not happen. Can you please supply
> a full log? It looks like module-filter-apply tries to use the filter while
> its master source is moving, but there is not enough of the log to verify.
> The simple fix might be to return false in find_paired_master() if
> so->source->output_from_master is NULL, but I need to be sure about the
> order of events.

I have attached the full log as pa.log.
Comment 4 Georg Chini 2018-02-06 14:31:00 UTC
Created attachment 137188 [details] [review]
Patch ignore monitor sources

Could you try the attached patch? Zoiper seems to test all the available sources and sinks if I read the log right. So module-filter-apply at some point tried to use the monitor source of the echo-cancel sink as source for the filter.
Comment 5 Georg Chini 2018-02-06 14:49:51 UTC
Since 11.0 there is a way to pass parameters to a filter loaded via filter.want. You should be able to specify them via the filter.apply.echo-cancel.parameters property.
Comment 6 Raman Gupta 2018-02-06 16:51:43 UTC
(In reply to Georg Chini from comment #4)
Could you try the attached patch? Zoiper seems to test all the available sources and sinks if I read the log right. So module-filter-apply at some point tried to use the monitor source of the echo-cancel sink as source for the filter.

Yes, this patch solves the segfault.

(In reply to Georg Chini from comment #5)
> Since 11.0 there is a way to pass parameters to a filter loaded via
> filter.want. You should be able to specify them via the
> filter.apply.echo-cancel.parameters property.

Nice! I googled "filter.apply.echo-cancel.parameters" with no results. Can you provide an example of its use or a docs or code reference?
Comment 7 Georg Chini 2018-02-06 21:07:59 UTC
Thanks for testing. Regarding the new feature, there is not much documentation. You can find some in the release notes for 11.0 under "Notes for application developers". Release notes are at https://www.freedesktop.org/wiki/Software/PulseAudio/Notes/11.0/. The commit which introduced the feature is here: https://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=caabff2728d9d588664f8a0ea2f8441804c8b91a
Comment 8 Tanu Kaskinen 2018-02-08 16:02:22 UTC
Since this is a crash bug, I'm marking this as a release blocker.
Comment 9 Tanu Kaskinen 2018-02-12 16:07:41 UTC
Georg's fix is now in master, closing bug.

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.