[pulseaudio-discuss] playback from loopback over network fades, dies every few minutes and then comes back

[Nick]

On 06/14/2015 12:03 PM, Georg Chini wrote:
> On 14.06.2015 18:54, Nick wrote:
>> Greetings PulseAudio folks:
>>
>> I'm trying to pipe audio between an amateur radio (basically a USB sound
>> card) hooked to a Raspberry Pi and my laptop over a local network. I've
>> built PulseAudio 6 on a Raspberry Pi B+ and set up module-tunnel-sink
>> and module-tunnel-source, and that's all functioning. I can record audio
>> on my laptop and it seems to work well. However, I need to be able to
>> monitor the sounds coming out of the radio live, so I set up a
>> module-loopback with the source set to the USB sound card on the RPi.
>>
>> Here are the relevant bits in my system.pa config file:
>>
>> load-module module-tunnel-sink server=laptop sink_name=xps rate=11025
>> load-module module-tunnel-source server=laptop source_name=xpss
>> rate=11025
>> load-module module-loopback
>> source=TI_USB_Audio_CODEC-00-CODEC.analog-stereo latency_msec=100
>> rate=11025
>>
>> I've downsampled because I'm trying to minimize bandwidth and don't need
>> hi-fi audio (after all, it's a ham radio). This works, but only for a
>> few minutes. Then, the audio from the loopback becomes choppy and
>> eventually fades out completely. It sits silently for about a minute
>> (sometimes more) and then comes back in full quality. A minute or so
>> later, the process repeats.
>>
>> Some interesting tidbits:
>> 1) Only the loopback fades. If I'm recording in an application on the
>> laptop from the networked tunnel source directly, it holds the signal
>> nicely the whole time (even during the fadeouts).
>> 2) If I connect to my local network over a VPN, the loopback fading does
>> not occur at all.
>> 3) The fading happens both on wifi connections and on hard-wired ones.
>> 4) If I change the target of the loopback in pavucontrol's Playback tab
>> to something else and then back to my laptop speakers, it often stops a
>> fadeout and comes back strong for a minute or so (and then fades out
>> again).
>> 5) The fading occurs both with the downsampled rate set on the loopback
>> and with the default.
>> 6) This happens on multiple remix methods, including the default and
>> trivial.
>> 7) This happens on both the Raspberry Pi B+ and on the Raspberry Pi 2.
>> CPU on the RPi2 is at about 20%.
>> 8) The client (my laptop) has PulseAudio 4.0, not 6.0 like the server.
>>
>> I've uploaded a recording of the fading phenomenon that you can listen
>> to here: http://partofthething.com/upload/pulseaudio-fadeout.mp3
>>
>> I'm not sure what to do to continue debugging. Any suggestions?
>>
>> Best regards,
>> -Nick
>>
> Hello Nick,
>
> can you send some debug output from your pulseaudio session? It
> might help to identify the problem. module-loopback should provide
> a state update each adjust_time.
>

Georg:
Yes. I ran with -vvvv and am copying things from the log that I think
might be relevant.

First, we have some info about resampling:

D: [pulseaudio] module-loopback.c: Loopback overall latency is 167.47 ms
+ 78.09 ms + 0.78 ms = 246.35 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 1412 bytes
I: [pulseaudio] module-loopback.c: New rate of 11060 Hz not within 2‰ of
11025 Hz, forcing smaller adjustment
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11047 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 153.18 ms
+ 67.98 ms + 0.38 ms = 221.55 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 1100 bytes
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11052 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 138.84 ms
+ 56.82 ms + 0.15 ms = 195.82 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 44 bytes

Then, an error:

E: [alsa-source-USB Audio] alsa-source.c: ALSA woke us up to read new
data from the device, but there was actually nothing to read!
E: [alsa-source-USB Audio] alsa-source.c: Most likely this is a bug in
the ALSA driver 'snd_usb_audio'. Please report this issue to the ALSA
developers.
E: [alsa-source-USB Audio] alsa-source.c: We were woken up with POLLIN
set -- however a subsequent snd_pcm_avail() returned 0 or another value
< min_avail.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 163.10 ms
+ 25.39 ms + 0.38 ms = 188.87 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 0 bytes

Then, more resampling messages followed by some buffer issues:

D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11025 Hz.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 4.64 ms +
439.09 ms + 0.92 ms = 444.65 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 0 bytes
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11025 Hz.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 272.80 ms
+ 434.29 ms + 0.42 ms = 707.51 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 10540 bytes
I: [pulseaudio] module-loopback.c: New rate of 11288 Hz not within 2‰ of
11025 Hz, forcing smaller adjustment
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11047 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 387.70 ms
+ 388.88 ms + 0.75 ms = 777.33 ms

As the fading ended, I think these messages were being printed:

D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11025 Hz.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 27.98 ms
+ 67.21 ms + 0.46 ms = 95.66 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 0 bytes
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11025 Hz.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
I: [pulseaudio] module-tunnel.c: Server signalled buffer overrun/underrun.
D: [pulseaudio] module-tunnel.c: Server reports playback started.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 218.50 ms
+ 254.51 ms + 0.40 ms = 473.41 ms
D: [pulseaudio] module-loopback.c: Should buffer 0 bytes, buffered at
minimum 808 bytes
D: [pulseaudio] module-loopback.c: [xps] Updated sampling rate to 11045 Hz.

Let me know if there's more info that might help. Many thanks!
Best,
-Nick

> Regards
>              Georg
>