Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
Alsa restore taking too long on boot
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Multimedia
View previous topic :: View next topic  
Author Message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Sun May 24, 2020 2:28 am    Post subject: Alsa restore taking too long on boot Reply with quote

Hi,

I have this problem that after i boot my system i have no sound for a few mins and then it shows.

Looking at the logs i can see the problem

Code:

May 24 05:16:11 Tron systemd-udevd[4550]: controlC0: Spawned process '/usr/sbin/alsactl restore 0' [4827] is taking longer than 59s to complete
May 24 05:16:11 Tron systemd-udevd[4529]: controlC0: Worker [4550] processing SEQNUM=2870 is taking a long time
May 24 05:16:13 Tron systemd-udevd[4529]: controlC1: Worker [4551] processing SEQNUM=2958 is taking a long time
May 24 05:16:13 Tron systemd-udevd[4551]: controlC1: Spawned process '/usr/sbin/alsactl restore 1' [5053] is taking longer than 59s to complete
May 24 05:18:11 Tron systemd-udevd[4550]: controlC0: Spawned process '/usr/sbin/alsactl restore 0' [4827] timed out after 2min 59s, >
May 24 05:18:11 Tron systemd-udevd[4529]: controlC0: Worker [4550] processing SEQNUM=2870 killed
May 24 05:18:11 Tron systemd-udevd[4529]: Worker [4550] terminated by signal 9 (KILL)
May 24 05:18:11 Tron systemd-udevd[4529]: controlC0: Worker [4550] failed
May 24 05:18:13 Tron systemd-udevd[4551]: controlC1: Spawned process '/usr/sbin/alsactl restore 1' [5053] timed out after 2min 59s, >
May 24 05:18:13 Tron systemd-udevd[4529]: controlC1: Worker [4551] processing SEQNUM=2958 killed
May 24 05:18:13 Tron systemd-udevd[4529]: Worker [4551] terminated by signal 9 (KILL)
May 24 05:18:13 Tron systemd-udevd[4529]: controlC1: Worker [4551] failed


Looks like alsa restore is running until it times out and then it works, the timeout time is the time that i have no sound because i only have dummy as my playback device.

Any ideas why this is happening?
Back to top
View user's profile Send private message
Fitzcarraldo
Veteran
Veteran


Joined: 30 Aug 2008
Posts: 1873
Location: United Kingdom

PostPosted: Sun May 24, 2020 3:08 am    Post subject: Reply with quote

Is /usr on a separate partition? Does your installation have an initramfs? Have you seen the following thread?:

https://forums.gentoo.org/viewtopic-t-914708.html

You could try commenting out the two lines beginning with 'TEST' in /lib/udev/rules.d/90-alsa-restore.rules as shown below, to avoid the long systemd-udevd timeouts and to find out if the systemd alsa-restore.service restores the sound card's state anyway after /usr has been mounted:

Code:
ACTION=="add", SUBSYSTEM=="sound", KERNEL=="controlC*", KERNELS!="card*", TEST=="/usr/sbin", TEST=="/usr/share/alsa", GOTO="alsa_restore_go"
GOTO="alsa_restore_end"

LABEL="alsa_restore_go"
#TEST!="/etc/alsa/state-daemon.conf", RUN+="/usr/sbin/alsactl restore $attr{device/number}"
#TEST=="/etc/alsa/state-daemon.conf", RUN+="/usr/sbin/alsactl nrestore $attr{device/number}"

LABEL="alsa_restore_end"

_________________
Clevo W230SS: amd64 nvidia-drivers & xf86-video-intel.
Compal NBLB2: ~amd64 xf86-video-ati. Dual boot Win 7 Pro 64-bit.
OpenRC eudev elogind & KDE on both.

Fitzcarraldo's blog
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Sun May 24, 2020 11:01 am    Post subject: Reply with quote

Fitzcarraldo wrote:
Is /usr on a separate partition? Does your installation have an initramfs? Have you seen the following thread?:

