search

kcat / openal-soft

OpenAL Soft is a software implementation of the OpenAL 3D audio API.
Other
2.16k stars 522 forks source link

context creation takes ~2s with pipewire (~1ms with pulse) #930

Closed fabiangreffrath closed 4 months ago

fabiangreffrath commented 10 months ago

Hi,

this is in a GNOME environment on a system running recent Debian testing [1].

$ cat oal.c

#include <stddef.h>
#include <stdio.h>
#include <time.h>

#include "alc.h"

struct timespec a, b;

int main (void)
{
    ALCdevice *device;
    ALCcontext *context;

    device = alcOpenDevice(NULL);

    clock_gettime(CLOCK_MONOTONIC_RAW, &a);
    context = alcCreateContext(device, NULL);
    clock_gettime(CLOCK_MONOTONIC_RAW, &b);

    printf("%lu\n", (b.tv_sec - a.tv_sec) * 1000000 + (b.tv_nsec - a.tv_nsec) / 1000);

    return 0;
}

CFLAGS="-I/usr/include/AL -lopenal" LDLIBS=$CFLAGS make oal

This is what happens with the pipewire backend:

$ cat alsoft.conf 
[general]
drivers = pipewire
$ for i in 1 2 3; do ./oal ; done
2013660
2013418
2007904

Now let's change to the pulse backend:

$ cat alsoft.conf 
[general]
drivers = pulse
$ for i in 1 2 3; do ./oal ; done
8287
9012
6866

[1] library versions:

ii  gstreamer1.0-pipewire:amd64     0.3.83-1        amd64        GStreamer 1.0 plugin for the PipeWire multimedia server
ii  libcanberra-pulse:amd64         0.30-10         amd64        PulseAudio backend for libcanberra
ii  libpipewire-0.3-0:amd64         0.3.83-1        amd64        libraries for the PipeWire multimedia server
ii  libpipewire-0.3-common          0.3.83-1        all          libraries for the PipeWire multimedia server - common files
ii  libpipewire-0.3-dev:amd64       0.3.83-1        amd64        libraries for the PipeWire multimedia server - development
ii  libpipewire-0.3-modules:amd64   0.3.83-1        amd64        libraries for the PipeWire multimedia server - modules
ii  libpulse-dev:amd64              16.1+dfsg1-2+b1 amd64        PulseAudio client development headers and libraries
ii  libpulse-mainloop-glib0:amd64   16.1+dfsg1-2+b1 amd64        PulseAudio client libraries (glib support)
ii  libpulse0:amd64                 16.1+dfsg1-2+b1 amd64        PulseAudio client libraries
ii  pipewire:amd64                  0.3.83-1        amd64        audio and video processing engine multimedia server
ii  pipewire-alsa:amd64             0.3.83-1        amd64        PipeWire ALSA plugin
ii  pipewire-audio                  0.3.83-1        all          recommended set of PipeWire packages for a standard audio desktop use
ii  pipewire-bin                    0.3.83-1        amd64        PipeWire multimedia server - programs
ii  pipewire-pulse                  0.3.83-1        amd64        PipeWire PulseAudio daemon
kcat commented 10 months ago

Are you able to provide an OpenAL Soft trace log? Set the ALSOFT_LOGLEVEL env var to 3, and it will print to stderr.

