thesofproject / sof

Sound Open Firmware
Other
548 stars 315 forks source link

`sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x50040000 (msg/reply size: 384/384): -61` #8563

Closed paulmenzel closed 4 months ago

paulmenzel commented 11 months ago

On a Dell Latitude 5430 Chromebook with Chrome OS, /var/log/messages, visible entering file:///var/log in Chrome’s location bar, Linux logs several sof-audio-pci-intel-tgl warnings and errors:

2023-12-01T11:43:58.591516Z NOTICE kernel: [    0.000000] Linux version 5.15.133-20573-g839a3133d611 (chrome-bot@chromeos-release-builder-us-central1-a-x32-6-ibti) (Chromium OS 17.0_pre498229-r6 clang version 17.0.0 (/mnt/host/source/src/third_party/llvm-project 14f0776550b5a49e1c42f49a00213f7f3fa047bf), LLD 17.0.0) #1 SMP PREEMPT Sun Nov 26 18:55:03 PST 2023
2023-12-01T11:43:58.591525Z INFO kernel: [    0.000000] Command line: cros_secure console= loglevel=7 init=/sbin/init cros_secure drm.trace=0x106 root=/dev/dm-0 rootwait ro dm_verity.error_behavior=3 dm_verity.max_bios=-1 dm_verity.dev_wait=1 dm="1 vroot none ro 1,0 6348800 verity payload=PARTUUID=12e8cf21-bcc0-49b5-85bb-56fb8102f7d4/PARTNROFF=1 hashtree=PARTUUID=12e8cf21-bcc0-49b5-85bb-56fb8102f7d4/PARTNROFF=1 hashstart=6348800 alg=sha256 root_hexdigest=4ad313ce4c441485f2be87533efe22a0d8b61bffb78260d17ccd2672e7edb538 salt=8051d68355ccfca99de821939b957ff34d38b866a2951a595e4c0613a1c51f97" noinitrd vt.global_cursor_default=0 kern_guid=12e8cf21-bcc0-49b5-85bb-56fb8102f7d4 add_efi_memmap noresume i915.modeset=1 ramoops.ecc=1 tpm_tis.force=0 intel_pmc_core.warn_on_s0ix_failures=1 i915.enable_guc=3 i915.enable_dc=4 xdomain=0 swiotlb=65536 intel_iommu=on i915.enable_psr=1
[…]
2023-12-01T11:43:58.591616Z INFO kernel: [    0.000000] DMI: Google Crota/Crota, BIOS Google_Crota.14505.456.0 04/21/2023
[…]
2023-12-01T11:47:57.633532Z ERR kernel: [  241.684496] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x50040000 (msg/reply size: 384/384): -61
2023-12-01T11:47:57.633548Z WARNING kernel: [  241.684504] sof-audio-pci-intel-tgl 0000:00:1f.3: kcontrol 11 read failed for widget CODEC_ADAPTER2.0
2023-12-01T11:47:57.660501Z ERR kernel: [  241.711434] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x50040000 (msg/reply size: 384/384): -61
2023-12-01T11:47:57.660519Z WARNING kernel: [  241.711467] sof-audio-pci-intel-tgl 0000:00:1f.3: kcontrol 1 read failed for widget CODEC_ADAPTER1.0
plbossart commented 10 months ago

could it be a mismatch in topology? not sure why anyone would use a CODEC_ADAPTER widget?

 kcontrol 11 read failed for widget CODEC_ADAPTER2.0
lgirdwood commented 10 months ago

@paulmenzel do you have the FW version in the logs, I suspect this is a Alderlake Chromebook with IPC3 and cavs-2.5 branch. Do you also know what the target "CODEC" is ? e.g. it could be a 3rd party processing module.

paulmenzel commented 10 months ago

do you have the FW version in the logs, I suspect this is a Alderlake Chromebook with IPC3 and cavs-2.5 branch.

I only have what I attached. How would I find out, or were is it logged?

Do you also know what the target "CODEC" is ? e.g. it could be a 3rd party processing module.

Could it be MAX98360_CS42L42, cf. coreboot’s src/mainboard/google/brya/variants/crota/overridetree.cb?

lgirdwood commented 10 months ago

do you have the FW version in the logs, I suspect this is a Alderlake Chromebook with IPC3 and cavs-2.5 branch.

I only have what I attached. How would I find out, or were is it logged?

oh ok, it could be under dev_dbg().