https://forums.gentoo.org/viewtopic-t-914708.html

You could try commenting out the two lines beginning with 'TEST' in /lib/udev/rules.d/90-alsa-restore.rules as shown below, to avoid the long systemd-udevd timeouts and to find out if the systemd alsa-restore.service restores the sound card's state anyway after /usr has been mounted:

Code:
ACTION=="add", SUBSYSTEM=="sound", KERNEL=="controlC*", KERNELS!="card*", TEST=="/usr/sbin", TEST=="/usr/share/alsa", GOTO="alsa_restore_go"
GOTO="alsa_restore_end"

LABEL="alsa_restore_go"
#TEST!="/etc/alsa/state-daemon.conf", RUN+="/usr/sbin/alsactl restore $attr{device/number}"
#TEST=="/etc/alsa/state-daemon.conf", RUN+="/usr/sbin/alsactl nrestore $attr{device/number}"

LABEL="alsa_restore_end"


/usr is on the same SSD\partition as the rest of the system, yes i have initramfs i used genkernel for this kernel.
Apart from the /lib/udev/rules that thread didn't help much but your suggestion to comment it out did solve the time out issues which now allow my sound to be started right on boot, so that a fix of sorts.

I did notice the following in the logs now (assuming it's udev):
Code:

...skipping...
-- Unit UNIT has finished shutting down.
May 24 13:55:12 Tron systemd[5102]: Stopped target Timers.
-- Subject: Unit UNIT has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit UNIT has finished shutting down.
May 24 13:55:12 Tron systemd[5102]: dbus.socket: Succeeded.
May 24 13:55:12 Tron systemd[5102]: Closed D-Bus User Message Bus Socket.
-- Subject: Unit UNIT has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit UNIT has finished shutting down.
May 24 13:55:12 Tron systemd[5102]: Reached target Shutdown.
-- Subject: Unit UNIT has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit UNIT has finished starting up.
--
-- The start-up result is RESULT.
May 24 13:55:12 Tron systemd[5102]: systemd-exit.service: Succeeded.
May 24 13:55:12 Tron systemd[5102]: Started Exit the Session.
-- Subject: Unit UNIT has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit UNIT has finished starting up.
--
-- The start-up result is RESULT.
May 24 13:55:12 Tron systemd[5102]: Reached target Exit the Session.
-- Subject: Unit UNIT has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit UNIT has finished starting up.
--
-- The start-up result is RESULT.
May 24 13:55:12 Tron systemd[5103]: pam_unix(systemd-user:session): session closed for user sddm
May 24 13:55:12 Tron systemd[1]: user@111.service: Succeeded.
May 24 13:55:12 Tron systemd[1]: Stopped User Manager for UID 111.
-- Subject: Unit user@111.service has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user@111.service has finished shutting down.
May 24 13:55:12 Tron systemd[1]: Stopping User Runtime Directory /run/user/111...
-- Subject: Unit user-runtime-dir@111.service has begun shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-runtime-dir@111.service has begun shutting down.
May 24 13:55:12 Tron systemd[1]: run-user-111.mount: Succeeded.
May 24 13:55:12 Tron systemd[1]: user-runtime-dir@111.service: Succeeded.
May 24 13:55:12 Tron systemd[1]: Stopped User Runtime Directory /run/user/111.
-- Subject: Unit user-runtime-dir@111.service has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-runtime-dir@111.service has finished shutting down.
May 24 13:55:12 Tron systemd[1]: Removed slice User Slice of UID 111.
-- Subject: Unit user-111.slice has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit user-111.slice has finished shutting down.


Another thing i could try is compiling the driver or codec into the kernel instead of using a module, in this kernel 5.4 i had to do that several times with network and others to make it work, somehow modules don't work well on this version.
Back to top
View user's profile Send private message
Anon-E-moose
Advocate
Advocate


Joined: 23 May 2008
Posts: 4891
Location: Dallas area

PostPosted: Sun May 24, 2020 11:27 am    Post subject: Reply with quote

You could also run the restore command from the cmdline to see what's going on.

Of course, it could also be that when alsa restore is running the rest of the alsa/snd subsystem isn't up yet.
_________________
PRIME x570-pro, 3700x, RX 550 - 5.8 zen kernel
Acer E5-575 (laptop), i3-7100u - i965 - 5.5 zen kernel
---both---
gcc 9.3.0, profile 17.1 (no-pie & modified) amd64-no-multilib, eudev, openrc, openbox, palemoon
Back to top
View user's profile Send private message
Fitzcarraldo
Veteran
Veteran


Joined: 30 Aug 2008
Posts: 1873
Location: United Kingdom

PostPosted: Sun May 24, 2020 1:44 pm    Post subject: Reply with quote

The thing is, the udev rule (/lib/udev/rules.d/90-alsa-restore.rules) is redundant because the systemd service file (/lib/systemd/system/alsa-restore.service) restores the sound card's state anyway, i.e. it performs the same task. Similarly, the OpenRC service file (/etc/init.d/alsasound) also restores the sound card's state anyway in the case of an installation using OpenRC. So, whether the installation uses systemd or OpenRC, the udev rule seems to be superfluous.
_________________
Clevo W230SS: amd64 nvidia-drivers & xf86-video-intel.
Compal NBLB2: ~amd64 xf86-video-ati. Dual boot Win 7 Pro 64-bit.
OpenRC eudev elogind & KDE on both.

Fitzcarraldo's blog
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Sun May 24, 2020 4:09 pm    Post subject: Reply with quote

Anon-E-moose wrote:
You could also run the restore command from the cmdline to see what's going on.

Of course, it could also be that when alsa restore is running the rest of the alsa/snd subsystem isn't up yet.


Manually it has a lock file and claims to exist

Code:

/usr/sbin/alsactl: state_lock:125: file /var/lib/alsa/asound.state lock error: File exists
/usr/sbin/alsactl: load_state:1683: Cannot open /var/lib/alsa/asound.state for reading: File exists
Found hardware: "HDA-Intel" "Realtek ALC889" "HDA:10ec0889,1458a132,00100004" "0x1458" "0xa132"
Hardware is initialized using a generic method
Found hardware: "HDA-Intel" "Nvidia GPU 84 HDMI/DP" "HDA:10de0084,1458371a,00100100" "0x1458" "0x371a"
Hardware is initialized using a generic method


The snd system not being up is a good theory, but what can i do about it?


Fitzcarraldo wrote:
The thing is, the udev rule (/lib/udev/rules.d/90-alsa-restore.rules) is redundant because the systemd service file (/lib/systemd/system/alsa-restore.service) restores the sound card's state anyway, i.e. it performs the same task. Similarly, the OpenRC service file (/etc/init.d/alsasound) also restores the sound card's state anyway in the case of an installation using OpenRC. So, whether the installation uses systemd or OpenRC, the udev rule seems to be superfluous.


I am actually using systemd, i see your point and commenting those out does fix the issue but 2 things still annoy me

1. Why do i need to make this modification locally, it shouldn't be needed at all or made globally, i don't like manual changes if i can help it

2. All that extra data created by systemd because of that change proves that something else is listening to this \ executing. how do i get rid of that clutter in my logs?
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Sun May 24, 2020 4:11 pm    Post subject: Reply with quote

Not sure if it's related here but i also have a 3.5mm mic problem as mentioned in this thread:
https://forums.gentoo.org/viewtopic-p-8449416.html
Back to top
View user's profile Send private message
Anon-E-moose
Advocate
Advocate


Joined: 23 May 2008
Posts: 4891
Location: Dallas area

PostPosted: Sun May 24, 2020 5:06 pm    Post subject: Reply with quote

What does ls -la /var/lib/alsa/ return?
_________________
PRIME x570-pro, 3700x, RX 550 - 5.8 zen kernel
Acer E5-575 (laptop), i3-7100u - i965 - 5.5 zen kernel
---both---
gcc 9.3.0, profile 17.1 (no-pie & modified) amd64-no-multilib, eudev, openrc, openbox, palemoon
Back to top
View user's profile Send private message
Fitzcarraldo
Veteran
Veteran


Joined: 30 Aug 2008
Posts: 1873
Location: United Kingdom

PostPosted: Sun May 24, 2020 7:03 pm    Post subject: Reply with quote

Troopo wrote:
I am actually using systemd, i see your point and commenting those out does fix the issue but 2 things still annoy me

1. Why do i need to make this modification locally, it shouldn't be needed at all or made globally, i don't like manual changes if i can help it

2. All that extra data created by systemd because of that change proves that something else is listening to this \ executing. how do i get rid of that clutter in my logs?

If you use the command 'systemd-analyze plot > boot.svg' to create a plot of the systemd boot process, you can see that the systemd service file alsa-restore.service is launched later in the boot process than systemd-udevd.service. The udev rule is installed by the ebuild media-sound/alsa-utils, as the rule is in the alsa-utils source code (/alsa-utils-1.2.2/alsactl/90-alsa-restore.rules.in). Presumably the ebuild could have removed the rule if either the systemd service file 90-alsa-restore.service or the OpenRC initscript alsasound are installed, since it is unnecessary. In fact, you yourself could delete that udev rule entirely; that might get rid of the systemd 'noise'. If you are adamant that you want to keep the redundant udev rule and therefore restore the sound card's state twice during the boot process, the other thing you could try would be to build the sound card module into the kernel instead, to see if it makes a difference.
_________________
Clevo W230SS: amd64 nvidia-drivers & xf86-video-intel.
Compal NBLB2: ~amd64 xf86-video-ati. Dual boot Win 7 Pro 64-bit.
OpenRC eudev elogind & KDE on both.

Fitzcarraldo's blog
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Sun May 24, 2020 8:20 pm    Post subject: Reply with quote

Anon-E-moose wrote:
What does ls -la /var/lib/alsa/ return?


Code:

drwxr-xr-x  2 root root  4096 May  8 01:20 .
drwxr-xr-x 39 root root  4096 Dec 30 20:00 ..
-rw-r--r--  1 root root     0 May  8 01:20 .keep_media-sound_alsa-utils-0.9
-rw-r--r--  1 root root 14335 Jan 23 21:08 asound.state


Fitzcarraldo wrote:
Troopo wrote:
I am actually using systemd, i see your point and commenting those out does fix the issue but 2 things still annoy me

1. Why do i need to make this modification locally, it shouldn't be needed at all or made globally, i don't like manual changes if i can help it

2. All that extra data created by systemd because of that change proves that something else is listening to this \ executing. how do i get rid of that clutter in my logs?

If you use the command 'systemd-analyze plot > boot.svg' to create a plot of the systemd boot process, you can see that the systemd service file alsa-restore.service is launched later in the boot process than systemd-udevd.service. The udev rule is installed by the ebuild media-sound/alsa-utils, as the rule is in the alsa-utils source code (/alsa-utils-1.2.2/alsactl/90-alsa-restore.rules.in). Presumably the ebuild could have removed the rule if either the systemd service file 90-alsa-restore.service or the OpenRC initscript alsasound are installed, since it is unnecessary. In fact, you yourself could delete that udev rule entirely; that might get rid of the systemd 'noise'. If you are adamant that you want to keep the redundant udev rule and therefore restore the sound card's state twice during the boot process, the other thing you could try would be to build the sound card module into the kernel instead, to see if it makes a difference.


Thanks i"ll try and update
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Mon May 25, 2020 3:45 am    Post subject: Reply with quote

I didn't try to build it into the kernel yet but i think based on my investigation into the logs that those systemd services mention are the SDDM and a few other things so i don't think alsa is causing those.

So commenting out those test lines in the rules did indeed solve this issue as it appears.

Although i do have something trying to start pulseaudio several times in the logs:
Code:

pulseaudio[5682]: [pulseaudio] pid.c: Daemon already running.


And still have mic not auto detected until i physically reconnect it after boot.

But at least something works, :)

