Repository navigation
[Stress test]: Kernel panic after unloading and reloading SOF modules 18 times on APL with PCM512x. #490
Description
Summary:
Kernel panic occurred after unloading and reloading SOF modules 18 times on APL with PCM512x.
BTW: no logger info, because of the following error:
error: Unable to open in file /sys/kernel/debug/sof/etrace
dmesg:
[ 394.718892] sof-audio sof-audio: error: failed to find dai HDMI3
[ 394.718907] sof-audio sof-audio: error: failed to find dai HDMI2
[ 394.718911] sof-audio sof-audio: error: failed to find dai HDMI1
[ 394.718915] sof-audio sof-audio: error: failed to find dai Port5
[ 394.740774] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 394.740810] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 394.740841] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 394.740853] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 394.774181] sof-audio sof-audio: warn: can't find PCM with DAI ID 3
[ 394.774204] sof-audio sof-audio: warn: can't find PCM with DAI ID 2
[ 394.774211] sof-audio sof-audio: warn: can't find PCM with DAI ID 1
[ 394.774220] sof-audio sof-audio: warn: can't find PCM with DAI ID 0
[ 394.774362] sof-audio sof-audio: free topology...
[ 394.774790] ------------[ cut here ]------------
[ 394.774793] kernel BUG at mm/slub.c:3901!
[ 394.774806] invalid opcode: 0000 [#1] SMP NOPTI
[ 394.774810] CPU: 3 PID: 6430 Comm: rmmod Not tainted 4.19.0-daily-20190102 #334
[ 394.774812] Hardware name: AAEON UP-APL01/UP-APL01, BIOS UPA1AM36 04/10/2018
[ 394.774821] RIP: 0010:kfree+0x113/0x160
[ 394.774823] Code: 18 48 89 da 4c 89 e6 e8 2b d9 a5 00 48 8b 45 00 48 85 c0 75 e4 e9 0e ff ff ff 49 8b 02 f6 c4 80 75 0a 49 8b 42 08 a8 01 75 02 <0f> 0b 49 8b 02 31 f6 f6 c4 80 74 05 41 0f b6 72 51 5b 5d 41 5c 4c
[ 394.774826] RSP: 0018:ffffa7d840dd3bd0 EFLAGS: 00010246
[ 394.774829] RAX: ffffe95405889248 RBX: ffffa251b84c5c80 RCX: ffffa251b84c5c98
[ 394.774831] RDX: 0000000000000000 RSI: ffffa251b84c5c98 RDI: 00005daf40000000
[ 394.774832] RBP: ffffa251b85a30a8 R08: ffffa251b84c5c98 R09: 0000000000000000
[ 394.774834] R10: ffffe95405e13140 R11: ffffa251b9803601 R12: ffffffffc0541685
[ 394.774836] R13: dead000000000100 R14: ffffa251b84c5d00 R15: 0000000000000000
[ 394.774838] FS: 00007f10f7751540(0000) GS:ffffa251bbb80000(0000) knlGS:0000000000000000
[ 394.774840] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 394.774842] CR2: 000055699fb76290 CR3: 000000015cfe4000 CR4: 00000000003406e0
[ 394.774844] Call Trace:
[ 394.774854] hdac_hdmi_dev_remove+0xb5/0x1c0 [snd_soc_hdac_hdmi]
[ 394.774860] device_release_driver_internal+0x17d/0x240
[ 394.774864] bus_remove_device+0xd7/0x120
[ 394.774868] device_del+0x133/0x350
[ 394.774874] snd_hdac_device_unregister+0x19/0x30 [snd_hda_core]
[ 394.774880] snd_hdac_ext_bus_device_remove+0x2a/0x60 [snd_hda_ext_core]
[ 394.774887] hda_dsp_remove+0x30/0x150 [snd_sof_intel_hda_common]
[ 394.774893] sof_remove+0x6f/0x80 [snd_sof]
[ 394.774897] platform_drv_remove+0x1e/0x40
[ 394.774900] device_release_driver_internal+0x17d/0x240
[ 394.774902] bus_remove_device+0xd7/0x120
[ 394.774905] device_del+0x133/0x350
[ 394.774908] platform_device_del.part.12+0x19/0x70
[ 394.774911] platform_device_unregister+0xe/0x20
[ 394.774914] sof_pci_remove+0x26/0x40 [sof_pci_dev]
[ 394.774919] pci_device_remove+0x36/0xb0
[ 394.774922] device_release_driver_internal+0x17d/0x240
[ 394.774925] driver_detach+0x2d/0x60
[ 394.774927] bus_remove_driver+0x47/0xa0
[ 394.774930] pci_unregister_driver+0x1d/0x90
[ 394.774935] __x64_sys_delete_module+0x155/0x210
[ 394.774939] do_syscall_64+0x43/0xf0
[ 394.774944] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 394.774948] RIP: 0033:0x7f10f72711b7
[ 394.774951] Code: 73 01 c3 48 8b 0d d1 8c 2c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 b0 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 8c 2c 00 f7 d8 64 89 01 48
[ 394.774952] RSP: 002b:00007ffe41a12f58 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 394.774955] RAX: ffffffffffffffda RBX: 00007ffe41a12fb8 RCX: 00007f10f72711b7
[ 394.774957] RDX: 000000000000000a RSI: 0000000000000800 RDI: 00005573980c8808
[ 394.774959] RBP: 00005573980c87a0 R08: 00007ffe41a11ed1 R09: 0000000000000000
[ 394.774961] R10: 00007f10f72edcc0 R11: 0000000000000206 R12: 00007ffe41a13180
[ 394.774962] R13: 00007ffe41a137a4 R14: 00005573980c7260 R15: 00005573980c87a0
[ 394.774965] Modules linked in: snd_soc_sst_bxt_pcm512x snd_soc_hdac_hdmi snd_soc_dmic sof_pci_dev(-) snd_sof_intel_hda_common snd_sof_intel_hda snd_sof_intel_byt snd_sof_nocodec snd_sof_xtensa_dsp snd_sof snd_soc_acpi_intel_match snd_soc_acpi snd_hda_ext_core snd_hda_core snd_soc_pcm512x_i2c snd_soc_pcm512x snd_soc_core snd_pcm x86_pkg_temp_thermal intel_lpss_pci intel_lpss mfd_core efivarfs mmc_block sdhci_pci cqhci xhci_pci sdhci xhci_hcd [last unloaded: snd_pcm]
[ 394.774991] ---[ end trace 2e2b4d4a97ad39f8 ]---
[ 394.774994] RIP: 0010:kfree+0x113/0x160
[ 394.774996] Code: 18 48 89 da 4c 89 e6 e8 2b d9 a5 00 48 8b 45 00 48 85 c0 75 e4 e9 0e ff ff ff 49 8b 02 f6 c4 80 75 0a 49 8b 42 08 a8 01 75 02 <0f> 0b 49 8b 02 31 f6 f6 c4 80 74 05 41 0f b6 72 51 5b 5d 41 5c 4c
[ 394.774998] RSP: 0018:ffffa7d840dd3bd0 EFLAGS: 00010246
[ 394.775000] RAX: ffffe95405889248 RBX: ffffa251b84c5c80 RCX: ffffa251b84c5c98
[ 394.775002] RDX: 0000000000000000 RSI: ffffa251b84c5c98 RDI: 00005daf40000000
[ 394.775004] RBP: ffffa251b85a30a8 R08: ffffa251b84c5c98 R09: 0000000000000000
[ 394.775006] R10: ffffe95405e13140 R11: ffffa251b9803601 R12: ffffffffc0541685
[ 394.775007] R13: dead000000000100 R14: ffffa251b84c5d00 R15: 0000000000000000
[ 394.775010] FS: 00007f10f7751540(0000) GS:ffffa251bbb80000(0000) knlGS:0000000000000000
[ 394.775012] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 394.775013] CR2: 000055699fb76290 CR3: 000000015cfe4000 CR4: 00000000003406e0
Test steps:
1. sof_bootloop.sh(input 100 times)
2. aplay -l
aplay: device_list:270: no soundcards found...
Test env:
sof master: a2e6f82
kernel sof-dev: 62aa569
tplg: sof-apl-pcm512x.tplg
Activity
plbossart commentedon Jan 2, 2019
@markyang can you try and check if #491 fixes the issue?
plbossart commentedon Jan 5, 2019
@markyang kind reminder that I need to have information on whether PR491 fixes the issue.
markyang commentedon Jan 7, 2019
@stevyan
markyang commentedon Jan 7, 2019
@plbossart It became worse after patching PR491 on the latest code. Fail to probe snd_soc_pcm512x_i2c module after removing all the SOF modules.
Test env:
sof master: a2e6f82
kernel sof-dev: 5931a30
tplg: sof-apl-pcm512x.tplg
Log:
491.patch.txt
boot_0.bootlog.txt
boot_1.bootlog.txt
ranj063 commentedon Jan 8, 2019
@plbossart I can only run the sof_bootloop once. It fails while trying to remove sof_pci_dev the second time around with a null pointer exception
plbossart commentedon Jan 8, 2019
thanks @ranj063, i'll have to look into this. Not sure why moving to devm_ make things worse, maybe there's something fishy behind all this.
ranj063 commentedon Jan 8, 2019
@plbossart btw i did not even try PR 491. This is what I saw even before. And I think I figured out why.
So if I wait until after the audio dsp is runtime suspended, I'm able to run the sof_bootloop for as many times as I want. So I added a 5 seconds sleep between iterations and it seems to work fine. I was just able to run 100 iterations of module load/unload with the 5s sleep between iterations.
ranj063 commentedon Jan 9, 2019
@plbossart @xiulipan this problem seems to be unique to me. I cannot execute sof_remove.sh if the audio device is not runtime suspended. I run into a kernel oops as in the logs below:
plbossart commentedon Jan 9, 2019
@ranj063 you get a kernel oops but after you get an IPC error. That means the error handling has a problem
markyang commentedon Jan 10, 2019
Summary:
This issue cannot be reproduced on APL with PCM512x.
Test env:
sof master: 8435536
kernel sof-dev: 7ea9493
tplg: sof-apl-pcm512x.tplg
stevyan commentedon Jan 16, 2019
Summary:
This issue can be reproduced on APL with PCM512x (xcc).
Test env:
sof master: 9d10e1a
kernel sof-dev: eec37ea
tplg: sof-apl-pcm512x.tplg
Reference Log:
[ 803.214065] sof-audio sof-audio: FW Poll Status: reg=0x1010303 successful
[ 803.215128] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215133] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 803.215147] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215151] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215154] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 803.215162] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215166] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215169] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 803.215179] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215183] sof-audio sof-audio: FW Poll Status: reg=0x303 successful
[ 803.215186] sof-audio sof-audio: DSP core(s) enabled? 0 : core_mask 1
[ 803.251846] sof-audio sof-audio: free topology...
[ 803.252216] ------------[ cut here ]------------
[ 803.252218] kernel BUG at mm/slub.c:3937!
[ 803.252229] invalid opcode: 0000 [#1] SMP NOPTI
[ 803.252239] CPU: 2 PID: 25737 Comm: rmmod Tainted: G B 4.20.0-daily-20190116 #eec37ea0
[ 803.252243] Hardware name: AAEON UP-APL01/UP-APL01, BIOS UPA1AM36 04/10/2018
[ 803.252251] RIP: 0010:kfree+0x115/0x160
[ 803.252255] Code: 89 da 4c 89 e6 e8 3b 70 c5 00 48 8b 45 00 48 85 c0 75 e4 e9 0e ff ff ff 49 8b 02 a9 00 00 01 00 75 0a 49 8b 42 08 a8 01 75 02 <0f> 0b 49 8b 02 31 f6 a9 00 00 01 00 74 05 41 0f b6 72 51 5b 5d 41
[ 803.252260] RSP: 0018:ffffac834120fbc0 EFLAGS: 00010246
[ 803.252263] RAX: ffffd2d3455cbf88 RBX: ffff92605729aec0 RCX: 0000000000000286
[ 803.252266] RDX: 0000000000000000 RSI: ffff92605729aee8 RDI: 00006da080000000
[ 803.252271] RBP: 000000000000007c R08: ffff92605db2ea80 R09: ffffffffad5bc8d0
[ 803.252274] R10: ffffd2d3455ca680 R11: 0000000000000001 R12: ffffffffad5bbecc
[ 803.252277] R13: ffff92605729ae80 R14: ffffac834120fbe0 R15: ffffffffae20480b
[ 803.252280] FS: 00007ffac0aaa540(0000) GS:ffff92607bb00000(0000) knlGS:0000000000000000
[ 803.252284] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 803.252286] CR2: 000055c3185e18c0 CR3: 000000017848a000 CR4: 00000000003406e0
[ 803.252289] Call Trace:
[ 803.252299] release_nodes+0x12c/0x220
[ 803.252307] device_release_driver_internal+0x18d/0x240
[ 803.252311] bus_remove_device+0xd7/0x120
[ 803.252315] device_del+0x133/0x350
[ 803.252323] snd_hdac_device_unregister+0x19/0x30 [snd_hda_core]
[ 803.252329] snd_hdac_ext_bus_device_remove+0x2a/0x60 [snd_hda_ext_core]
[ 803.252337] hda_dsp_remove+0x27/0x110 [snd_sof_intel_hda_common]
[ 803.252344] sof_remove+0x77/0x80 [snd_sof]
[ 803.252348] platform_drv_remove+0x1e/0x40
[ 803.252352] device_release_driver_internal+0x17d/0x240
[ 803.252356] bus_remove_device+0xd7/0x120
[ 803.252360] device_del+0x133/0x350
[ 803.252364] platform_device_del.part.15+0x19/0x70
[ 803.252367] platform_device_unregister+0xe/0x20
[ 803.252371] sof_pci_remove+0x26/0x40 [sof_pci_dev]
[ 803.252376] pci_device_remove+0x36/0xb0
[ 803.252381] device_release_driver_internal+0x17d/0x240
[ 803.252385] driver_detach+0x2d/0x60
[ 803.252388] bus_remove_driver+0x47/0xa0
[ 803.252392] pci_unregister_driver+0x1d/0x90
[ 803.252398] __x64_sys_delete_module+0x155/0x210
[ 803.252403] do_syscall_64+0x43/0xf0
[ 803.252409] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 803.252413] RIP: 0033:0x7ffac05c81b7
[ 803.252417] Code: 73 01 c3 48 8b 0d d1 8c 2c 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 b0 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a1 8c 2c 00 f7 d8 64 89 01 48
[ 803.252422] RSP: 002b:00007ffd58b76458 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 803.252426] RAX: ffffffffffffffda RBX: 00007ffd58b764b8 RCX: 00007ffac05c81b7
[ 803.252429] RDX: 000000000000000a RSI: 0000000000000800 RDI: 000055869b516808
[ 803.252432] RBP: 000055869b5167a0 R08: 00007ffd58b753d1 R09: 0000000000000000
[ 803.252435] R10: 00007ffac0644cc0 R11: 0000000000000206 R12: 00007ffd58b76680
[ 803.252438] R13: 00007ffd58b777a1 R14: 000055869b515260 R15: 000055869b5167a0
[ 803.252441] Modules linked in: snd_soc_sst_bxt_pcm512x snd_soc_hdac_hdmi snd_soc_dmic sof_p
ci_dev(-) snd_sof_intel_hda_common snd_sof_intel_hda snd_sof_intel_byt snd_sof_nocodec snd_sof
_xtensa_dsp snd_sof snd_soc_acpi_intel_match snd_soc_acpi snd_hda_ext_core snd_hda_core snd_so
c_pcm512x_i2c snd_soc_pcm512x snd_soc_core snd_pcm x86_pkg_temp_thermal intel_lpss_pci intel_l
pss mfd_core efivarfs mmc_block sdhci_pci cqhci sdhci xhci_pci xhci_hcd [last unloaded: snd_pc
m]
[ 803.252489] ---[ end trace 6558995274032d00 ]---
[ 803.252494] RIP: 0010:kfree+0x115/0x160
[ 803.252497] Code: 89 da 4c 89 e6 e8 3b 70 c5 00 48 8b 45 00 48 85 c0 75 e4 e9 0e ff ff ff 4
9 8b 02 a9 00 00 01 00 75 0a 49 8b 42 08 a8 01 75 02 <0f> 0b 49 8b 02 31 f6 a9 00 00 01 00 74
05 41 0f b6 72 51 5b 5d 41
[ 803.252502] RSP: 0018:ffffac834120fbc0 EFLAGS: 00010246
[ 803.252505] RAX: ffffd2d3455cbf88 RBX: ffff92605729aec0 RCX: 0000000000000286
[ 803.252508] RDX: 0000000000000000 RSI: ffff92605729aee8 RDI: 00006da080000000
[ 803.252511] RBP: 000000000000007c R08: ffff92605db2ea80 R09: ffffffffad5bc8d0
[ 803.252514] R10: ffffd2d3455ca680 R11: 0000000000000001 R12: ffffffffad5bbecc
[ 803.252517] R13: ffff92605729ae80 R14: ffffac834120fbe0 R15: ffffffffae20480b
[ 803.252520] FS: 00007ffac0aaa540(0000) GS:ffff92607bb00000(0000) knlGS:0000000000000000
[ 803.252524] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 803.252527] CR2: 000055c3185e18c0 CR3: 000000017848a000 CR4: 00000000003406e0
plbossart commentedon Feb 8, 2019
closing, this works fine now. If there is still a problem a new issue needs to be re-opened
drm/gma500: Fix WARN_ON(lock->magic != lock) error
ACPI: tables: FPDT: Don't call acpi_os_map_memory() on invalid phys a…
riscv: kprobe: Fixup kernel panic when probing an illegal position
ACPI: tables: FPDT: Don't call acpi_os_map_memory() on invalid phys a…
powerpc/bpf/32: Fix failing test_bpf tests