snd_cs46xx regression, producing Oops

snd_cs46xx regression, producing Oops

[Jan Engelhardt]

Commit v5.14-rc1-39-g5bff69b3645d introduced a breakage into
snd_cs46xx. When loading the module, an Oops is thrown. The system
works fine afterwards, but the final reboot/poweroff message to ACPI
has no effect after such Oops occurred. (Blacklisting snd_cs46xx
works around the reboot problem.)

bisected to:
commit 5bff69b3645db7b3018ecbc26218d8866aeaf214
Author: Takashi Iwai <tiwai@suse.de>
Date:   Thu Jul 15 09:58:52 2021 +0200

    ALSA: cs46xx: Allocate resources with device-managed APIs
    
    This patch converts the resource management in PCI cs46xx driver with
    devres as a clean up.  Each manual resource management is converted
    with the corresponding devres helper, and the card object release is
    managed now via card->private_free instead of a lowlevel snd_device.


trace log from modern kernel:
[    0.000000] Linux version 5.18.9 (jengelh@f3) (gcc (SUSE Linux) 12.1.0, GNU ld (GNU Binutils; openSUSE Tumbleweed) 2.38.20220525-6) #3 PREEMPT_DYNAMIC Tue Jul 5 10:43:37 CEST 2022
...
[   32.475313] snd_intel8x0 0000:00:02.7: intel8x0_measure_ac97_clock: measured 59821 usecs (2877 samples)
[   32.475410] snd_intel8x0 0000:00:02.7: clocking to 48000
[   33.683930] snd_cs46xx 0000:00:0d.0: Direct firmware load for cs46xx/cwc4630 failed with error -2
[   33.684035] snd_cs46xx 0000:00:0d.0: firmware load error [cwc4630]
[   33.684092] snd_cs46xx: probe of 0000:00:0d.0 failed with error -2
[   33.684772] BUG: unable to handle page fault for address: f7cd846c
[   33.684833] #PF: supervisor write access in kernel mode
[   33.684886] #PF: error_code(0x0002) - not-present page
[   33.684936] *pde = 010e9067 *pte = 00000000 
[   33.684992] Oops: 0002 [#1] PREEMPT
[   33.685045] CPU: 0 PID: 413 Comm: systemd-udevd Tainted: G            E     5.18.9 #3 aa51fdb6e59156e58028f32c0abfef9c9b603d9b
[   33.685119] Hardware name: ECS L7S7A2/L7S7A2, BIOS 07.00T 04/02/01
[   33.685172] EIP: snd_cs46xx_codec_write+0x3b/0xe0 [snd_cs46xx]
[   33.685265] Code: ec 18 83 7d 08 01 89 45 f0 0f 8f b0 00 00 00 89 f0 0f b7 f9 8b 8e 58 01 00 00 ba 01 00 00 00 e8 cb 83 af da 8b 46 28 8b 4d f0 <89> 88 6c 04 00 00 8b 46 28 89 b8 70 04 00 00 8b 46 28 05 60 04 00
[   33.685356] EAX: f7cd8000 EBX: c232c548 ECX: 00000002 EDX: 00000001
[   33.685410] ESI: c232c548 EDI: 00009f9f EBP: c1fd5b08 ESP: c1fd5ae4
[   33.685463] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 EFLAGS: 00210297
[   33.685528] CR0: 80050033 CR2: f7cd846c CR3: 0335d000 CR4: 00000690
[   33.685581] Call Trace:
[   33.685637]  ? snd_cs46xx_codec_write+0xe0/0xe0 [snd_cs46xx 58d1cdc18910e2717003e6be0e13f1fe4cf1ef4e]
[   33.685721]  snd_cs46xx_ac97_write+0x2a/0x50 [snd_cs46xx 58d1cdc18910e2717003e6be0e13f1fe4cf1ef4e]
[   33.685804]  snd_ac97_write+0x51/0x80 [snd_ac97_codec 9efa9e43a5e3a59d5b4ae0b33ee748e5f4f27a3a]
[   33.685908]  snd_ac97_powerdown+0xc9/0x120 [snd_ac97_codec 9efa9e43a5e3a59d5b4ae0b33ee748e5f4f27a3a]
[   33.685990]  snd_ac97_dev_free+0x13/0x30 [snd_ac97_codec 9efa9e43a5e3a59d5b4ae0b33ee748e5f4f27a3a]
[   33.686072]  __snd_device_free+0x3d/0x80 [snd 6a4ed59569dfc8ba5a4beabb0b5a692067dfc833]
[   33.686178]  snd_device_free_all+0x43/0x80 [snd 6a4ed59569dfc8ba5a4beabb0b5a692067dfc833]
[   33.686260]  release_card_device+0x23/0x90 [snd 6a4ed59569dfc8ba5a4beabb0b5a692067dfc833]
[   33.686340]  device_release+0x37/0xa0
[   33.686399]  kobject_put+0xb1/0x230
[   33.686454]  ? snd_card_disconnect+0x134/0x230 [snd 6a4ed59569dfc8ba5a4beabb0b5a692067dfc833]
[   33.686536]  put_device+0x11/0x20
[   33.686587]  __snd_card_release+0x69/0x80 [snd 6a4ed59569dfc8ba5a4beabb0b5a692067dfc833]
[   33.686668]  release_nodes+0x3d/0xb0
[   33.686726]  devres_release_all+0x77/0xd0
[   33.686780]  device_unbind_cleanup+0x10/0x60
[   33.686833]  really_probe+0x1ee/0x370
[   33.686885]  ? pm_runtime_barrier+0x44/0x90
[   33.686945]  __driver_probe_device+0x111/0x200
[   33.686998]  ? kernfs_create_dir_ns+0x79/0xc0
[   33.687053]  driver_probe_device+0x27/0xa0
[   33.687106]  __driver_attach+0xb7/0x1b0
[   33.687158]  ? __device_attach_driver+0x100/0x100
[   33.687211]  bus_for_each_dev+0x5a/0x90
[   33.687263]  driver_attach+0x1e/0x30
[   33.687314]  ? __device_attach_driver+0x100/0x100
[   33.687366]  bus_add_driver+0x14f/0x200
[   33.687419]  driver_register+0x7c/0xd0
[   33.687469]  ? sysfs_add_bin_file_mode_ns+0x67/0xd0
[   33.687524]  ? 0xf7f10000
[   33.687574]  __pci_register_driver+0x3c/0x40
[   33.687628]  cs46xx_driver_init+0x1c/0x1000 [snd_cs46xx 58d1cdc18910e2717003e6be0e13f1fe4cf1ef4e]
[   33.687710]  do_one_initcall+0x3f/0x1a0
[   33.687764]  ? kmem_cache_alloc_trace+0x13f/0x2f0
[   33.687822]  ? do_init_module+0x24/0x240
[   33.687882]  do_init_module+0x46/0x240
[   33.687935]  ? __vfree+0x20/0x50
[   33.687992]  load_module+0x2393/0x2540
[   33.691234]  ? try_module_get+0xb0/0xb0
[   33.691293]  __ia32_sys_finit_module+0xb4/0x130
[   33.691351]  __do_fast_syscall_32+0x67/0xb0
[   33.691411]  ? syscall_exit_to_user_mode+0x1a/0x40
[   33.691466]  ? __do_fast_syscall_32+0x71/0xb0
[   33.691519]  ? irqentry_exit_to_user_mode+0x8/0x20
[   33.691571]  do_fast_syscall_32+0x31/0x70
[   33.691624]  do_SYSENTER_32+0x15/0x20
[   33.691676]  entry_SYSENTER_32+0x98/0xf0
[   33.691732] EIP: 0xb7f27549
[   33.691782] Code: 03 74 c0 01 10 05 03 74 b8 01 10 06 03 74 b4 01 10 07 03 74 b0 01 10 08 03 74 d8 01 00 00 00 00 00 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90 90 90 90 8d 76 00 58 b8 77 00 00 00 cd 80 90 8d 76
[   33.691873] EAX: ffffffda EBX: 00000012 ECX: b7bbe036 EDX: 00000000
[   33.691926] ESI: b7bc5dd8 EDI: 01add640 EBP: ffffff08 ESP: bfee05ac
[   33.691979] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b EFLAGS: 00200246
[   33.692046] Modules linked in: drm_ttm_helper(E) snd_cs46xx(E+) ttm(E) snd_rawmidi(E) mxm_wmi(E) snd_intel8x0(E) wmi(E) pcspkr(E) snd_ac97_codec(E) video(E) ac97_bus(E) 8139too(E) snd_pcm(E) drm_dp_helper(E) 8139cp(E) sis900(E) snd_timer(E) parport_pc(E) mii(E) tiny_power_button(E) snd(E) soundcore(E) i2c_sis96x(E) button(E) parport(E) ext4(E) mbcache(E) jbd2(E) fuse(E) configfs(E) ip_tables(E) x_tables(E) xfs(E) libcrc32c(E) hid_generic(E) usbhid(E) sr_mod(E) cdrom(E) ata_generic(E) ohci_pci(E) serio_raw(E) sata_sil(E) ohci_hcd(E) ehci_pci(E) ehci_hcd(E) pata_sis(E) usbcore(E) libata(E) floppy(E) sg(E)
[   33.692314] CR2: 00000000f7cd846c
[   33.692365] ---[ end trace 0000000000000000 ]---
[   33.692414] EIP: snd_cs46xx_codec_write+0x3b/0xe0 [snd_cs46xx]
[   33.692483] Code: ec 18 83 7d 08 01 89 45 f0 0f 8f b0 00 00 00 89 f0 0f b7 f9 8b 8e 58 01 00 00 ba 01 00 00 00 e8 cb 83 af da 8b 46 28 8b 4d f0 <89> 88 6c 04 00 00 8b 46 28 89 b8 70 04 00 00 8b 46 28 05 60 04 00
[   33.692572] EAX: f7cd8000 EBX: c232c548 ECX: 00000002 EDX: 00000001
[   33.692626] ESI: c232c548 EDI: 00009f9f EBP: c1fd5b08 ESP: c1fd5ae4
[   33.692679] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 EFLAGS: 00210297
[   33.692742] CR0: 80050033 CR2: f7cd846c CR3: 0335d000 CR4: 00000690

On a 5.14, it's just the three lines
  snd_cs46xx 0000:00:0d.0: Direct firmware load for cs46xx/cwc4630 failed with error -2
  snd_cs46xx 0000:00:0d.0: firmware load error [cwc4630]
  snd_cs46xx: probe of 0000:00:0d.0 failed with error -2
and life goes on.

Re: snd_cs46xx regression, producing Oops

[Takashi Iwai]

On Tue, 05 Jul 2022 12:56:14 +0200,
Jan Engelhardt wrote:
> 
> 
> Commit v5.14-rc1-39-g5bff69b3645d introduced a breakage into
> snd_cs46xx. When loading the module, an Oops is thrown. The system
> works fine afterwards, but the final reboot/poweroff message to ACPI
> has no effect after such Oops occurred. (Blacklisting snd_cs46xx
> works around the reboot problem.)
> 
> bisected to:
> commit 5bff69b3645db7b3018ecbc26218d8866aeaf214
> Author: Takashi Iwai <tiwai@suse.de>
> Date:   Thu Jul 15 09:58:52 2021 +0200
> 
>     ALSA: cs46xx: Allocate resources with device-managed APIs
>     
>     This patch converts the resource management in PCI cs46xx driver with
>     devres as a clean up.  Each manual resource management is converted
>     with the corresponding devres helper, and the card object release is
>     managed now via card->private_free instead of a lowlevel snd_device.

Could you try the patch below?


thanks,

Takashi

-- 8< --
From: Takashi Iwai <tiwai@suse.de>
Subject: [PATCH] ALSA: cs46xx: Fix missing snd_card_free() call at probe error

The previous cleanup with devres may lead to the incorrect release
orders at the probe error handling due to the devres's nature.  Until
we register the card, snd_card_free() has to be called at first for
releasing the stuff properly when the driver tries to manage and
release the stuff via card->private_free().

This patch fixes it by calling snd_card_free() manually on the error
from the probe callback.

Fixes: 5bff69b3645d ("ALSA: cs46xx: Allocate resources with device-managed APIs")
Cc: <stable@vger.kernel.org>
Reported-by: Jan Engelhardt <jengelh@inai.de>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
---
 sound/pci/cs46xx/cs46xx.c | 22 +++++++++++++---------
 1 file changed, 13 insertions(+), 9 deletions(-)

diff --git a/sound/pci/cs46xx/cs46xx.c b/sound/pci/cs46xx/cs46xx.c
index bd60308769ff..8634004a606b 100644
--- a/sound/pci/cs46xx/cs46xx.c
+++ b/sound/pci/cs46xx/cs46xx.c
@@ -74,36 +74,36 @@ static int snd_card_cs46xx_probe(struct pci_dev *pci,
 	err = snd_cs46xx_create(card, pci,
 				external_amp[dev], thinkpad[dev]);
 	if (err < 0)
-		return err;
+		goto error;
 	card->private_data = chip;
 	chip->accept_valid = mmap_valid[dev];
 	err = snd_cs46xx_pcm(chip, 0);
 	if (err < 0)
-		return err;
+		goto error;
 #ifdef CONFIG_SND_CS46XX_NEW_DSP
 	err = snd_cs46xx_pcm_rear(chip, 1);
 	if (err < 0)
-		return err;
+		goto error;
 	err = snd_cs46xx_pcm_iec958(chip, 2);
 	if (err < 0)
-		return err;
+		goto error;
 #endif
 	err = snd_cs46xx_mixer(chip, 2);
 	if (err < 0)
-		return err;
+		goto error;
 #ifdef CONFIG_SND_CS46XX_NEW_DSP
 	if (chip->nr_ac97_codecs ==2) {
 		err = snd_cs46xx_pcm_center_lfe(chip, 3);
 		if (err < 0)
-			return err;
+			goto error;
 	}
 #endif
 	err = snd_cs46xx_midi(chip, 0);
 	if (err < 0)
-		return err;
+		goto error;
 	err = snd_cs46xx_start_dsp(chip);
 	if (err < 0)
-		return err;
+		goto error;
 
 	snd_cs46xx_gameport(chip);
 
@@ -117,11 +117,15 @@ static int snd_card_cs46xx_probe(struct pci_dev *pci,
 
 	err = snd_card_register(card);
 	if (err < 0)
-		return err;
+		goto error;
 
 	pci_set_drvdata(pci, card);
 	dev++;
 	return 0;
+
+ error:
+	snd_card_free(card);
+	return err;
 }
 
 static struct pci_driver cs46xx_driver = {
-- 
2.35.3

Re: snd_cs46xx regression, producing Oops

[Jan Engelhardt]

On Tuesday 2022-07-05 13:56, Takashi Iwai wrote:
>> 
>> Commit v5.14-rc1-39-g5bff69b3645d introduced a breakage into
>> snd_cs46xx.
>
>Could you try the patch below?
>Subject: [PATCH] ALSA: cs46xx: Fix missing snd_card_free() call at probe error

I confirm your patch cures the oops.

>Fixes: 5bff69b3645d ("ALSA: cs46xx: Allocate resources with device-managed APIs")

Re: snd_cs46xx regression, producing Oops

[Takashi Iwai]

On Tue, 05 Jul 2022 17:21:44 +0200,
Jan Engelhardt wrote:
> 
> On Tuesday 2022-07-05 13:56, Takashi Iwai wrote:
> >> 
> >> Commit v5.14-rc1-39-g5bff69b3645d introduced a breakage into
> >> snd_cs46xx.
> >
> >Could you try the patch below?
> >Subject: [PATCH] ALSA: cs46xx: Fix missing snd_card_free() call at probe error
> 
> I confirm your patch cures the oops.

Thanks for quick testing.  I'm going to queue and merge for the next
PR.


Takashi