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

Wed Dec 20 09:25:10 UTC 2023

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.