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>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20210205031209.GB29458@xsang-OptiPlex-9020>
Date:   Fri, 5 Feb 2021 11:12:09 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Yang Shi <shy828301@...il.com>
Cc:     0day robot <lkp@...el.com>, LKML <linux-kernel@...r.kernel.org>,
        lkp@...ts.01.org, guro@...com, ktkhai@...tuozzo.com,
        vbabka@...e.cz, shakeelb@...gle.com, david@...morbit.com,
        hannes@...xchg.org, mhocko@...e.com, akpm@...ux-foundation.org,
        shy828301@...il.com, linux-mm@...ck.org,
        linux-fsdevel@...r.kernel.org
Subject: [mm]  [confidence: ] 3510a44e0e: WARNING:suspicious_RCU_usage


Greeting,

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

commit: 3510a44e0edaff61742421af22300d489765f018 ("mm: vmscan: use per memcg nr_deferred of shrinker")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git Yang-Shi/Make-shrinker-s-nr_deferred-memcg-aware/20210204-012207


in testcase: rcutorture
version: 
with following parameters:

	runtime: 300s
	test: default
	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-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------------------------+------------+------------+
|                                                                  | ff3d9a671b | 3510a44e0e |
+------------------------------------------------------------------+------------+------------+
| boot_successes                                                   | 18         | 0          |
| boot_failures                                                    | 0          | 20         |
| WARNING:suspicious_RCU_usage                                     | 0          | 20         |
| mm/vmscan.c:#suspicious_rcu_dereference_protected()usage         | 0          | 20         |
| kernel/rcu/rcutorture.c:#suspicious_rcu_dereference_check()usage | 0          | 1          |
+------------------------------------------------------------------+------------+------------+


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


