Re: Problem with module-rtp-recv, Sample Specification stuck at 44011Hz (instead of 44100Hz), Buffer Latency constantly increasing

NicoHood <pulseaudio-discuss@xxxxxxxxxxx> · Sun, 31 Dec 2023 16:24:37 +0100

Hi,
I just wanted to report the same. I am using ArchLinux for ARM on my 
Raspi 3. I have not updated the device for... 1, maybe 2 years now. 
After the update I got those lags. No matter what I do, I am unable to 
fix the issue. I also tried it as root, with realtime flags etc.

This is the update log, which version got updated (as I said, its been a 
long time)
[2023-11-09T12:33:58+0000] [ALPM] upgraded pulseaudio-rtp (15.0-1 -> 16.1-6)
[2023-11-09T12:33:58+0000] [ALPM] upgraded pulseaudio-zeroconf (15.0-1 
-> 16.1-6)

Right now I am using version 16.1-7, which still does not work as expected.

I am using paprefs on the sender side to send the RTP signal (so no 
special flags are used). The sender is a normal (x64) Computer, no 
raspberry pi. I also have another x64 computer which receives the signal 
fine with no latency (also using archlinux, latest version). But on the 
arm device (raspberry) the issue occurs since v16.

Any ideas?

Cheers
Nico

On 20/12/2023 10:25, Chris Beat wrote:
Hi,

I have a problem with module-rtp-recv.

On the sender side, I start with:
pacmd load-module module-rtp-send format=s16be channels=2 rate=44100 
source=NullSink.monitor

On the receiver side, I start with:
pacmd load-module module-rtp-recv

On the receiver side I notice the following:

- the value of "Buffer Latency" of the rtp-recv sink-input constantly 
increases, with a rate of
approximately 100 ms per minute (so after 10 minutes there is roughly a 
1 second delay between
sender and receiver).
- the value of "Sample Specification" of the rtp-recv sink-input shows 
"s16be 2ch 44011Hz", the
value of the sink itself it is "s16le 2ch 44100Hz".

So my speculation is that because of this difference of 99Hz between 
sink-input (44011Hz) and sink
(44100Hz) there is samples "left over" that keep piling up and thus 
filling up the buffer.

I tried to understand the logic in the source code of
https://github.com/pulseaudio/pulseaudio/blob/master/src/modules/rtp/module-rtp-recv.c but failed.

Below is a log excerpt of the pulseaudio daemon when loading 
module-rtp-recv:

Dec 20 09:35:45 raspberrypi pulseaudio[1137]: Created 4 "UNIX socket 
client"
Dec 20 09:35:45 raspberrypi pulseaudio[1137]: Loaded "module-rtp-recv" 
(index: #6; argument: "").
Dec 20 09:35:45 raspberrypi pulseaudio[1137]: CLI got EOF from user.
Dec 20 09:35:45 raspberrypi pulseaudio[1137]: Freed 4 "UNIX socket client"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Negotiated format: pcm, 
format.sample_format =
"\"s16be\""  format.rate = "44100"  format.channels = "2"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Resampler:
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:   rate 44100 -> 44100 
(method speex-float-1)
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:   format s16be -> s16le 
(intermediate float32le)
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:   channels 2 -> 2 
(resampling 2)
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Choosing speex quality 
setting 1.
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq requested: 
maxlength=33554432, tlength=0,
base=4, prebuf=0, minreq=1 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq sanitized: 
maxlength=33554432,
tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq requested: 
maxlength=33554432, tlength=0,
base=4, prebuf=0, minreq=1 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq sanitized: 
maxlength=33554432,
tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Created input 1 "RTP 
Stream (PulseAudio RTP Stream on
netbook.zuhause)" on alsa_output.platform-bcm2835_audio.analog-stereo 
with sample spec s16be 2ch
44100Hz and channel map front-left,front-right
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:     media.role = "stream"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:     media.name = "RTP 
Stream (PulseAudio RTP Stream on
netbook.zuhause)"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:     rtp.session = 
"PulseAudio RTP Stream on
netbook.zuhause"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:     rtp.origin = "makemkv 
3912044479 0 IN IP4
192.168.2.15"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]:     rtp.payload = "10"
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq requested: 
maxlength=41943040,
tlength=41943040, base=4, prebuf=70568, minreq=0 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: memblockq sanitized: 
maxlength=41943040,
tlength=41943040, base=4, prebuf=70568, minreq=4 maxrewind=0
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Initialising GStreamer RTP 
backend for receive
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Requested volume: 
front-left: 56210 /  86% / -4.00 dB,
   front-right: 56210 /  86% / -4.00 dB
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Got hardware volume: 
front-left: 56210 /  86% / -4.00
dB,   front-right: 56210 /  86% / -4.00 dB
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Calculated software 
volume: front-left: 65536 / 100% /
0.00 dB,   front-right: 65536 / 100% / 0.00 dB (accurate-enough=yes)
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: Volume not changing
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: 
alsa_output.platform-bcm2835_audio.analog-stereo:
state: IDLE -> RUNNING
Dec 20 09:35:49 raspberrypi pulseaudio[1137]: New session 'PulseAudio 
RTP Stream on netbook.zuhause'
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Discontinuity detected, 
possibly lost some packets
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Updating sample rate
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: wi=7188 ri=0
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Write index deviates by 
7.19 ms, expected 500.00 ms
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Estimated target rate: 
40143 Hz, using average of
44021 Hz  (α=0.020)
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: New rate of 42936 Hz not 
within 2‰ of 44100 Hz,
forcing smaller adjustment
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Updated sampling rate to 
44011 Hz.
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Requesting rewind due to 
end of underrun
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Requested to rewind 17632 
bytes.
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Limited to 17376 bytes.
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: before: 4344
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: after: 0
Dec 20 09:35:50 raspberrypi pulseaudio[1137]: Tried rewind, but was 
apparently not possible.
Dec 20 09:36:05 raspberrypi pulseaudio[1137]: Checking for dead streams ...

There are no further log entries regarding updates of the sampling rate, 
so maybe this is a bug in
module-rtp-recv.c ?

Regards, Chris.