BUG: sleeping function called from invalid context at kernel/locking/mutex.c:580

From: Naresh Kamboju
Date: Wed Oct 12 2022 - 03:06:27 EST

Following kernel deadlock warnings and BUG noticed on arm64 Qcom db845c device
While booting Linux next 20221012 tag kernel Image and kselftest configs.

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

[ 18.690573] ============================================
[ 18.695938] WARNING: possible recursive locking detected
[ 18.701307] 6.0.0-next-20221012 #1 Not tainted
[ 18.705804] --------------------------------------------
[ 18.711168] kworker/u16:5/256 is trying to acquire lock:
[ 18.716544] ffff58730911e4f8 (&irq_desc_lock_class){-.-.}-{2:2},
at: __irq_get_desc_lock+0x64/0xa4
[ 18.725629]
[ 18.725629] but task is already holding lock:
[ 18.731519] ffff5873071c64f8 (&irq_desc_lock_class){-.-.}-{2:2},
at: __irq_get_desc_lock+0x64/0xa4
[ 18.733233] remoteproc remoteproc0: remote processor
remoteproc-adsp is now up
[ 18.740563]
[ 18.740563] other info that might help us debug this:
[ 18.740566] Possible unsafe locking scenario:
[ 18.740566]
[ 18.740569] CPU0
[ 18.740571] ----
[ 18.740573] lock(&irq_desc_lock_class);
[ 18.740579] lock(&irq_desc_lock_class);
[ 18.740585]
[ 18.740585] *** DEADLOCK ***
[ 18.740585]
[ 18.740587] May be due to missing lock nesting notation
[ 18.740587]
[ 18.757926] cfg80211: Loading compiled-in X.509 certificates for
regulatory database
[ 18.760420] 6 locks held by kworker/u16:5/256:
[ 18.760424] #0: ffff587300032938
((wq_completion)events_unbound){+.+.}-{0:0}, at:
process_one_work+0x1e8/0x6d4
[ 18.793798] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 18.794138] #1: ffff800009a1bdd0
(deferred_probe_work){+.+.}-{0:0}, at: process_one_work+0x1e8/0x6d4
[ 18.815528] #2: ffff5873019e68f8 (&dev->mutex){....}-{3:3}, at:
__device_attach+0x44/0x200
[ 18.833287] #3: ffffdd47e98f1cf0 (cpu_hotplug_lock){++++}-{0:0},
at: cpus_read_lock+0x18/0x24
M[K[ *** ] (2 of 2) A start j[ 18.842012] #4: ffff587301248518
(subsys mutex#8){+.ob is running for…n to /usr/lib/rfsa (9s / no
limit)
[ 18.857511] #5: ffff5873071c64f8
(&irq_desc_lock_class){-.-.}-{2:2}, at: __irq_get_desc_lock+0x64/0xa4
[ 18.871877]
[ 18.871877] stack backtrace:
[ 18.876286] CPU: 4 PID: 256 Comm: kworker/u16:5 Not tainted
6.0.0-next-20221012 #1
[ 18.883936] Hardware name: Thundercomm Dragonboard 845c (DT)
[ 18.889655] Workqueue: events_unbound deferred_probe_work_func
[ 18.895566] Call trace:
[ 18.898046] dump_backtrace+0xe4/0x140
[ 18.901847] show_stack+0x30/0x60
[ 18.905203] dump_stack_lvl+0x8c/0xb8
[ 18.908918] dump_stack+0x18/0x34
[ 18.912274] __lock_acquire+0x1154/0x2040
[ 18.916330] lock_acquire.part.0+0xe8/0x24c
[ 18.920568] lock_acquire+0x84/0xa0
[ 18.924102] _raw_spin_lock_irqsave+0x70/0xb0
[ 18.928523] __irq_get_desc_lock+0x64/0xa4
[ 18.928532] enable_irq+0x40/0xb0
[ 18.928542] lmh_enable_interrupt+0x3c/0x50 [lmh]
Coldplug All udev De[ 18.94080vices.
[ 18.952775] __irq_startup+0x88/0xbc
[K[ 18.957451] irq_startup+0x84/0x180
[ 18.961243] __enable_irq+0x88/0xa0
[ 18.964776] enable_irq+0x54/0xb0
[ 18.968140] qcom_cpufreq_ready+0x2c/0x3c
[ 18.972200] cpufreq_online+0x2f4/0xb24
[ 18.976083] cpufreq_add_dev+0xdc/0x100
[ 18.979964] subsys_interface_register+0x134/0x14c
[ 18.984819] cpufreq_register_driver+0x16c/0x2e0
[ 18.989488] qcom_cpufreq_hw_driver_probe+0xdc/0x150
[ 18.994510] platform_probe+0x70/0x100
[ 18.998311] really_probe+0xd4/0x3f4
[ 19.001936] __driver_probe_device+0x8c/0x1a0
[ 19.006347] driver_probe_device+0x4c/0x13c
[ 19.010584] __device_attach_driver+0xd8/0x180
[ 19.015081] bus_for_each_drv+0x88/0xe0
[ 19.018966] __device_attach+0xb4/0x200
[ 19.022845] device_initial_probe+0x28/0x40
[ 19.027081] bus_probe_device+0xa8/0xb0
[ 19.030965] deferred_probe_work_func+0xc0/0x120
[ 19.035637] process_one_work+0x280/0x6d4
[ 19.039695] worker_thread+0x7c/0x430
[ 19.043407] kthread+0x110/0x114
[ 19.046677] ret_from_fork+0x10/0x20
[ 19.108471] cpu cpu4: EM: created perf domain
Starting Wait for udev To …plete Device Initialization.
[ 19.125768] remoteproc remoteproc1: remote processor
remoteproc-cdsp is now up
[ 19.138140] xhci_hcd 0000:01:00.0: Adding to iommu group 6
[ 19.150419] coresight stm0: STM32 initialized
[ 19.254272] ath10k_snoc 18800000.wifi: Adding to iommu group 10
[ 19.372948] ath10k_snoc 18800000.wifi: supply vdd-3.3-ch1 not
found, using dummy regulator
[ 19.472640] geni_spi 880000.spi: FIFO mode disabled, but couldn't
get DMA, fall back to FIFO mode
[ 19.485178] gpi 800000.dma-controller: Adding to iommu group 11
[ OK ] Reached target [0;1;39mHardware activated USB gadget.
[ 19.528153] i2c 16-0010: Fixing up cyclic dependency with acb3000.camss
[ 19.559810] i2c 10-003b: Fixing up cyclic dependency with hdmi-out
[ 19.575396] gpi a00000.dma-controller: Adding to iommu group 12
[ 19.590779] qcom-venus aa00000.video-codec: Adding to iommu group 13
[ 19.608167] qcom-venus aa00000.video-codec: non legacy binding
[ 19.618073] remoteproc remoteproc2: 4080000.remoteproc is available
[ 19.629950] qcom-camss acb3000.camss: Adding to iommu group 14
[ 19.630180] Bluetooth: Core ver 2.22
[ 19.639713] NET: Registered PF_BLUETOOTH protocol family
[ 19.645247] Bluetooth: HCI device and connection manager initialized
[ 19.651711] Bluetooth: HCI socket layer initialized
[ 19.656813] Bluetooth: L2CAP socket layer initialized
[ 19.661960] Bluetooth: SCO socket layer initialized
[ 19.743786] adreno 5000000.gpu: Adding to iommu group 15
[ 19.764896] Bluetooth: HCI UART driver ver 2.3
[ 19.769470] Bluetooth: HCI UART protocol H4 registered
[ 19.778004] msm-mdss ae00000.mdss: Adding to iommu group 16
[ 19.783005] Bluetooth: HCI UART protocol LL registered
[ 19.809993] Bluetooth: HCI UART protocol Broadcom registered
[ 19.819508] Bluetooth: HCI UART protocol QCA registered
[ 19.829474] Bluetooth: HCI UART protocol Marvell registered
[ 19.858355] EXT4-fs (sde9): mounted filesystem with ordered data
mode. Quota mode: none.
[ 19.893331] platform ae94000.dsi: Fixing up cyclic dependency with 10-003b
[ OK ] Finished Mount DSP partition to /usr/lib/rfsa.
[ 19.917937] platform ae94000.dsi: Fixing up cyclic dependency with
ae01000.display-controller
[ OK ] Reached target Local File Systems.
[ OK ] Listening on Load/Save RF …itch Status /dev/rfkill Watch.
[ 19.950987] BUG: sleeping function called from invalid context at
kernel/locking/mutex.c:580
[ 19.959591] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid:
258, name: kworker/u16:7
[ 19.968096] preempt_count: 100, expected: 0
[ 19.972374] RCU nest depth: 0, expected: 0
[ 19.976562] INFO: lockdep is turned off.
[ 19.980574] CPU: 0 PID: 258 Comm: kworker/u16:7 Not tainted
6.0.0-next-20221012 #1
[ 19.988245] Hardware name: Thundercomm Dragonboard 845c (DT)
[ 19.993986] Workqueue: events_unbound async_run_entry_fn
[ 19.999395] Call trace:
[ 20.001886] dump_backtrace+0xe4/0x140
[ 20.005700] show_stack+0x30/0x60
[ 20.009069] dump_stack_lvl+0x8c/0xb8
[ 20.012798] dump_stack+0x18/0x34
[ 20.016169] __might_resched+0x1c4/0x240
[ 20.020155] __might_sleep+0x58/0xb0
[ 20.020802] rtc-pm8xxx c440000.spmi:pmic@0:rtc@6000: registered as rtc0
[ 20.023766] __mutex_lock+0x54/0x424
[ 20.023778] mutex_lock_nested+0x50/0x6c
[ 20.030501] rtc-pm8xxx c440000.spmi:pmic@0:rtc@6000: setting system
clock to 1970-01-01T00:00:30 UTC (30)
[ 20.033086] input: pm8941_pwrkey as
/devices/platform/soc@0/c440000.spmi/spmi-0/0-00/c440000.spmi:pmic@0:pon@800/c440000.spmi:pmic@0:pon@800:pwrkey/input/input1
[ 20.034047] lpg_brightness_single_set+0x48/0x9c [leds_qcom_lpg]
[ 20.034132] systemd-journald[295]: Time jumped backwards, rotating.
[ 20.074723] led_set_brightness_nosleep+0x54/0x80
[ 20.079509] led_heartbeat_function+0x88/0x180
[ 20.084024] call_timer_fn+0xc0/0x3c4
[ 20.087751] __run_timers.part.0+0x220/0x27c
[ 20.092085] run_timer_softirq+0x44/0x80
[ 20.096073] __do_softirq+0x1e4/0x62c
[ 20.099793] ____do_softirq+0x18/0x24
[ 20.103520] call_on_irq_stack+0x2c/0x58
[ 20.107511] do_softirq_own_stack+0x24/0x3c
[ 20.111757] __irq_exit_rcu+0x168/0x1a0
[ 20.115661] irq_exit_rcu+0x18/0x40
[ 20.119203] el1_interrupt+0x38/0x64
[ 20.122838] el1h_64_irq_handler+0x18/0x2c
[ 20.127002] el1h_64_irq+0x64/0x68
[ 20.130465] arch_counter_get_cntvct+0x14/0x30
[ 20.134979] __delay+0xa4/0x110
[ 20.138179] __const_udelay+0x34/0x44
[ 20.141900] qcom_geni_serial_poll_bit+0xc4/0x104
[ 20.146675] qcom_geni_serial_stop_rx+0xc0/0x190
[ 20.151367] qcom_geni_serial_set_termios+0x4c/0x360
[ 20.156410] uart_change_speed+0x60/0x130
[ 20.160479] uart_set_termios+0x90/0x190
[ 20.164460] tty_set_termios+0x194/0x240
[ 20.168447] ttyport_open+0x144/0x180
[ 20.172169] serdev_device_open+0x38/0xe4
[ 20.176248] hci_uart_register_device+0x68/0x3ac [hci_uart]
[ 20.181957] qca_serdev_probe+0x2f4/0x530 [hci_uart]
[ 20.186753] input: pm8941_resin as
/devices/platform/soc@0/c440000.spmi/spmi-0/0-00/c440000.spmi:pmic@0:pon@800/c440000.spmi:pmic@0:pon@800:resin/input/input2
[ 20.187003] serdev_drv_probe+0x44/0x90
[ 20.187016] really_probe+0xd4/0x3f4
[ 20.208885] __driver_probe_device+0x8c/0x1a0
[ 20.213311] driver_probe_device+0x4c/0x13c
[ 20.217555] __driver_attach_async_helper+0x64/0x110
[ 20.222594] async_run_entry_fn+0x40/0x180
[ 20.226759] process_one_work+0x280/0x6d4
[ 20.230837] worker_thread+0x7c/0x430
[ 20.234557] kthread+0x110/0x114
[ 20.237849] ret_from_fork+0x10/0x20

Full boot log link,
- https://qa-reports.linaro.org/lkft/linux-next-master/build/next-20221012/testrun/12361480/suite/log-parser-boot/test/check-kernel-bug/log
- https://lkft.validation.linaro.org/scheduler/job/5660839#L3720


metadata:
git_ref: master
git_repo: https://gitlab.com/Linaro/lkft/mirrors/next/linux-next
git_sha: f843795727e4f5612c612cd178db1557978da742
git_describe: next-20221012
kernel_version: 6.0.0
kernel-config: https://builds.tuxbuild.com/2G10hEBW0Cdgh2jzrxvNzlRXdec/config
build-url: https://gitlab.com/Linaro/lkft/mirrors/next/linux-next/-/pipelines/664367901
artifact-location: https://builds.tuxbuild.com/2G10hEBW0Cdgh2jzrxvNzlRXdec
toolchain: gcc-11
System.map: https://builds.tuxbuild.com/2G10hEBW0Cdgh2jzrxvNzlRXdec/System.map
vmlinux.xz: https://builds.tuxbuild.com/2G10hEBW0Cdgh2jzrxvNzlRXdec/vmlinux.xz


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