[pulseaudio-discuss] Webrtc AEC Raspberry Pi weird effects.

[Arun Raghavan]

Hi Stuart,

On Wed, 13 May 2020, at 10:33 AM, Stuart Naylor wrote:
>  
> I will post the recordings.
> 
>  EC
> https://drive.google.com/file/d/13WCq9Bs-cW-cJsGFwU9s6DZ2UNLPXyMU/view?usp=sharing
> 
> 
> No-EC
> 
> https://drive.google.com/file/d/1HH5klDS_Y5Lcmsuc2EWsBO517V4dwLV0/view?usp=sharing

So I take it this is with webrtc?

What you're 

>  If I run speexdsp AEC with exact same setup but via alsa with 
> pulseaudio removed then the results are quite good.
>  The speaker is only 12” from the mic and 12” from me and quite loud as 
> wondering what upstairs thinks.
>  But anyway the results are pretty good.
> 
>  EC
> 
> https://drive.google.com/file/d/1ohO0YaO3CEwrXWwcj8qDbUpWuQo5sv2T/view?usp=sharing
> 
> 
> No-EC
> 
> https://drive.google.com/file/d/12qNv6O9o-ttFoWE9tytqXdbAKCkPT6NW/view?usp=sharing

Ah, that is quite good!

> Journalctl is giving the usual but this is a single usb soundcard with 
> single clock for capture/playback.
> 
>  May 13 14:14:30 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Doing resync
> 
>  May 13 14:14:30 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (37856), drop
> 
>  May 13 14:14:49 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Doing resync
> 
>  May 13 14:14:49 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (131103), dro
> 
>  May 13 14:14:49 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Doing resync
> 
>  May 13 14:14:49 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (75977), drop
> 
>  May 13 14:14:50 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (62480), drop
> 
>  May 13 14:14:51 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (13404), drop
> 
>  May 13 14:14:52 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (10231), drop
> 
>  May 13 14:14:53 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (9131), drop
> 
>  May 13 14:14:54 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (9136), drop
> 
>  May 13 14:14:55 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (9651), drop
> 
>  May 13 14:14:56 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (9915), drop
> 
>  May 13 14:14:57 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (9814), drop
> 
>  May 13 14:14:58 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback too far ahead (10011), drop
> 
>  May 13 14:15:00 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback after capture (-580), drop
> 
>  May 13 14:15:03 raspberrypi pulseaudio[608]: E: [alsa-source-USB 
> Audio] module-echo-cancel.c: Playback after capture (-158), drop
> 
>  May 13 14:15:20 raspberrypi pulseaudio[608]: E: [alsa-sink-USB Audio] 
> alsa-sink.c: ALSA woke us up to write new data to the device
> 
>  May 13 14:15:20 raspberrypi pulseaudio[608]: E: [alsa-sink-USB Audio] 
> alsa-sink.c: Most likely this is a bug in the ALSA driver 's
> 
>  May 13 14:15:20 raspberrypi pulseaudio[608]: E: [alsa-sink-USB Audio] 
> alsa-sink.c: We were woken up with POLLOUT set -- however a

The source dropped messages are from us trying to do drift compensation and matching the samples we believe correspond to each other given we know what the playback and capture latencies are.

Now if your device driver does not report the ALSA pointer correctly, this can throw the latency reports, and thus the AEC off. In your ALSA-only test, you are likely not exercising the ALSA API in the same way as PulseAudio does (for power saving etc.).

Do you see the same problem if you load the ALSA modules with tsched=off?

> I am sure there is something not quite write with the 
> webrtc_audio_processing when it comes to arm Linux maybe even just the 
> Pi which here is a Pi4.
>  Anyone any idea why the first EC with pulseaudio is so bad whilst even 
> the supposedly weaker speexdsp aec actually makes quite a good job with 
> exactly same hardware and setup?

I think one thing to do is minimise the dropped source/sink buffers, to get some steady performance.

Another way to experiment is to load module-echo-cancel with save_aec=true. This will dump the playback, capture, and cancelled data to /tmp.

You can then run echo-cancel-test (you'll need to have a PA build handy), which allows you to rerun on the same input with different AEC engines/parameters. However, all this only makes sense if you can get a steady state with buffers not being dropped. Each dropped buffer is going to introduce a discontinuity/non-linearity that throws the AEC engine for a toss for a short while at least.

Hope this helps,
Arun