lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<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

Powered by Openwall GNU/*/Linux Powered by OpenVZ