Repository navigation
[BUG][CML] Kernel NULL pointer deference in module reload stress test #1386
Description
Describe the bug
"BUG: kernel NULL pointer dereference" will be seen when run module reload stress test. sometimes happens at removing snd_soc_max98357a, and sometimes happens at removing snd_soc_rt5682. dmesg log may not always be caught, because it just blocked there, and dmesg shows no error.
To Reproduce
- reboot system
- run module reload stress test script
sof_bootloop.sh
Environment
Kernel: topic/sof-dev : 5d67c4b
Firmware: cml-008-drop-stable: sof-cnl.ri providec by Poland team
Topology: file: self compiled sof-cml-rt5682-max98357a.tplg from cml-008-drop-stable
platform: CML Chrome
frequency
very high probability in first ten removal.
kernel NULL pointer deference in dmesg
[ 260.432776] BUG: kernel NULL pointer dereference, address: 0000000000000008
[ 260.432780] #PF: supervisor write access in kernel mode
[ 260.432782] #PF: error_code(0x0002) - not-present page
[ 260.432783] PGD 0 P4D 0
[ 260.432786] Oops: 0002 [#3] SMP NOPTI
[ 260.432789] CPU: 5 PID: 3191 Comm: rmmod Tainted: G D 5.4.0-rc3+ #30
[ 260.432791] Hardware name: Google Hatch/Hatch, BIOS 07/05/2019
[ 260.432796] RIP: 0010:mutex_lock+0x14/0x30
[ 260.432799] Code: 1f 80 00 00 00 00 be 02 00 00 00 e9 36 fb ff ff 66 0f 1f 44 00 00 53 48 89 fb e8 97 e8 ff ff 65 48 8b 14 25 00 5d 01 00 31 c0 48 0f b1 13 75 02 5b c3 48 89 df 5b eb cd 0f 1f 00 66 2e 0f 1f
[ 260.432800] RSP: 0018:ffffaedac254fde8 EFLAGS: 00010246
[ 260.432802] RAX: 0000000000000000 RBX: 0000000000000008 RCX: 0000000000000000
[ 260.432804] RDX: ffff9fa312d3d400 RSI: 0000000000000000 RDI: 0000000000000008
[ 260.432805] RBP: 0000000000000000 R08: ffff9fa314c00000 R09: ffff9fa314c00058
[ 260.432806] R10: 0000000000000000 R11: ffffffffbd443bd8 R12: ffffffffc0b29000
[ 260.432807] R13: ffffffffc0b29000 R14: 0000000000000000 R15: 0000000000000000
[ 260.432809] FS: 00007fa8d3216540(0000) GS:ffff9fa316340000(0000) knlGS:0000000000000000
[ 260.432811] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 260.432812] CR2: 0000000000000008 CR3: 0000000202840005 CR4: 00000000003606e0
[ 260.432813] Call Trace:
[ 260.432820] snd_sof_ipc_free+0x15/0x30 [snd_sof]
[ 260.432824] snd_sof_device_remove+0x29/0x90 [snd_sof]
[ 260.432827] sof_pci_remove+0x10/0x30 [snd_sof_pci]
[ 260.432830] pci_device_remove+0x36/0xb0
[ 260.432834] device_release_driver_internal+0xe0/0x1c0
[ 260.432837] driver_detach+0x3a/0x80
[ 260.432839] bus_remove_driver+0x53/0xd0
[ 260.432843] pci_unregister_driver+0x1d/0x90
[ 260.432847] __x64_sys_delete_module+0x155/0x240
[ 260.432850] do_syscall_64+0x43/0x120
[ 260.432853] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 260.432856] RIP: 0033:0x7fa8d2d371b7
[ 260.432858] 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
[ 260.432859] RSP: 002b:00007fff33ffc9e8 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 260.432862] RAX: ffffffffffffffda RBX: 00007fff33ffca48 RCX: 00007fa8d2d371b7
[ 260.432863] RDX: 000000000000000a RSI: 0000000000000800 RDI: 000055e3176417d8
[ 260.432864] RBP: 000055e317641770 R08: 00007fff33ffb961 R09: 0000000000000000
[ 260.432865] R10: 00007fa8d2db3cc0 R11: 0000000000000206 R12: 00007fff33ffcc10
[ 260.432867] R13: 00007fff33ffe792 R14: 000055e317641260 R15: 000055e317641770
[ 260.432869] Modules linked in: snd_sof_pci(-) snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_hda_ext_core snd_hda_codec snd_hwdep snd_hda_core snd_sof_acpi snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_bdw snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_soc_max98090 snd_soc_max98357a snd_soc_wm8804_i2c snd_soc_wm8804 snd_soc_pcm512x_i2c snd_soc_pcm512x snd_soc_rt5682 snd_soc_rt5677_spi snd_soc_rt5670 snd_soc_rt5651 snd_soc_rt5645 snd_soc_rt5640 snd_soc_rl6231 snd_soc_rt298 snd_soc_rt286 snd_soc_rl6347a snd_soc_da7219 snd_soc_da7213 snd_soc_core snd_pcm asix usbnet snd_intel_nhlt snd_seq_midi snd_seq_midi_event snd_rawmidi i915 x86_pkg_temp_thermal snd_seq intel_powerclamp snd_seq_device snd_timer iwlmvm i2c_algo_bit drm_kms_helper elan_i2c syscopyarea sysfillrect sysimgblt snd fb_sys_fops int3403_thermal drm int3400_thermal soundcore processor_thermal_device int340x_thermal_zone acpi_thermal_rel intel_soc_dts_iosf intel_lpss_pci iwlwifi mei_me
[ 260.432887] intel_lpss mfd_core mei efivarfs sdhci_pci xhci_pci cqhci sdhci xhci_hcd [last unloaded: snd_pcm]
[ 260.432893] CR2: 0000000000000008
[ 260.432896] ---[ end trace 08ee176aed8dc45e ]---
[ 260.432900] RIP: 0010:trace_event_raw_event_hw_interval_param+0x150/0x1a0 [snd_pcm]
[ 260.432903] Code: 01 89 50 44 41 0f b6 54 24 08 d0 ea 83 e2 01 89 50 48 41 0f b6 54 24 08 c0 ea 02 83 e2 01 89 50 4c 41 0f b6 54 24 08 c0 ea 03 <83> e2 01 89 50 50 e8 a5 fe ab fb e9 08 ff ff ff 31 d2 31 f6 e8 b7
[ 260.432904] RSP: 0018:ffffaedac0627e98 EFLAGS: 00010286
[ 260.432906] RAX: ffffffffc0867060 RBX: ffff9fa312af3898 RCX: ffff9fa3162e72e0
[ 260.432907] RDX: ffff9fa3162e72e0 RSI: 00000000000000c0 RDI: ffff9fa312af3898
[ 260.432909] RBP: ffff9fa3162e72c0 R08: 0000746e65696369 R09: 8080808080808080
[ 260.432910] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff9fa3162eb500
[ 260.432911] R13: 0000000000000000 R14: ffff9fa3149f20c0 R15: 0ffff9fa3162eb50
[ 260.432913] FS: 00007fa8d3216540(0000) GS:ffff9fa316340000(0000) knlGS:0000000000000000
[ 260.432914] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 260.432916] CR2: 0000000000000008 CR3: 0000000202840005 CR4: 00000000003606e0
Activity
aiChaoSONG commentedon Oct 28, 2019
similar issue exist on topic/sof-dev + master:
invalid sof component type for removal
[ 131.298905] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[ 131.299257] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[ 131.350551] sof-audio-pci 0000:00:1f.3: ASoC: invalid component type -223310 for removal
[ 131.350555] sof-audio-pci 0000:00:1f.3: ASoC: invalid component type 1446162693 for removal
[ 131.350557] sof-audio-pci 0000:00:1f.3: ASoC: invalid component type 1446167301 for removal
[ 131.350559] sof-audio-pci 0000:00:1f.3: ASoC: invalid component type 1446168069 for removal
[ 131.350560] sof-audio-pci 0000:00:1f.3: ASoC: invalid component type 37916368 for removal
[ 131.350566] general protection fault: 0000 [#3] SMP NOPTI
[ 131.350569] CPU: 4 PID: 6592 Comm: rmmod Tainted: G D W 5.4.0-rc4+ #28
[ 131.350570] Hardware name: Google Hatch/Hatch, BIOS 07/05/2019
[ 131.350577] RIP: 0010:snd_soc_tplg_component_remove+0x7c/0x500 [snd_soc_core]
[ 131.350580] Code: 84 a4 03 00 00 0f 82 8c 03 00 00 83 fa 07 0f 84 bf 02 00 00 83 fa 09 0f 85 75 04 00 00 83 fb 08 0f 84 1d 04 00 00 49 8d 47 08 <49> 8b 57 08 4d 89 fd 48 39 e8 4c 8d 7a f8 0f 84 c3 00 00 00 45 39
[ 131.350581] RSP: 0018:ffff945d03877c48 EFLAGS: 00010286
[ 131.350583] RAX: 2500000002428ee0 RBX: 0000000000000008 RCX: 0000000000000006
[ 131.350584] RDX: 0000000000000000 RSI: 0000000000000082 RDI: 0000000000000000
[ 131.350586] RBP: ffff8aac127ed0d8 R08: 0000000000003cdb R09: 000000000000005c
[ 131.350587] R10: ffff8aac51dade28 R11: ffff945d038779a0 R12: 0000000000000000
[ 131.350588] R13: ffff8aac44880029 R14: ffff8aac127ed028 R15: 2500000002428ed8
[ 131.350590] FS: 00007f5aa1ff4540(0000) GS:ffff8aac56300000(0000) knlGS:0000000000000000
[ 131.350592] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 131.350593] CR2: 0000562150d3a840 CR3: 00000002024fe005 CR4: 00000000003606e0
[ 131.350594] Call Trace:
[ 131.350602] soc_cleanup_card_resources+0x124/0x340 [snd_soc_core]
[ 131.350607] snd_soc_unbind_card+0x9b/0xe0 [snd_soc_core]
[ 131.350611] snd_soc_unregister_card+0x1d/0x60 [snd_soc_core]
[ 131.350615] release_nodes+0x121/0x220
[ 131.350618] device_release_driver_internal+0xf0/0x1c0
[ 131.350621] bus_remove_device+0xd6/0x140
[ 131.350623] device_del+0x15f/0x380
[ 131.350627] platform_device_del.part.15+0xe/0x60
[ 131.350629] platform_device_unregister+0x17/0x30
[ 131.350633] snd_sof_device_remove+0x50/0x90 [snd_sof]
[ 131.350635] sof_pci_remove+0x10/0x30 [snd_sof_pci]
[ 131.350638] pci_device_remove+0x36/0xb0
[ 131.350641] device_release_driver_internal+0xe0/0x1c0
[ 131.350643] driver_detach+0x3a/0x80
[ 131.350644] bus_remove_driver+0x53/0xd0
[ 131.350647] pci_unregister_driver+0x1d/0x90
[ 131.350651] __x64_sys_delete_module+0x155/0x240
[ 131.350654] do_syscall_64+0x43/0x120
[ 131.350657] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 131.350660] RIP: 0033:0x7f5aa1b151b7
[ 131.350662] 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
[ 131.350663] RSP: 002b:00007ffe9eac2348 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 131.350665] RAX: ffffffffffffffda RBX: 00007ffe9eac23a8 RCX: 00007f5aa1b151b7
[ 131.350666] RDX: 000000000000000a RSI: 0000000000000800 RDI: 000055fe8b8127d8
[ 131.350667] RBP: 000055fe8b812770 R08: 00007ffe9eac12c1 R09: 0000000000000000
[ 131.350669] R10: 00007f5aa1b91cc0 R11: 0000000000000206 R12: 00007ffe9eac2570
[ 131.350670] R13: 00007ffe9eac4792 R14: 000055fe8b812260 R15: 000055fe8b812770
[ 131.350672] Modules linked in: snd_soc_sof_rt5682 snd_soc_hdac_hdmi snd_soc_dmic snd_sof_pci(-) snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_hda_ext_core snd_hda_codec snd_hwdep snd_hda_core snd_sof_acpi snd_sof_intel_byt snd_soc_acpi_intel_match snd_sof_intel_bdw snd_sof_intel_ipc snd_sof snd_sof_xtensa_dsp snd_soc_acpi snd_soc_max98090 snd_soc_max98357a snd_soc_wm8804_i2c snd_soc_wm8804 snd_soc_pcm512x_i2c snd_soc_pcm512x snd_soc_rt5682 snd_soc_rt5677_spi snd_soc_rt5670 snd_soc_rt5651 snd_soc_rt5645 snd_soc_rt5640 snd_soc_rl6231 snd_soc_rt298 snd_soc_rt286 snd_soc_rl6347a snd_soc_da7219 snd_soc_da7213 snd_soc_core snd_pcm asix usbnet snd_intel_nhlt snd_seq_midi snd_seq_midi_event i915 x86_pkg_temp_thermal snd_rawmidi intel_powerclamp snd_seq elan_i2c iwlmvm i2c_algo_bit drm_kms_helper snd_seq_device snd_timer syscopyarea snd sysfillrect sysimgblt fb_sys_fops soundcore int3403_thermal drm int3400_thermal iwlwifi processor_thermal_device mei_me intel_lpss_pci
[ 131.350699] int340x_thermal_zone acpi_thermal_rel intel_lpss mei intel_soc_dts_iosf mfd_core efivarfs sdhci_pci xhci_pci cqhci sdhci xhci_hcd [last unloaded: snd_pcm]
[ 131.350708] ---[ end trace fe08efe4dd7103bb ]---
[ 131.350710] RIP: 0010:0xffffffffc089c0ae
[ 131.350711] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 131.350713] RSP: 0000:ffff945d0043be78 EFLAGS: 00010286
[ 131.350715] RAX: 0000000000000000 RBX: ffff8aac53526e98 RCX: ffff8aac562e72e0
[ 131.350716] RDX: ffff8aac562e72e0 RSI: 00000000000000c0 RDI: ffff8aac53526e98
[ 131.350717] RBP: ffff8aac562e72c0 R08: 0000746e65696369 R09: 8080808080808080
[ 131.350718] R10: 0000000000000018 R11: fefefefefefefeff R12: ffff8aac562eb500
[ 131.350719] R13: 0000000000000000 R14: ffff8aac5367b540 R15: 0ffff8aac562eb50
[ 131.350721] FS: 00007f5aa1ff4540(0000) GS:ffff8aac56300000(0000) knlGS:0000000000000000
[ 131.350722] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 131.350724] CR2: 0000562150d3a840 CR3: 00000002024fe005 CR4: 00000000003606e0
[ 131.796982] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 131.797011] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 132.296930] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 132.296959] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
plbossart commentedon Oct 28, 2019
I am afraid you will have bisect and provide more information on when this last worked, if ever, and more details on where the issue happens. The logs that you provide are just not detailed enough.
aiChaoSONG commentedon Oct 29, 2019
not reproduced on today's daily, topic/sof-dev: 195c173 + master: 0e8cf66. I think 195c173 fix this issue.
dengyangchao commentedon Oct 30, 2019
when doing module unload/reload stress test(PA off), it sometimes stuck at
removing snd_soc_rt5682and wait more than 5mins still stuck at there.Environment
platform: CML Chrome
Firmware: 2ca6a4a https://github.com/thesofproject/sof/commits/master
Kernel: f5e70ce https://github.com/thesofproject/linux/commits/topic/sof-dev
Topology: file: tools/topology/sof-cml-rt5682-max98357a.tplg same as firmware
Dmesg
dmesg.log
add test scripts here:
sof_bootloop.txt
sof_bootone.txt
sof_insert.txt
sof_remove.txt
plbossart commentedon Oct 30, 2019
@dengyangchao did you check the dmesg? It looks like a really bad error, not just some delay in removing the module.
[ 96.512107] RIP: 0010:snd_ctl_remove+0xf8/0x110 [snd]
aiChaoSONG commentedon Oct 31, 2019
just run
sof_remove.shafter reboot, got the same error on Dell CML labtop and ASUS CML Chromebook.Dell CML laptop
dell_cml_laptop.log
AUSU CML Chromebook
ausu_chromebook.log
dengyangchao commentedon Nov 1, 2019
@plbossart run 100 times module unload/reload on CML Chrome today, it can remove and insert successfully.
but still can see this message in every iteration
RIP: 0010:snd_ctl_remove+0xf8/0x110 [snd]when doing module unload/reload also observed this message in other platforms ICL RVP HDA, CFL-S RVP HDA, GLK Chrome.
I don't know what the message mean, is it really a error? if yes, i'd like to open another bug to track
Dmesg
boot_99.log
plbossart commentedon Nov 1, 2019
yes I saw this "RIP: 0010:snd_ctl_remove+0xf8/0x110 [snd]" error on WHL w/ HDA as well
added #1424 to track this
dengyangchao commentedon Nov 4, 2019
can't reproduce, close , and related issue track on #1424