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>] [day] [month] [year] [list]
Message-ID: <20210316024354.GA11637@xsang-OptiPlex-9020>
Date:   Tue, 16 Mar 2021 10:43:54 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     David Howells <dhowells@...hat.com>
Cc:     Alexander Viro <viro@...iv.linux.org.uk>,
        Miklos Szeredi <miklos@...redi.hu>,
        Matthew Wilcox <willy@...radead.org>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        lkp@...el.com
Subject: [vfs]  [confidence: ] 94e7896d11: WARNING:suspicious_RCU_usage



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 <oliver.sang@...el.com>


[    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/lkp@lists.01.org       Intel Corporation

Thanks,
Oliver Sang


View attachment "config-5.12.0-rc3-00002-g94e7896d1139" of type "text/plain" (145633 bytes)

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

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