[  429.418462] WARNING: suspicious RCU usage
[  429.492107] 5.11.0-rc4-next-20210125-00008-g3510a44e0eda #1 Not tainted
[  429.522073] -----------------------------
[  429.528493] mm/vmscan.c:196 suspicious rcu_dereference_protected() usage!
[  429.591222]
[  429.591222] other info that might help us debug this:
[  429.591222]
[  429.631478]
[  429.631478] rcu_scheduler_active = 2, debug_locks = 1
[  429.640256] 2 locks held by kworker/0:2/113:
[  429.701612] #0: ffff8881002e8c58 ((wq_completion)cgroup_destroy){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/kernel/workqueue.c:2246) 
[  429.743808] #1: ffff888128193e78 ((work_completion)(&(&css->destroy_rwork)->work)){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/kernel/workqueue.c:2246) 
[  429.855537]
[  429.855537] stack backtrace:
[  429.881543] CPU: 0 PID: 113 Comm: kworker/0:2 Not tainted 5.11.0-rc4-next-20210125-00008-g3510a44e0eda #1
[  429.961424] Workqueue: cgroup_destroy css_free_rwork_fn
[  429.969020] Call Trace:
[  430.006272] ? shrinker_info_protected (kbuild/src/consumer/mm/vmscan.c:196 (discriminator 5)) 
[  430.051527] ? free_shrinker_info (kbuild/src/consumer/mm/vmscan.c:248) 
[  430.059015] ? mem_cgroup_css_free (kbuild/src/consumer/mm/memcontrol.c:5126 kbuild/src/consumer/mm/memcontrol.c:5326) 
[  430.114659] ? css_free_rwork_fn (kbuild/src/consumer/include/linux/spinlock.h:359 kbuild/src/consumer/kernel/cgroup/cgroup.c:319 kbuild/src/consumer/kernel/cgroup/cgroup.c:4916) 
[  430.152816] ? process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic.h:29 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:28 kbuild/src/consumer/include/linux/jump_label.h:254 kbuild/src/consumer/include/linux/jump_label.h:264 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280) 
[  430.159991] ? ftrace_likely_update (kbuild/src/consumer/kernel/trace/trace_branch.c:225) 
[  430.213016] ? worker_thread (kbuild/src/consumer/include/linux/list.h:282 (discriminator 1) kbuild/src/consumer/kernel/workqueue.c:2422 (discriminator 1)) 
[  430.218431] ? rescuer_thread (kbuild/src/consumer/kernel/workqueue.c:2364) 
[  OK  ] Started Load Kernel Modules.
[  430.763235] ? kthread (kbuild/src/consumer/kernel/kthread.c:292 (discriminator 1)) 
[  430.767879] ? kthread_freezable_should_stop (kbuild/src/consumer/kernel/kthread.c:245) 
[  430.801093] ? ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302) 
[  OK  ] Started Remount Root and Kernel File Systems.
[  431.265726] _warn_unseeded_randomness: 8 callbacks suppressed
[  431.265822] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Create System Users...
[  432.014024] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  432.309092] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  432.309349] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  432.310050] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
Starting Load/Save Random Seed...
Mounting FUSE Control File System...
[  434.060249] _warn_unseeded_randomness: 11 callbacks suppressed
[  434.060350] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  434.618246] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  434.618507] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
Mounting Kernel Configuration File System...
[  435.660062] _warn_unseeded_randomness: 5 callbacks suppressed
[  435.660160] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  435.780213] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Apply Kernel Variables...
[  OK  ] Reached target NFS client services.
[  436.742460] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  436.742721] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  436.743360] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  OK  ] Started Create System Users.
[  OK  ] Started Load/Save Random Seed.
[  OK  ] Mounted FUSE Control File System.
[  OK  ] Mounted Kernel Configuration File System.
[  439.228577] _warn_unseeded_randomness: 10 callbacks suppressed
[  439.228680] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Create Static Device Nodes in /dev...
[  439.879913] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  440.277795] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  440.278057] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  440.278776] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  OK  ] Started Apply Kernel Variables.
[  OK  ] Started Create Static Device Nodes in /dev.
[  OK  ] Reached target Local File Systems (Pre).
[  OK  ] Reached target Local File Systems.
[  443.162257] _warn_unseeded_randomness: 4 callbacks suppressed
[  443.162367] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Preprocess NFS configuration...
[  443.916533] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  444.257290] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  444.257542] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  444.258443] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
Starting udev Kernel Device Manager...
[  445.384693] _warn_unseeded_randomness: 13 callbacks suppressed
[  445.384796] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  445.385005] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  445.385563] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  OK  ] Started Preprocess NFS configuration.
[  OK  ] Started Journal Service.
[  447.220330] _warn_unseeded_randomness: 3 callbacks suppressed
[  447.220539] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Flush Journal to Persistent Storage...
[  OK  ] Started udev Kernel Device Manager.
[  448.023069] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=0 
[  448.309765] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  448.310024] random: get_random_u64 called from randomize_stack_top+0x33/0x8c with crng_init=0 
[  448.412577] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=0 
[  OK  ] Started Flush Journal to Persistent Storage.
[  450.258909] _warn_unseeded_randomness: 4 callbacks suppressed
[  450.259007] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=0 
Starting Create Volatile Files and Directories...
[  450.661632] random: fast init done
[  450.919941] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=1 
[  451.147245] random: get_random_u64 called from arch_rnd+0x3f/0x61 with crng_init=1 
[  OK  ] Started Create Volatile Files and Directories.
[  454.518478] _warn_unseeded_randomness: 6 callbacks suppressed
[  454.518568] random: get_random_u64 called from copy_process+0x736/0x2951 with crng_init=1 
Starting Update UTMP about System Boot/Shutdown...
[  455.704795] random: get_random_bytes called from key_alloc+0x5bb/0x95d with crng_init=1 


To reproduce:

        # build kernel
	cd linux
	cp config-5.11.0-rc4-next-20210125-00008-g3510a44e0eda .config
	make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 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



Thanks,
Oliver Sang


View attachment "config-5.11.0-rc4-next-20210125-00008-g3510a44e0eda" of type "text/plain" (126183 bytes)

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

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

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