Bug 1971387 - Upgrade to alsa-utils-1.2.5-2.fc34.x86_64 causes multi-minute delays at bootup
Summary: Upgrade to alsa-utils-1.2.5-2.fc34.x86_64 causes multi-minute delays at bootup
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: alsa-lib
Version: 34
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Jaroslav Kysela
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1971559 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-06-14 00:27 UTC by larsh
Modified: 2021-06-17 01:18 UTC (History)
3 users (show)

Fixed In Version: alsa-lib-1.2.5.1-1.fc34
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-06-17 01:18:45 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description larsh 2021-06-14 00:27:50 UTC
Description of problem:
After I upgraded to alsa-utils-1.2.5-2.fc34.x86_64 the machine hangs at bootup for 2-3 minutes

Downgrading to alsa-utils-1.2.4-2.fc34.x86_64 restores the old (fast) behavior.

Version-Release number of selected component (if applicable):
alsa-utils-1.2.5-2.fc34.x86_64

How reproducible:
Every time.
Verified on two different Thinkpads: X1 extreme gen2, and an old T440P.

Steps to Reproduce:
1. Upgrade to alsa-utils-1.2.5-2.fc34.x86_64
2. Reboot. Observe long waittime at reboot.

Actual results:
Long delay at bootup.

Expected results:
Normal bootup time without delay.

Additional info:
Relevant parts from the logs (reverse order):

Jun 12 13:22:18 think systemd-udevd[768]: controlC0: Failed to execute '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC0', ignoring: Input/o>
Jun 12 13:22:18 think systemd-udevd[768]: controlC0: Failed to wait for spawned command '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC0': >
Jun 12 13:22:18 think systemd-udevd[768]: controlC0: Process '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC0' terminated by signal ABRT.
Jun 12 13:22:18 think systemd-udevd[874]: controlC1: Failed to execute '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC1', ignoring: Input/o>
Jun 12 13:22:18 think systemd-udevd[874]: controlC1: Failed to wait for spawned command '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC1': >
Jun 12 13:22:18 think systemd-udevd[874]: controlC1: Process '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC1' terminated by signal ABRT.
Jun 12 13:22:18 think audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-coredump@1-2589-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=>
Jun 12 13:22:18 think audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-coredump@0-2256-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=>
Jun 12 13:22:18 think audit[2698]: SYSTEM_BOOT pid=2698 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg=' comm="systemd-update-utmp" exe="/usr/lib/systemd/systemd-update-utmp" hostname=? addr=? terminal=?>
Jun 12 13:22:18 think systemd-coredump[2676]: [🡕] Process 2584 (alsactl) of user 0 dumped core.

Stack trace of thread 2584:
#0  0x00007f2f19cad2a2 raise (libc.so.6 + 0x3d2a2)
#1  0x00007f2f19c968a4 abort (libc.so.6 + 0x268a4)
#2  0x00007f2f19c96789 __assert_fail_base.cold (libc.so.6 + 0x26789)
#3  0x00007f2f19ca5a16 __assert_fail (libc.so.6 + 0x35a16)
#4  0x00007f2f19eb5d3a snd_config_delete (libasound.so.2 + 0x55d3a)
#5  0x0000558a669f7ada main (alsactl + 0x8ada)
#6  0x00007f2f19c97b75 __libc_start_main (libc.so.6 + 0x27b75)
#7  0x0000558a669f859e _start (alsactl + 0x959e)
Jun 12 13:22:18 think systemd-coredump[2675]: [🡕] Process 2255 (alsactl) of user 0 dumped core.

Stack trace of thread 2255:
#0  0x00007f9e88def2a2 raise (libc.so.6 + 0x3d2a2)
#1  0x00007f9e88dd88a4 abort (libc.so.6 + 0x268a4)
#2  0x00007f9e88dd8789 __assert_fail_base.cold (libc.so.6 + 0x26789)
#3  0x00007f9e88de7a16 __assert_fail (libc.so.6 + 0x35a16)
#4  0x00007f9e88ff7d3a snd_config_delete (libasound.so.2 + 0x55d3a)
#5  0x00005637bf4ddada main (alsactl + 0x8ada)
#6  0x00007f9e88dd9b75 __libc_start_main (libc.so.6 + 0x27b75)
#7  0x00005637bf4de59e _start (alsactl + 0x959e)

