Arch Linux

uknown1

Member

Registered: 2020-12-09

Posts: 5

Pulseaudio daemon doesn't respond for some time after boot

For the past two weeks, I wasn't able to connect my bluetooth headphone right after booting, bluetoothctl would just fail immediately. I'd retry for a while and somehow it would magically work. Then I tried starting pavucontrol shortly after boot and it was stuck on "Establishing connection to Pulseaudio... Please wait" and then after 5 minutes, it would also magically start working. After some more experimenting I figured that I wasn't able to use audio devices or programs that interact with the pulseaudio daemon for ~7 minutes after boot. Initially the problem appeared once a day and then I wouldn't have it after subsequent boots, and then it would reappear that evening or the next day(aka after my laptop was powered off for a long time). Whenever the problem occurs, the next poweroff/reboot would take quite a long time. After some tinkering with the pulseaudio config files and resetting them, right now I am getting this problem each time I boot up, but the poweroff/reboot time seems to be quicker(mostly at least) - it takes a little longer than it normally would, but not painfully long as before. I removed quiet from the kernel options but I don't see any errors/wait-times in the poweroff/reboot sequence, it reaches the appropriate poweroff/reboot target and is just stuck there for a small while before turning off.

My pulseaudio config is set such that the daemon runs as an user process.

$ pacmd list
    Daemon not responding.
$ pactl list
    Connection failure: Timeout
$ pamixer --list-sinks
    Connection error
$ aplay -l
    **** List of PLAYBACK Hardware Devices ****
     -- no output till the problem solves itself

These commands begin working properly after a short time. And commands like amixer and alsamixer work perfectly fine even when these don't. I am also unable to play YouTube videos when this problem exists, the YouTube player says 'If playback doesn't begin shortly, try restarting your device'.

I ran journalctl -fe when the audio wasn't working to hopefully catch the error and the problem is something about the kernel not being able to sync a register with a codec called snd_hda_codec_realtek(probably my sound card).

Jun 22 09:04:32 arch kernel: snd_hda_codec_realtek ehdaudio0D0: Unable to sync register 0x2b8000. -5
Jun 22 09:04:32 arch kernel: snd_hda_codec_realtek ehdaudio0D0: Unable to sync register 0x2b8000. -5

This error repeats exactly twice in dmesg and journalctl(the lines are colored red) and after a short time a bunch of info is reported in journalctl, among them is Started Sound Service.. After this audio starts working and the commands that previously outputted errors work fine.

Here is an excerpt from journalctl showing an instance of this problem where pulseaudio.service was also unable to start till the error got logged. Note that even in cases where pulseaudio.service started successfully, the problem still persists and is fixed only after the error shows up.(The errors are in lines 4 & 6 in the code block).

Jun 22 09:01:28 arch systemd[456]: pulseaudio.service: start operation timed out. Terminating.
Jun 22 09:02:58 arch systemd[456]: pulseaudio.service: State 'stop-sigterm' timed out. Killing.
Jun 22 09:02:58 arch systemd[456]: pulseaudio.service: Killing process 463 (pulseaudio) with signal SIGKILL.
Jun 22 09:04:28 arch kernel: snd_hda_codec_realtek ehdaudio0D0: Unable to sync register 0x2b8000. -5
Jun 22 09:04:28 arch systemd[456]: pulseaudio.service: Processes still around after SIGKILL. Ignoring.
Jun 22 09:04:32 arch kernel: snd_hda_codec_realtek ehdaudio0D0: Unable to sync register 0x2b8000. -5
Jun 22 09:04:33 arch systemd[456]: pulseaudio.service: Main process exited, code=killed, status=9/KILL
Jun 22 09:04:33 arch systemd[456]: pulseaudio.service: Failed with result 'timeout'.
Jun 22 09:04:33 arch systemd[456]: Failed to start Sound Service.
Jun 22 09:04:33 arch systemd[456]: Reached target Main User Target.
Jun 22 09:04:33 arch systemd[456]: Startup finished in 4min 35.220s.
Jun 22 09:04:33 arch systemd[456]: pulseaudio.service: Scheduled restart job, restart counter is at 1.
Jun 22 09:04:33 arch systemd[456]: Stopped Sound Service.
Jun 22 09:04:33 arch systemd[456]: Starting Sound Service...
Jun 22 09:04:33 arch rtkit-daemon[475]: Successfully made thread 2517 of process 2517 owned by '1000' high priority at nice level -11.
Jun 22 09:04:33 arch rtkit-daemon[475]: Supervising 1 threads of 1 processes of 1 users.
Jun 22 09:04:33 arch pulseaudio[2517]: Stale PID file, overwriting.
Jun 22 09:04:33 arch rtkit-daemon[475]: Supervising 1 threads of 1 processes of 1 users.
Jun 22 09:04:33 arch rtkit-daemon[475]: Successfully made thread 2523 of process 2517 owned by '1000' RT at priority 5.
Jun 22 09:04:33 arch rtkit-daemon[475]: Supervising 2 threads of 1 processes of 1 users.
Jun 22 09:04:33 arch systemd[456]: Started Sound Service.
Jun 22 09:04:33 arch bluetoothd[404]: Endpoint registered: sender=:1.25 path=/MediaEndpoint/A2DPSink/sbc
Jun 22 09:04:33 arch bluetoothd[404]: Endpoint registered: sender=:1.25 path=/MediaEndpoint/A2DPSource/sbc
Jun 22 09:04:33 arch kernel: Bluetooth: RFCOMM TTY layer initialized
Jun 22 09:04:33 arch kernel: Bluetooth: RFCOMM socket layer initialized
Jun 22 09:04:33 arch kernel: Bluetooth: RFCOMM ver 1.11
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 2 threads of 1 processes of 1 users.
Jun 22 09:04:50 arch rtkit-daemon[475]: Successfully made thread 2613 of process 2517 owned by '1000' RT at priority 5.
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 3 threads of 1 processes of 1 users.
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 3 threads of 1 processes of 1 users.
Jun 22 09:04:50 arch rtkit-daemon[475]: Successfully made thread 2614 of process 2517 owned by '1000' RT at priority 5.
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 4 threads of 1 processes of 1 users.
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 4 threads of 1 processes of 1 users.
Jun 22 09:04:50 arch rtkit-daemon[475]: Successfully made thread 2615 of process 2517 owned by '1000' RT at priority 5.
Jun 22 09:04:50 arch rtkit-daemon[475]: Supervising 5 threads of 1 processes of 1 users.

