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

[NicoHood]

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.