ThinkPad P14s Gen 5 AMD micmute LED is not working sometimes.

[pma1]

The mic and sound output works fine. The mute LED works fine. But when press Fn+F4, the mic-mute led is not working sometimes after bootup. The failrate is like 1/10.

Tested with latest alsa-ucm from git, it's reproduced. /sys/class/sound/ctl-led/mic/card1# cat list 7

amixer -c 1 controls

numid=12,iface=CARD,name='Headphone Jack' numid=11,iface=CARD,name='Mic Jack' numid=13,iface=CARD,name='Speaker Phantom Jack' numid=10,iface=MIXER,name='Master Playback Switch' numid=9,iface=MIXER,name='Master Playback Volume' numid=2,iface=MIXER,name='Headphone Playback Switch' numid=1,iface=MIXER,name='Headphone Playback Volume' numid=16,iface=MIXER,name='PCM Playback Volume' numid=17,iface=MIXER,name='Mic ACP LED Capture Switch' numid=8,iface=MIXER,name='Mic Boost Volume' numid=7,iface=MIXER,name='Capture Switch' numid=6,iface=MIXER,name='Capture Volume' numid=5,iface=MIXER,name='Auto-Mute Mode' numid=4,iface=MIXER,name='Speaker Playback Switch' numid=3,iface=MIXER,name='Speaker Playback Volume' numid=15,iface=PCM,name='Capture Channel Map' numid=14,iface=PCM,name='Playback Channel Map'

echo 'Capture Switch' > detach

echo 'Mic ACP LED Capture Switch' > attach

/sys/class/sound/ctl-led/mic/card1# cat list 17

Then the micmute LED will work. alsa-info-amd-micmutled.txt

[perexg]

The ctl-led mic setting is set here: https://github.com/alsa-project/alsa-ucm-conf/blob/40d9c6c/ucm2/HDA/HDA.conf#L57-L58 . The alsactl utility should execute the Boot sequences on boot (udev / alsa-state service). I would check logs,if there's something suspicious when things are not working.

[pma1]

alsa-info-matterhorn-p-amd-3-6.5-1025-oem-ucm1.2.6.3.log

Uploaded the failure log of alsa-info with 6.5 kernel and UCM 1.2.6.3.

[mschiu77]

@perexg It seems that the BootSequence is not executed correctly in the fail case. What log would you suggest us to check? How do we make sure the detach/attach are really invoked in the HDA.conf?

[perexg]

It may be something with the card probe order. UCM tries to detect the ACP microphone here: https://github.com/alsa-project/alsa-ucm-conf/blob/master/ucm2/HDA/HDA.conf#L6 . But if ACP driver is loaded with a delay, the microphone is not detected, thus the FixedBootSequence is not executed.

To debug: You can add those lines at the end of the above file:

FixedBootSequence [
   exec "/usr/local/bin/run-my-script"
]

and create a bash script like (do not forget to make it executable):

#!/bin/bash

cat /proc/asound/cards > /tmp/alsa-cards-hda.txt

Reboot and check the contents of /tmp/alsa-cards-hda.txt , if there is ACP sound card.

[superm1]

I think you're on to something.

Is this the same bug as https://bugzilla.kernel.org/show_bug.cgi?id=219229?

[pma1]

t14g5-amd-micmuteled-fail-journal.log

@perexg no output from FixedBootSequence from the script.

I suspect it's the following error in log above: Sep 10 09:39:40 u-ThinkPad-T14-Gen-5 wireplumber[2848]: SPA handle 'api.alsa.acp.device' could not be loaded; is it installed? Sep 10 09:39:40 u-ThinkPad-T14-Gen-5 wireplumber[2848]: Failed to create 'api.alsa.acp.device' device

Note: The log above is from v6.11-rc6 which will reproduce this issue every one time of boot because of bug:219229. V6.9- kernel version can NOT reproduce bug:219229, but have a failrate 1/10 of micmute led issue.

[perexg]

The FixedBootSequence should be called using udev rule (invoking alsactl). Perhaps SELinux blocked this call (check audit log).

From log:

Sep 10 09:39:33 u-ThinkPad-T14-Gen-5 kernel: initcall snd_amd_acp_pci_driver_init+0x0/0xff0 [snd_acp_pci] returned 0 after 70 usecs
...
Sep 10 09:39:33 u-ThinkPad-T14-Gen-5 systemd[1]: Starting alsa-restore.service - Save/Restore Sound Card State..
...
Sep 10 09:39:35 u-ThinkPad-T14-Gen-5 kernel: probe of hdaudioC1D0 returned 0 after 42320 usecs

So the HDA driver is loaded after alsa-restore service. In this case, udev rule in /lib/udev/rules.d/90-alsa-restore.rules should handle this (your distro may have slightly different filename/config):

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 $devnode"
TEST=="/etc/alsa/state-daemon.conf", RUN+="/usr/sbin/alsactl nrestore $devnode"