Do you also know what the target "CODEC" is ? e.g. it could be a 3rd party processing module.

Could it be MAX98360_CS42L42, cf. coreboot’s src/mainboard/google/brya/variants/crota/overridetree.cb?

Sorry, I was meaning a FW codec, this could be WAVES or Maxim Smart AMP module that is using the kcontrol for configuration.

Does audio still work as expected after the messages ? I suspect these could be more informational than fatal.

paulmenzel commented 10 months ago

Sorry, I was meaning a FW codec, this could be WAVES or Maxim Smart AMP module that is using the kcontrol for configuration.

Are Chromium OS folks lurking here? Maybe they can answer?

Does audio still work as expected after the messages ? I suspect these could be more informational than fatal.

Yes, audio works. Should the debug level be adapted?

lgirdwood commented 10 months ago

Does audio still work as expected after the messages ? I suspect these could be more informational than fatal.

Yes, audio works. Should the debug level be adapted?

Probably should be fixed in FW as kernel is correctly reporting a error returned by FW. Probably low priority.

paulmenzel commented 10 months ago

I checked the recovery image loosely using the script crosfirmware.sh in the coreboot repository. I deleted the lines, where the extracted files are removed. util/chromeos/crosfirmware.sh crota downloads the compressed image chromeos_15604.57.0_brya_recovery_stable-channel_mp-v13.bin.zip.

The contained root partition root-a.ext2 can be mounted as read-only.

sudo mount -t ext2 -o loop root-a.ext2 /mnt/

The image contains the firmware files below.

$ cd /mnt
$ ls -lR lib/firmware/intel/sof*
lib/firmware/intel/sof:
total 44
drwxr-xr-x 2 root root 4096 Oct 27 07:22 anahera
drwxr-xr-x 2 root root 4096 Oct 27 07:22 community
drwxr-xr-x 2 root root 4096 Oct 27 07:22 crota
drwxr-xr-x 2 root root 4096 Oct 27 07:22 gimble
drwxr-xr-x 2 root root 4096 Oct 27 07:22 kano
drwxr-xr-x 2 root root 4096 Oct 27 07:22 primus
drwxr-xr-x 2 root root 4096 Oct 27 07:22 redrix
drwxr-xr-x 2 root root 4096 Oct 27 07:22 taeko
drwxr-xr-x 2 root root 4096 Oct 27 07:22 taniks
drwxr-xr-x 2 root root 4096 Oct 27 07:22 tarlo
drwxr-xr-x 2 root root 4096 Oct 27 07:22 vell

lib/firmware/intel/sof/anahera:
total 0
lrwxrwxrwx 1 root root 21 Oct 27 03:51 sof-adl.ldc -> ../redrix/sof-adl.ldc
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ri -> ../redrix/sof-adl.ri

lib/firmware/intel/sof/community:
total 776
-rw-r--r-- 1 root root 112732 Oct 27 03:51 sof-adl.ldc
-rw-r--r-- 1 root root 668416 Oct 27 03:51 sof-adl.ri
lrwxrwxrwx 1 root root     13 Oct 27 03:51 sof-rpl.ldc -> ./sof-adl.ldc
lrwxrwxrwx 1 root root     12 Oct 27 03:51 sof-rpl.ri -> ./sof-adl.ri

lib/firmware/intel/sof/crota:
total 0
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ldc -> ../taeko/sof-adl.ldc
lrwxrwxrwx 1 root root 19 Oct 27 03:51 sof-adl.ri -> ../taeko/sof-adl.ri

lib/firmware/intel/sof/gimble:
total 0
lrwxrwxrwx 1 root root 21 Oct 27 03:51 sof-adl.ldc -> ../redrix/sof-adl.ldc
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ri -> ../redrix/sof-adl.ri

lib/firmware/intel/sof/kano:
total 748
-rw-r--r-- 1 root root 103452 Oct 27 03:51 sof-adl.ldc
-rw-r--r-- 1 root root 647936 Oct 27 03:51 sof-adl.ri
lrwxrwxrwx 1 root root     12 Oct 27 03:51 sof-rpl.ri -> ./sof-adl.ri

lib/firmware/intel/sof/primus:
total 0
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ldc -> ../taeko/sof-adl.ldc
lrwxrwxrwx 1 root root 19 Oct 27 03:51 sof-adl.ri -> ../taeko/sof-adl.ri

