On 17/06/2022 21:54, Chris Beat wrote:
Hi, in my setup I have a Raspberry with an old USB soundcard as a RTP sender and an old netbook as the RTP receiver. I use the netbook to connect a bluetooth speaker to it. If important: this is unicast RTP. If I start streaming music on the sender side, it takes a long time until I get output on the receiver side (with "long" I mean magnitude of: several seconds, up to minutes), and also the "pitch" of the music is audible lower / slower than what I can hear on the sending device. Troubleshooting steps so far: If I start the pulseaudio daemon on the sender side (with module-rtp-send), then on the receiver side, I get this message in the log (about every 5 seconds): "Sample rates too different, not adjusting (44100 vs. 57567)." The 57567 value slowly increases in time. I also noticed that on the receiver side, the sink-input "Buffer Latency" quickly increases over time, as seen here for example: ~$ pactl list sink-inputs Sink Input #0 Driver: module-loopback.c Owner Module: 7 Client: n/a Sink: 1 Sample Specification: s16le 2ch 44103Hz Channel Map: front-left,front-right Format: pcm, format.sample_format = "\"s16le\"" format.rate = "44100" format.channels = "2" format.channel_map = "\"front-left,front-right\"" Corked: no Mute: no Volume: front-left: 65536 / 100% / 0.00 dB, front-right: 65536 / 100% / 0.00 dB balance 0.00 Buffer Latency: 135137 usec Sink Latency: 69810 usec Resample method: speex-float-1 Properties: media.role = "abstract" media.name = "Loopback from Monitor of NullSink" media.icon_name = "audio-input-microphone" Sink Input #1 Driver: module-rtp-recv.c Owner Module: 10 Client: n/a Sink: 0 Sample Specification: s16be 2ch 44100Hz Channel Map: front-left,front-right Format: pcm, format.sample_format = "\"s16be\"" format.rate = "44100" format.channels = "2" Corked: no Mute: no Volume: front-left: 65536 / 100% / 0.00 dB, front-right: 65536 / 100% / 0.00 dB balance 0.00 Buffer Latency: 13670815 usec Sink Latency: 6885 usec Resample method: speex-float-1 Properties: media.role = "stream" media.name = "RTP Stream (PulseAudio RTP Stream on raspberrypi)" rtp.session = "PulseAudio RTP Stream on raspberrypi" rtp.origin = "pi 3864408555 0 IN IP4 192.168.2.30" rtp.payload = "10" ~$ Here the "Buffer Latency" is already almost 14 seconds, this is only shortly (1-2 minutes) after a restart of the daemon. Any idea on how to either solve this quick and dirty, or troubleshoot further? some information from the two devices: #### Raspberry RTP sender BEGIN INFO #### pi@raspberrypi:~ $ pulseaudio --version pulseaudio 14.2 pi@raspberrypi:~ $ pacmd dump ### Configuration dump generated at Fri Jun 17 21:49:17 2022 load-module module-udev-detect load-module module-alsa-card device_id="1" name="usb-041e_USB_Audio-00" card_name="alsa_card.usb-041e_USB_Audio-00" namereg_fail=false tsched=yes fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1" load-module module-native-protocol-unix load-module module-systemd-login load-module module-rtp-send source=alsa_input.usb-041e_USB_Audio-00.iec958-stereo destination_ip=192.168.2.15 load-module module-rtp-recv sap_address=192.168.2.30 load-module module-cli-protocol-unix set-sink-volume alsa_output.usb-041e_USB_Audio-00.iec958-stereo 0x10000 set-sink-mute alsa_output.usb-041e_USB_Audio-00.iec958-stereo no suspend-sink alsa_output.usb-041e_USB_Audio-00.iec958-stereo no set-source-volume alsa_output.usb-041e_USB_Audio-00.iec958-stereo.monitor 0x10000 set-source-mute alsa_output.usb-041e_USB_Audio-00.iec958-stereo.monitor no suspend-source alsa_output.usb-041e_USB_Audio-00.iec958-stereo.monitor no set-source-volume alsa_input.usb-041e_USB_Audio-00.iec958-stereo 0x10000 set-source-mute alsa_input.usb-041e_USB_Audio-00.iec958-stereo no suspend-source alsa_input.usb-041e_USB_Audio-00.iec958-stereo no set-card-profile alsa_card.usb-041e_USB_Audio-00 output:iec958-stereo+input:iec958-stereo set-default-sink alsa_output.usb-041e_USB_Audio-00.iec958-stereo set-default-source alsa_input.usb-041e_USB_Audio-00.iec958-stereo ### EOF pi@raspberrypi:~ $ #### Raspberry RTP sender END INFO #### #### Netbook RTP receiver BEGIN INFO #### xxx@netbook:~$ pulseaudio --version pulseaudio 14.2 xxx@netbook:~$ pacmd dump ### Configuration dump generated at Fri Jun 17 21:49:46 2022 load-module module-bluetooth-policy load-module module-bluetooth-discover load-module module-bluez5-discover load-module module-native-protocol-unix load-module module-systemd-login load-module module-null-sink sink_name="NullSink" sink_properties="device.description='NullSink'" load-module module-null-sink sink_name="NullSinkDel" sink_properties="device.description='NullSinkDel'" load-module module-loopback latency_msec=200 adjust_time=1 source=NullSink.monitor sink=NullSinkDel source_dont_move=yes sink_dont_move=yes load-module module-rtp-send source=NullSink.monitor destination_ip=192.168.2.230 load-module module-rtp-send source=NullSink.monitor destination_ip=192.168.2.30 load-module module-rtp-recv sink=NullSink sap_address=192.168.2.15 load-module module-cli-protocol-unix set-sink-volume NullSink 0x10000 set-sink-mute NullSink no suspend-sink NullSink no set-sink-volume NullSinkDel 0x10000 set-sink-mute NullSinkDel no suspend-sink NullSinkDel no set-source-volume NullSink.monitor 0x10000 set-source-mute NullSink.monitor no suspend-source NullSink.monitor no set-source-volume NullSinkDel.monitor 0x10000 set-source-mute NullSinkDel.monitor no suspend-source NullSinkDel.monitor no set-default-sink NullSink set-default-source NullSink.monitor ### EOF xxx@netbook:~$ ##### ... some logging with log level "debug": xxx@netbook:~$ systemctl --user restart pulseaudio;journalctl --follow Hint: You are currently not seeing messages from other users and the system. Users in groups 'adm', 'systemd-journal' can see all messages. Pass -q to turn off this notice. -- Journal begins at Thu 2022-06-16 13:05:00 CEST. -- Jun 17 21:50:29 netbook pulseaudio[16443]: Bluetooth Headset Backend API support using the native backend Jun 17 21:50:29 netbook pulseaudio[16443]: Registering Profile /Profile/HSPAGProfile 00001112-0000-1000-8000-00805f9b34fb Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Jun 17 21:50:29 netbook pulseaudio[16443]: oFono is running: no Jun 17 21:50:29 netbook pulseaudio[16443]: Registering Profile /Profile/HSPHSProfile 00001108-0000-1000-8000-00805f9b34fb Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci1 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Properties changed in adapter /org/bluez/hci0 Jun 17 21:50:29 netbook pulseaudio[16443]: Loopback overall latency is 1809.60 ms + 200.00 ms + -1870.11 ms = 139.39 ms Jun 17 21:50:29 netbook pulseaudio[16443]: Loopback latency at base rate is 139.39 ms Jun 17 21:50:29 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 43721 Hz. Jun 17 21:50:30 netbook pulseaudio[16443]: Loopback overall latency is 808.51 ms + 201.73 ms + -868.96 ms = 141.12 ms Jun 17 21:50:30 netbook pulseaudio[16443]: Loopback latency at base rate is 139.39 ms Jun 17 21:50:30 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 43721 Hz. Jun 17 21:50:31 netbook pulseaudio[16443]: Got signal SIGUSR2. Jun 17 21:50:31 netbook pulseaudio[16443]: Loaded "module-cli-protocol-unix" (index: #11; argument: ""). Jun 17 21:50:31 netbook pulseaudio[16443]: Created 2 "UNIX socket client" Jun 17 21:50:31 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:31 netbook pulseaudio[16443]: Freed 2 "UNIX socket client" Jun 17 21:50:31 netbook pulseaudio[16443]: Adding 64911 usec of silence to queue Jun 17 21:50:31 netbook pulseaudio[16443]: Dropping 7296 usec of audio from queue Jun 17 21:50:31 netbook pulseaudio[16443]: Adding 66649 usec of silence to queue Jun 17 21:50:31 netbook pulseaudio[16443]: Dropping 65483 usec of audio from queue Jun 17 21:50:31 netbook pulseaudio[16443]: Loopback overall latency is 9.41 ms + 197.98 ms + -6.14 ms = 201.12 ms Jun 17 21:50:31 netbook pulseaudio[16443]: Loopback latency at base rate is 199.42 ms Jun 17 21:50:31 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44075 Hz. Jun 17 21:50:32 netbook pulseaudio[16443]: Loopback overall latency is 22.47 ms + 180.94 ms + -3.18 ms = 200.10 ms Jun 17 21:50:32 netbook pulseaudio[16443]: Loopback latency at base rate is 200.00 ms Jun 17 21:50:32 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44099 Hz. Jun 17 21:50:33 netbook pulseaudio[16443]: Negotiated format: pcm, format.sample_format = "\"s16be\"" format.rate = "44100" format.channels = "2" Jun 17 21:50:33 netbook pulseaudio[16443]: Resampler: Jun 17 21:50:33 netbook pulseaudio[16443]: rate 44100 -> 44100 (method speex-float-1) Jun 17 21:50:33 netbook pulseaudio[16443]: format s16be -> s16le (intermediate float32le) Jun 17 21:50:33 netbook pulseaudio[16443]: channels 2 -> 2 (resampling 2) Jun 17 21:50:33 netbook pulseaudio[16443]: Choosing speex quality setting 1. Jun 17 21:50:33 netbook pulseaudio[16443]: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0 Jun 17 21:50:33 netbook pulseaudio[16443]: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0 Jun 17 21:50:33 netbook pulseaudio[16443]: Created input 1 "RTP Stream (PulseAudio RTP Stream on raspberrypi)" on NullSink with sample spec s16be 2ch 44100Hz and channel map front-left,front-right Jun 17 21:50:33 netbook pulseaudio[16443]: media.role = "stream" Jun 17 21:50:33 netbook pulseaudio[16443]: media.name = "RTP Stream (PulseAudio RTP Stream on raspberrypi)" Jun 17 21:50:33 netbook pulseaudio[16443]: rtp.session = "PulseAudio RTP Stream on raspberrypi" Jun 17 21:50:33 netbook pulseaudio[16443]: rtp.origin = "pi 3864408555 0 IN IP4 192.168.2.30" Jun 17 21:50:33 netbook pulseaudio[16443]: rtp.payload = "10" Jun 17 21:50:33 netbook pulseaudio[16443]: memblockq requested: maxlength=41943040, tlength=41943040, base=4, prebuf=44100, minreq=0 maxrewind=0 Jun 17 21:50:33 netbook pulseaudio[16443]: memblockq sanitized: maxlength=41943040, tlength=41943040, base=4, prebuf=44100, minreq=4 maxrewind=0 Jun 17 21:50:33 netbook pulseaudio[16443]: Initialising native RTP backend for receive Jun 17 21:50:33 netbook pulseaudio[16443]: NullSink: state: IDLE -> RUNNING Jun 17 21:50:33 netbook pulseaudio[16443]: New session 'PulseAudio RTP Stream on raspberrypi' Jun 17 21:50:33 netbook pulseaudio[16443]: Loopback overall latency is 34.92 ms + 166.38 ms + -1.16 ms = 200.02 ms Jun 17 21:50:33 netbook pulseaudio[16443]: Loopback latency at base rate is 200.02 ms Jun 17 21:50:33 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44100 Hz. Jun 17 21:50:34 netbook pulseaudio[16443]: Requesting rewind due to end of underrun Jun 17 21:50:34 netbook pulseaudio[16443]: Requested to rewind 1276 bytes. Jun 17 21:50:34 netbook pulseaudio[16443]: Processing rewind... Jun 17 21:50:34 netbook pulseaudio[16443]: Have to rewind 844 bytes on render memblockq. Jun 17 21:50:34 netbook pulseaudio[16443]: Processing rewind... Jun 17 21:50:34 netbook pulseaudio[16443]: Have to rewind 844 bytes on implementor. Jun 17 21:50:34 netbook pulseaudio[16443]: Rewound 844 bytes. Jun 17 21:50:34 netbook pulseaudio[16443]: Created 3 "Native client (UNIX socket client)" Jun 17 21:50:34 netbook pulseaudio[16443]: Protocol version: remote 34, local 34 Jun 17 21:50:34 netbook pulseaudio[16443]: Got credentials: uid=1000 gid=1000 success=1 Jun 17 21:50:34 netbook pulseaudio[16443]: SHM possible: yes Jun 17 21:50:34 netbook pulseaudio[16443]: Negotiated SHM: yes Jun 17 21:50:34 netbook pulseaudio[16443]: Memfd possible: yes Jun 17 21:50:34 netbook pulseaudio[16443]: Negotiated SHM type: shared memfd Jun 17 21:50:34 netbook pulseaudio[16443]: Using shared memfd memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65496 Jun 17 21:50:34 netbook pulseaudio[16443]: SHM block is 65496 bytes, ringbuffer capacity is 2 * 32724 bytes Jun 17 21:50:34 netbook pulseaudio[16443]: Enabling srbchannel... Jun 17 21:50:34 netbook pulseaudio[16443]: Client enabled srbchannel. Jun 17 21:50:34 netbook pulseaudio[16443]: Loopback overall latency is 16.89 ms + 186.78 ms + -3.16 ms = 200.07 ms Jun 17 21:50:34 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:34 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:35 netbook pulseaudio[16443]: Loopback overall latency is 17.65 ms + 185.75 ms + -3.13 ms = 200.08 ms Jun 17 21:50:35 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:50:35 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:36 netbook pulseaudio[16443]: Created 4 "UNIX socket client" Jun 17 21:50:36 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:36 netbook pulseaudio[16443]: Freed 4 "UNIX socket client" Jun 17 21:50:36 netbook pulseaudio[16443]: Loopback overall latency is 11.43 ms + 194.07 ms + -5.25 ms = 200.08 ms Jun 17 21:50:36 netbook pulseaudio[16443]: Loopback latency at base rate is 200.10 ms Jun 17 21:50:36 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44104 Hz. Jun 17 21:50:37 netbook pulseaudio[16443]: Loopback overall latency is 53.79 ms + 152.23 ms + -5.77 ms = 200.03 ms Jun 17 21:50:37 netbook pulseaudio[16443]: Loopback latency at base rate is 200.05 ms Jun 17 21:50:37 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:38 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:50:38 netbook pulseaudio[16443]: wi=5449433 ri=4810884 Jun 17 21:50:38 netbook pulseaudio[16443]: Write index deviates by 675.86 ms, expected 500.00 ms Jun 17 21:50:38 netbook pulseaudio[16443]: Estimated target rate: 45708 Hz, using average of 44132 Hz (α=0.020) Jun 17 21:50:38 netbook pulseaudio[16443]: New rate of 44520 Hz not within 2‰ of 44100 Hz, forcing smaller adjustment Jun 17 21:50:38 netbook pulseaudio[16443]: Updated sampling rate to 44188 Hz. Jun 17 21:50:38 netbook pulseaudio[16443]: Loopback overall latency is 42.72 ms + 162.49 ms + -4.97 ms = 200.05 ms Jun 17 21:50:38 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:50:38 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:40 netbook pulseaudio[16443]: Loopback overall latency is 84.10 ms + 127.52 ms + -1.09 ms = 200.07 ms Jun 17 21:50:40 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:40 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:40 netbook pulseaudio[16443]: Loopback overall latency is 7.98 ms + 195.27 ms + -2.82 ms = 200.06 ms Jun 17 21:50:40 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:40 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:41 netbook pulseaudio[16443]: Created 5 "UNIX socket client" Jun 17 21:50:41 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:41 netbook pulseaudio[16443]: Freed 5 "UNIX socket client" Jun 17 21:50:42 netbook pulseaudio[16443]: Loopback overall latency is 113.44 ms + 92.47 ms + -5.71 ms = 200.05 ms Jun 17 21:50:42 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:50:42 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:42 netbook pulseaudio[16443]: Loopback overall latency is 36.06 ms + 170.92 ms + -6.71 ms = 200.07 ms Jun 17 21:50:42 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:42 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:43 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:50:43 netbook pulseaudio[16443]: wi=10869919 ri=9971938 Jun 17 21:50:43 netbook pulseaudio[16443]: Write index deviates by 1103.29 ms, expected 500.00 ms Jun 17 21:50:43 netbook pulseaudio[16443]: Estimated target rate: 48319 Hz, using average of 47481 Hz (α=0.800) Jun 17 21:50:43 netbook pulseaudio[16443]: New rate of 48913 Hz not within 2‰ of 44188 Hz, forcing smaller adjustment Jun 17 21:50:43 netbook pulseaudio[16443]: Updated sampling rate to 44276 Hz. Jun 17 21:50:44 netbook pulseaudio[16443]: Loopback overall latency is 27.73 ms + 179.24 ms + -6.69 ms = 200.06 ms Jun 17 21:50:44 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:44 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:45 netbook pulseaudio[16443]: Loopback overall latency is 67.12 ms + 137.04 ms + -3.94 ms = 200.07 ms Jun 17 21:50:45 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:50:45 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:46 netbook pulseaudio[16443]: Loopback overall latency is 52.23 ms + 154.50 ms + -6.38 ms = 200.06 ms Jun 17 21:50:46 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:46 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:46 netbook pulseaudio[16443]: Created 6 "UNIX socket client" Jun 17 21:50:46 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:46 netbook pulseaudio[16443]: Freed 6 "UNIX socket client" Jun 17 21:50:47 netbook pulseaudio[16443]: Loopback overall latency is 91.12 ms + 114.17 ms + -5.09 ms = 200.07 ms Jun 17 21:50:47 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:50:47 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:48 netbook pulseaudio[16443]: Loopback overall latency is 13.57 ms + 187.67 ms + -0.99 ms = 200.05 ms Jun 17 21:50:48 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:50:48 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:48 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:50:48 netbook pulseaudio[16443]: wi=16276086 ri=15112476 Jun 17 21:50:48 netbook pulseaudio[16443]: Write index deviates by 1517.74 ms, expected 500.00 ms Jun 17 21:50:48 netbook pulseaudio[16443]: Estimated target rate: 48278 Hz, using average of 48118 Hz (α=0.800) Jun 17 21:50:48 netbook pulseaudio[16443]: New rate of 50567 Hz not within 2‰ of 44276 Hz, forcing smaller adjustment Jun 17 21:50:48 netbook pulseaudio[16443]: Updated sampling rate to 44364 Hz. Jun 17 21:50:49 netbook pulseaudio[16443]: Loopback overall latency is 112.12 ms + 92.47 ms + -4.10 ms = 200.07 ms Jun 17 21:50:49 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:49 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:49 netbook pulseaudio[16443]: Checking for dead streams ... Jun 17 21:50:50 netbook pulseaudio[16443]: Loopback overall latency is 36.12 ms + 170.17 ms + -5.68 ms = 200.07 ms Jun 17 21:50:50 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:50:50 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:51 netbook pulseaudio[16443]: Loopback overall latency is 23.89 ms + 178.51 ms + -1.99 ms = 200.06 ms Jun 17 21:50:51 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:51 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:51 netbook pulseaudio[16443]: Created 7 "UNIX socket client" Jun 17 21:50:51 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:51 netbook pulseaudio[16443]: Freed 7 "UNIX socket client" Jun 17 21:50:52 netbook pulseaudio[16443]: Loopback overall latency is 60.66 ms + 143.91 ms + -4.37 ms = 200.03 ms Jun 17 21:50:52 netbook pulseaudio[16443]: Loopback latency at base rate is 200.04 ms Jun 17 21:50:52 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44101 Hz. Jun 17 21:50:53 netbook pulseaudio[16443]: Loopback overall latency is 43.40 ms + 161.38 ms + -4.42 ms = 200.07 ms Jun 17 21:50:53 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:53 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:53 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:50:53 netbook pulseaudio[16443]: wi=21653593 ri=19864755 Jun 17 21:50:53 netbook pulseaudio[16443]: Write index deviates by 1930.43 ms, expected 500.00 ms Jun 17 21:50:53 netbook pulseaudio[16443]: Estimated target rate: 48355 Hz, using average of 48308 Hz (α=0.800) Jun 17 21:50:53 netbook pulseaudio[16443]: New rate of 51762 Hz not within 2‰ of 44364 Hz, forcing smaller adjustment Jun 17 21:50:53 netbook pulseaudio[16443]: Updated sampling rate to 44452 Hz. Jun 17 21:50:54 netbook pulseaudio[16443]: Loopback overall latency is 79.90 ms + 126.77 ms + 19.11 ms = 200.06 ms Jun 17 21:50:54 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:50:54 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:55 netbook pulseaudio[16443]: Loopback overall latency is 60.98 ms + 141.99 ms + -2.55 ms = 200.06 ms Jun 17 21:50:55 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:55 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:56 netbook pulseaudio[16443]: Loopback overall latency is 99.91 ms + 106.93 ms + -6.17 ms = 200.06 ms Jun 17 21:50:56 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:56 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:57 netbook pulseaudio[16443]: Loopback overall latency is 14.16 ms + 191.51 ms + -5.25 ms = 200.07 ms Jun 17 21:50:57 netbook pulseaudio[16443]: Loopback latency at base rate is 200.09 ms Jun 17 21:50:57 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:50:57 netbook pulseaudio[16443]: Created 8 "UNIX socket client" Jun 17 21:50:57 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:50:57 netbook pulseaudio[16443]: Freed 8 "UNIX socket client" Jun 17 21:50:58 netbook pulseaudio[16443]: Loopback overall latency is 110.92 ms + 92.47 ms + -3.02 ms = 200.04 ms Jun 17 21:50:58 netbook pulseaudio[16443]: Loopback latency at base rate is 200.05 ms Jun 17 21:50:58 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:50:58 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:50:58 netbook pulseaudio[16443]: wi=27017007 ri=24965355 Jun 17 21:50:58 netbook pulseaudio[16443]: Write index deviates by 2329.21 ms, expected 500.00 ms Jun 17 21:50:58 netbook pulseaudio[16443]: Estimated target rate: 48305 Hz, using average of 48305 Hz (α=0.766) Jun 17 21:50:58 netbook pulseaudio[16443]: New rate of 52723 Hz not within 2‰ of 44452 Hz, forcing smaller adjustment Jun 17 21:50:58 netbook pulseaudio[16443]: Updated sampling rate to 44540 Hz. Jun 17 21:50:59 netbook pulseaudio[16443]: Loopback overall latency is 34.18 ms + 172.49 ms + -6.24 ms = 200.06 ms Jun 17 21:50:59 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:50:59 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:00 netbook pulseaudio[16443]: Loopback overall latency is 14.60 ms + 189.56 ms + -3.72 ms = 200.08 ms Jun 17 21:51:00 netbook pulseaudio[16443]: Loopback latency at base rate is 200.09 ms Jun 17 21:51:00 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:01 netbook pulseaudio[16443]: Loopback overall latency is 45.65 ms + 154.96 ms + -0.27 ms = 200.07 ms Jun 17 21:51:01 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:51:01 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:02 netbook pulseaudio[16443]: Loopback overall latency is 29.38 ms + 177.79 ms + -6.01 ms = 200.06 ms Jun 17 21:51:02 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:02 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:02 netbook pulseaudio[16443]: Created 9 "UNIX socket client" Jun 17 21:51:02 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:51:02 netbook pulseaudio[16443]: Freed 9 "UNIX socket client" Jun 17 21:51:03 netbook pulseaudio[16443]: Loopback overall latency is 60.80 ms + 143.21 ms + -3.67 ms = 200.06 ms Jun 17 21:51:03 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:03 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:03 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:51:03 netbook pulseaudio[16443]: wi=32359227 ri=29679389 Jun 17 21:51:03 netbook pulseaudio[16443]: Write index deviates by 2716.14 ms, expected 500.00 ms Jun 17 21:51:03 netbook pulseaudio[16443]: Estimated target rate: 48276 Hz, using average of 48305 Hz (α=0.020) Jun 17 21:51:03 netbook pulseaudio[16443]: New rate of 53657 Hz not within 2‰ of 44540 Hz, forcing smaller adjustment Jun 17 21:51:03 netbook pulseaudio[16443]: Updated sampling rate to 44629 Hz. Jun 17 21:51:04 netbook pulseaudio[16443]: Loopback overall latency is 40.84 ms + 160.65 ms + -1.13 ms = 200.07 ms Jun 17 21:51:04 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:51:04 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:05 netbook pulseaudio[16443]: Loopback overall latency is 71.02 ms + 125.66 ms + 24.74 ms = 200.06 ms Jun 17 21:51:05 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:05 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:06 netbook pulseaudio[16443]: Loopback overall latency is 52.80 ms + 148.52 ms + -0.89 ms = 200.07 ms Jun 17 21:51:06 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:51:06 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:07 netbook pulseaudio[16443]: Loopback overall latency is 81.70 ms + 121.15 ms + -2.26 ms = 200.06 ms Jun 17 21:51:07 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:51:07 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:07 netbook pulseaudio[16443]: Created 10 "UNIX socket client" Jun 17 21:51:07 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:51:07 netbook pulseaudio[16443]: Freed 10 "UNIX socket client" Jun 17 21:51:08 netbook pulseaudio[16443]: Loopback overall latency is 59.26 ms + 145.80 ms + -4.70 ms = 200.07 ms Jun 17 21:51:08 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:08 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:08 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:51:08 netbook pulseaudio[16443]: wi=37672365 ri=34739743 Jun 17 21:51:08 netbook pulseaudio[16443]: Write index deviates by 3087.23 ms, expected 500.00 ms Jun 17 21:51:08 netbook pulseaudio[16443]: Estimated target rate: 48207 Hz, using average of 48231 Hz (α=0.754) Jun 17 21:51:08 netbook pulseaudio[16443]: New rate of 54470 Hz not within 2‰ of 44629 Hz, forcing smaller adjustment Jun 17 21:51:08 netbook pulseaudio[16443]: Updated sampling rate to 44718 Hz. Jun 17 21:51:09 netbook pulseaudio[16443]: Loopback overall latency is 89.25 ms + 118.43 ms + -7.31 ms = 200.05 ms Jun 17 21:51:09 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:51:09 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:09 netbook pulseaudio[16443]: Checking for dead streams ... Jun 17 21:51:10 netbook pulseaudio[16443]: Loopback overall latency is 3.94 ms + 200.35 ms + -4.00 ms = 200.06 ms Jun 17 21:51:10 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:10 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:11 netbook pulseaudio[16443]: Loopback overall latency is 97.22 ms + 106.93 ms + -3.73 ms = 200.05 ms Jun 17 21:51:11 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:51:11 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:12 netbook pulseaudio[16443]: Loopback overall latency is 5.98 ms + 197.63 ms + -3.16 ms = 200.06 ms Jun 17 21:51:12 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:12 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:12 netbook pulseaudio[16443]: Created 11 "UNIX socket client" Jun 17 21:51:12 netbook pulseaudio[16443]: CLI got EOF from user. Jun 17 21:51:12 netbook pulseaudio[16443]: Freed 11 "UNIX socket client" Jun 17 21:51:13 netbook pulseaudio[16443]: Loopback overall latency is 100.24 ms + 106.93 ms + -6.56 ms = 200.05 ms Jun 17 21:51:13 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:51:13 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:13 netbook pulseaudio[16443]: Updating sample rate Jun 17 21:51:13 netbook pulseaudio[16443]: wi=42964354 ri=39779954 Jun 17 21:51:13 netbook pulseaudio[16443]: Write index deviates by 3443.80 ms, expected 500.00 ms Jun 17 21:51:13 netbook pulseaudio[16443]: Estimated target rate: 48152 Hz, using average of 48170 Hz (α=0.767) Jun 17 21:51:13 netbook pulseaudio[16443]: Sample rates too different, not adjusting (44100 vs. 55260). Jun 17 21:51:13 netbook pulseaudio[16443]: Updated sampling rate to 44100 Hz. Jun 17 21:51:14 netbook pulseaudio[16443]: Loopback overall latency is 14.48 ms + 193.12 ms + -6.78 ms = 200.06 ms Jun 17 21:51:14 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:14 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:15 netbook pulseaudio[16443]: Loopback overall latency is 110.20 ms + 92.47 ms + -2.32 ms = 200.05 ms Jun 17 21:51:15 netbook pulseaudio[16443]: Loopback latency at base rate is 200.06 ms Jun 17 21:51:15 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44102 Hz. Jun 17 21:51:16 netbook pulseaudio[16443]: Loopback overall latency is 40.60 ms + 164.05 ms + -4.18 ms = 200.07 ms Jun 17 21:51:16 netbook pulseaudio[16443]: Loopback latency at base rate is 200.08 ms Jun 17 21:51:16 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. Jun 17 21:51:17 netbook pulseaudio[16443]: Loopback overall latency is 33.51 ms + 172.37 ms + -5.57 ms = 200.06 ms Jun 17 21:51:17 netbook pulseaudio[16443]: Loopback latency at base rate is 200.07 ms Jun 17 21:51:17 netbook pulseaudio[16443]: [NullSinkDel] Updated sampling rate to 44103 Hz. ^C xxx@netbook:~$ #### Netbook RTP receiver END INFO ####
Hi, I solved this - cause of the problem was a mismatch with the sample rate of the source... ## sender side: Source #3 State: RUNNING Name: alsa_input.usb-041e_USB_Audio-00.iec958-stereo Description: SoundBlaster MP3+ Digital Stereo (IEC958) Driver: module-alsa-card.c Sample Specification: s16le 2ch 48000Hz ^^^^ Source Output #0 Driver: module-rtp-send.c Owner Module: 4 Client: n/a Source: 3 Sample Specification: s16be 2ch 44100Hz ^^^ Channel Map: front-left,front-right Format: pcm, format.sample_format = "\"s16be\"" format.rate = "44100" format.channels = "2" format.channel_map = "\"front-left,front-right\"" Corked: no Mute: no Volume: front-left: 65536 / 100% / 0,00 dB, front-right: 65536 / 100% / 0,00 dB balance 0,00 Buffer Latency: 1655 usec Source Latency: 1196 usec Resample method: copy Properties: media.name = "RTP Monitor Stream" rtp.source = "0.0.0.0" rtp.destination = "192.168.2.15" rtp.mtu = "1280" rtp.port = "46750" rtp.ttl = "1" ## receiver side: Sink Input #50 Driver: module-rtp-recv.c Owner Module: 25 Client: n/a Sink: 1 Sample Specification: s16be 2ch 44364Hz Channel Map: front-left,front-right Format: pcm, format.sample_format = "\"s16be\"" format.rate = "44100" format.channels = "2" Corked: no Mute: no Volume: front-left: 65536 / 100% / 0.00 dB, front-right: 65536 / 100% / 0.00 dB balance 0.00 Buffer Latency: 1679994 usec Sink Latency: 36922 usec Resample method: speex-float-1 Properties: media.role = "stream" media.name = "RTP Stream (PulseAudio RTP Stream on raspberrypi)" rtp.session = "PulseAudio RTP Stream on raspberrypi" rtp.origin = "pi 3864982388 0 IN IP4 192.168.2.30" rtp.payload = "10" module-stream-restore.id = "sink-input-by-media-role:stream" SOLUTION: If I load relevant modules with an explicit rate value of 48000, everything works as expected: ## On sender side: pacmd load-module module-rtp-send source=alsa_input.usb-041e_USB_Audio-00.iec958-stereo destination_ip=192.168.2.30 rate=48000 ## on receiver side: pacmd load-module module-rtp-recv sink=NullSink sap_address=192.168.2.15 => works as expected on receiver side. Sorry for not noticing something probably rather obvious... Also apologies for a probably stupid question: should modules like module-rtp-send or module-loopback not automatically recognize the sample rate of the source and either use the same value or re-sample? Kind regards.