LABEL="alsa_restore_end"

[pma1]

@perexg Ubuntu 24.04 do have this udev rule:

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", TEST=="/usr/sbin/alsactl", RUN+="/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore $attr{device/number}"
TEST=="/etc/alsa/state-daemon.conf", TEST=="/usr/sbin/alsactl", RUN+="/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime nrestore $attr{device/number}"

LABEL="alsa_restore_end"

Tested your udev rule too, no effects.

[perexg]

Check if you have SELinux in the permissive mode (if active) to test FixedBootSequence additions. Also alsactl have '-v' option which can be used multiple times to produce some debug log to see what's wrong. I can give only hints. This hardware is not in my hands.

[pma1]

@perexg selinux is disabled: $ sudo sestatus SELinux status: disabled

After adding '-v', it's still no useful log. +++ /lib/udev/rules.d/90-alsa-restore.rules 2024-09-19 14:23:15.996178585 +0800 @@ -2,7 +2,7 @@ GOTO="alsa_restore_end"

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

LABEL="alsa_restore_end"

[pma1]

@superm1 and @perexg Not sure if there are 2 issues here, another finding: After the commit "eb24c9788cd9 (HEAD) tpm: disable the TPM if NULL name changes", sometimes 'Mic ACP LED Capture Switch' is not shown, sometimes it is shown, the micmute led will never be working. If CONFIG_TCG_TPM2_HMAC=n, the micmute led is OK. At first I thought it's because of timing, but after Jarkko fix the timing issue with patches: https://lore.kernel.org/linux-integrity/D4AB1EB73L84.2CVJGCDFJSWX0@kernel.org/T/#t

The issue is still there.

[pma1]

amd-micmuteled-tpm2-hmac.tar.gz

Attach the log of both disabled and enabled TPM2_HMAC.

[superm1]

To me it sounds like a subtle race condition still. How about changing the conditions for /lib/systemd/system/alsa-restore.service to also wait for LED to be present?

[pma1]

@superm1 Do you mean to change udev rules?

I did change /usr/lib/udev/rules.d/90-alsa-restore.rules from ACTION=="add" to ACTION=="bind"

The micmute LED will never be working.

[superm1]

@superm1 Do you mean to change udev rules?

I did change /usr/lib/udev/rules.d/90-alsa-restore.rules from ACTION=="add" to ACTION=="bind"

The micmute LED will never be working.

I think you should make rule or make systemd unit (whichever is used) try to wait for kernels led device to be ready.

[superm1]

I think you should make rule or make systemd unit (whichever is used) try to wait for kernels led device to be ready

Just to add some more; it's not clear to me why there is both a udev rule and a systemd unit for the restore. @perexg can you explain?

I would think adding a new ConditionPathExistsGlob for the systemd unit for the matching LED.

#
# Note that two different ALSA card state management schemes exist and they
# can be switched using a file exist check - /etc/alsa/state-daemon.conf .
#

[Unit]
Description=Save/Restore Sound Card State
Documentation=man:alsactl(1)
ConditionPathExists=!/etc/alsa/state-daemon.conf
ConditionPathExistsGlob=/dev/snd/control*
After=alsa-state.service

[Service]
Type=oneshot
RemainAfterExit=true
ExecStartPre=/bin/mkdir -p /run/alsa
ExecStart=-/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore
ExecStop=-/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime store

In the udev rule I think you can add more conditions for the TEST conditions.

❯ cat /usr/lib/udev/rules.d/90-alsa-restore.rules
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", TEST=="/usr/sbin/alsactl", RUN+="/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore $attr{device/number}"
TEST=="/etc/alsa/state-daemon.conf", TEST=="/usr/sbin/alsactl", RUN+="/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime nrestore $attr{device/number}"

LABEL="alsa_restore_end"

[perexg]

@perexg can you explain?

The udev rule is for plug-and-play hardware like USB sound cards.

EDIT: Could someone with affected hardware just replace the RUN commands with a script running same commands but in verbose mode and store the debugging details to a file ? Also strace output may help to check the differences.

[pma1]

@perexg here is the log with verbose mode, https://github.com/user-attachments/files/17069128/amd-micmuteled-tpm2-hmac.tar.gz

But looks like the log is same after adding "-v", please let me know if I missed something.

[perexg]

Sorry, the correct option is -d for alsactl:

# alsactl -h 
Usage: alsactl <options> command
...
  -d,--debug       debug mode
  -v,--version     print version of this program
...

[pma1]

amd-micmuteled-bad-alsa-d.tar.gz

log attached. Add "-d": +++ /lib/udev/rules.d/90-alsa-restore.rules 2024-10-15 05:57:05.569241827 -0700 @@ -2,7 +2,7 @@ GOTO="alsa_restore_end"

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

LABEL="alsa_restore_end"

