Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 94e7896d1139503fee1d00954f93f5f35f22b86f ("vfs: Use the mounts_to_id array to do /proc/mounts and co.")
https://git.kernel.org/cgit/linux/kernel/git/dhowells/linux-fs.git mount-xarray
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------+------------+------------+
| | 00edd5c47c | 94e7896d11 |
+-----------------------------------------------------------------+------------+------------+
| boot_successes | 6 | 0 |
| boot_failures | 0 | 6 |
| WARNING:suspicious_RCU_usage | 0 | 6 |
| include/linux/xarray.h:#suspicious_rcu_dereference_check()usage | 0 | 6 |
+-----------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>
[ 9.960631] WARNING: suspicious RCU usage
[ 9.961019] 5.12.0-rc3-00002-g94e7896d1139 #1 Not tainted
[ 9.961533] -----------------------------
[ 9.961894] include/linux/xarray.h:1164 suspicious rcu_dereference_check() usage!
[ 9.962570]
[ 9.962570] other info that might help us debug this:
[ 9.962570]
[ 9.963277]
[ 9.963277] rcu_scheduler_active = 2, debug_locks = 1
[ 9.963867] 2 locks held by mount/188:
[ 9.964212] #0: 46a10ed0 (&p->lock){+.+.}-{3:3}, at: seq_read_iter (kbuild/src/consumer/fs/seq_file.c:185)
[ 9.964900] #1: 42b4dbd8 (namespace_sem){++++}-{3:3}, at: m_start (kbuild/src/consumer/kernel/module.c:4450)
[ 9.965596]
[ 9.965596] stack backtrace:
[ 9.966003] CPU: 0 PID: 188 Comm: mount Not tainted 5.12.0-rc3-00002-g94e7896d1139 #1
[ 9.966668] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 9.967301] Call Trace:
[ 9.967459] ? dump_stack (kbuild/src/consumer/lib/dump_stack.c:131)
[ 9.967688] ? lockdep_rcu_suspicious (kbuild/src/consumer/kernel/locking/lockdep.c:6429)
[ 9.968030] ? xas_start (kbuild/src/consumer/include/linux/xarray.h:1164 kbuild/src/consumer/lib/xarray.c:188)
[ 9.968367] ? xas_load (kbuild/src/consumer/lib/xarray.c:233)
[ 9.968630] ? xas_find (kbuild/src/consumer/lib/xarray.c:1244)
[ 9.968962] ? m_start (kbuild/src/consumer/kernel/module.c:1998)
[ 9.969284] ? kvmalloc_node (kbuild/src/consumer/mm/util.c:598)
[ 9.969649] ? seq_read_iter (kbuild/src/consumer/fs/seq_file.c:222)
[ 9.969946] ? security_file_permission (kbuild/src/consumer/include/linux/fsnotify.h:68 kbuild/src/consumer/include/linux/fsnotify.h:90 kbuild/src/consumer/include/linux/fsnotify.h:115 kbuild/src/consumer/security/security.c:1465)
[ 9.970333] ? vfs_read (kbuild/src/consumer/fs/read_write.c:416 kbuild/src/consumer/fs/read_write.c:496)
[ 9.970663] ? ksys_read (kbuild/src/consumer/fs/read_write.c:635)
[ 9.970975] ? __ia32_sys_read (kbuild/src/consumer/fs/read_write.c:642)
[ 9.971319] ? do_int80_syscall_32 (kbuild/src/consumer/arch/x86/entry/common.c:77 kbuild/src/consumer/arch/x86/entry/common.c:94)
[ 9.971705] ? entry_INT80_32 (kbuild/src/consumer/arch/x86/entry/entry_32.S:1064)
[ 9.972059]
[ 9.972199] =============================
[ 9.972598] WARNING: suspicious RCU usage
[ 9.972996] 5.12.0-rc3-00002-g94e7896d1139 #1 Not tainted
[ 9.973533] -----------------------------
[ 9.973927] include/linux/xarray.h:1180 suspicious rcu_dereference_check() usage!
[ 9.974647]
[ 9.974647] other info that might help us debug this:
[ 9.974647]
[ 9.975388]
[ 9.975388] rcu_scheduler_active = 2, debug_locks = 1
[ 9.976012] 2 locks held by mount/188:
[ 9.976381] #0: 46a10ed0 (&p->lock){+.+.}-{3:3}, at: seq_read_iter (kbuild/src/consumer/fs/seq_file.c:185)
[ 9.977082] #1: 42b4dbd8 (namespace_sem){++++}-{3:3}, at: m_start (kbuild/src/consumer/kernel/module.c:4450)
[ 9.977769]
[ 9.977769] stack backtrace:
[ 9.978177] CPU: 0 PID: 188 Comm: mount Not tainted 5.12.0-rc3-00002-g94e7896d1139 #1
[ 9.978949] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 9.979754] Call Trace:
[ 9.980001] ? dump_stack (kbuild/src/consumer/lib/dump_stack.c:131)
[ 9.980353] ? lockdep_rcu_suspicious (kbuild/src/consumer/kernel/locking/lockdep.c:6429)
[ 9.980827] ? xas_load (kbuild/src/consumer/include/linux/xarray.h:1180 kbuild/src/consumer/lib/xarray.c:204 kbuild/src/consumer/lib/xarray.c:240)
[ 9.981167] ? xas_find (kbuild/src/consumer/lib/xarray.c:1244)
[ 9.981499] ? m_start (kbuild/src/consumer/kernel/module.c:1998)
[ 9.981829] ? kvmalloc_node (kbuild/src/consumer/mm/util.c:598)
[ 9.982185] ? seq_read_iter (kbuild/src/consumer/fs/seq_file.c:222)
[ 9.982563] ? security_file_permission (kbuild/src/consumer/include/linux/fsnotify.h:68 kbuild/src/consumer/include/linux/fsnotify.h:90 kbuild/src/consumer/include/linux/fsnotify.h:115 kbuild/src/consumer/security/security.c:1465)
[ 9.983013] ? vfs_read (kbuild/src/consumer/fs/read_write.c:416 kbuild/src/consumer/fs/read_write.c:496)
[ 9.983362] ? ksys_read (kbuild/src/consumer/fs/read_write.c:635)
[ 9.983715] ? __ia32_sys_read (kbuild/src/consumer/fs/read_write.c:642)
[ 9.984101] ? do_int80_syscall_32 (kbuild/src/consumer/arch/x86/entry/common.c:77 kbuild/src/consumer/arch/x86/entry/common.c:94)
[ 9.984531] ? entry_INT80_32 (kbuild/src/consumer/arch/x86/entry/entry_32.S:1064)
[ 9.984931]
[ 9.985082] =============================
[ 9.985457] WARNING: suspicious RCU usage
[ 9.985847] 5.12.0-rc3-00002-g94e7896d1139 #1 Not tainted
[ 9.986366] -----------------------------
[ 9.986772] include/linux/xarray.h:1180 suspicious rcu_dereference_check() usage!
[ 9.987497]
[ 9.987497] other info that might help us debug this:
[ 9.987497]
[ 9.988297]
[ 9.988297] rcu_scheduler_active = 2, debug_locks = 1
[ 9.988917] 2 locks held by mount/188:
[ 9.989238] #0: 46a10ed0 (&p->lock){+.+.}-{3:3}, at: seq_read_iter (kbuild/src/consumer/fs/seq_file.c:185)
[ 9.989949] #1: 42b4dbd8 (namespace_sem){++++}-{3:3}, at: m_start (kbuild/src/consumer/kernel/module.c:4450)
[ 9.990627]
[ 9.990627] stack backtrace:
[ 9.990988] CPU: 0 PID: 188 Comm: mount Not tainted 5.12.0-rc3-00002-g94e7896d1139 #1
[ 9.991673] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 9.992322] Call Trace:
[ 9.992485] ? dump_stack (kbuild/src/consumer/lib/dump_stack.c:131)
[ 9.992726] ? lockdep_rcu_suspicious (kbuild/src/consumer/kernel/locking/lockdep.c:6429)
[ 9.993038] ? m_next (kbuild/src/consumer/include/trace/events/module.h:107)
[ 9.993264] ? seq_read_iter (kbuild/src/consumer/fs/seq_file.c:260)
[ 9.993561] ? vfs_read (kbuild/src/consumer/fs/read_write.c:416 kbuild/src/consumer/fs/read_write.c:496)
[ 9.993870] ? ksys_read (kbuild/src/consumer/fs/read_write.c:635)
[ 9.994164] ? __ia32_sys_read (kbuild/src/consumer/fs/read_write.c:642)
[ 9.994511] ? do_int80_syscall_32 (kbuild/src/consumer/arch/x86/entry/common.c:77 kbuild/src/consumer/arch/x86/entry/common.c:94)
[ 9.994798] ? entry_INT80_32 (kbuild/src/consumer/arch/x86/entry/entry_32.S:1064)
[ 9.995073]
[ 9.995170] =============================
[ 9.995461] WARNING: suspicious RCU usage
[ 9.995823] 5.12.0-rc3-00002-g94e7896d1139 #1 Not tainted
[ 9.996247] -----------------------------
[ 9.996635] include/linux/xarray.h:1197 suspicious rcu_dereference_check() usage!
[ 9.997350]
[ 9.997350] other info that might help us debug this:
[ 9.997350]
[ 9.998073]
[ 9.998073] rcu_scheduler_active = 2, debug_locks = 1
[ 9.998644] 2 locks held by mount/188:
[ 9.998886] #0: 46a10ed0 (&p->lock){+.+.}-{3:3}, at: seq_read_iter (kbuild/src/consumer/fs/seq_file.c:185)
[ 9.999381] #1: 42b4dbd8 (namespace_sem){++++}-{3:3}, at: m_start (kbuild/src/consumer/kernel/module.c:4450)
[ 9.999832]
[ 9.999832] stack backtrace:
[ 10.000175] CPU: 0 PID: 188 Comm: mount Not tainted 5.12.0-rc3-00002-g94e7896d1139 #1
[ 10.000866] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 10.001611] Call Trace:
[ 10.001843] ? dump_stack (kbuild/src/consumer/lib/dump_stack.c:131)
[ 10.002152] ? lockdep_rcu_suspicious (kbuild/src/consumer/kernel/locking/lockdep.c:6429)
[ 10.002561] ? xas_find (kbuild/src/consumer/include/linux/xarray.h:1197 kbuild/src/consumer/lib/xarray.c:1257)
[ 10.002795] ? m_next (kbuild/src/consumer/include/linux/rbtree.h:84 kbuild/src/consumer/include/linux/rbtree_latch.h:95 kbuild/src/consumer/include/linux/rbtree_latch.h:151 kbuild/src/consumer/kernel/module.c:164)
[ 10.003090] ? seq_read_iter (kbuild/src/consumer/fs/seq_file.c:260)
[ 10.003372] ? vfs_read (kbuild/src/consumer/fs/read_write.c:416 kbuild/src/consumer/fs/read_write.c:496)
[ 10.003708] ? ksys_read (kbuild/src/consumer/fs/read_write.c:635)
[ 10.003996] ? __ia32_sys_read (kbuild/src/consumer/fs/read_write.c:642)
[ 10.004322] ? do_int80_syscall_32 (kbuild/src/consumer/arch/x86/entry/common.c:77 kbuild/src/consumer/arch/x86/entry/common.c:94)
[ 10.004702] ? entry_INT80_32 (kbuild/src/consumer/arch/x86/entry/entry_32.S:1064)
Starting udev
[ 10.064650] pidof (198) used greatest stack depth: 6576 bytes left
[ 10.073260] udevd[199]: starting version 3.2.7
[ 10.074337] random: udevd: uninitialized urandom read (16 bytes read)
[ 10.075145] random: udevd: uninitialized urandom read (16 bytes read)
[ 10.075846] random: udevd: uninitialized urandom read (16 bytes read)
[ 10.079193] udevd[199]: specified group 'kvm' unknown
[ 10.086060] udevd[200]: starting eudev-3.2.7
[ 10.150829] udevd[200]: specified group 'kvm' unknown
[ 10.210420] udevadm (202) used greatest stack depth: 6452 bytes left
[ 10.281092] cfg80211: failed to load regulatory.db
[ 10.339261] _warn_unseeded_randomness: 210 callbacks suppressed
[ 10.339266] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 10.339278] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 10.339283] random: get_random_u32 called from arch_align_stack+0x2d/0x40 with crng_init=1
[ 10.730797] uniq (319) used greatest stack depth: 6308 bytes left
[ 10.982377] bootlogd (246) used greatest stack depth: 6204 bytes left
LKP: HOSTNAME vm-snb-i386-31, MAC 52:54:00:12:34:56, kernel 5.12.0-rc3-00002-g94e7896d1139 1, serial console /dev/ttyS0
[ 11.340473] _warn_unseeded_randomness: 1356 callbacks suppressed
[ 11.340479] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 11.340491] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 11.340496] random: get_random_u32 called from arch_align_stack+0x2d/0x40 with crng_init=1
Poky (Yocto Project Reference Distro) 2.7+snapshot vm-snb-i386-31 /dev/ttyS0
[ 12.076581] mount: mounting debug on /sys/kernel/debug failed: No such file or directory
[ 13.277015] _warn_unseeded_randomness: 553 callbacks suppressed
[ 13.277021] random: get_random_u32 called from copy_process+0x232/0x1690 with crng_init=1
[ 13.279970] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 13.279985] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 14.353760] _warn_unseeded_randomness: 66 callbacks suppressed
[ 14.353765] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 14.353777] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 14.353782] random: get_random_u32 called from arch_align_stack+0x2d/0x40 with crng_init=1
[ 15.367853] _warn_unseeded_randomness: 18 callbacks suppressed
[ 15.367859] random: get_random_u32 called from copy_process+0x232/0x1690 with crng_init=1
[ 15.370218] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 15.370231] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 16.378861] _warn_unseeded_randomness: 13 callbacks suppressed
[ 16.378867] random: get_random_u32 called from copy_process+0x232/0x1690 with crng_init=1
[ 16.381685] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 16.381698] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 17.392700] _warn_unseeded_randomness: 14 callbacks suppressed
[ 17.392705] random: get_random_u32 called from arch_rnd+0x1b/0x40 with crng_init=1
[ 17.392715] random: get_random_u32 called from randomize_stack_top+0x35/0x50 with crng_init=1
[ 17.392721] random: get_random_u32 called from arch_align_stack+0x2d/0x40 with crng_init=1
[ 18.127683] rcu-scale: rcu_scale_writer 0 has 100 measurements
[ 18.138555] Dumping ftrace buffer:
[ 18.138937] (ftrace buffer empty)
[ 18.139225] rcu-scale: Test complete
[ 18.139621] rcu-torture: Stopping rcu_scale_reader task
[ 18.140217] rcu-torture: Stopping rcu_scale_reader
[ 18.140821] rcu-torture: Stopping rcu_scale_writer task
[ 18.141296] rcu-torture: Stopping rcu_scale_writer
[ 18.143177] rcu-scale: writer 0 gps: 100
[ 18.143553] rcu-scale: start: 18099598870 end: 18099622235 duration: 23365 gps: 100 batches: 0
[ 18.144322] rcu-scale: 0 writer-duration: 0 324
[ 18.146536] rcu-scale: 0 writer-duration: 1 109
[ 18.147029] rcu-scale: 0 writer-duration: 2 109
[ 18.147554] rcu-scale: 0 writer-duration: 3 104
[ 18.148049] rcu-scale: 0 writer-duration: 4 105
[ 18.148579] rcu-scale: 0 writer-duration: 5 109
[ 18.149050] rcu-scale: 0 writer-duration: 6 110
[ 18.149511] rcu-scale: 0 writer-duration: 7 112
[ 18.150067] rcu-scale: 0 writer-duration: 8 107
[ 18.150553] rcu-scale: 0 writer-duration: 9 110
[ 18.151003] rcu-scale: 0 writer-duration: 10 105
[ 18.151488] rcu-scale: 0 writer-duration: 11 105
[ 18.151987] rcu-scale: 0 writer-duration: 12 105
[ 18.152703] rcu-scale: 0 writer-duration: 13 105
[ 18.153192] rcu-scale: 0 writer-duration: 14 101
[ 18.153750] rcu-scale: 0 writer-duration: 15 121
[ 18.154306] rcu-scale: 0 writer-duration: 16 119
[ 18.154797] rcu-scale: 0 writer-duration: 17 107
[ 18.155279] rcu-scale: 0 writer-duration: 18 102
[ 18.155769] rcu-scale: 0 writer-duration: 19 107
To reproduce:
# build kernel
cd linux
cp config-5.12.0-rc3-00002-g94e7896d1139 .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/[email protected] Intel Corporation
Thanks,
Oliver Sang