Message-ID: <20210513151004.GG20142@xsang-OptiPlex-9020>
Date:   Thu, 13 May 2021 23:10:04 +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]  1eba0ef981: WARNING:suspicious_RCU_usage



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: 1eba0ef981fd3b5d5e94243aeced8884f43aef50 ("rcutorture: Use hrtimers for reader and writer delays")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master


in testcase: rcutorture
version: 
with following parameters:

	runtime: 300s
	test: cpuhotplug
	torture_type: srcu

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):



If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>


[   91.037427] WARNING: suspicious RCU usage
[   91.037844] 5.11.0-rc1-00020-g1eba0ef981fd #1 Not tainted
[   91.038433] -----------------------------
[   91.038856] kernel/rcu/rcutorture.c:1160 suspicious rcu_dereference_check() usage!
[   91.039647]
[   91.039647] other info that might help us debug this:
[   91.039647]
[   91.040476]
[   91.040476] rcu_scheduler_active = 2, debug_locks = 1
[   91.041160] no locks held by rcu_torture_wri/569.
[   91.041659]
[   91.041659] stack backtrace:
[   91.042160] CPU: 1 PID: 569 Comm: rcu_torture_wri Not tainted 5.11.0-rc1-00020-g1eba0ef981fd #1
[   91.043044] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[   91.043874] Call Trace:
[   91.044141] dump_stack (kbuild/src/consumer/lib/dump_stack.c:122) 
[   91.044472] lockdep_rcu_suspicious (kbuild/src/consumer/kernel/locking/lockdep.c:6356) 
[   91.044905] rcu_torture_writer (kbuild/src/consumer/kernel/rcu/rcutorture.c:1160 (discriminator 10)) rcutorture
[   91.045455] ? _raw_spin_unlock_irqrestore (kbuild/src/consumer/include/linux/spinlock_api_smp.h:161 kbuild/src/consumer/kernel/locking/spinlock.c:191) 
[   91.045971] ? __kthread_parkme (kbuild/src/consumer/kernel/kthread.c:235) 
[   91.046434] kthread (kbuild/src/consumer/kernel/kthread.c:292) 
[   91.046769] ? rcu_torture_pipe_update (kbuild/src/consumer/kernel/rcu/rcutorture.c:1120) rcutorture
[   91.047341] ? kthread_insert_work_sanity_check (kbuild/src/consumer/kernel/kthread.c:245) 
[   91.047926] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_32.S:856) 
[   91.053651] srcu-torture: Creating rcu_torture_fakewriter task
[   91.056700] srcu-torture: Creating rcu_torture_fakewriter task
[   91.058012] srcu-torture: rcu_torture_fakewriter task started
[   91.066367] srcu-torture: Creating rcu_torture_fakewriter task
[   91.075726] srcu-torture: rcu_torture_fakewriter task started
[   91.076978] srcu-torture: Creating rcu_torture_fakewriter task
[   91.077730] srcu-torture: rcu_torture_fakewriter task started
[   91.078408] srcu-torture: Creating rcu_torture_reader task
[   91.079105] srcu-torture: rcu_torture_fakewriter task started
[   91.079766] srcu-torture: Creating rcu_torture_stats task
[   91.080471] srcu-torture: rcu_torture_reader task started
[   91.081063] srcu-torture: Creating torture_shuffle task
[   91.081707] srcu-torture: rcu_torture_stats task started
[   91.082378] srcu-torture: Creating torture_stutter task
[   91.083053] srcu-torture: torture_shuffle task started
[   91.083636] srcu-torture: Creating torture_onoff task
[   91.084265] srcu-torture: torture_stutter task started
[   91.084842] srcu-torture: rcu_torture_fwd_prog_init: Disabled, unsupported by RCU flavor under test
[   91.090328] srcu-torture: Creating rcu_torture_read_exit task
[   91.092874] srcu-torture: torture_onoff task started
[   91.093417] srcu-torture: torture_onoff begin holdoff
[   91.106516] srcu-torture: rcu_torture_read_exit: Start of test
[   92.376562] _warn_unseeded_randomness: 82 callbacks suppressed
[   92.376567] random: get_random_u32 called from arch_pick_mmap_layout+0x55/0x100 with crng_init=1 
[   92.376579] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1 
[   92.376586] random: get_random_u32 called from arch_align_stack+0x35/0x50 with crng_init=1 
[   96.735555] srcu-torture: rcu_torture_read_exit: End of episode
[  103.305966] Kernel tests: Boot OK!
[  103.305983]
[  110.365702] srcu-torture: rcu_torture_read_exit: Start of episode
[  110.565716] srcu-torture: rcu_torture_read_exit: End of episode
[  114.059929]
[  114.438035] mount: mount point /sys/kernel/debug does not exist
[  114.438053]
[  116.574285] install debs round one: dpkg -i --force-confdef --force-depends /opt/deb/gawk_1%3a4.1.4+dfsg-1_i386.deb
[  116.574301]
[  116.579570] Selecting previously unselected package gawk.
[  116.579585]
[  116.583552] (Reading database ... 16210 files and directories currently installed.)
[  116.583568]
[  116.591054] Preparing to unpack .../gawk_1%3a4.1.4+dfsg-1_i386.deb ...
[  116.591068]
[  116.593620] Unpacking gawk (1:4.1.4+dfsg-1) ...
[  116.593633]
[  116.598717] Setting up gawk (1:4.1.4+dfsg-1) ...
[  116.598730]
[  116.601141] mount debug /sys/kernel/debug -t debugfs
[  116.601153]
[  116.603034] none on / type rootfs (rw)
[  116.603045]
[  116.611258] sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
[  116.611272]
[  116.614762] proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
[  116.614776]
[  116.622250] devtmpfs on /dev type devtmpfs (rw,nosuid,size=1962280k,nr_inodes=57010,mode=755)
[  116.622265]
[  116.629010] securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
[  116.629024]
[  116.632282] tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
[  116.632296]
[  116.641035] devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
[  116.641075]
[  116.644579] tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755)
[  116.644594]
[  116.651722] tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k)
[  116.651738]
[  116.657767] tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
[  116.657779]
[  120.703053] cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd)
[  120.703071]
[  120.709811] pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
[  120.709825]
[  120.715017] cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event)
[  120.715032]
[  120.729312] cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
[  120.729331]
[  120.734284] cgroup on /sys/fs/cgroup/hugetlb type cgroup (rw,nosuid,nodev,noexec,relatime,hugetlb)


To reproduce:

        # build kernel
	cd linux
	cp config-5.11.0-rc1-00020-g1eba0ef981fd .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



---
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.11.0-rc1-00020-g1eba0ef981fd" of type "text/plain" (150571 bytes)

View attachment "job-script" of type "text/plain" (4403 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (37040 bytes)

View attachment "rcutorture" of type "text/plain" (122363 bytes)

Powered by blists - more mailing lists