[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20211002154023.GB22347@xsang-OptiPlex-9020>
Date: Sat, 2 Oct 2021 23:40:23 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
Cc: LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
lkp@...el.com
Subject: [rcutorture] be6350ccbb: WARNING:bad_unlock_balance_detected
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: be6350ccbb78fbc8186f4b3265ed331654ef3ad9 ("rcutorture: Sanitize rcutorture_one_extend() use of idxold")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2021.09.22a
in testcase: rcutorture
version:
with following parameters:
runtime: 300s
test: cpuhotplug
torture_type: rcu
test-description: rcutorture is rcutorture kernel module load/unload test.
test-url: https://www.kernel.org/doc/Documentation/RCU/torture.txt
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------------------------------------------------------------+------------+------------+
| | 1ae66df91a | be6350ccbb |
+--------------------------------------------------------------------------------------------------------+------------+------------+
| WARNING:bad_unlock_balance_detected | 0 | 58 |
| is_trying_to_release_lock(rcu_read_lock_sched)at | 0 | 33 |
| WARNING:at_kernel/time/timer.c:#call_timer_fn | 0 | 55 |
| BUG:KFENCE:invalid_write_in_handle_exception_return | 0 | 1 |
| BUG:KFENCE:out-of-bounds_write_in_handle_exception_return | 0 | 1 |
| BUG:KFENCE:use-after-free_write_in_handle_exception_return | 0 | 1 |
| WARNING:at_kernel/softirq.c:#__local_bh_disable_ip | 0 | 53 |
| EIP:__local_bh_disable_ip | 0 | 53 |
| WARNING:at_kernel/softirq.c:#__local_bh_enable_ip | 0 | 57 |
| EIP:__local_bh_enable_ip | 0 | 57 |
| WARNING:suspicious_RCU_usage | 0 | 10 |
| include/trace/events/lock.h:#suspicious_rcu_dereference_check()usage | 0 | 10 |
| WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_one_read[rcutorture] | 0 | 57 |
| EIP:rcu_torture_one_read | 0 | 56 |
| BUG:scheduling_while_atomic | 0 | 55 |
| EIP:call_timer_fn | 0 | 54 |
| Kernel_panic-not_syncing:Aiee,killing_interrupt_handler | 0 | 29 |
| is_trying_to_release_lock(rcu_read_lock_bh)at | 0 | 24 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/torture.c | 0 | 46 |
| BUG:kernel_NULL_pointer_dereference,address | 0 | 19 |
| Oops:#[##] | 0 | 24 |
| WARNING:stack_recursion | 0 | 26 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 24 |
| BUG:unable_to_handle_page_fault_for_address | 0 | 5 |
| EIP:update_group_capacity | 0 | 1 |
| kernel_BUG_at_kernel/sched/core.c | 0 | 3 |
| invalid_opcode:#[##] | 0 | 3 |
| EIP:__sched_setscheduler | 0 | 3 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 3 |
| Kernel_panic-not_syncing:stack-protector:Kernel_stack_is_corrupted_in:vprintk_store | 0 | 1 |
| WARNING:inconsistent_lock_state | 0 | 1 |
| inconsistent{IN-SOFTIRQ-W}->{SOFTIRQ-ON-W}usage | 0 | 1 |
| WARNING:at_kernel/module.c:#module_assert_mutex_or_preempt | 0 | 1 |
| EIP:module_assert_mutex_or_preempt | 0 | 1 |
| Kernel_panic-not_syncing:stack-protector:Kernel_stack_is_corrupted_in:rcu_torture_one_read[rcutorture] | 0 | 1 |
+--------------------------------------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 27.567579][ T496] rcu-torture: rcu_torture_reader task started
[ 27.570786][ T496]
[ 27.571020][ T496] =====================================
[ 27.571561][ T496] WARNING: bad unlock balance detected!
[ 27.572095][ T496] 5.15.0-rc1-00093-gbe6350ccbb78 #1 Not tainted
[ 27.572689][ T496] -------------------------------------
[ 27.573260][ T496] rcu_torture_rea/496 is trying to release lock (rcu_read_lock_sched) at:
[ 27.574076][ T496] [<f6c5a490>] rcutorture_one_extend+0x190/0x480 [rcutorture]
[ 27.574781][ T496] but there are no more locks to release!
[ 27.575398][ T496]
[ 27.575398][ T496] other info that might help us debug this:
[ 27.576141][ T496] no locks held by rcu_torture_rea/496.
[ 27.576648][ T496]
[ 27.576648][ T496] stack backtrace:
[ 27.577186][ T496] CPU: 0 PID: 496 Comm: rcu_torture_rea Not tainted 5.15.0-rc1-00093-gbe6350ccbb78 #1 9163dea460308125cc5b8cc0f1df3eca089bc795
[ 27.578407][ T496] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 27.579294][ T496] Call Trace:
[ 27.579612][ T496] dump_stack_lvl+0x55/0x79
[ 27.579924][ T488] rcu-torture: Creating torture_shuffle task
[ 27.580060][ T496] ? rcutorture_one_extend+0x190/0x480 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.580773][ T497] rcu-torture: rcu_torture_stats task started
[ 27.581665][ T496] dump_stack+0xd/0x10
[ 27.581674][ T496] print_unlock_imbalance_bug.cold+0x96/0x9e
[ 27.581684][ T496] ? rcutorture_one_extend+0x190/0x480 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581712][ T496] ? rcutorture_one_extend+0x190/0x480 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581719][ T496] ? rcutorture_one_extend+0x190/0x480 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581726][ T496] lock_release+0x1b4/0x440
[ 27.581731][ T496] ? rcu_read_delay+0x1f/0x180 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581738][ T496] rcutorture_one_extend+0x19f/0x480 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581746][ T496] rcu_torture_one_read+0x438/0x700 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581758][ T496] rcu_torture_reader+0x8d/0x200 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581766][ T496] ? rcutorture_booster_init+0x1c0/0x1c0 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581775][ T496] ? __kthread_parkme+0x5c/0x80
[ 27.581781][ T496] kthread+0x10d/0x140
[ 27.581785][ T496] ? rcu_torture_one_read+0x700/0x700 [rcutorture 26936e0d59ae68533deba419b7fc8ae986e561cf]
[ 27.581792][ T496] ? set_kthread_struct+0x40/0x40
[ 27.581796][ T496] ret_from_fork+0x1c/0x28
To reproduce:
# build kernel
cd linux
cp config-5.15.0-rc1-00093-gbe6350ccbb78 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
View attachment "config-5.15.0-rc1-00093-gbe6350ccbb78" of type "text/plain" (159246 bytes)
View attachment "job-script" of type "text/plain" (4629 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (19944 bytes)
Powered by blists - more mailing lists