Will try the kernel change just out of curiosity and report back.
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Mon May 25, 2020 9:58 pm    Post subject: Reply with quote

Ok so just to update after building the audio drivers into the kernel i still have the same problem if that also rules file is there so it didn't help, disabling the rule was the only fix that worked.
Also the systemd clutter is still there but i don't think it is related to audio.
Back to top
View user's profile Send private message
Fitzcarraldo
Veteran
Veteran


Joined: 30 Aug 2008
Posts: 1873
Location: United Kingdom

PostPosted: Tue May 26, 2020 2:54 am    Post subject: Reply with quote

Troopo wrote:
Although i do have something trying to start pulseaudio several times in the logs:
Code:

pulseaudio[5682]: [pulseaudio] pid.c: Daemon already running.

I wouldn't worry too much about that; it's common behaviour in installations using PulseAudio -- see e.g. the following for the reasons:

https://unix.stackexchange.com/questions/204522/how-does-pulseaudio-start

https://wiki.archlinux.org/index.php/PulseAudio/Troubleshooting#Daemon_already_running

The same thing happens in my installations running KDE. If I can be bothered to do something about it, I can prevent it happening by doing the following:

Code:
$ echo "autospawn = no" > ~/.config/pulse/client.conf
$ sudo mv /etc/xdg/autostart/pulseaudio.desktop /etc/xdg/autostart/pulseaudio.desktop.bak

