[linux-next:master] [kasan] 187292be96: WARNING:suspicious_RCU_usage

[kernel test robot]

Hello,

we noticed this is a revert commit, below report is for an issue we observed
on this commit but not on its parent. just FYI.

113edefd366346b3 187292be96ae2be247807fac1c3
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:6 100% 6:6 dmesg.WARNING:suspicious_RCU_usage


kernel test robot noticed "WARNING:suspicious_RCU_usage" on:

commit: 187292be96ae2be247807fac1c3a6d89a7cc2a84 ("kasan: revert eviction of stack traces in generic mode")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: rcutorture
version:
with following parameters:

runtime: 300s
test: cpuhotplug
torture_type: busted_srcud



compiler: clang-17
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <olive...@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202402201506.b7e...@intel.com


[ 292.513535][ T653] WARNING: suspicious RCU usage
[ 292.514923][ T653] 6.8.0-rc4-00126-g187292be96ae #1 Not tainted
[ 292.516369][ T653] -----------------------------
[ 292.517743][ T653] kernel/rcu/rcutorture.c:1983 suspicious rcu_dereference_check() usage!
[ 292.519310][ T653]
[ 292.519310][ T653] other info that might help us debug this:
[ 292.519310][ T653]
[ 292.523130][ T653]
[ 292.523130][ T653] rcu_scheduler_active = 2, debug_locks = 1
[ 292.525644][ T653] no locks held by rcu_torture_rea/653.
[ 292.526974][ T653]
[ 292.526974][ T653] stack backtrace:
[ 292.529271][ T653] CPU: 0 PID: 653 Comm: rcu_torture_rea Not tainted 6.8.0-rc4-00126-g187292be96ae #1
[ 292.530780][ T653] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 292.532329][ T653] Call Trace:
[ 292.533524][ T653] <TASK>
[ 292.534696][ T653] dump_stack_lvl (lib/dump_stack.c:?)
[ 292.535941][ T653] ? __cfi_dump_stack_lvl (lib/dump_stack.c:98)
[ 292.537221][ T653] ? lockdep_rcu_suspicious (kernel/locking/lockdep.c:6712)
[ 292.538523][ T653] rcu_torture_one_read (kernel/rcu/rcutorture.c:?) rcutorture
[ 292.539887][ T653] ? __cfi_lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4312)
[ 292.541226][ T653] ? rcu_torture_timer (kernel/rcu/rcutorture.c:1955) rcutorture
[ 292.542621][ T653] ? __cfi_rcu_torture_timer (kernel/rcu/rcutorture.c:2055) rcutorture
[ 292.544012][ T653] ? init_timer_key (include/linux/lockdep.h:135 include/linux/lockdep.h:142 include/linux/lockdep.h:148 kernel/time/timer.c:847 kernel/time/timer.c:867)
[ 292.545262][ T653] rcu_torture_reader (kernel/rcu/rcutorture.c:2093) rcutorture
[ 292.546579][ T653] ? __cfi_rcu_torture_reader (kernel/rcu/rcutorture.c:2076) rcutorture
[ 292.547872][ T653] ? __cfi__raw_spin_unlock_irqrestore (kernel/locking/spinlock.c:193)
[ 292.549108][ T653] ? __cfi_rcu_torture_timer (kernel/rcu/rcutorture.c:2055) rcutorture
[ 292.550341][ T653] ? __kthread_parkme (kernel/kthread.c:?)
[ 292.551425][ T653] ? __kthread_parkme (include/linux/instrumented.h:? include/asm-generic/bitops/instrumented-non-atomic.h:141 kernel/kthread.c:280)
[ 292.552489][ T653] kthread (kernel/kthread.c:390)
[ 292.553504][ T653] ? __cfi_rcu_torture_reader (kernel/rcu/rcutorture.c:2076) rcutorture
[ 292.554689][ T653] ? __cfi_kthread (kernel/kthread.c:341)
[ 292.555749][ T653] ret_from_fork (arch/x86/kernel/process.c:153)
[ 292.556792][ T653] ? __cfi_kthread (kernel/kthread.c:341)
[ 292.557852][ T653] ret_from_fork_asm (arch/x86/entry/entry_64.S:250)
[ 292.558920][ T653] </TASK>



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240220/202402201506.b7e...@intel.com



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki

[Marco Elver]

On Tue, 20 Feb 2024 at 08:35, kernel test robot <olive...@intel.com> wrote:
>
>
>
> Hello,
>
> we noticed this is a revert commit, below report is for an issue we observed
> on this commit but not on its parent. just FYI.
>
> 113edefd366346b3 187292be96ae2be247807fac1c3
> ---------------- ---------------------------
> fail:runs %reproduction fail:runs
> | | |
> :6 100% 6:6 dmesg.WARNING:suspicious_RCU_usage
>
>
> kernel test robot noticed "WARNING:suspicious_RCU_usage" on:
>
> commit: 187292be96ae2be247807fac1c3a6d89a7cc2a84 ("kasan: revert eviction of stack traces in generic mode")
> https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

This commit didn't touch rcutorture or the rcu subsystem in any way,
so I currently don't understand how rcutorture would be affected.
While stackdepot has started to use RCU, this already happened in a
previous commit, and this particular commit actually reduced RCU usage
(no more evictions and re-allocations of stacktraces).

The only explanation I have is that it improved performance of a
KASAN-enabled kernel (which the config here has enabled) so much that
previously undiscovered issues have now become much more likely to
occur.

[+Cc rcu folks]

[Neeraj upadhyay]

Hi,

On Tue, Feb 20, 2024 at 1:33 PM Marco Elver <el...@google.com> wrote:
>
> On Tue, 20 Feb 2024 at 08:35, kernel test robot <olive...@intel.com> wrote:
> >
> >
> >
> > Hello,
> >
> > we noticed this is a revert commit, below report is for an issue we observed
> > on this commit but not on its parent. just FYI.
> >
> > 113edefd366346b3 187292be96ae2be247807fac1c3
> > ---------------- ---------------------------
> > fail:runs %reproduction fail:runs
> > | | |
> > :6 100% 6:6 dmesg.WARNING:suspicious_RCU_usage
> >
> >
> > kernel test robot noticed "WARNING:suspicious_RCU_usage" on:
> >
> > commit: 187292be96ae2be247807fac1c3a6d89a7cc2a84 ("kasan: revert eviction of stack traces in generic mode")
> > https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
>
> This commit didn't touch rcutorture or the rcu subsystem in any way,
> so I currently don't understand how rcutorture would be affected.
> While stackdepot has started to use RCU, this already happened in a
> previous commit, and this particular commit actually reduced RCU usage
> (no more evictions and re-allocations of stacktraces).
>
> The only explanation I have is that it improved performance of a
> KASAN-enabled kernel (which the config here has enabled) so much that
> previously undiscovered issues have now become much more likely to
> occur.
>
> [+Cc rcu folks]
>
> > in testcase: rcutorture

The rcutorture test type executed here is busted_srcud (torture_type:
busted_srcud). The busted_srcud torture test creates bad reader critical
section usages - in this case the rcu reader lock acquired was not
srcu lock, which subsequently resulted in rcu_dereference_check() to
cause a splat due to srcu read lock not being held.

So, this is expected behavior, and not a problem in either KASAN or RCU.



Thanks
Neeraj