lib/firmware/intel/sof/redrix:
total 1376
-rw-r--r-- 1 root root   72716 Oct 27 03:51 sof-adl.ldc
-rw-r--r-- 1 root root 1323776 Oct 27 03:51 sof-adl.ri

lib/firmware/intel/sof/taeko:
total 812
-rw-r--r-- 1 root root 104636 Oct 27 03:51 sof-adl.ldc
-rw-r--r-- 1 root root 713472 Oct 27 03:51 sof-adl.ri
lrwxrwxrwx 1 root root     13 Oct 27 03:51 sof-rpl.ldc -> ./sof-adl.ldc
lrwxrwxrwx 1 root root     12 Oct 27 03:51 sof-rpl.ri -> ./sof-adl.ri

lib/firmware/intel/sof/taniks:
total 0
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ldc -> ../taeko/sof-adl.ldc
lrwxrwxrwx 1 root root 19 Oct 27 03:51 sof-adl.ri -> ../taeko/sof-adl.ri

lib/firmware/intel/sof/tarlo:
total 0
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ldc -> ../taeko/sof-adl.ldc
lrwxrwxrwx 1 root root 19 Oct 27 03:51 sof-adl.ri -> ../taeko/sof-adl.ri

lib/firmware/intel/sof/vell:
total 0
lrwxrwxrwx 1 root root 20 Oct 27 03:51 sof-adl.ldc -> ../taeko/sof-adl.ldc
lrwxrwxrwx 1 root root 19 Oct 27 03:51 sof-adl.ri -> ../taeko/sof-adl.ri