...

Jun 12 13:22:17 think systemd[1]: Failed to start Wait for udev To Complete Device Initialization.
Jun 12 13:22:17 think systemd[1]: systemd-udev-settle.service: Failed with result 'exit-code'.
Jun 12 13:22:17 think systemd[1]: systemd-udev-settle.service: Main process exited, code=exited, status=1/FAILURE
Jun 12 13:21:21 think systemd-udevd[768]: controlC0: Spawned process '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC0' [2584] is taking lon>
Jun 12 13:21:21 think systemd-udevd[714]: controlC0: Worker [768] processing SEQNUM=3871 is taking a long time
Jun 12 13:21:19 think systemd-udevd[874]: controlC1: Spawned process '/sbin/alsactl -E ALSA_CONFIG_PATH=/etc/alsa/alsactl.conf --initfile=/lib/alsa/init/00main nrestore /dev/snd/controlC1' [2255] is taking lon>
Jun 12 13:21:19 think systemd-udevd[714]: controlC1: Worker [874] processing SEQNUM=3704 is taking a long time

...

Jun 12 13:20:20 think kernel: audit: type=1701 audit(1623529220.569:112): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=2584 comm="alsactl" exe="/usr/sbin/alsactl" sig=6 res=1
Jun 12 13:20:20 think audit[2584]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=2584 comm="alsactl" exe="/usr/sbin/alsactl" sig=6 res=1
Jun 12 13:20:20 think kernel: input: HDA Intel PCH Headphone as /devices/pci0000:00/0000:00:1f.3/sound/card0/input20
Jun 12 13:20:20 think kernel: input: HDA Intel PCH Mic as /devices/pci0000:00/0000:00:1f.3/sound/card0/input19
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:      Mic=0x19
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:      Internal Mic=0x1a
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:    inputs:
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:    mono: mono_out=0x0
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:    hp_outs=1 (0x16/0x0/0x0/0x0/0x0)
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0:    speaker_outs=0 (0x0/0x0/0x0/0x0/0x0)
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0: autoconfig for CX8070: line_outs=1 (0x17/0x0/0x0/0x0/0x0) type:speaker
Jun 12 13:20:20 think kernel: snd_hda_codec_conexant hdaudioC0D0: CX8070: BIOS auto-probing.

Comment 1 Jaroslav Kysela 2021-06-14 07:49:05 UTC
It's already fixed in upstream: https://github.com/alsa-project/alsa-utils/commit/6018c2014ac24877b2aa58c2c57f2fd901e6c7b1 . I'll update Fedora packages ASAP.

Comment 2 Jaroslav Kysela 2021-06-14 12:01:35 UTC
*** Bug 1971559 has been marked as a duplicate of this bug. ***

Comment 3 Fedora Update System 2021-06-14 13:24:55 UTC
FEDORA-2021-3149b1b25c has been submitted as an update to Fedora 34. https://bodhi.fedoraproject.org/updates/FEDORA-2021-3149b1b25c

Comment 4 larsh 2021-06-14 16:14:29 UTC
Awesome. Thank you. (Didn't think to check upstream - my apologies.)

Comment 5 Fedora Update System 2021-06-15 01:08:34 UTC
FEDORA-2021-3149b1b25c has been pushed to the Fedora 34 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-3149b1b25c`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-3149b1b25c

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 6 larsh 2021-06-15 19:46:48 UTC
I can confirm that there is no hanging upon restart. All good now. Thanks.

Comment 7 Fedora Update System 2021-06-17 01:18:45 UTC
FEDORA-2021-3149b1b25c has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.