While booting arm64 hikey board with stable-rc 5.9.13-rc1 the following warning noticed. This is hard to reproduce.
Step to reproduce: ------------------------ # Boot arm64 hikey device with stable-rc 5.9.13-rc1 # Since it is hard to reproduce you may notice this warning
Crash log : -------------- [ 10.763081] [drm] Initialized kirin 1.0.0 20150718 for f4100000.ade on minor 1 [ 10.764088] Bluetooth: hci0: change remote baud rate command in firmware [[0;32m OK [0m] Started TEE Supplicant. [ 10.791741] mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 400000Hz, actual 400000HZ div = 31) E/TC:0 tee_entry_std:545 Bad arg address 0x6b681000 [[0;32m OK [0m] Started Periodic Command Scheduler. [ 10.846417] mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 25000000Hz, actual 24800000HZ div = 0) [ 10.887083] [ 10.887087] [ 10.887095] ===================================== [ 10.887098] ============================= [ 10.887101] WARNING: bad unlock balance detected! [ 10.887107] WARNING: suspicious RCU usage [ 10.887112] 5.9.13-rc1 #1 Not tainted [ 10.887120] 5.9.13-rc1 #1 Not tainted [ 10.887122] ------------------------------------- [ 10.887129] systemd-udevd/306 is trying to release lock ( [ 10.887133] ----------------------------- [ 10.887135] fs_reclaim) at: [ 10.887144] /usr/src/kernel/kernel/sched/core.c:7270 Illegal context switch in RCU-bh read-side critical section! [ 10.887163] [<ffff80001030f2e8>] __alloc_pages_nodemask+0x250/0x4c0 [ 10.887166] [ 10.887166] other info that might help us debug this: [ 10.887166] [ 10.887170] but there are no more locks to release! [ 10.887175] [ 10.887175] other info that might help us debug this: [ 10.887179] [ 10.887179] rcu_scheduler_active = 2, debug_locks = 0 [ 10.887182] 1 lock held by systemd-udevd/306: [ 10.887189] 1 lock held by systemd-sysctl/342: [ 10.887192] #0: ffff00007474e518 [ 10.887199] #0: [ 10.887202] ( [ 10.887209] ffff000070c54708 [ 10.887212] &mm->mmap_lock){++++}-{3:3} [ 10.887219] ( [ 10.887228] , at: do_page_fault+0x168/0x420 [ 10.887230] &type->i_mutex_dir_key [ 10.887235] [ 10.887235] stack backtrace: [ 10.887237] #3){++++}-{3:3} [ 10.887246] CPU: 1 PID: 306 Comm: systemd-udevd Not tainted 5.9.13-rc1 #1 [ 10.887255] , at: iterate_dir+0x54/0x1d0 [ 10.887258] Hardware name: HiKey Development Board (DT) [ 10.887264] [ 10.887264] stack backtrace: [ 10.887266] Call trace: [ 10.887276] dump_backtrace+0x0/0x1f8 [ 10.887283] show_stack+0x2c/0x38 [ 10.887292] dump_stack+0xec/0x158 [ 10.887303] print_unlock_imbalance_bug+0xec/0xf0 [ 10.887311] lock_release+0x300/0x388 [ 10.887320] __alloc_pages_nodemask+0x268/0x4c0 [ 10.887329] alloc_pages_vma+0x90/0x240 [ 10.887338] handle_mm_fault+0x8d4/0x12f0 [ 10.887346] do_page_fault+0x1c4/0x420 [ 10.887353] do_translation_fault+0xb0/0xcc [ 10.887363] do_mem_abort+0x50/0xb0 [ 10.887372] el1_abort+0x28/0x30 [ 10.887379] el1_sync_handler+0xc0/0xf0 [ 10.887386] el1_sync+0x7c/0x100 [ 10.887397] __arch_copy_to_user+0x1d8/0x310 [ 10.887407] copy_page_to_iter+0x110/0x3e8 [ 10.887416] generic_file_buffered_read+0x4b8/0xaa8 [ 10.887423] generic_file_read_iter+0xd4/0x168 [ 10.887432] blkdev_read_iter+0x50/0x78 [ 10.887442] new_sync_read+0x100/0x1a0 [ 10.887449] vfs_read+0x1b4/0x1d8 [ 10.887457] ksys_read+0x74/0xf8 [ 10.887465] __arm64_sys_read+0x24/0x30 [ 10.887472] el0_svc_common.constprop.3+0x7c/0x198 [ 10.887478] do_el0_svc+0x34/0xa0 [ 10.887486] el0_sync_handler+0x16c/0x210 [ 10.887492] el0_sync+0x140/0x180 [ 10.887504] CPU: 6 PID: 342 Comm: systemd-sysctl Not tainted 5.9.13-rc1 #1 [ 10.887510] Hardware name: HiKey Development Board (DT) [ 10.887515] Call trace: [ 10.887524] dump_backtrace+0x0/0x1f8 [ 10.887531] show_stack+0x2c/0x38 [ 10.887542] dump_stack+0xec/0x158 [ 10.887552] lockdep_rcu_suspicious+0xd4/0xf8 [ 10.887561] ___might_sleep+0x1e4/0x208 [ 10.887569] __might_sleep+0x54/0x90 [ 10.887577] __might_fault+0x58/0xa8 [ 10.887584] filldir64+0x1f0/0x488 [ 10.887593] call_filldir+0xb0/0x140 [ 10.887600] ext4_readdir+0x700/0x900 [ 10.887607] iterate_dir+0x88/0x1d0 [ 10.887615] __arm64_sys_getdents64+0x70/0x1a0 [ 10.887622] el0_svc_common.constprop.3+0x7c/0x198 [ 10.887629] do_el0_svc+0x34/0xa0 [ 10.887637] el0_sync_handler+0x16c/0x210 [ 10.887644] el0_sync+0x140/0x180 [ 10.912334] Console: switching to colour frame buffer device 256x72
Reported-by: Naresh Kamboju naresh.kamboju@linaro.org
Full boot log link, https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-5.9.y/build/v5.9.12...
metadata: git branch: linux-5.9.y git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git commit: 1372e1af58d410676db7917cc3484ca22d471623 git describe: v5.9.12-47-g1372e1af58d4 make_kernelversion: 5.9.13-rc1 kernel-config: http://snapshots.linaro.org/openembedded/lkft/lkft/sumo/hikey/lkft/linux-sta...
-- Linaro LKFT https://lkft.linaro.org
On Mon, Dec 07, 2020 at 11:06:10AM +0530, Naresh Kamboju wrote:
While booting arm64 hikey board with stable-rc 5.9.13-rc1 the following warning noticed. This is hard to reproduce.
Ugh. You've got two warnings interleaved here. This is impossible to read. Do you have any examples where only one of them happens?
Step to reproduce:
# Boot arm64 hikey device with stable-rc 5.9.13-rc1 # Since it is hard to reproduce you may notice this warning
Crash log :
[ 10.763081] [drm] Initialized kirin 1.0.0 20150718 for f4100000.ade on minor 1 [ 10.764088] Bluetooth: hci0: change remote baud rate command in firmware [[0;32m OK [0m] Started TEE Supplicant. [ 10.791741] mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 400000Hz, actual 400000HZ div = 31) E/TC:0 tee_entry_std:545 Bad arg address 0x6b681000 [[0;32m OK [0m] Started Periodic Command Scheduler. [ 10.846417] mmc_host mmc2: Bus speed (slot 0) = 24800000Hz (slot req 25000000Hz, actual 24800000HZ div = 0) [ 10.887083] [ 10.887087] [ 10.887095] ===================================== [ 10.887098] ============================= [ 10.887101] WARNING: bad unlock balance detected! [ 10.887107] WARNING: suspicious RCU usage [ 10.887112] 5.9.13-rc1 #1 Not tainted [ 10.887120] 5.9.13-rc1 #1 Not tainted [ 10.887122] ------------------------------------- [ 10.887129] systemd-udevd/306 is trying to release lock ( [ 10.887133] ----------------------------- [ 10.887135] fs_reclaim) at: [ 10.887144] /usr/src/kernel/kernel/sched/core.c:7270 Illegal context switch in RCU-bh read-side critical section! [ 10.887163] [<ffff80001030f2e8>] __alloc_pages_nodemask+0x250/0x4c0 [ 10.887166] [ 10.887166] other info that might help us debug this: [ 10.887166] [ 10.887170] but there are no more locks to release! [ 10.887175] [ 10.887175] other info that might help us debug this: [ 10.887179] [ 10.887179] rcu_scheduler_active = 2, debug_locks = 0 [ 10.887182] 1 lock held by systemd-udevd/306: [ 10.887189] 1 lock held by systemd-sysctl/342: [ 10.887192] #0: ffff00007474e518 [ 10.887199] #0: [ 10.887202] ( [ 10.887209] ffff000070c54708 [ 10.887212] &mm->mmap_lock){++++}-{3:3} [ 10.887219] ( [ 10.887228] , at: do_page_fault+0x168/0x420 [ 10.887230] &type->i_mutex_dir_key [ 10.887235] [ 10.887235] stack backtrace: [ 10.887237] #3){++++}-{3:3} [ 10.887246] CPU: 1 PID: 306 Comm: systemd-udevd Not tainted 5.9.13-rc1 #1 [ 10.887255] , at: iterate_dir+0x54/0x1d0 [ 10.887258] Hardware name: HiKey Development Board (DT) [ 10.887264] [ 10.887264] stack backtrace: [ 10.887266] Call trace: [ 10.887276] dump_backtrace+0x0/0x1f8 [ 10.887283] show_stack+0x2c/0x38 [ 10.887292] dump_stack+0xec/0x158 [ 10.887303] print_unlock_imbalance_bug+0xec/0xf0 [ 10.887311] lock_release+0x300/0x388 [ 10.887320] __alloc_pages_nodemask+0x268/0x4c0 [ 10.887329] alloc_pages_vma+0x90/0x240 [ 10.887338] handle_mm_fault+0x8d4/0x12f0 [ 10.887346] do_page_fault+0x1c4/0x420 [ 10.887353] do_translation_fault+0xb0/0xcc [ 10.887363] do_mem_abort+0x50/0xb0 [ 10.887372] el1_abort+0x28/0x30 [ 10.887379] el1_sync_handler+0xc0/0xf0 [ 10.887386] el1_sync+0x7c/0x100 [ 10.887397] __arch_copy_to_user+0x1d8/0x310 [ 10.887407] copy_page_to_iter+0x110/0x3e8 [ 10.887416] generic_file_buffered_read+0x4b8/0xaa8 [ 10.887423] generic_file_read_iter+0xd4/0x168 [ 10.887432] blkdev_read_iter+0x50/0x78 [ 10.887442] new_sync_read+0x100/0x1a0 [ 10.887449] vfs_read+0x1b4/0x1d8 [ 10.887457] ksys_read+0x74/0xf8 [ 10.887465] __arm64_sys_read+0x24/0x30 [ 10.887472] el0_svc_common.constprop.3+0x7c/0x198 [ 10.887478] do_el0_svc+0x34/0xa0 [ 10.887486] el0_sync_handler+0x16c/0x210 [ 10.887492] el0_sync+0x140/0x180 [ 10.887504] CPU: 6 PID: 342 Comm: systemd-sysctl Not tainted 5.9.13-rc1 #1 [ 10.887510] Hardware name: HiKey Development Board (DT) [ 10.887515] Call trace: [ 10.887524] dump_backtrace+0x0/0x1f8 [ 10.887531] show_stack+0x2c/0x38 [ 10.887542] dump_stack+0xec/0x158 [ 10.887552] lockdep_rcu_suspicious+0xd4/0xf8 [ 10.887561] ___might_sleep+0x1e4/0x208 [ 10.887569] __might_sleep+0x54/0x90 [ 10.887577] __might_fault+0x58/0xa8 [ 10.887584] filldir64+0x1f0/0x488 [ 10.887593] call_filldir+0xb0/0x140 [ 10.887600] ext4_readdir+0x700/0x900 [ 10.887607] iterate_dir+0x88/0x1d0 [ 10.887615] __arm64_sys_getdents64+0x70/0x1a0 [ 10.887622] el0_svc_common.constprop.3+0x7c/0x198 [ 10.887629] do_el0_svc+0x34/0xa0 [ 10.887637] el0_sync_handler+0x16c/0x210 [ 10.887644] el0_sync+0x140/0x180 [ 10.912334] Console: switching to colour frame buffer device 256x72
Reported-by: Naresh Kamboju naresh.kamboju@linaro.org
Full boot log link, https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-5.9.y/build/v5.9.12...
metadata: git branch: linux-5.9.y git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git git commit: 1372e1af58d410676db7917cc3484ca22d471623 git describe: v5.9.12-47-g1372e1af58d4 make_kernelversion: 5.9.13-rc1 kernel-config: http://snapshots.linaro.org/openembedded/lkft/lkft/sumo/hikey/lkft/linux-sta...
-- Linaro LKFT https://lkft.linaro.org
linux-stable-mirror@lists.linaro.org