[perexg]

Not very helpful. I hacked this script:

#!/bin/bash

DIR="/tmp/alsactl"
DATE=$(date --iso-8601=ns)
FILENAME="${DIR}/${DATE}.txt"
PSTREE=$(pstree -sg $$)

mkdir -p "${DIR}" || exit 1
echo -e "${DATE}\nCOMMAND: \"alsactl $@\"\nTREE: ${PSTREE}\n\n" > "${FILENAME}"
/sbin/alsactl.ok -d $@ &>> "${FILENAME}"
RETVAL=$?

echo -e "\n\nRETVAL=$RETVAL" >> "${FILENAME}"

exit $RETVAL

Just do something like this:

mv /sbin/alsactl /sbin/alsactl.ok
mv ABOVE_SCRIPT /sbin/alsactl
chmod 755 /sbin/alsactl
chcon --reference=/sbin/alsactl.ok /sbin/alsactl

... reboot ... debug contents (files) should be in /tmp/alsactl directory

[pma1]

alsactl-add-debug-micmutefail.tar.gz

log captured.

Thanks.

[perexg]

Analysis: There are three sound cards in the system - HDA HDMI, HDA Audio and ACP bridge (for microphone):

 0 [Generic        ]: HDA-Intel - HD-Audio Generic
                      HD-Audio Generic at 0x905c8000 irq 143
 1 [Generic_1      ]: HDA-Intel - HD-Audio Generic
                      HD-Audio Generic at 0x905c0000 irq 144
 2 [acp63          ]: acp63 - acp63
                      LENOVO-21MFZC2YUS-ThinkPadP14sGen5AMD

UCM tries to combine HDA Audio + ACP to one profile, but open fails (which means return to legacy initialization method):

2024-10-15T17:31:16,502951240-07:00  /sbin/alsactl.ok: init_ucm:48: ucm open '-hw:0': -6

2024-10-15T17:31:17,601697444-07:00  /sbin/alsactl.ok: init_ucm:48: ucm open '-hw:1': -6

2024-10-15T17:31:21,483551834-07:00  /sbin/alsactl.ok: init_ucm:48: ucm open '-hw:2': 0
2024-10-15T17:31:21,483551834-07:00  /sbin/alsactl.ok: init_ucm:53: ucm _fboot: -2

Looking to timestamps, the card2 (acp63) is initialized really slowly and AFTER HDA hardware. It means that condition in UCM configs is not evaluated as expected: https://github.com/alsa-project/alsa-ucm-conf/blob/c83452ed33d76a22fbe034df53a45f6fa435f75d/ucm2/HDA/HDA.conf#L6 .

I see some ways to resolve this issue:

1) handle this in UCM in find-card: helper 2) modify HDA driver to load the snd_acp_pci driver when the HDA legacy is initialized for AMD hardware and ACP bridge is present 3) modify udev rule to handle this situation for AMD hardware (insert snd_acp_pci driver before HDA initialization)

Reasons against case 1 - we don't have an effective way to determine, if AMD hardware has a microphone on ACP bridge and the wait time may be long (~4 seconds in the above case).

Reasons against case 2 - in kernel HDA and ACP drivers are separate and the multiple sound card linking is implemented in UCM (user space).

Case 3 seems like a best option IMHO. Here is the proposed udev rule (untested):

# store to /lib/udev/rules.d/59-alsa-init.rules
SUBSYSTEM!="sound", GOTO="alsa_init_end"
KERNEL!="card*", GOTO="alsa_init_end"
ACTION!="add", GOTO="alsa_init_end"

SUBSYSTEMS=="pci",ATTRS{vendor}=="0x1022",DRIVERS=="snd_hda_intel",RUN{builtin}+="kmod load snd_acp_pci"

LABEL="alsa_init_end"

EDIT: Note that ACP sound card probe may be deferred, so an extra delay may be required after kmod load...

[pma1]

@perexg Thank you very much.

Tested the solution 3 of udev rule, still can not work. log attached: alsactl-load-acp-micmute-fail.tar.gz

[perexg]

You can try to modify slightly the rule to:

SUBSYSTEMS=="pci",ATTRS{vendor}=="0x1022",DRIVERS=="snd_hda_intel",RUN{builtin}+="kmod load snd_acp_pci",RUN+="sleep 10"

The goal is to have ACP driver loaded and ACP sound card should be active after this step. You can also replace "sleep 10" with our own script which may list active sound cards - e.g. cat /proc/asound/cards at this point.

[pma1]

micmute-fail-sleep-30-udev.tar.gz

Still not working, change it even to "sleep 30", but looks it is executed at very early stage before bluetooth driver loading: Oct 17 08:30:14 u-ThinkPad-P14s-Gen-5-AMD (udev-worker)[1100]: card1: Process 'sleep 30' failed with exit code 1.

Please check the journal log in tarball.

Thank you very much.