You are not logged in.
I'm having an issue with my Pulseaudio setup. When I boot up, my duplex profile is not available
% pactl -f json list cards|jq '.[2].profiles|with_entries(.value|=.description)'
{
"input:analog-stereo": "Analog Stereo Input",
"output:analog-stereo": "Analog Stereo Output",
"output:iec958-stereo": "Digital Stereo (IEC958) Output",
"output:iec958-ac3-surround-51": "Digital Surround 5.1 (IEC958/AC3) Output",
"output:iec958-ac3-surround-51+input:analog-stereo": "Digital Surround 5.1 (IEC958/AC3) Output + Analog Stereo Input",
"off": "Off"
}Then, after I restart pulseaudio the profiles show up correctly normally:
% pulseaudio -k
% pactl -f json list cards|jq '.[2].profiles|with_entries(.value|=.description)'
{
"input:analog-stereo": "Analog Stereo Input",
"output:analog-stereo": "Analog Stereo Output",
"output:analog-stereo+input:analog-stereo": "Analog Stereo Duplex",
"output:iec958-stereo": "Digital Stereo (IEC958) Output",
"output:iec958-stereo+input:analog-stereo": "Digital Stereo (IEC958) Output + Analog Stereo Input",
"output:iec958-ac3-surround-51": "Digital Surround 5.1 (IEC958/AC3) Output",
"output:iec958-ac3-surround-51+input:analog-stereo": "Digital Surround 5.1 (IEC958/AC3) Output + Analog Stereo Input",
"off": "Off"
}I haven't found anything relevant on my logs, but I probably just don't know where to look. Any advice or guesses?
Thank you.
Last edited by hgabreu (2022-09-27 12:45:25)
Offline
I remembered that I have pulse-autoconf installed. And after disabling it, the duplex profile show up correctly on boot (without needing to restart pulseaudio).
I'm not sure what is wrong though, as the logs (below) do not show anything relevant:
% journalctl --user --quiet -b --unit pulse-autoconf.service --unit pulseaudio.service
Sep 25 08:31:13 host pulse-autoconf[733]: INFO Sourcing configuration file "/home/user/.config/pulse-autoconf/pulse-autoconf.d/50-edit-config.conf"
Sep 25 08:31:13 host pulse-autoconf[733]: INFO This is pulse-autoconf 1.9.0
Sep 25 08:31:13 host systemd[723]: Started PulseAudio automatic configuration.
Sep 25 08:31:13 host systemd[723]: Starting Sound Service...
Sep 25 08:31:14 host pulseaudio[776]: module-combine is deprecated: Please use module-combine-sink instead of module-combine!
Sep 25 08:31:14 host pulseaudio[776]: We will now load module-combine-sink. Please make sure to remove module-combine from your configuration.
Sep 25 08:31:14 host pulseaudio[776]: stat('/etc/pulse/default.pa.d'): No such file or directory
Sep 25 08:31:14 host systemd[723]: Started Sound Service.
Sep 25 08:31:14 host pulseaudio[776]: Could not find org.bluez.BatteryProviderManager1.RegisterBatteryProvider(), is bluetoothd started with experimenta>
Sep 25 08:31:14 host pulseaudio[776]: org.bluez.ProfileManager1.RegisterProfile() failed: org.bluez.Error.NotPermitted: UUID already registered
Sep 25 08:31:14 host pulseaudio[776]: org.bluez.ProfileManager1.RegisterProfile() failed: org.bluez.Error.NotPermitted: UUID already registered
Sep 25 08:31:14 host pulse-autoconf[733]: INFO Applying preset "EchoCancellationWithSourcesMix"
Sep 25 08:31:14 host pulse-autoconf[733]: INFO Echo cancellation sink master is "combined"
Sep 25 08:31:14 host pulse-autoconf[733]: INFO Echo cancellation source master is "alsa_input.usb-Generic_NexiGo_N660P_FHD_Webcam_200901010001-02.anal>
Sep 25 08:31:14 host pulseaudio[776]: No remapping configured, proceeding nonetheless!
Sep 25 08:31:14 host pulseaudio[776]: Doing resync
Sep 25 08:31:14 host pulseaudio[776]: Playback too far ahead (5797), drop source 2224
Sep 25 08:31:14 host pulseaudio[776]: Doing resync
Sep 25 08:31:14 host pulseaudio[776]: Playback too far ahead (7745), drop source 2968
Sep 25 08:31:15 host pulseaudio[776]: Playback too far ahead (11100), drop source 4256
Sep 25 08:31:16 host pulseaudio[776]: Playback too far ahead (10410), drop source 3992
Sep 25 08:31:17 host pulseaudio[776]: Playback too far ahead (10357), drop source 3976
Sep 25 08:31:18 host pulseaudio[776]: Playback too far ahead (10200), drop source 3912
Sep 25 08:31:19 host pulseaudio[776]: Playback too far ahead (10079), drop source 3864
Sep 25 08:31:20 host pulseaudio[776]: Playback too far ahead (9991), drop source 3832
Sep 25 08:31:21 host pulseaudio[776]: Playback too far ahead (9922), drop source 3808
Sep 25 08:31:22 host pulseaudio[776]: Playback too far ahead (9903), drop source 3800
Sep 25 08:31:23 host pulseaudio[776]: Playback too far ahead (9915), drop source 3800
Sep 25 08:31:24 host pulseaudio[776]: Playback too far ahead (9918), drop source 3808
Sep 25 08:31:25 host pulseaudio[776]: Playback too far ahead (9890), drop source 3792
Sep 25 08:31:26 host pulseaudio[776]: Playback too far ahead (9895), drop source 3792
Sep 25 08:31:27 host pulseaudio[776]: Playback too far ahead (9915), drop source 3800
Sep 25 08:31:28 host pulseaudio[776]: Playback too far ahead (9938), drop source 3816
Sep 25 08:31:29 host pulseaudio[776]: Playback too far ahead (9940), drop source 3816
Sep 25 08:31:30 host pulseaudio[776]: Playback too far ahead (9961), drop source 3824
Sep 25 08:31:31 host pulseaudio[776]: Playback too far ahead (9948), drop source 3816
Sep 25 08:31:32 host pulseaudio[776]: Playback too far ahead (9945), drop source 3816
Sep 25 08:31:33 host pulseaudio[776]: Playback too far ahead (9944), drop source 3816
Sep 25 08:31:34 host pulseaudio[776]: Playback too far ahead (9945), drop source 3816
Sep 25 08:31:35 host pulseaudio[776]: Playback too far ahead (9965), drop source 3824
Sep 25 08:31:36 host pulseaudio[776]: Playback too far ahead (9971), drop source 3824
Sep 25 08:31:37 host pulseaudio[776]: Playback too far ahead (9979), drop source 3824
Sep 25 08:31:38 host pulseaudio[776]: Playback too far ahead (10007), drop source 3840
Sep 25 08:31:39 host systemd[723]: pulseaudio.service: Consumed 4.275s CPU time.
Sep 25 08:31:39 host systemd[723]: Starting Sound Service...
Sep 25 08:31:40 host pulseaudio[2375]: module-combine is deprecated: Please use module-combine-sink instead of module-combine!
Sep 25 08:31:40 host pulseaudio[2375]: We will now load module-combine-sink. Please make sure to remove module-combine from your configuration.
Sep 25 08:31:40 host pulseaudio[2375]: stat('/etc/pulse/default.pa.d'): No such file or directory
Sep 25 08:31:40 host systemd[723]: Started Sound Service.
Sep 25 08:31:40 host pulseaudio[2375]: Could not find org.bluez.BatteryProviderManager1.RegisterBatteryProvider(), is bluetoothd started with experiment>
Sep 25 08:31:40 host pulseaudio[2375]: org.bluez.ProfileManager1.RegisterProfile() failed: org.bluez.Error.NotPermitted: UUID already registered
Sep 25 08:31:40 host pulseaudio[2375]: org.bluez.ProfileManager1.RegisterProfile() failed: org.bluez.Error.NotPermitted: UUID already registered
Sep 25 08:31:40 host pulse-autoconf[733]: WARN PulseAudio restart detected, not unloading modules
Sep 25 08:31:40 host pulse-autoconf[733]: INFO Applying preset "EchoCancellationWithSourcesMix"
Sep 25 08:31:40 host pulse-autoconf[733]: INFO Echo cancellation sink master is "combined"
Sep 25 08:31:40 host pulse-autoconf[733]: INFO Echo cancellation source master is "alsa_input.pci-0000_00_1f.3.analog-stereo"
Sep 25 08:31:40 host pulseaudio[2375]: No remapping configured, proceeding nonetheless!
Sep 25 08:31:40 host pulseaudio[2375]: Doing resync
Sep 25 08:31:40 host pulseaudio[2375]: Playback too far ahead (3352), drop source 856
Sep 25 08:31:40 host pulseaudio[2375]: Doing resync
Sep 25 08:31:40 host pulseaudio[2375]: Playback too far ahead (4916), drop source 1256
Sep 25 08:31:41 host pulseaudio[2375]: Playback too far ahead (55623), drop source 14232
Sep 25 08:31:42 host pulseaudio[2375]: Playback too far ahead (10253), drop source 2624
Sep 25 08:31:43 host pulseaudio[2375]: Playback too far ahead (10877), drop source 2784
Sep 25 08:31:44 host pulseaudio[2375]: Playback too far ahead (11739), drop source 3000
Sep 25 08:31:45 host pulseaudio[2375]: Playback too far ahead (12645), drop source 3232
Sep 25 08:31:46 host pulseaudio[2375]: Playback too far ahead (12505), drop source 3200
Sep 25 08:31:47 host pulseaudio[2375]: Playback too far ahead (11982), drop source 3064
Sep 25 08:31:48 host pulseaudio[2375]: Playback too far ahead (11940), drop source 3056
Sep 25 08:31:49 host pulseaudio[2375]: Playback too far ahead (12095), drop source 3096
Sep 25 08:31:50 host pulseaudio[2375]: Playback too far ahead (12834), drop source 3280
Sep 25 08:31:51 host pulseaudio[2375]: Playback too far ahead (13359), drop source 3416
Sep 25 08:31:52 host pulseaudio[2375]: Playback too far ahead (13859), drop source 3544
Sep 25 08:31:53 host pulseaudio[2375]: Playback too far ahead (12468), drop source 3184
Sep 25 08:31:54 host pulseaudio[2375]: Playback too far ahead (10883), drop source 2784
Sep 25 08:31:55 host pulseaudio[2375]: Playback too far ahead (10494), drop source 2680
Sep 25 08:31:56 host pulseaudio[2375]: Playback too far ahead (10707), drop source 2736
Sep 25 08:31:57 host pulseaudio[2375]: Playback too far ahead (11423), drop source 2920
Sep 25 08:31:58 host pulseaudio[2375]: Playback too far ahead (11918), drop source 3048
Sep 25 08:31:59 host pulseaudio[2375]: Playback too far ahead (12261), drop source 3136
Sep 25 08:32:00 host pulseaudio[2375]: Playback too far ahead (11321), drop source 2896
Sep 25 08:32:01 host pulseaudio[2375]: Playback too far ahead (10954), drop source 2800
Sep 25 08:32:02 host pulseaudio[2375]: Playback too far ahead (10772), drop source 2752
Sep 25 08:32:03 host pulseaudio[2375]: Playback too far ahead (10420), drop source 2664
Sep 25 08:32:04 host pulseaudio[2375]: Playback too far ahead (10156), drop source 2592
Sep 25 08:32:05 host pulseaudio[2375]: Playback too far ahead (10002), drop source 2560
Sep 25 08:32:06 host pulseaudio[2375]: Playback after capture (-180), drop sink 120
Sep 25 08:32:08 host pulseaudio[2375]: Playback after capture (-97), drop sink 104
Sep 25 08:32:11 host pulseaudio[2375]: Playback after capture (-204), drop sink 128
Sep 25 08:32:13 host pulseaudio[2375]: Playback after capture (-58), drop sink 88
Sep 25 08:32:17 host pulseaudio[2375]: Playback after capture (-99), drop sink 104
Sep 25 08:32:26 host pulseaudio[2375]: Playback after capture (-58), drop sink 88
Sep 25 08:39:04 host pulseaudio[2375]: Playback after capture (-205), drop sink 128
Sep 25 08:39:06 host pulseaudio[2375]: Playback after capture (-170), drop sink 120Just for reference, here's my pulse-autoconf config
% grep -E '^[^#]+' ~/.config/pulse-autoconf/pulse-autoconf.d/50-edit-config.conf
preset="EchoCancellationWithSourcesMix"
ecSinkMasters=() # outputs, i.e. speakers
ecSinkMasters=("exact:combined")
ecSinkMasters+=("startswith:alsa_output.pci-0000_00_1f.3") # wired headphones
ecSinkMasters+=("startswith:alsa_output.pci-0000_01_00.1.") # monitor/screens (hdmi/dp)
ecSinkMasters+=("startswith:") # Any sink
ecSourceMasters=() # inputs, i.e. microphones
ecSourceMasters+=("exact:alsa_input.pci-0000_00_1f.3.analog-stereo") # wired headphones mic
ecSourceMasters+=("startswith:alsa_input.usb-Generic_NexiGo_N660P_FHD_Webcam_200901010001-02") # webcam mic
ecSourceMasters+=("notendswith:.monitor") # Exclude monitor sources
ecSourceMasters+=("startswith:") # Any source
ecSinkMastersPreferNewer=true
ecSourceMastersPreferNewer=trueOffline
I haven't seen anything like this happen on my system, and I can't come up with a sane explanation why anything that pulse-autoconf does could affect the available profiles.
That being said, and I am grasping at straws here, maybe pulse-autoconf is too quick off the mark and exposes some race within PulseAudio or ALSA.
PulseAudio is socket-activated, and the very first user of the socket is pulse-autoconf when it does various invocations of pactl in quick succession. So maybe while PulseAudio is starting up for the very first time, and possibly ALSA devices and profiles are still being probed for, pulse-autoconf is already loading its modules in the PulseAudio server, and that interferes with the probing.
What happens if you put something like this into a pulse-autoconf configuration file?
# Cause PulseAudio to be started through its socket
pactl list short sources > /dev/null
# Wait a bit to give PulseAudio and ALSA some time to initialize
sleep 1sIf that works around your issues I will probably add a workaround to pulse-autoconf and file an issue for PulseAudio.
Offline
Thanks a lot for the reply eomanis.
I added that to my config and it did not work, then I started playing around with increasing the sleep time, putting a sleep before the pactl call and such.
Turned out that a simple `sleep 1s` in the beginning of my pulse-autoconf config did the trick. Probably some weird race condition like you suggested.
Thank you very much for the support and for writing such a useful package.
Offline
I have released version 1.10.0 which has a workaround.
If pulse-autoconf is started within the first 20 seconds since system startup, it will wait 2 seconds before attempting to use PulseAudio. Both time spans are configurable.
I assume your system starts up and has an immediate automatic login straight to the graphical user session, which also auto-starts pulse-autoconf.
Now that I think about it, some time ago I wanted to hook up a small PC to a TV for media and video chat, but I had to use the analog headphone jack for audio-out instead of HDMI because more often than not the HDMI audio profiles were reported as "unavailable".
That PC also started straight to the desktop, maybe it was the same issue.
Thank you for making pulse-autoconf better.
Software must reliably work in as many situations as possible, preferably with default settings, otherwise people won't use it much, convenience is king.
Offline
Your assumption of my setup is correct. It auto logs into a graphical session for my user and pulse-autoconf is systemd enabled for me.
Last edited by hgabreu (2022-10-03 16:27:40)
Offline