BUG: sleeping function called from invalid context at arch/arm64/mm/fault.c:593

From: Naresh Kamboju
Date: Thu Sep 15 2022 - 06:18:12 EST


[Please ignore this email if it is already reported]
Following kernel warning and BUG have been found while running kselftests gpio
test case on arm64 Raspberry Pi 4 Model B device running 6.0.0-rc5.

Reported-by: Linux Kernel Functional Testing <lkft@xxxxxxxxxx>

crash log:

[ 53.796405] kselftest: Running tests in gpio
TAP version 13
1..2
# selftests: gpio: gpio-mockup.sh
# 1. Module load tests
# 1.1. dynamic allocation of gpio
[ 55.416786]
[ 55.418311] =============================
[ 55.422371] WARNING: suspicious RCU usage
[ 55.426431] 6.0.0-rc5 #1 Not tainted
[ 55.430052] -----------------------------
[ 55.434112] kernel/sched/core.c:9854 Illegal context switch in
RCU-bh read-side critical section!
[ 55.443108]
[ 55.443108] other info that might help us debug this:
[ 55.443108]
[ 55.451222]
[ 55.451222] rcu_scheduler_active = 2, debug_locks = 1
[ 55.457839] 1 lock held by modprobe/563:
[ 55.461812] #0: ffff00004cf450f8 (&dev->mutex){....}-{3:3}, at:
device_release_driver_internal+0x50/0x290
[ 55.471632]
[ 55.471632] stack backtrace:
[ 55.476046] CPU: 2 PID: 563 Comm: modprobe Not tainted 6.0.0-rc5 #1
[ 55.482401] Hardware name: Raspberry Pi 4 Model B (DT)
[ 55.487607] Call trace:
[ 55.490079] dump_backtrace+0xe4/0x130
[ 55.493879] show_stack+0x30/0x70
[ 55.497235] dump_stack_lvl+0x8c/0xb8
[ 55.500947] dump_stack+0x18/0x34
[ 55.504303] lockdep_rcu_suspicious+0xf8/0x10c
[ 55.508806] __might_resched+0xd0/0x240
[ 55.512694] __might_sleep+0x58/0xb0
[ 55.516316] do_page_fault+0x244/0x4d0
[ 55.520116] do_translation_fault+0xd8/0x100
[ 55.524443] do_mem_abort+0x58/0xb0
[ 55.527979] el1_abort+0x44/0x70
[ 55.531248] el1h_64_sync_handler+0xa4/0xd0
[ 55.535487] el1h_64_sync+0x64/0x68
[ 55.539020] __lock_acquire+0x53c/0x2040
[ 55.542995] lock_acquire.part.0+0xe8/0x24c
[ 55.547233] lock_acquire+0x84/0xa0
[ 55.550766] down_write+0x60/0xc4
[ 55.554123] simple_recursive_removal+0x58/0x290
[ 55.558803] debugfs_remove+0x5c/0x80
[ 55.562516] gpio_mockup_debugfs_cleanup+0x24/0x34 [gpio_mockup]
[ 55.568614] devm_action_release+0x24/0x3c
[ 55.572764] release_nodes+0x64/0x9c
[ 55.576384] devres_release_all+0x94/0xec
[ 55.580447] device_unbind_cleanup+0x24/0x74
[ 55.584773] device_release_driver_internal+0x240/0x290
[ 55.590070] driver_detach+0x5c/0xf0
[ 55.593691] bus_remove_driver+0x6c/0x10c
[ 55.597753] driver_unregister+0x38/0x6c
[ 55.601728] platform_driver_unregister+0x24/0x34
[ 55.606497] gpio_mockup_exit+0x24/0x20c [gpio_mockup]
[ 55.611707] __arm64_sys_delete_module+0x184/0x2f0
[ 55.616562] invoke_syscall+0x8c/0x120
[ 55.620362] el0_svc_common.constprop.0+0x104/0x124
[ 55.625307] do_el0_svc+0x44/0xc0
[ 55.628664] el0_svc+0x48/0xc0
[ 55.631757] el0t_64_sync_handler+0xbc/0x140
[ 55.636084] el0t_64_sync+0x18c/0x190
[ 55.639793]
[ 55.641298] =============================
[ 55.645356] WARNING: suspicious RCU usage
[ 55.649417] 6.0.0-rc5 #1 Not tainted
[ 55.653037] -----------------------------
[ 55.657096] kernel/sched/core.c:9854 Illegal context switch in
RCU-sched read-side critical section!
[ 55.666356]
[ 55.666356] other info that might help us debug this:
[ 55.666356]
[ 55.674469]
[ 55.674469] rcu_scheduler_active = 2, debug_locks = 1
[ 55.681084] 1 lock held by modprobe/563:
[ 55.685057] #0: ffff00004cf450f8 (&dev->mutex){....}-{3:3}, at:
device_release_driver_internal+0x50/0x290
[ 55.694863]
[ 55.694863] stack backtrace:
[ 55.699275] CPU: 2 PID: 563 Comm: modprobe Not tainted 6.0.0-rc5 #1
[ 55.705628] Hardware name: Raspberry Pi 4 Model B (DT)
[ 55.710834] Call trace:
[ 55.713306] dump_backtrace+0xe4/0x130
[ 55.717103] show_stack+0x30/0x70
[ 55.720459] dump_stack_lvl+0x8c/0xb8
[ 55.724170] dump_stack+0x18/0x34
[ 55.727526] lockdep_rcu_suspicious+0xf8/0x10c
[ 55.732029] __might_resched+0x214/0x240
[ 55.736003] __might_sleep+0x58/0xb0
[ 55.739625] do_page_fault+0x244/0x4d0
[ 55.743424] do_translation_fault+0xd8/0x100
[ 55.747751] do_mem_abort+0x58/0xb0
[ 55.751286] el1_abort+0x44/0x70
[ 55.754556] el1h_64_sync_handler+0xa4/0xd0
[ 55.758794] el1h_64_sync+0x64/0x68
[ 55.762326] __lock_acquire+0x53c/0x2040
[ 55.766301] lock_acquire.part.0+0xe8/0x24c
[ 55.770538] lock_acquire+0x84/0xa0
[ 55.774072] down_write+0x60/0xc4
[ 55.777428] simple_recursive_removal+0x58/0x290
[ 55.782107] debugfs_remove+0x5c/0x80
[ 55.785818] gpio_mockup_debugfs_cleanup+0x24/0x34 [gpio_mockup]
[ 55.791911] devm_action_release+0x24/0x3c
[ 55.796061] release_nodes+0x64/0x9c
[ 55.799682] devres_release_all+0x94/0xec
[ 55.803743] device_unbind_cleanup+0x24/0x74
[ 55.808070] device_release_driver_internal+0x240/0x290
[ 55.813367] driver_detach+0x5c/0xf0
[ 55.816988] bus_remove_driver+0x6c/0x10c
[ 55.821050] driver_unregister+0x38/0x6c
[ 55.825025] platform_driver_unregister+0x24/0x34
[ 55.829793] gpio_mockup_exit+0x24/0x20c [gpio_mockup]
[ 55.835002] __arm64_sys_delete_module+0x184/0x2f0
[ 55.839858] invoke_syscall+0x8c/0x120
[ 55.843657] el0_svc_common.constprop.0+0x104/0x124
[ 55.848602] do_el0_svc+0x44/0xc0
[ 55.851958] el0_svc+0x48/0xc0
[ 55.855051] el0t_64_sync_handler+0xbc/0x140
[ 55.859378] el0t_64_sync+0x18c/0x190
[ 55.863087] BUG: sleeping function called from invalid context at
arch/arm64/mm/fault.c:593
[ 55.871554] in_atomic(): 0, irqs_disabled(): 128, non_block: 0,
pid: 563, name: modprobe
[ 55.879757] preempt_count: 0, expected: 0
[ 55.883816] RCU nest depth: 0, expected: 0
[ 55.887965] 1 lock held by modprobe/563:
[ 55.891936] #0: ffff00004cf450f8 (&dev->mutex){....}-{3:3}, at:
device_release_driver_internal+0x50/0x290
[ 55.901743] irq event stamp: 10213
[ 55.905185] hardirqs last enabled at (10213): [<ffff8000096e2e74>]
_raw_spin_unlock_irqrestore+0x84/0xa0
[ 55.914888] hardirqs last disabled at (10212): [<ffff8000096e3314>]
_raw_spin_lock_irqsave+0xa4/0xb0
[ 55.924151] softirqs last enabled at (9742): [<ffff800008010be4>]
__do_softirq+0x514/0x62c
[ 55.932618] softirqs last disabled at (9737): [<ffff8000080b4768>]
__irq_exit_rcu+0x164/0x19c
[ 55.941265] CPU: 2 PID: 563 Comm: modprobe Not tainted 6.0.0-rc5 #1
[ 55.947618] Hardware name: Raspberry Pi 4 Model B (DT)
[ 55.952823] Call trace:
[ 55.955296] dump_backtrace+0xe4/0x130
[ 55.959093] show_stack+0x30/0x70
[ 55.962448] dump_stack_lvl+0x8c/0xb8
[ 55.966159] dump_stack+0x18/0x34
[ 55.969515] __might_resched+0x1c4/0x240
[ 55.973490] __might_sleep+0x58/0xb0
[ 55.977111] do_page_fault+0x244/0x4d0
[ 55.980910] do_translation_fault+0xd8/0x100
[ 55.985238] do_mem_abort+0x58/0xb0
[ 55.988774] el1_abort+0x44/0x70
[ 55.992043] el1h_64_sync_handler+0xa4/0xd0
[ 55.996281] el1h_64_sync+0x64/0x68
[ 55.999814] __lock_acquire+0x53c/0x2040
[ 56.003789] lock_acquire.part.0+0xe8/0x24c
[ 56.008028] lock_acquire+0x84/0xa0
[ 56.011560] down_write+0x60/0xc4
[ 56.014916] simple_recursive_removal+0x58/0x290
[ 56.019594] debugfs_remove+0x5c/0x80
[ 56.023306] gpio_mockup_debugfs_cleanup+0x24/0x34 [gpio_mockup]
[ 56.029400] devm_action_release+0x24/0x3c
[ 56.033549] release_nodes+0x64/0x9c
[ 56.037170] devres_release_all+0x94/0xec
[ 56.041232] device_unbind_cleanup+0x24/0x74
[ 56.045559] device_release_driver_internal+0x240/0x290
[ 56.050855] driver_detach+0x5c/0xf0
[ 56.054477] bus_remove_driver+0x6c/0x10c
[ 56.058539] driver_unregister+0x38/0x6c
[ 56.062513] platform_driver_unregister+0x24/0x34
[ 56.067281] gpio_mockup_exit+0x24/0x20c [gpio_mockup]
[ 56.072490] __arm64_sys_delete_module+0x184/0x2f0
[ 56.077346] invoke_syscall+0x8c/0x120
[ 56.081145] el0_svc_common.constprop.0+0x104/0x124
[ 56.086089] do_el0_svc+0x44/0xc0
[ 56.089446] el0_svc+0x48/0xc0
[ 56.092539] el0t_64_sync_handler+0xbc/0x140
[ 56.096866] el0t_64_sync+0x18c/0x190
[ 56.100584] Unable to handle kernel NULL pointer dereference at
virtual address 0000000000000150
[ 56.109495] Mem abort info:
[ 56.112320] ESR = 0x0000000096000006
[ 56.116116] EC = 0x25: DABT (current EL), IL = 32 bits
[ 56.121499] SET = 0, FnV = 0
[ 56.124589] EA = 0, S1PTW = 0
[ 56.127767] FSC = 0x06: level 2 translation fault
[ 56.132708] Data abort info:
[ 56.135622] ISV = 0, ISS = 0x00000006
[ 56.139505] CM = 0, WnR = 0
[ 56.142506] user pgtable: 4k pages, 48-bit VAs, pgdp=000000004adb5000
[ 56.149035] [0000000000000150] pgd=08000000469d2003,
p4d=08000000469d2003, pud=0800000046b70003, pmd=0000000000000000
[ 56.159807] Internal error: Oops: 96000006 [#1] PREEMPT SMP
[ 56.165455] Modules linked in: gpio_mockup(-) algif_hash
aes_neon_bs aes_neon_blk xhci_pci raspberrypi_cpufreq
snd_soc_hdmi_codec xhci_pci_renesas brcmfmac brcmutil hci_uart btqca
btbcm cfg80211 bluetooth reset_raspberrypi crct10dif_ce
clk_raspberrypi raspberrypi_hwmon rfkill iproc_rng200 pwm_bcm2835 v3d
rng_core i2c_bcm2835 drm_shmem_helper vc4 bcm2711_thermal cec
drm_display_helper drm_cma_helper gpu_sched pcie_brcmstb
drm_kms_helper fuse drm
[ 56.205467] CPU: 2 PID: 563 Comm: modprobe Tainted: G W
6.0.0-rc5 #1
[ 56.213318] Hardware name: Raspberry Pi 4 Model B (DT)
[ 56.218523] pstate: 600000c5 (nZCv daIF -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 56.225582] pc : __lock_acquire+0x53c/0x2040
[ 56.229910] lr : lock_acquire.part.0+0xe8/0x24c
[ 56.234499] sp : ffff80000d03b8a0
[ 56.237852] x29: ffff80000d03b8a0 x28: ffff800008456678 x27: 0000000000000000
[ 56.245091] x26: ffff800008456678 x25: 0000000000000150 x24: 0000000000000000
[ 56.252329] x23: ffff00004c200040 x22: 0000000000000000 x21: 0000000000000001
[ 56.259567] x20: 0000000000000000 x19: 0000000000000000 x18: 0000000000000000
[ 56.266804] x17: ffff800008b93ed0 x16: 0000000000000000 x15: 0000000000000028
[ 56.274041] x14: 000000000004ffff x13: ffff80000b40dd00 x12: ffff80000802cff8
[ 56.281279] x11: ffff80000b40d840 x10: ffff80000802cdfc x9 : 0000000100000000
[ 56.288517] x8 : ffff00004c200040 x7 : ffff800008456678 x6 : 0000000000000000
[ 56.295755] x5 : 0000000000000001 x4 : 0000000000000001 x3 : 0000000000000000
[ 56.302992] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff80000aeb6000
[ 56.310230] Call trace:
[ 56.312701] __lock_acquire+0x53c/0x2040
[ 56.316674] lock_acquire.part.0+0xe8/0x24c
[ 56.320911] lock_acquire+0x84/0xa0
[ 56.324444] down_write+0x60/0xc4
[ 56.327799] simple_recursive_removal+0x58/0x290
[ 56.332477] debugfs_remove+0x5c/0x80
[ 56.336186] gpio_mockup_debugfs_cleanup+0x24/0x34 [gpio_mockup]
[ 56.342276] devm_action_release+0x24/0x3c
[ 56.346425] release_nodes+0x64/0x9c
[ 56.350043] devres_release_all+0x94/0xec
[ 56.354104] device_unbind_cleanup+0x24/0x74
[ 56.358430] device_release_driver_internal+0x240/0x290
[ 56.363725] driver_detach+0x5c/0xf0
[ 56.367346] bus_remove_driver+0x6c/0x10c
[ 56.371407] driver_unregister+0x38/0x6c
[ 56.375380] platform_driver_unregister+0x24/0x34
[ 56.380147] gpio_mockup_exit+0x24/0x20c [gpio_mockup]
[ 56.385356] __arm64_sys_delete_module+0x184/0x2f0
[ 56.390211] invoke_syscall+0x8c/0x120
[ 56.394009] el0_svc_common.constprop.0+0x104/0x124
[ 56.398952] do_el0_svc+0x44/0xc0
[ 56.402308] el0_svc+0x48/0xc0
[ 56.405400] el0t_64_sync_handler+0xbc/0x140
[ 56.409725] el0t_64_sync+0x18c/0x190
[ 56.413435] Code: 6b01001f 54002668 a94573fb 1400003d (f9400321)
[ 56.419613] ---[ end trace 0000000000000000 ]---


Full test log,
https://lkft.validation.linaro.org/scheduler/job/5528616#L1360

metadata:
git_ref: master
git_repo: https://gitlab.com/Linaro/lkft/mirrors/torvalds/linux-mainline
git_sha: 3245cb65fd91cd514801bf91f5a3066d562f0ac4
git_describe: v6.0-rc5-25-g3245cb65fd91
kernel_version: 6.0.0-rc5
kernel-config: https://builds.tuxbuild.com/2EkryDJF2MJ3zNyYOYb016CJbRv/config
vmlinux.xz: https://builds.tuxbuild.com/2EkryDJF2MJ3zNyYOYb016CJbRv/vmlinux.xz
System.map: https://builds.tuxbuild.com/2EkryDJF2MJ3zNyYOYb016CJbRv/System.map
build-url: https://gitlab.com/Linaro/lkft/mirrors/torvalds/linux-mainline/-/pipelines/639865874
artifact-location: https://builds.tuxbuild.com/2EkryDJF2MJ3zNyYOYb016CJbRv
toolchain: gcc-11


--
Linaro LKFT
https://lkft.linaro.org