2022-07-07 14:49:40

by kernel test robot

[permalink] [raw]
Subject: [locking/lockdep] 4051a81774: WARNING:suspicious_RCU_usage


(please be noted we reported
"[locking/lockdep] 4051a81774: page_allocation_failure:order:#,mode:#(GFP_KERNEL),nodemask=(null)"
on
https://lore.kernel.org/all/20220620020727.GA3669@xsang-OptiPlex-9020/
which raised some discussion.
now we noticed this has already been merged into mainline, while we found
some other issues as below)

Greeting,

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

commit: 4051a81774d6d8e28192742c26999d6f29bc0e68 ("locking/lockdep: Use sched_clock() for random numbers")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

in testcase: boot

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

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 <[email protected]>


though we don't have enough knowledge how this commit could raise below issue,
but seems it's quite persistent:

v5.19-rc2 4051a81774d6d8e28192742c269
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
:10 130% 13:13 dmesg.WARNING:suspicious_RCU_usage
:10 130% 13:13 dmesg.drivers/net/plip/plip.c:#suspicious_rcu_dereference_check()usage


[ 7.104979][ T1] random: get_random_bytes called from ic_open_devs+0x14a/0x2a5 with crng_init=0
[ 7.105055][ T1]
[ 7.105056][ T1] =============================
[ 7.105057][ T1] WARNING: suspicious RCU usage
[ 7.105058][ T1] 5.19.0-rc2-00001-g4051a81774d6 #1 Not tainted
[ 7.105060][ T1] -----------------------------
[ 7.105060][ T1] drivers/net/plip/plip.c:1114 suspicious rcu_dereference_check() usage!
[ 7.105062][ T1]
[ 7.105062][ T1] other info that might help us debug this:
[ 7.105062][ T1]
[ 7.105063][ T1]
[ 7.105063][ T1] rcu_scheduler_active = 2, debug_locks = 1
[ 7.105064][ T1] 1 lock held by swapper/0/1:
[ 7.105066][ T1] #0: ffffffffac9f02a8 (rtnl_mutex){+.+.}-{3:3}, at: ic_open_devs+0xd/0x2a5
[ 7.105073][ T1]
[ 7.105073][ T1] stack backtrace:
[ 7.105074][ T1] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc2-00001-g4051a81774d6 #1
[ 7.105077][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 7.105078][ T1] Call Trace:
[ 7.105080][ T1] <TASK>
[ 7.105081][ T1] dump_stack_lvl+0x57/0x7d
[ 7.105087][ T1] plip_open+0x1bf/0x200
[ 7.105092][ T1] __dev_open+0xe7/0x1c0
[ 7.105095][ T1] __dev_change_flags+0x1e4/0x280
[ 7.105098][ T1] dev_change_flags+0x1c/0x80
[ 7.105101][ T1] ic_open_devs+0xe2/0x2a5
[ 7.105103][ T1] ip_auto_config+0x133/0x49b
[ 7.105105][ T1] ? root_nfs_parse_addr+0x99/0x99
[ 7.105107][ T1] do_one_initcall+0x5c/0x300
[ 7.105112][ T1] do_initcalls+0x127/0x148
[ 7.105117][ T1] kernel_init_freeable+0xdf/0x10f
[ 7.105119][ T1] ? rest_init+0x180/0x180
[ 7.105123][ T1] kernel_init+0x11/0x140
[ 7.105125][ T1] ret_from_fork+0x1f/0x30
[ 7.105127][ T1] </TASK>
[ 7.105535][ T1] random: get_random_u32 called from neigh_parms_alloc+0xf4/0x140 with crng_init=0



To reproduce:

# build kernel
cd linux
cp config-5.19.0-rc2-00001-g4051a81774d6 .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz 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.



--
0-DAY CI Kernel Test Service
https://01.org/lkp



Attachments:
(No filename) (4.08 kB)
config-5.19.0-rc2-00001-g4051a81774d6 (158.61 kB)
job-script (4.78 kB)
dmesg.xz (23.41 kB)
Download all attachments