[<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