[module-tunnel.c] Inaccurate calculation of transnport latency
Hi guys!
I have two embedded boards (R-Car H3 and Raspberry Pi 3B+ (RPI)). They are connected over local network and run headless Linux. I'm sending audio in both directions over the tunnel.
Audio server is R-Car H3. Its default.pa modifications:
load-module module-udev-detect tsched=0 //to avoid audio distortions
load-module module-native-protocol-tcp auth-ip-acl=127.0.0.1;192.168.222.0/24 auth-anonymous=1
load-module module-zeroconf-publish
Audio client is RPI. Its default.pa modifications:
load-module module-zeroconf-discover
I'm using loopback module to play RPI's USB mic to R-Car's H3 speakers:
pacmd load-module module-loopback source=alsa_input.usb-GN_Netcom_A_S_Jabra_EVOLVE_20_0000449E874E07-00.analog-mono sink=tunnel.h3ulcb.local.alsa_output.platform-sound.analog-stereo
~20 seconds audio plays without issues but then glitches appear and audio disappears completely.
Pulseaudio output after verbose logging enabling:
W: [pulseaudio] module-loopback.c: Too many underruns, increasing latency to 556.50 ms
D: [pulseaudio] module-loopback.c: Loopback overall latency is 316118.62 ms + 260.34 ms + 1352967857.27 ms = 1353284236.17 ms
D: [pulseaudio] module-loopback.c: Loopback latency at base rate is 1353284236.17 ms
D: [pulseaudio] module-loopback.c: [tunnel.h3ulcb.local.alsa_output.platform-sound.analog-stereo] Updated sampling rate to 44540 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 326140.75 ms + 138.93 ms + 1352957855.18 ms = 1353284134.80 ms
D: [pulseaudio] module-loopback.c: Loopback latency at base rate is 1353284136.18 ms
D: [pulseaudio] module-loopback.c: [tunnel.h3ulcb.local.alsa_output.platform-sound.analog-stereo] Updated sampling rate to 44540 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 336128.14 ms + 50.07 ms + 1352947857.88 ms = 1353284036.03 ms
D: [pulseaudio] module-loopback.c: Loopback latency at base rate is 1353284036.53 ms
D: [pulseaudio] module-loopback.c: [tunnel.h3ulcb.local.alsa_output.platform-sound.analog-stereo] Updated sampling rate to 44540 Hz.
D: [pulseaudio] module-loopback.c: Loopback overall latency is 346120.36 ms + 0.00 ms + 1352937855.66 ms = 1353283975.96 ms
D: [pulseaudio] module-loopback.c: Loopback latency at base rate is 1353283975.96 ms
D: [pulseaudio] module-loopback.c: [tunnel.h3ulcb.local.alsa_output.platform-sound.analog-stereo] Updated sampling rate to 44540 Hz.
Pulseaudio 12.2 is used.
Root-cause of this issue is incorrect stream latency calculation because of transport latency.
Both devices do not have NTP so their time is not actual (now it is time of system image build). Server's time is 08-APR-2020. Client's time is 24-MAR-2020.
Transport latency is calculated as remote and local time difference (module-tunnel.c):
u->transport_usec = pa_timeval_diff(&remote, &local);
And my case passes all requirements:
if (pa_timeval_cmp(&local, &remote) < 0 && pa_timeval_cmp(&remote, &now)) {
So I have transport latency in 15 days! And this latency is causing audio issues.
My proposed solution is attached to the bug.
0001-module-tunnel-Skip-transport-latency-if-it-is-too-hu.patch