(Audio still works fine after I do that.)
_________________
Clevo W230SS: amd64 nvidia-drivers & xf86-video-intel.
Compal NBLB2: ~amd64 xf86-video-ati. Dual boot Win 7 Pro 64-bit.
OpenRC eudev elogind & KDE on both.

Fitzcarraldo's blog
Back to top
View user's profile Send private message
Troopo
Apprentice
Apprentice


Joined: 14 Jun 2015
Posts: 222

PostPosted: Tue May 26, 2020 7:43 am    Post subject: Reply with quote

Fitzcarraldo wrote:
Troopo wrote:
Although i do have something trying to start pulseaudio several times in the logs:
Code:

pulseaudio[5682]: [pulseaudio] pid.c: Daemon already running.

I wouldn't worry too much about that; it's common behaviour in installations using PulseAudio -- see e.g. the following for the reasons:

https://unix.stackexchange.com/questions/204522/how-does-pulseaudio-start

https://wiki.archlinux.org/index.php/PulseAudio/Troubleshooting#Daemon_already_running

The same thing happens in my installations running KDE. If I can be bothered to do something about it, I can prevent it happening by doing the following:

Code:
$ echo "autospawn = no" > ~/.config/pulse/client.conf
$ sudo mv /etc/xdg/autostart/pulseaudio.desktop /etc/xdg/autostart/pulseaudio.desktop.bak

(Audio still works fine after I do that.)


Thank you that worked :)

I really don't want to go offtopic but any chance you have an idea regarding the mic problem? i think it's pluseadudio related since when i connect\disconnect the mic, i can see the following in the logs:
Code:

May 26 10:37:53 Tron kdeconnectd[5604]: org.kde.pulseaudio: No object for name "alsa_output.pci-0000_00_1b.0.analog-stereo.monitor"
May 26 10:37:53 Tron plasmashell[5568]: org.kde.plasma.pulseaudio: No object for name "alsa_output.pci-0000_00_1b.0.analog-stereo.monitor"



My guess is that after it resets it auto detects it, similarly to the audio timeout from earlier in this thread.
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Multimedia All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum