Pipewire version has high latency

[RX14]

I'm using pulseeffects-git from AUR right now (on Arch) with pipewire and pipewire-pulse. I'm using it to filter my microphone input into discord with rnnoise and an equaliser. The latency for this pipeline from input speech to the speech displaying on the spectrogram and being output to discord is quite high (between the spectrogram and discord is low). On first startup, the latency is high, but can be rescued by turning off and on the recording pipeline. Once the pipeline is restarted, the latency is initially low but drifts higher over time, up to around a second, unusable for voice chat. I didn't observe this behaviour on the pulseaudio version.

The "reporting bugs" instructions are still for pulse, so I'm not sure what more information to provide.

[wwmm]

The "reporting bugs" instructions are still for pulse, so I'm not sure what more information to provide.

G_MESSAGES_DEBUG=pulseeffects pulseeffects still applies to the PipeWire version. Just remember to kill the current instance first pulseeffects -q.

Is there any difference if you change the latency settings in our menu?

In any case this sounds like a PipeWire issue. Our effects pipeline is still implemented on GStreamer just like it was done in Pulseaudio. The difference is that instead of using Gstreamer's pulsesrc and pulsesink plugins we now use pipewiresrc and pipewiresink. But as you can see in this PipeWire issue https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/30 pipewiresrc does not seem to be reporting its latency.

[werthen]

I am facing the same issues. A lot of latency being introduced as time goes on. Taking out Noise Reduction seems to help, but my machine should have no problem running this, as I also use pro audio tools as well.

Using the command posted I get this:

(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.593: pipe_manager: pulseeffects_source port 98 is connected to Firefox port 164
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.593: pipe_manager: pulseeffects_source port 100 is connected to Firefox port 148
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.612: sie: rtkit: changed GstPipeWireSrc:source thread real-time priority value to 5
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.615: sie: rtkit: changed GstQueue:queue1 thread real-time priority value to 5
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.631: sie: sampling rate: 48000 Hz
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.677: peadapter: input block size 1085 frames
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.678: peadapter: we will read in chunks of 480 frames
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.679: sie: total latency: 30 ms
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.680: sie: NULL -> READY -> PLAYING
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.681: sie: READY -> PAUSED -> PLAYING
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.682: sie: PAUSED -> PLAYING -> VOID_PENDING
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:46.682: sie: total latency: 30 ms
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:54.248: pipe_manager: Stream/Output/Audio Firefox was removed
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:54.248: pipe_manager: Stream/Input/Audio Firefox was removed
(pulseeffects:3357): pulseeffects-DEBUG: 22:49:54.250: pipe_manager: Stream/Output/Audio 102 Firefox was added

Changing latency only has a worse effect when reduced. Otherwise it stays the same (which is right now not great).

I can not upload mp3 files to github, so here is a soundcloud link which shows the crackling delayed audio I have https://soundcloud.com/jttrmusic/pulseeffects-audio-recording/s-MyH8l4ICFXl

[wwmm]

@werthen the log above was taken with which latency value set in our menu? I ask because the number of input frames delivered by PipeWire seem too high for the default value of 50 ms:

peadapter: input block size 1085 frames

I did a quick test with my C-1u Beringher mic and I have this:

peadapter: input block size 256 frames

[wwmm]

I did another test with my webcam C270:

peadapter: input block size 228 frames

Again PipeWire is sending a lot less frames than in your case. Which microphone are you using? I am suspecting PipeWire is not handling it as it should.

[wwmm]

There is one test you can do. Kill pulseeffects pulseeffects -q and run the command gst-launch-1.0 -v pipewiresrc ! queue ! audio/x-raw ! pipewiresink while the microphone is set the as default source. If the sound is still bad in your speakers the problem is not in PulseEffects. This command is a minimal version of our microphone effects pipeline. I only enable a few options and set a few properties.

[wwmm]

I only enable a few options and set a few properties.

And obviously we put plugins in the middle. What may or may not be making a difference. But this is something you can test disabling all plugins.

[werthen]

@wwmm I've read your comments and will address them in a single one. First of all: My microphone is a condenser mic connected to a Focusrite Scarlett 6i6 audio interface, so my mic is by all means that interface. I've noticed the issue only pops up in some applications. Discord and Firefox are two of them, but in google chrome it behaves correctly.

The latency set in the menu is 50ms, but I experimented with that value but nothing helps.

Using the command you provided the microphone sounds fine. I'm also able to use my microphone in calls without pulseeffects without issue.

When disabling plugins, the issue is still there. I am testing with the RNNoise and Maximizer plugins.

So again, it seems only some applications have this issue, when looking at the logs for chrome and firefox you also see the input block size differ greatly, even though my setup is exactly the same.

Chrome output

(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.033: pipe_manager: Stream/Input/Audio 126 Google Chrome input was added
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.034: pipe_manager: pulseeffects_source port 120 is connected to Google Chrome input port 125
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.034: pipe_manager: pulseeffects_source port 122 is connected to Google Chrome input port 195
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.047: sie: rtkit: changed GstQueue:queue1 thread real-time priority value to 5
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.048: sie: rtkit: changed GstPipeWireSrc:source thread real-time priority value to 5
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.072: pipe_manager: Stream/Output/Audio 171 Google Chrome was added
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 167 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 49
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 157 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 53
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 179 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 55
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 161 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 57
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 137 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 59
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 173 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 61
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 182 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 63
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 160 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 65
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 148 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 67
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 174 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 69
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 191 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 71
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.076: pipe_manager: Google Chrome port 165 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 73
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.081: sie: sampling rate: 48000 Hz
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.113: peadapter: input block size 228 frames
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.113: peadapter: we will read in chunks of 480 frames
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.156: sie: total latency: 35 ms
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.157: sie: NULL -> READY -> PLAYING
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.157: sie: READY -> PAUSED -> PLAYING
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.157: sie: PAUSED -> PLAYING -> VOID_PENDING
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:18.157: sie: total latency: 35 ms
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.236: pipe_manager: Stream/Input/Audio Google Chrome input was removed
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.330: pipe_manager: Stream/Output/Audio 204 Google Chrome was added
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 186 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 49
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 195 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 53
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 197 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 55
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 125 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 57
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 155 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 59
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 139 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 61
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 146 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 63
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 141 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 65
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 185 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 67
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 147 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 69
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 203 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 71
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:31.332: pipe_manager: Google Chrome port 124 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 73
(pulseeffects:41580): pulseeffects-DEBUG: 10:02:36.143: sie: No app wants to play audio. We will stop our pipeline.

Output Firefox

(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.569: pipe_manager: Stream/Input/Audio 192 Firefox was added
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 142 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 49
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 141 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 53
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 195 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 55
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 206 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 57
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 151 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 59
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.572: pipe_manager: Firefox port 185 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 61
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 197 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 63
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 208 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 65
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 143 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 67
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 147 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 69
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 125 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 71
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: Firefox port 199 is connected to alsa_output.usb-Focusrite_Scarlett_6i6_USB_100037D8-00.multichannel-output port 73
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: pulseeffects_source port 120 is connected to Firefox port 181
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.573: pipe_manager: pulseeffects_source port 122 is connected to Firefox port 171
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.586: sie: rtkit: changed GstQueue:queue1 thread real-time priority value to 5
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.588: sie: rtkit: changed GstPipeWireSrc:source thread real-time priority value to 5
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.603: sie: sampling rate: 48000 Hz
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.645: peadapter: input block size 996 frames
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.645: peadapter: we will read in chunks of 480 frames
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.646: sie: total latency: 30 ms
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.647: sie: NULL -> READY -> PLAYING
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.647: sie: READY -> PAUSED -> PLAYING
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.648: sie: PAUSED -> PLAYING -> VOID_PENDING
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:35.648: sie: total latency: 30 ms
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:47.452: pipe_manager: Stream/Output/Audio Firefox was removed
(pulseeffects:41580): pulseeffects-DEBUG: 10:05:47.452: pipe_manager: Stream/Input/Audio Firefox was removed

[werthen]

Please also disregard the real-time log message, I enabled that option at one time but the issues are still there without it.

[RX14]

My reproduction of this bug was in Discord too, fwiw. I didn't consider it would depend on the application receiving the audio...

This does smell more like a pipewire issue in this case.

[wwmm]

I think I will need to reproduce this on my computer to see what is really going on. Is there a step by step to reproduce this on Firefox or discord that does not require actually talking to someone?

[wwmm]

I didn't consider it would depend on the application receiving the audio...

I am suspecting this is related to how PipeWire is handling each application latency request. And on how the updated value is being propagated on the processing chain when one of them asks for a lower value.

[werthen]

I think I will need to reproduce this on my computer to see what is really going on. Is there a step by step to reproduce this on Firefox or discord that does not require actually talking to someone?

I use this voice recorder to test it in the browser. https://online-voice-recorder.com/

[werthen]

I didn't consider it would depend on the application receiving the audio...

I am suspecting this is related to how PipeWire is handling each application latency request. And on how the updated value is being propagated on the processing chain when one of them asks for a lower value.

I just tried the latest master branch (seeing it pertained to the buffer issues) and the issue seems to be fixed, now both in firefox and discord I can use pulseeffects no problem!

[wwmm]

I just tried the latest master branch (seeing it pertained to the buffer issues) and the issue seems to be fixed, now both in firefox and discord I can use pulseeffects no problem!

I wasn't expecting that commit to affect this issue. My intention was fixing another bug I found out while investigating this one. I say this because you said

When disabling plugins, the issue is still there...

The changes in the latest commit only take place when rnnoise, convolver or the crystalizer plugins are enabled. There shouldn't be any difference if all plugins are disabled. Strange...

[werthen]

I just tried the latest master branch (seeing it pertained to the buffer issues) and the issue seems to be fixed, now both in firefox and discord I can use pulseeffects no problem!

I wasn't expecting that commit to affect this issue. My intention was fixing another bug I found out while investigating this one. I say this because you said

When disabling plugins, the issue is still there...

The changes in the latest commit only take place when rnnoise, convolver or the crystalizer plugins are enabled. There shouldn't be any difference if all plugins are disabled. Strange...

Now I'm starting to doubt it myself, maybe I just tested it when disabling the effects after Firefox picked up the Pulseeffects Source. I could roll back and recompile from the previous commit if that would be of any help, but that would take a bit more time as right now I'm just using the package on the AUR.

[wwmm]

Well... If that problem was fixed I wouldn't bother installing an older version :-). It will probably be better to do some tests with the latest version every now and then to check if everything is still fine.

The reason why these plugins are "problematic" is that they require specific buffer sizes to work. Crystalizer and the convolver require buffer sizes following a power of 2. And rnnoise needs buffers with 480 samples. For some reason pipewiresink does not seem to like the idea of receiving buffers with a different size than the one negotiated when the pipeline was started. This wasn't a problem in pulsesink.

In any case the solution is more robust now. Different from Pulseaudio PipeWire tries to make its buffer size to follow a power of 2 in some situations. So now our peadapter plugin can just pass through the buffers when we detect that PipeWire changed its buffers size to a power of 2.

In rnnoise passthrough is not an option. So now I am using 2 instances of peadapter on it. One before forcing the size to 480 and another after forcing the size to whatever size PipeWire is sending us. This way pipewiresink receives buffers with the same size as the ones sent by pipewiresrc. Maybe that fixed this issue.

[wwmm]

https://online-voice-recorder.com/

Thanks. I did not think about searching for an online tool. I did some test with the older version on Firefox and it seems fine. Did you update PipeWire in the meantime? There was a new PipeWire release yesterday. Maybe that fixed this issue.

[werthen]

https://online-voice-recorder.com/

Thanks. I did not think about searching for an online tool. I did some test with the older version on Firefox and it seems fine. Did you update PipeWire in the meantime? There was a new PipeWire release yesterday. Maybe that fixed this issue.

I did update pipewire but the latest version on the Arch repositories is from 20/01, so that didnt influence my tests.

[wwmm]

You are right. For some reason I thought PipeWire 0.3.20 was released yesterday... I must be going crazy XD

[RX14]

I tested this with the latest master build and it's all fixed for me too. Thanks!

[RX14]

Actually never mind, this still occurs, the latency seems better now, but probably still around 500ms max. When I disable and re-enable the noise reduction plugin the latency lowers again to almost zero then slowly climbs up. The immediate latency problem still seems solved, but I suspect there's no latency feedback to drop samples when the 50ms latency is breached by jitter to bound it to that value.

[wwmm]

Just to make sure I understand your issue by latency do you mean the time elapsed between the moment you speak and the one where you see activity in the spectrum or the moment you listen to your voice on your speakers?

[RX14]

Yep, moment I speak to it showing up in the spectrum, or showing up in discord. It slowly creeps up, whether noise reduction is enabled or not. My device is a laptop so the scheduling jitter is very high. I imagine that CPU spikes cause latency spikes in the scheduler and this can blow past 50ms in the 99th percentile, then there is no feedback loop from latency measured to dropping samples.

[wwmm]

What is shown by pw-top when the latency gets bigger?

[RX14]

Here's without pulseeffects, when everything's fine

Here's with pulseeffects, after it's ran a while and latency is getting up there

While testing loopback through discord (it has an audio test feature) without pulseeffects, the latency stays bounded and quite low, when testing with pulseffects, it starts off a bit worse as expected, but ends up being able to say whole phrases before you hear yourself coming back.

[RX14]

I've started using a scarlett solo USB interface, and testing using mumble instead of discord. The problem is identical: 500ms of latency which is too much to bear when talking to someone in realtime because you keep talking over each other. The pw-top output with the multitude of errors is about identical.

This is using latest pipewire.

[wwmm]

And to make things even more strange alsa_input.pci latency shown by pw-top is smaller when PulseEffects is running...

While testing loopback through discord (it has an audio test feature)

I tried a few tests with it but so far I could not reproduce this latency drift yet.

[wwmm]

I wonder if the limitations of my sound card driver are hiding this issue. My card is one of those where Pulseaudio is not able to use timer based scheduling because a batch feature is disabled by the driver. So the scheduling is based on the system IRQ frequency. I do not know how PipeWire is handling this. Maybe something is wrong with it and there is a drift that can only be seen when the scheduling is not tied to the system IRQ frequency. This could explain why I can't reproduce the drift.

[wwmm]

I've started using a scarlett solo USB interface

And as far as I remember usb cards never use IRQ based scheduling. So if PipeWire has a flaw with timer based scheduling using a usb device will not help.

[wwmm]

I know that the issue is only present when PulseEffects is running. But PipeWire is still the one mixing all streams together and synchronizing the devices.

[wwmm]

How long does it take for the drift to be noticeable? I am doing a test now where discord loopback has been active for a few minutes and so far the delay is constant. Depending on whether I also enable output effects instead of only mic effects the amount of delay can be larger. But it seems constant.

[RX14]

How long does it take for the drift to be noticeable? I am doing a test now where discord loopback has been active for a few minutes and so far the delay is constant. Depending on whether I also enable output effects instead of only mic effects the amount of delay can be larger. But it seems constant.

10 minutes or so.

I've recreated the pulseeffects setup using JACK plugins feeding into mumble and found that I need to increase PULSE_LATENCY_MSEC=22 (1024/48000) for the pineline to not have underruns. I suspect that your problem with reproducing this is that you're not running on a dual core laptop and so the pipeline is never underrunning (because you have more cores than scheduled processes, for me it's the other way around, and this has much higher worst case linux scheduler latency) and you're never getting underruns. Do you see any errors in the pipeline in pw-top?

The desired effect on underruns is for samples to be dropped (clicks and pops like JACK) instead of the latency of the pipeline growing. I suspect this is the issue, but I may well be wrong.

[wwmm]

Do you see any errors in the pipeline in pw-top?

Oh... I thought you were seeing the errors somewhere else. I did not notice errors in pw-top. I will have to give a class on microsoft teams now but I will try to pay attention the next time I test.

I suspect that your problem with reproducing this is that you're not running on a dual core laptop

I am on a Ryzen 3700x. So I definitely have more cores.

Based on the output of sudo journalctl | grep -i underrun I only have 2 underruns produced while I was playing Atelier Ryza 2.

[RX14]

For reference: I have 2-3ms of idle jitter on my system. This means that in the 99th percentile, sleep(100us) will return 2-3ms late. It's a heavily loaded laptop!

Using the same PULSE_LATENCY_MSEC=22 (on mumble) when testing with pulseeffects reduces the errors in the pipeline in pw-top to one every 30s or so. I'm glad I got to fiddle around with pw-jack cause it lead me to understand the problem more, and how pipewire handles latency in pipelines. Reducing the default pulseaudio latency request means that the whole pipeline has more time to not underrun with.

Unfortunately, this has not solved the problem at all :(

My suspicions of underruns being related to this problem seems to be incorrect, since while typing this reply, the pipeline has only underrun 10 times, but the latency has increased to 3 seconds! I'm going to double check that this doesn't occur with the JACK setup and report back.

[RX14]

Well.... It seems like this is just a pipewire or pipewire-pulse issue at this point... I'm using mumble on it's own to monitor the audio input, no pulseeffects, and while the delay is a lot less noticable, and the delay decreases a lot slower, it does slowly reach unusable levels.

[RX14]

I've discovered the problem with monitoring my own audio for measuring latency: the sample clock in my audio interface runs slightly faster than the one in my soundcard, meaning that unless the "loopback program" (mumble and audacity both fail this test) drops samples, the samples pile up on the sending side because they are arriving slightly faster than they are sent out. This obviously doesn't cause a problem in actual use because you're not sending the audio directly to your own soundcard.

The issue I reported is real! I discovered it while talking to my friends. But it seems that my testing method for it has been flawed from the start and so all of my above conclusions are flawed. I'll have to start again with tracing this issue down.

[werthen]

For what it's worth, I'm also still having the issue when running pulseeffects, but also delayed with a few minutes. I myself do not notice it when using loopback for example, but when calling with friends I've had delays of almost 10 seconds after a while.

Disabling pulseeffects returns it back to normal.

[wwmm]

but the latency has increased to 3 seconds! but when calling with friends I've had delays of almost 10 seconds after a while.

That is too much. Really too much. Something is terribly broken somewhere. The question is what is broken... I still do not see what I could do from PulseEffects side. Somehow this problem seems to be at a lower level...

Disabling pulseeffects returns it back to normal.

When PulseEffects is running there is a lot more going on. We load virtual devices and move the applications to it. When effects both for mic and apps output are enabled we put 2 GStreamer pipelines that are recording from something and playing to something at the same time. So the sound server has a lot more to do when we are running. It can be something wrong in PulseEffects. But it could also just be the amount of stress on the server that is triggering the bug.

[werthen]

Yeah actually a real easy way to replicate this for me is to just enable every single effect. Over the course of a few minutes using discord's mic test I hear the lag getting worse and worse (just a second in the beginning, and almost 8 seconds after just a minute). I'm using not so low end hardware as well (Ryzen 7 2700X), so that shouldn't be the biggest issue. Almost seems as if it plays out its buffer partly, and the buffer just keeps getting added on to because it's not being played back in time.

[wwmm]

Yeah actually a real easy way to replicate this for me is to just enable every single effect

Interesting. Not all of the plugins used in PulseEffects add latency. Some change the audio buffer in place. The cpu usage will increase. But a 2700X should be more than capable of handling this load.

[wwmm]

Yeah actually a real easy way to replicate this for me is to just enable every single effect

In both pipelines or only in the microphone effects pipeline?

[wwmm]

@RX14 and @werthen what kind of priority type are you using in PulseEffects settings menu? Real Time, Niceness or None? I think I had it set to real time in all my tests.

[wwmm]

It is not the priority type. I was finally able to find a way reproduce this. Although it is not that reliable yet. For some reason if I apply effects both for Discord input and output I do not see the issue. But if I apply effects only for the microphone sometimes I can see the delay getting bigger over time.

[wwmm]

But even this way I only see the drift if I enable the webrtc plugin.

[wwmm]

I did a few tests and something is not right in the webrtc plugin. I will investigate. If this plugin is enabled when the pipeline that applies effects for apps output is running everything is fine. But If the output effects pipeline is disabled the delay gets bigger really fast. This must be related to the webrtc probe that has to be put in the sound card in other to remove echo.

[wwmm]

The master branch has been updated. Now the webrtc plugin does not cause a delay drift anymore. So far I could not find any other way to cause the drift. So if this is happening for you when the webrtc plugin is disabled I have no idea why it is happening.

[RX14]

I've not been using the webrtc plugin at all. My initial report was with just rnnoise.

Keep in mind that using the discord mic test will always drift (even without pulseffects) if you're using different soundcards for the mic and the audio output. The only way to test properly is using actual calls in discord or mumble, and looking at the speaking indicator to estimate delay.

I've switched back to using pulseaudio and pulseffects-legacy for now, I don't have the time to be able to reproduce this.

[werthen]

I can still test it out, the noise reduction is a nice to have, but not critical for me. I also have only noise reduction and maximizer enabled usually.

[wwmm]

I also have only noise reduction and maximizer enabled usually.

Ok. So there is something else going on. The noise reduction already has the improvements that I did to the webrtc plugin today. And so far I did not find another way to trigger the delay after the webrtc fix. So I am not sure about what else could be doing this.

[werthen]

Just to give an update: I am able to use pulseeffects and it will work in almost all cases. I've had cases where the delay became a few seconds, but didnt think of recording logs or anything of the like. Ill keep trying to run pulseeffects in debug mode and look at pw-top if/when the problem arises.