lib/firmware/intel/sof-tplg:
total 964
drwxr-xr-x 2 root root  4096 Oct 27 07:22 anahera
drwxr-xr-x 2 root root  4096 Oct 27 07:22 crota
drwxr-xr-x 2 root root  4096 Oct 27 07:22 gimble
drwxr-xr-x 2 root root  4096 Oct 27 07:22 kano
drwxr-xr-x 2 root root  4096 Oct 27 07:21 pdm1
drwxr-xr-x 2 root root  4096 Oct 27 07:22 primus
drwxr-xr-x 2 root root  4096 Oct 27 07:22 redrix
-rw-r--r-- 1 root root 46959 Oct 27 03:44 sof-adl-cs35l41.tplg
-rw-r--r-- 1 root root 49603 Oct 27 03:44 sof-adl-max98357a-rt5682-4ch.tplg
-rw-r--r-- 1 root root 49603 Oct 27 03:44 sof-adl-max98357a-rt5682.tplg
lrwxrwxrwx 1 root root    31 Oct 27 03:44 sof-adl-max98360a-cs42l42.tplg -> ./sof-adl-max98360a-rt5682.tplg
-rw-r--r-- 1 root root 55039 Oct 27 03:44 sof-adl-max98360a-nau8825.tplg
-rw-r--r-- 1 root root 52331 Oct 27 03:44 sof-adl-max98360a-rt5682-2way.tplg
-rw-r--r-- 1 root root 55039 Oct 27 03:44 sof-adl-max98360a-rt5682-4ch.tplg
-rw-r--r-- 1 root root 55039 Oct 27 03:44 sof-adl-max98360a-rt5682.tplg
-rw-r--r-- 1 root root 45627 Oct 27 03:44 sof-adl-max98373-nau8825.tplg
-rw-r--r-- 1 root root 54395 Oct 27 03:44 sof-adl-max98390-rt5682.tplg
-rw-r--r-- 1 root root 48959 Oct 27 03:44 sof-adl-max98390-ssp2-rt5682-ssp0.tplg
-rw-r--r-- 1 root root 55039 Oct 27 03:44 sof-adl-nau8318-nau8825.tplg
-rw-r--r-- 1 root root 46163 Oct 27 03:44 sof-adl-nau8825.tplg
-rw-r--r-- 1 root root 49603 Oct 27 03:44 sof-adl-rt1019-nau8825.tplg
-rw-r--r-- 1 root root 55039 Oct 27 03:44 sof-adl-rt1019-rt5682.tplg
-rw-r--r-- 1 root root 40727 Oct 27 03:44 sof-adl-rt5682.tplg
-rw-r--r-- 1 root root 37959 Oct 27 03:44 sof-adl-rt711.tplg
-rw-r--r-- 1 root root 59583 Oct 27 03:44 sof-adl-sdw-max98373-rt5682.tplg
lrwxrwxrwx 1 root root    20 Oct 27 03:44 sof-rpl-cs35l41.tplg -> sof-adl-cs35l41.tplg
lrwxrwxrwx 1 root root    33 Oct 27 03:44 sof-rpl-max98357a-rt5682-4ch.tplg -> sof-adl-max98357a-rt5682-4ch.tplg
lrwxrwxrwx 1 root root    29 Oct 27 03:44 sof-rpl-max98357a-rt5682.tplg -> sof-adl-max98357a-rt5682.tplg
lrwxrwxrwx 1 root root    31 Oct 27 03:44 sof-rpl-max98360a-cs42l42.tplg -> ./sof-adl-max98360a-rt5682.tplg
lrwxrwxrwx 1 root root    30 Oct 27 03:44 sof-rpl-max98360a-nau8825.tplg -> sof-adl-max98360a-nau8825.tplg
lrwxrwxrwx 1 root root    34 Oct 27 03:44 sof-rpl-max98360a-rt5682-2way.tplg -> sof-adl-max98360a-rt5682-2way.tplg
lrwxrwxrwx 1 root root    33 Oct 27 03:44 sof-rpl-max98360a-rt5682-4ch.tplg -> sof-adl-max98360a-rt5682-4ch.tplg
lrwxrwxrwx 1 root root    29 Oct 27 03:44 sof-rpl-max98360a-rt5682.tplg -> sof-adl-max98360a-rt5682.tplg
lrwxrwxrwx 1 root root    29 Oct 27 03:44 sof-rpl-max98373-nau8825.tplg -> sof-adl-max98373-nau8825.tplg
lrwxrwxrwx 1 root root    28 Oct 27 03:44 sof-rpl-max98390-rt5682.tplg -> sof-adl-max98390-rt5682.tplg
lrwxrwxrwx 1 root root    38 Oct 27 03:44 sof-rpl-max98390-ssp2-rt5682-ssp0.tplg -> sof-adl-max98390-ssp2-rt5682-ssp0.tplg
lrwxrwxrwx 1 root root    28 Oct 27 03:44 sof-rpl-nau8318-nau8825.tplg -> sof-adl-nau8318-nau8825.tplg
lrwxrwxrwx 1 root root    20 Oct 27 03:44 sof-rpl-nau8825.tplg -> sof-adl-nau8825.tplg
lrwxrwxrwx 1 root root    27 Oct 27 03:44 sof-rpl-rt1019-nau8825.tplg -> sof-adl-rt1019-nau8825.tplg
lrwxrwxrwx 1 root root    26 Oct 27 03:44 sof-rpl-rt1019-rt5682.tplg -> sof-adl-rt1019-rt5682.tplg
lrwxrwxrwx 1 root root    19 Oct 27 03:44 sof-rpl-rt5682.tplg -> sof-adl-rt5682.tplg
lrwxrwxrwx 1 root root    18 Oct 27 03:44 sof-rpl-rt711.tplg -> sof-adl-rt711.tplg
lrwxrwxrwx 1 root root    32 Oct 27 03:44 sof-rpl-sdw-max98373-rt5682.tplg -> sof-adl-sdw-max98373-rt5682.tplg
drwxr-xr-x 2 root root  4096 Oct 27 07:22 taeko
drwxr-xr-x 2 root root  4096 Oct 27 07:22 taniks
drwxr-xr-x 2 root root  4096 Oct 27 07:22 tarlo
drwxr-xr-x 2 root root  4096 Oct 27 07:22 vell

lib/firmware/intel/sof-tplg/anahera:
total 44
-rw-r--r-- 1 root root 43939 Oct 27 03:51 sof-adl-max98360a-rt5682.tplg

lib/firmware/intel/sof-tplg/crota:
total 0
lrwxrwxrwx 1 root root 39 Oct 27 03:51 sof-adl-max98360a-cs42l42.tplg -> ../primus/sof-adl-max98360a-rt5682.tplg

lib/firmware/intel/sof-tplg/gimble:
total 0
lrwxrwxrwx 1 root root 38 Oct 27 03:51 sof-adl-max98390-rt5682.tplg -> ../redrix/sof-adl-max98390-rt5682.tplg

lib/firmware/intel/sof-tplg/kano:
total 48
-rw-r--r-- 1 root root 48635 Oct 27 03:51 sof-adl-max98373-nau8825.tplg
lrwxrwxrwx 1 root root    31 Oct 27 03:51 sof-rpl-max98373-nau8825.tplg -> ./sof-adl-max98373-nau8825.tplg