The 2 second delay makes it seem like PipeWirePlayback::start is timing out while waiting to get the stream buffering info (it starts playback, then waits for about 2 seconds while periodically calling pw_stream_get_time_n to get the buffering length and update size for the stream, which isn't otherwise available right away). It can take a few cycles before that info becomes available, but definitely shouldn't take 2 seconds.

I'm currently using PipeWire 0.3.80 without a problem, so I wonder if some behavior changed in a newer version or there's something about the system/audio device causing the detection to fail.

fabiangreffrath commented 10 months ago

Sure, please find its output attached. The 2s delay happens after the Fixed device latency: 0ns has been printed.

$ ALSOFT_LOGLEVEL=3 ./oal 
[ALSOFT] (II) Initializing library v1.23.1-unknown UNKNOWN
[ALSOFT] (II) Supported backends: pipewire, pulse, alsa, sndio, oss, jack, port, null, wave
[ALSOFT] (II) Loading config /etc/openal/alsoft.conf...
[ALSOFT] (II) Loading config /etc/xdg/alsoft.conf...
[ALSOFT] (II) Loading config /home/fabian/.alsoftrc...
[ALSOFT] (II) Loading config /home/fabian/.config/alsoft.conf...
[ALSOFT] (II) Got binary: "/home/fabian", "oal"
[ALSOFT] (II) Loading config /home/fabian/alsoft.conf...
[ALSOFT] (II)  found 'drivers' = 'pipewire'
[ALSOFT] (II) Key disable-cpu-exts not found
[ALSOFT] (II) Vendor ID: ""
[ALSOFT] (II) Name: "12th Gen Intel(R) Core(TM) i5-1235U"
[ALSOFT] (II) Extensions: +SSE +SSE2 +SSE3 +SSE4.1
[ALSOFT] (II) Key rt-prio not found
[ALSOFT] (II) Key rt-time-limit not found
[ALSOFT] (II) Key game_compat/enable-sub-data-ext not found
[ALSOFT] (II) Key game_compat/reverse-x not found
[ALSOFT] (II) Key game_compat/reverse-y not found
[ALSOFT] (II) Key game_compat/reverse-z not found
[ALSOFT] (II) Key game_compat/nfc-scale not found
[ALSOFT] (II) Key resampler not found
[ALSOFT] (II) Key uhj/decode-filter not found
[ALSOFT] (II) Key uhj/filter not found
[ALSOFT] (II) Key uhj/encode-filter not found
[ALSOFT] (II) Key trap-al-error not found
[ALSOFT] (II) Key trap-alc-error not found
[ALSOFT] (II) Key reverb/boost not found
[ALSOFT] (II) Found drivers = "pipewire"
[ALSOFT] (II) Found PipeWire version "0.3.83" (0.3.80 or newer)
[ALSOFT] (II) Key pipewire/assume-audio not found
[ALSOFT] (II) Ignoring metadata "settings"
[ALSOFT] (II) Ignoring node class Midi/Bridge
[ALSOFT] (II) Ignoring metadata "route-settings"
[ALSOFT] (II) Ignoring node class Video/Source
[ALSOFT] (II) Initialized backend "pipewire"
[ALSOFT] (II) Added "pipewire" for playback
[ALSOFT] (II) Added "pipewire" for capture
[ALSOFT] (II) Key excludefx not found
[ALSOFT] (II) Key default-reverb not found
[ALSOFT] (II) Opening default playback device
[ALSOFT] (II) Got default playback device "alsa_output.pci-0000_00_1f.3.analog-stereo"
[ALSOFT] (II) Got default capture device "alsa_input.pci-0000_00_1f.3.analog-stereo"
[ALSOFT] (II) Got sink device "alsa_output.pci-0000_00_1f.3.analog-stereo"
[ALSOFT] (II)   "Built-in Audio Analog Stereo" = ID 54
[ALSOFT] (II) Device ID 54 sample rate: 48000 (range: 44100 -> 48000)
[ALSOFT] (II) Device ID 54 got 2 positions for Stereo
[ALSOFT] (II) Got source device "alsa_input.pci-0000_00_1f.3.analog-stereo"
[ALSOFT] (II)   "Built-in Audio Analog Stereo" = ID 55
[ALSOFT] (II) Device ID 55 sample rate: 48000 (range: 44100 -> 192000)
[ALSOFT] (II) Device ID 55 got 2 positions for Stereo
[ALSOFT] (II) Created device 0x55de8d4f3db0, "Built-in Audio Analog Stereo"
[ALSOFT] (II) Key frequency not found
[ALSOFT] (II) Key period_size not found
[ALSOFT] (II) Key periods not found
[ALSOFT] (II) Key sample-type not found
[ALSOFT] (II) Key channels not found
[ALSOFT] (II) Key ambi-format not found
[ALSOFT] (II) Key hrtf not found
[ALSOFT] (II) Key stereo-encoding not found
[ALSOFT] (II) Pre-reset: Stereo, Float32, 48000hz, 960 / 2880 buffer
[ALSOFT] (II) Key pipewire/rt-mix not found
[ALSOFT] (II) Post-reset: Stereo, Float32, 48000hz, 960 / 2880 buffer
[ALSOFT] (II) Key stereo-mode not found
[ALSOFT] (II) Key cf_level not found
[ALSOFT] (II) Stereo rendering
[ALSOFT] (II) Channel config, Main: 3, Real: 2
[ALSOFT] (II) Allocating 5 channels, 20480 bytes
[ALSOFT] (II) Enabling single-band first-order ambisonic decoder
[ALSOFT] (II) Key sources not found
[ALSOFT] (II) Key sends not found
[ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
[ALSOFT] (II) Key dither not found
[ALSOFT] (II) Key dither-depth not found
[ALSOFT] (II) Dithering disabled
[ALSOFT] (II) Key output-limiter not found
[ALSOFT] (II) Output limiter disabled
[ALSOFT] (II) Fixed device latency: 0ns
[ALSOFT] (II) Post-start: Stereo, Float32, 48000hz, 960 / 2880 buffer
[ALSOFT] (II) Increasing allocated voices to 256
[ALSOFT] (II) Key volume-adjust not found
[ALSOFT] (II) Created context 0x55de8d579c00
kcat commented 10 months ago

That definitely indicates it's timing out waiting for the buffer info, especially given it didn't change the "Post-start" format from "Post-reset" (PipeWire will generally make the update size a power of 2, with the buffer size some multiple of it).

The actual loop that waits for the information is here. The only things that could be different/missing would be:

  1. PipeWire is no longer setting a spa_io_rate_match on the stream (mRateMatch), or is setting one but its rate field is left as 0 indicating no update size. And/or,
  2. The pw_time's avail_buffers and queued_buffers fields are 0, indicating no buffers available or queued on the stream. And/or,
  3. The pw_time's rate field has a 0 denominator, indicating no sample rate/speed for the stream.

If all of those are set properly, it should set the appropriate OpenAL device fields and break out of waiting. It's not good for any of that stuff to be missing, so something is behaving badly with PipeWire.

jsrobson10 commented 10 months ago

I am having a similar issue on KDE Plasma on Arch Linux. For me, pulse (via pipewire-pulse) is instant, but pipewire takes exactly 2 seconds and times out with [ALSOFT] (EE) Timeout getting PipeWire stream buffering info. I had issues linking the oal.c file mentioned, so i ran commands using openal-info (using the most recent build) instead. 

 $ ALSOFT_DRIVERS=pipewire ALSOFT_LOGLEVEL=3 ets "./openal-info"
[2023-11-02 12:37:57] Available playback devices:
[2023-11-02 12:37:57] [ALSOFT] (II) Initializing library v1.23.1-6420bc86 master
[2023-11-02 12:37:57] [ALSOFT] (II) Supported backends: pipewire, pulse, alsa, sndio, oss, jack, port, null, wave
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /etc/openal/alsoft.conf...
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /etc/xdg/alsoft.conf...
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /home/jay/.config/kdedefaults/alsoft.conf...
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /home/jay/.alsoftrc...
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /home/jay/.config/alsoft.conf...
[2023-11-02 12:37:57] [ALSOFT] (II) Got binary: "/home/jay/Documents/git/openal-soft/build", "openal-info"
[2023-11-02 12:37:57] [ALSOFT] (II) Loading config /home/jay/Documents/git/openal-soft/build/alsoft.conf...
[2023-11-02 12:37:57] [ALSOFT] (II) Vendor ID: "AuthenticAMD"
[2023-11-02 12:37:57] [ALSOFT] (II) Name: "AMD Ryzen 5 2600 Six-Core Processor"
[2023-11-02 12:37:57] [ALSOFT] (II) Extensions: +SSE +SSE2 +SSE3 +SSE4.1
[2023-11-02 12:37:57] [ALSOFT] (II) Found PipeWire version "0.3.83" (0.3.83 or newer)
[2023-11-02 12:37:57] [ALSOFT] (II) Ignoring metadata "settings"
[2023-11-02 12:37:57] [ALSOFT] (II) Ignoring node class Midi/Bridge
[2023-11-02 12:37:57] [ALSOFT] (II) Initialized backend "pipewire"
[2023-11-02 12:37:57] [ALSOFT] (II) Added "pipewire" for playback
[2023-11-02 12:37:57] [ALSOFT] (II) Added "pipewire" for capture
[2023-11-02 12:37:57] [ALSOFT] (II) Got default playback device "alsa_output.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.analog-stereo"
[2023-11-02 12:37:57] [ALSOFT] (II) Got default capture device "alsa_input.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.mono-fallback"
[2023-11-02 12:37:57] [ALSOFT] (II) Got sink device "alsa_output.pci-0000_07_00.1.hdmi-stereo"
[2023-11-02 12:37:57] [ALSOFT] (II)   "TU104 HD Audio Controller Digital Stereo (HDMI)" = ID 40
[2023-11-02 12:37:57] [ALSOFT] (II) Device ID 40 enumerable format:
[2023-11-02 12:37:57] [ALSOFT] (II)   sample rate: 48000 (range: 32000 -> 48000)
[2023-11-02 12:37:57] [ALSOFT] (II)   2 positions for Stereo
[2023-11-02 12:37:57] [ALSOFT] (II) Device ID 40 enumerable format:
[2023-11-02 12:37:57] [ALSOFT] (II)   sample rate: 48000 (range: 32000 -> 48000)
[2023-11-02 12:37:57] [ALSOFT] (II) Got sink device "alsa_output.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.analog-stereo"
[2023-11-02 12:37:57] [ALSOFT] (II)   "Audio Adapter (Unitek Y-247A) Analog Stereo" = ID 41
[2023-11-02 12:37:57] [ALSOFT] (II) Device ID 41 enumerable format:
[2023-11-02 12:37:57] [ALSOFT] (II)   sample rate: 48000 (range: 44100 -> 48000)
[2023-11-02 12:37:57] [ALSOFT] (II)   2 positions for Stereo
[2023-11-02 12:37:57] [ALSOFT] (II) Got source device "alsa_input.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.mono-fallback"
[2023-11-02 12:37:57] [ALSOFT] (II)   "Audio Adapter (Unitek Y-247A) Mono" = ID 42
[2023-11-02 12:37:57] [ALSOFT] (II) Device ID 42 enumerable format:
[2023-11-02 12:37:57] [ALSOFT] (II)   sample rate: 48000 (range: 44100 -> 48000)
[2023-11-02 12:37:57] [ALSOFT] (II)   1 position for Mono
[2023-11-02 12:37:57]     Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:37:57]     TU104 HD Audio Controller Digital Stereo (HDMI)
[2023-11-02 12:37:57] Available capture devices:
[2023-11-02 12:37:57]     Audio Adapter (Unitek Y-247A) Mono
[2023-11-02 12:37:57]     Monitor of TU104 HD Audio Controller Digital Stereo (HDMI)
[2023-11-02 12:37:57]     Monitor of Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:37:57] Default playback device: Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:37:57] Default capture device: Audio Adapter (Unitek Y-247A) Mono
[2023-11-02 12:37:57] ALC version: 1.1
[2023-11-02 12:37:57] [ALSOFT] (II) Opening default playback device
[2023-11-02 12:37:57] [ALSOFT] (II) Created device 0x560a7c25c7b0, "Audio Adapter (Unitek Y-247A) Analog Stereo"
[2023-11-02 12:37:57] 
[2023-11-02 12:37:57] ** Info for device "Audio Adapter (Unitek Y-247A) Analog Stereo" **
[2023-11-02 12:37:57] ALC version: 1.1
[2023-11-02 12:37:57] ALC extensions:
[2023-11-02 12:37:57]     ALC_ENUMERATE_ALL_EXT, ALC_ENUMERATION_EXT, ALC_EXT_CAPTURE, ALC_EXT_debug,
[2023-11-02 12:37:57]     ALC_EXT_DEDICATED, ALC_EXTX_direct_context, ALC_EXT_disconnect,
[2023-11-02 12:37:57]     ALC_EXT_EFX, ALC_EXT_thread_local_context, ALC_SOFT_device_clock,
[2023-11-02 12:37:57]     ALC_SOFT_HRTF, ALC_SOFT_loopback, ALC_SOFT_loopback_bformat,
[2023-11-02 12:37:57]     ALC_SOFT_output_limiter, ALC_SOFT_output_mode, ALC_SOFT_pause_device,
[2023-11-02 12:37:57]     ALC_SOFT_reopen_device, ALC_SOFT_system_events
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /home/jay/Documents/git/openal-soft/build for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /home/jay/.local/share/openal/hrtf for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /home/jay/.local/share/flatpak/exports/share/openal/hrtf for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /var/lib/flatpak/exports/share/openal/hrtf for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /usr/local/share/openal/hrtf for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Searching /usr/share/openal/hrtf for *.mhr
[2023-11-02 12:37:57] [ALSOFT] (II)  got /usr/share/openal/hrtf/Default HRTF.mhr
[2023-11-02 12:37:57] [ALSOFT] (II) Adding file entry "/usr/share/openal/hrtf/Default HRTF.mhr"
[2023-11-02 12:37:57] [ALSOFT] (II) Adding built-in entry "!1_Built-In HRTF"
[2023-11-02 12:37:57] Available HRTF profiles:
[2023-11-02 12:37:57]     Default HRTF
[2023-11-02 12:37:57]     Built-In HRTF
[2023-11-02 12:37:57] [ALSOFT] (II) Pre-reset: Stereo, Float32, 48000hz, 960 / 2880 buffer
[2023-11-02 12:37:57] [ALSOFT] (II) Post-reset: Stereo, Float32, 48000hz, 960 / 2880 buffer
[2023-11-02 12:37:57] [ALSOFT] (II) Stereo rendering
[2023-11-02 12:37:57] [ALSOFT] (II) Channel config, Main: 3, Real: 2
[2023-11-02 12:37:57] [ALSOFT] (II) Allocating 5 channels, 20480 bytes
[2023-11-02 12:37:57] [ALSOFT] (II) Enabling single-band first-order ambisonic decoder
[2023-11-02 12:37:57] [ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
[2023-11-02 12:37:57] [ALSOFT] (II) Dithering disabled
[2023-11-02 12:37:57] [ALSOFT] (II) Output limiter disabled
[2023-11-02 12:37:57] [ALSOFT] (II) Fixed device latency: 0ns
[2023-11-02 12:37:57] [ALSOFT] (II) Device ID 41 current format:
[2023-11-02 12:37:57] [ALSOFT] (II)   sample rate: 48000
[2023-11-02 12:37:57] [ALSOFT] (II)   2 positions for Stereo
[2023-11-02 12:37:59] [ALSOFT] (EE) Timeout getting PipeWire stream buffering info
[2023-11-02 12:37:59] [ALSOFT] (II) Post-start: Stereo, Float32, 48000hz, 960 / 2880 buffer
[2023-11-02 12:37:59] [ALSOFT] (II) Increasing allocated voices to 256
[2023-11-02 12:37:59] [ALSOFT] (II) Created context 0x560a7c2dc6a0
[2023-11-02 12:37:59] Device output mode: Stereo (basic)
[2023-11-02 12:37:59] Device sample rate: 48000hz
[2023-11-02 12:37:59] Device HRTF profile: (disabled)
[2023-11-02 12:37:59] OpenAL vendor string: OpenAL Community
[2023-11-02 12:37:59] OpenAL renderer string: OpenAL Soft
[2023-11-02 12:37:59] OpenAL version string: 1.1 ALSOFT 1.23.1
[2023-11-02 12:37:59] OpenAL extensions:
[2023-11-02 12:37:59]     AL_EXT_ALAW, AL_EXT_BFORMAT, AL_EXT_debug, AL_EXTX_direct_context,
[2023-11-02 12:37:59]     AL_EXT_DOUBLE, AL_EXT_EXPONENT_DISTANCE, AL_EXT_FLOAT32, AL_EXT_IMA4,
[2023-11-02 12:37:59]     AL_EXT_LINEAR_DISTANCE, AL_EXT_MCFORMATS, AL_EXT_MULAW,
[2023-11-02 12:37:59]     AL_EXT_MULAW_BFORMAT, AL_EXT_MULAW_MCFORMATS, AL_EXT_OFFSET,
[2023-11-02 12:37:59]     AL_EXT_source_distance_model, AL_EXT_SOURCE_RADIUS, AL_EXT_STATIC_BUFFER,
[2023-11-02 12:37:59]     AL_EXT_STEREO_ANGLES, AL_LOKI_quadriphonic, AL_SOFT_bformat_ex,
[2023-11-02 12:37:59]     AL_SOFTX_bformat_hoa, AL_SOFT_block_alignment, AL_SOFT_buffer_length_query,
[2023-11-02 12:37:59]     AL_SOFT_callback_buffer, AL_SOFTX_convolution_effect,
[2023-11-02 12:37:59]     AL_SOFT_deferred_updates, AL_SOFT_direct_channels,
[2023-11-02 12:37:59]     AL_SOFT_direct_channels_remix, AL_SOFT_effect_target, AL_SOFT_events,
[2023-11-02 12:37:59]     AL_SOFT_gain_clamp_ex, AL_SOFTX_hold_on_disconnect, AL_SOFT_loop_points,
[2023-11-02 12:37:59]     AL_SOFTX_map_buffer, AL_SOFT_MSADPCM, AL_SOFT_source_latency,
[2023-11-02 12:37:59]     AL_SOFT_source_length, AL_SOFT_source_resampler, AL_SOFT_source_spatialize,
[2023-11-02 12:37:59]     AL_SOFT_source_start_delay, AL_SOFT_UHJ, AL_SOFT_UHJ_ex
[2023-11-02 12:37:59] Available resamplers:
[2023-11-02 12:37:59]     Nearest
[2023-11-02 12:37:59]     Linear
[2023-11-02 12:37:59]     Cubic *
[2023-11-02 12:37:59]     11th order Sinc (fast)
[2023-11-02 12:37:59]     11th order Sinc
[2023-11-02 12:37:59]     23rd order Sinc (fast)
[2023-11-02 12:37:59]     23rd order Sinc
[2023-11-02 12:37:59] EFX version: 1.0
[2023-11-02 12:37:59] Max auxiliary sends: 2
[2023-11-02 12:37:59] Supported filters:
[2023-11-02 12:37:59]     Low-pass, High-pass, Band-pass
[2023-11-02 12:37:59] Supported effects:
[2023-11-02 12:37:59]     EAX Reverb, Reverb, Chorus, Distortion, Echo, Flanger, Frequency Shifter,
[2023-11-02 12:37:59]     Vocal Morpher, Pitch Shifter, Ring Modulator, Autowah, Compressor,
[2023-11-02 12:37:59]     Equalizer, Dedicated Dialog, Dedicated LFE
[2023-11-02 12:37:59] [ALSOFT] (II) Freeing context 0x560a7c2dc6a0
[2023-11-02 12:37:59] [ALSOFT] (II) Freed 0 context property objects
[2023-11-02 12:37:59] [ALSOFT] (II) Freed 0 AuxiliaryEffectSlot property objects
[2023-11-02 12:37:59] [ALSOFT] (II) Freeing device 0x560a7c25c7b0

$ ALSOFT_DRIVERS=pulse ALSOFT_LOGLEVEL=3 ets "./openal-info"
[2023-11-02 12:40:31] Available playback devices:
[2023-11-02 12:40:31] [ALSOFT] (II) Initializing library v1.23.1-6420bc86 master
[2023-11-02 12:40:31] [ALSOFT] (II) Supported backends: pipewire, pulse, alsa, sndio, oss, jack, port, null, wave
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /etc/openal/alsoft.conf...
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /etc/xdg/alsoft.conf...
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /home/jay/.config/kdedefaults/alsoft.conf...
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /home/jay/.alsoftrc...
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /home/jay/.config/alsoft.conf...
[2023-11-02 12:40:31] [ALSOFT] (II) Got binary: "/home/jay/Documents/git/openal-soft/build", "openal-info"
[2023-11-02 12:40:31] [ALSOFT] (II) Loading config /home/jay/Documents/git/openal-soft/build/alsoft.conf...
[2023-11-02 12:40:31] [ALSOFT] (II) Vendor ID: "AuthenticAMD"
[2023-11-02 12:40:31] [ALSOFT] (II) Name: "AMD Ryzen 5 2600 Six-Core Processor"
[2023-11-02 12:40:31] [ALSOFT] (II) Extensions: +SSE +SSE2 +SSE3 +SSE4.1
[2023-11-02 12:40:31] [ALSOFT] (II) Initialized backend "pulse"
[2023-11-02 12:40:31] [ALSOFT] (II) Added "pulse" for playback
[2023-11-02 12:40:31] [ALSOFT] (II) Added "pulse" for capture
[2023-11-02 12:40:31] [ALSOFT] (II) Got device "Audio Adapter (Unitek Y-247A) Analog Stereo", "alsa_output.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.analog-stereo"
[2023-11-02 12:40:31] [ALSOFT] (II) Got device "TU104 HD Audio Controller Digital Stereo (HDMI)", "alsa_output.pci-0000_07_00.1.hdmi-stereo"
[2023-11-02 12:40:31]     Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:40:31]     TU104 HD Audio Controller Digital Stereo (HDMI)
[2023-11-02 12:40:31] Available capture devices:
[2023-11-02 12:40:31] [ALSOFT] (II) Got device "Audio Adapter (Unitek Y-247A) Mono", "alsa_input.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.mono-fallback"
[2023-11-02 12:40:31] [ALSOFT] (II) Got device "Monitor of TU104 HD Audio Controller Digital Stereo (HDMI)", "alsa_output.pci-0000_07_00.1.hdmi-stereo.monitor"
[2023-11-02 12:40:31] [ALSOFT] (II) Got device "Monitor of Audio Adapter (Unitek Y-247A) Analog Stereo", "alsa_output.usb-C-Media_Electronics_Inc._USB_Audio_Device-00.analog-stereo.monitor"
[2023-11-02 12:40:31]     Audio Adapter (Unitek Y-247A) Mono
[2023-11-02 12:40:31]     Monitor of TU104 HD Audio Controller Digital Stereo (HDMI)
[2023-11-02 12:40:31]     Monitor of Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:40:31] Default playback device: Audio Adapter (Unitek Y-247A) Analog Stereo
[2023-11-02 12:40:31] Default capture device: Audio Adapter (Unitek Y-247A) Mono
[2023-11-02 12:40:31] ALC version: 1.1
[2023-11-02 12:40:31] [ALSOFT] (II) Opening default playback device
[2023-11-02 12:40:31] [ALSOFT] (II) Connecting to "(default)"
[2023-11-02 12:40:31] [ALSOFT] (II) Created device 0x561e37defd80, "Audio Adapter (Unitek Y-247A) Analog Stereo"
[2023-11-02 12:40:31] 
[2023-11-02 12:40:31] ** Info for device "Audio Adapter (Unitek Y-247A) Analog Stereo" **
[2023-11-02 12:40:31] ALC version: 1.1
[2023-11-02 12:40:31] ALC extensions:
[2023-11-02 12:40:31]     ALC_ENUMERATE_ALL_EXT, ALC_ENUMERATION_EXT, ALC_EXT_CAPTURE, ALC_EXT_debug,
[2023-11-02 12:40:31]     ALC_EXT_DEDICATED, ALC_EXTX_direct_context, ALC_EXT_disconnect,
[2023-11-02 12:40:31]     ALC_EXT_EFX, ALC_EXT_thread_local_context, ALC_SOFT_device_clock,
[2023-11-02 12:40:31]     ALC_SOFT_HRTF, ALC_SOFT_loopback, ALC_SOFT_loopback_bformat,
[2023-11-02 12:40:31]     ALC_SOFT_output_limiter, ALC_SOFT_output_mode, ALC_SOFT_pause_device,
[2023-11-02 12:40:31]     ALC_SOFT_reopen_device, ALC_SOFT_system_events
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /home/jay/Documents/git/openal-soft/build for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /home/jay/.local/share/openal/hrtf for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /home/jay/.local/share/flatpak/exports/share/openal/hrtf for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /var/lib/flatpak/exports/share/openal/hrtf for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /usr/local/share/openal/hrtf for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Searching /usr/share/openal/hrtf for *.mhr
[2023-11-02 12:40:31] [ALSOFT] (II)  got /usr/share/openal/hrtf/Default HRTF.mhr
[2023-11-02 12:40:31] [ALSOFT] (II) Adding file entry "/usr/share/openal/hrtf/Default HRTF.mhr"
[2023-11-02 12:40:31] [ALSOFT] (II) Adding built-in entry "!1_Built-In HRTF"
[2023-11-02 12:40:31] Available HRTF profiles:
[2023-11-02 12:40:31]     Default HRTF
[2023-11-02 12:40:31]     Built-In HRTF
[2023-11-02 12:40:31] [ALSOFT] (II) Pre-reset: Stereo, Float32, 48000hz, 960 / 2880 buffer
[2023-11-02 12:40:31] [ALSOFT] (II) Active port: analog-output-speaker (Speakers)
[2023-11-02 12:40:31] [ALSOFT] (II) minreq=7056, tlength=21168, prebuf=0
[2023-11-02 12:40:31] [ALSOFT] (II) Post-reset: Stereo, Float32, 44100hz, 882 / 2646 buffer
[2023-11-02 12:40:31] [ALSOFT] (II) Stereo rendering
[2023-11-02 12:40:31] [ALSOFT] (II) Channel config, Main: 3, Real: 2
[2023-11-02 12:40:31] [ALSOFT] (II) Allocating 5 channels, 20480 bytes
[2023-11-02 12:40:31] [ALSOFT] (II) Enabling single-band first-order ambisonic decoder
[2023-11-02 12:40:31] [ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
[2023-11-02 12:40:31] [ALSOFT] (II) Dithering disabled
[2023-11-02 12:40:31] [ALSOFT] (II) Output limiter disabled
[2023-11-02 12:40:31] [ALSOFT] (II) Fixed device latency: 0ns
[2023-11-02 12:40:31] [ALSOFT] (II) Post-start: Stereo, Float32, 44100hz, 882 / 2646 buffer
[2023-11-02 12:40:31] [ALSOFT] (II) Increasing allocated voices to 256
[2023-11-02 12:40:31] [ALSOFT] (II) Created context 0x561e37e15430
[2023-11-02 12:40:31] Device output mode: Stereo (basic)
[2023-11-02 12:40:31] Device sample rate: 44100hz
[2023-11-02 12:40:31] Device HRTF profile: (disabled)
[2023-11-02 12:40:31] OpenAL vendor string: OpenAL Community
[2023-11-02 12:40:31] OpenAL renderer string: OpenAL Soft
[2023-11-02 12:40:31] OpenAL version string: 1.1 ALSOFT 1.23.1
[2023-11-02 12:40:31] OpenAL extensions:
[2023-11-02 12:40:31]     AL_EXT_ALAW, AL_EXT_BFORMAT, AL_EXT_debug, AL_EXTX_direct_context,
[2023-11-02 12:40:31]     AL_EXT_DOUBLE, AL_EXT_EXPONENT_DISTANCE, AL_EXT_FLOAT32, AL_EXT_IMA4,
[2023-11-02 12:40:31]     AL_EXT_LINEAR_DISTANCE, AL_EXT_MCFORMATS, AL_EXT_MULAW,
[2023-11-02 12:40:31]     AL_EXT_MULAW_BFORMAT, AL_EXT_MULAW_MCFORMATS, AL_EXT_OFFSET,
[2023-11-02 12:40:31]     AL_EXT_source_distance_model, AL_EXT_SOURCE_RADIUS, AL_EXT_STATIC_BUFFER,
[2023-11-02 12:40:31]     AL_EXT_STEREO_ANGLES, AL_LOKI_quadriphonic, AL_SOFT_bformat_ex,
[2023-11-02 12:40:31]     AL_SOFTX_bformat_hoa, AL_SOFT_block_alignment, AL_SOFT_buffer_length_query,
[2023-11-02 12:40:31]     AL_SOFT_callback_buffer, AL_SOFTX_convolution_effect,
[2023-11-02 12:40:31]     AL_SOFT_deferred_updates, AL_SOFT_direct_channels,
[2023-11-02 12:40:31]     AL_SOFT_direct_channels_remix, AL_SOFT_effect_target, AL_SOFT_events,
[2023-11-02 12:40:31]     AL_SOFT_gain_clamp_ex, AL_SOFTX_hold_on_disconnect, AL_SOFT_loop_points,
[2023-11-02 12:40:31]     AL_SOFTX_map_buffer, AL_SOFT_MSADPCM, AL_SOFT_source_latency,
[2023-11-02 12:40:31]     AL_SOFT_source_length, AL_SOFT_source_resampler, AL_SOFT_source_spatialize,
[2023-11-02 12:40:31]     AL_SOFT_source_start_delay, AL_SOFT_UHJ, AL_SOFT_UHJ_ex
[2023-11-02 12:40:31] Available resamplers:
[2023-11-02 12:40:31]     Nearest
[2023-11-02 12:40:31]     Linear
[2023-11-02 12:40:31]     Cubic *
[2023-11-02 12:40:31]     11th order Sinc (fast)
[2023-11-02 12:40:31]     11th order Sinc
[2023-11-02 12:40:31]     23rd order Sinc (fast)
[2023-11-02 12:40:31]     23rd order Sinc
[2023-11-02 12:40:31] EFX version: 1.0
[2023-11-02 12:40:31] Max auxiliary sends: 2
[2023-11-02 12:40:31] Supported filters:
[2023-11-02 12:40:31]     Low-pass, High-pass, Band-pass
[2023-11-02 12:40:31] Supported effects:
[2023-11-02 12:40:31]     EAX Reverb, Reverb, Chorus, Distortion, Echo, Flanger, Frequency Shifter,
[2023-11-02 12:40:31]     Vocal Morpher, Pitch Shifter, Ring Modulator, Autowah, Compressor,
[2023-11-02 12:40:31]     Equalizer, Dedicated Dialog, Dedicated LFE
[2023-11-02 12:40:31] [ALSOFT] (II) Freeing context 0x561e37e15430
[2023-11-02 12:40:31] [ALSOFT] (II) Freed 0 context property objects
[2023-11-02 12:40:31] [ALSOFT] (II) Freed 0 AuxiliaryEffectSlot property objects
[2023-11-02 12:40:31] [ALSOFT] (II) Freeing device 0x561e37defd80

$
kcat commented 10 months ago

It seems to be a PipeWire issue, that should hopefully be resolved in the next release: https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/3592 https://gitlab.freedesktop.org/pipewire/pipewire/-/commit/3d8c7c40b5cc16eaf7bd1fb72c17783ce42e2d0e

It seems that sometimes, there will be an extra buffer that's not reported as queued or available, and with real-time mixing there may only be one buffer. So in some cases, avail_buffers and queued_buffers are left as 0 so OpenAL Soft can't calculate the buffer size.

The next release of PipeWire should hopefully fix it. Though in the mean time, you can disable real-time mixing which should make PipeWire use an additional buffer that OpenAL Soft can then count. Create or modify ~/.config/alsoft.conf and add:

[pipewire]
rt-mix = false

or run alsoft-config and under Backends->PipeWire, deselect "Real-time Mixing" and click Apply. This will slightly increase latency, but shouldn't be any worse than other backends.

kcat commented 10 months ago

PipeWire 0.3.84 was released. Are you able to test if it still happens with the newest version?

fabiangreffrath commented 10 months ago

I'll check it out once it hits Debian testing (it's currently in unstable).

fabiangreffrath commented 10 months ago

Yes, I can confirm that this issue is fixed with PipeWire 0.3.84. Thank you very much!