I've tried:

• resetting pulseaudio(as per this Archwiki subsection)

• reinstalling pulseaudio and pulseaudio-bluetooth

• trying to start pulseaudio manually(says daemon already running)

• stopping, starting, and disabling and enabling the pulseaudio systemd service

• setting the option probe_mask=1 for the module snd_hda_intel

• checking the status of pulseaudio.service -- sometimes it shows Started Sound Service immediately after attempting to start it, sometimes it's stuck in Starting Sound Service and starts after a while after reporting Stale PID file, overwriting. -- in either case, the described problem behaves the same way

Last edited by uknown1 (2021-06-23 03:29:27)

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 21,736

Re: Pulseaudio daemon doesn't respond for some time after boot

Does running

sudo alsactl init

help? is this a dual boot system and if so did you ensure and double ensure that Windows fast boot is disabled?

Other than that this reads like a kernel issue, no amount of pulseaudio fumbling will help you. Test the LTS kernel or potentially some older kernels to check whether the issue is reproducible anywhere

uknown1

Member

Registered: 2020-12-09

Posts: 5

Re: Pulseaudio daemon doesn't respond for some time after boot

Thank you very much for your reply.

This is a dual boot system and fast startup was disabled(I checked it after reading your reply).

$ sudo alsactl init
alsa-lib main.c:761:(execute_sequence) unable to execute cset 'name='Speaker Playback Volume' 60%'
alsa-lib main.c:2366:(set_boot_user) Unable to execute boot sequence
Found hardware: "sof-hda-dsp" "Realtek ALC256" "HDA:8086280b,80860101,00100000 HDA:10ec0256,1d721901,00100002 cfg-dmics:2" "" ""
Hardware is initialized using a generic method
/usr/share/alsa/init/default:98: value write error: Input/output error

This command took some time to run and finally threw an error.

The issue was fixed simply by switching to an LTS kernel. Everything works fine now.

V1del

Forum Moderator

Registered: 2012-10-16

Posts: 21,736

Re: Pulseaudio daemon doesn't respond for some time after boot

alsactl often does something of use even if it throws an error.

Does the LTS kernel also treat the card as sof-hda (check dmesg/lspci -k) ? In any case this is an issue you'd ideally report upstream since "getting stuck" on an old kernel version isn't really a sustainable long term solution.

uknown1

Member

Registered: 2020-12-09

Posts: 5

Re: Pulseaudio daemon doesn't respond for some time after boot

dmesg -k shows the card being detected as sof-hda in both kernel versions. However lspci -k shows the newer kernel using a different driver and module with the sof term in them.

$ diff lspci lts-lspci
49,50c49,50
<   Kernel driver in use: sof-audio-pci-intel-cnl
<   Kernel modules: snd_hda_intel, snd_soc_skl, snd_sof_pci_intel_cnl
---
>   Kernel driver in use: sof-audio-pci
>   Kernel modules: snd_hda_intel, snd_soc_skl, snd_sof_pci

The newer kernel uses sof-audio-pci-intel-cnl and a corresponding module while the LTS kernel uses just sof-audio-pci.

Does reporting upstream mean opening a bug report on bugs.archlinux.org?