lib/firmware/intel/sof-tplg/pdm1:
total 56
-rw-r--r-- 1 root root 52331 Oct 27 03:44 sof-adl-max98360a-rt5682-2way.tplg
lrwxrwxrwx 1 root root    34 Oct 27 03:44 sof-rpl-max98360a-rt5682-2way.tplg -> sof-adl-max98360a-rt5682-2way.tplg

lib/firmware/intel/sof-tplg/primus:
total 56
-rw-r--r-- 1 root root 50467 Oct 27 03:51 sof-adl-max98360a-rt5682.tplg

lib/firmware/intel/sof-tplg/redrix:
total 48
-rw-r--r-- 1 root root 48731 Oct 27 03:51 sof-adl-max98390-rt5682.tplg

lib/firmware/intel/sof-tplg/taeko:
total 56
-rw-r--r-- 1 root root 50467 Oct 27 03:51 sof-adl-max98357a-rt5682.tplg
lrwxrwxrwx 1 root root    31 Oct 27 03:51 sof-rpl-max98357a-rt5682.tplg -> ./sof-adl-max98357a-rt5682.tplg

lib/firmware/intel/sof-tplg/taniks:
total 40
-rw-r--r-- 1 root root 38991 Oct 27 03:51 sof-adl-max98357a-rt5682-2way.tplg

lib/firmware/intel/sof-tplg/tarlo:
total 0
lrwxrwxrwx 1 root root 38 Oct 27 03:51 sof-adl-max98357a-rt5682.tplg -> ../taeko/sof-adl-max98357a-rt5682.tplg

lib/firmware/intel/sof-tplg/vell:
total 40
-rw-r--r-- 1 root root 39159 Oct 27 03:51 sof-adl-cs35l41.tplg
lgirdwood commented 10 months ago

total 0 lrwxrwxrwx 1 root root 39 Oct 27 03:51 sof-adl-max98360a-cs42l42.tplg -> ../primus/sof-adl-max98360a-rt5682.tplg

I suspect this is the Maxim smart amp topology and if speakers are working then the error can be ignored.

paulmenzel commented 10 months ago

Good to know, that nothing is wrong.

Nevertheless, in my opinion errors should only be logged, if the user needs to act on something. Otherwise “real” error log lines get ignored or overwritten. Could it be demoted to debug?

plbossart commented 10 months ago

the kernel does not know which entity the IPC message is addressed to, it just send/receives stuff blindly, so there's no real way to demote the error level selectively.

paulmenzel commented 10 months ago

If my goal was to get all errors addressed, the SOF blob would need to be improved?

ellyq commented 9 months ago

This seems like a regression introduced in 6.6.13/6.7.

[   17.330327] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx error for 0x30030000 (msg/reply size: 16/0): -22
[   17.330336] sof-audio-pci-intel-tgl 0000:00:1f.3: sof_ipc3_route_setup: route DMIC0.IN -> BUF4.0 failed
[   17.330340] sof-audio-pci-intel-tgl 0000:00:1f.3: sof_ipc3_set_up_all_pipelines: route set up failed
[   17.330342] sof-audio-pci-intel-tgl 0000:00:1f.3: Failed to restore pipeline after resume -22
[   17.330347] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.330980] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331091] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331205] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331290] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331358] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331431] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331519] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331607] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331704] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.331781] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   17.349598] Bluetooth: RFCOMM TTY layer initialized
[   17.349611] Bluetooth: RFCOMM socket layer initialized
[   17.349620] Bluetooth: RFCOMM ver 1.11
[   49.600416] systemd-journald[579]: /var/log/journal/9e3f37d0b26f42c485aa66ad5606c96e/user-1000.journal: Journal file uses a different sequence number ID, rotating.
[   50.973882] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   50.974418] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22
[   50.974601] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_pm_runtime_get on 0000:00:1f.3: -22

We can reproduce the issue on CML, TGL and ADL, so some commit pushed in the past 2 months completely broke audio on Chromebooks in upstream. Will debug it this weekend.

https://forum.chrultrabook.com/t/latest-kernels-6-6-13-6-7-break-audio-on-tgl/753

lgirdwood commented 4 months ago

Reported fixed https://forum.chrultrabook.com/t/latest-kernels-6-6-13-6-7-break-audio-on-tgl/753/2