[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20190605162239.omjxn5fhrqwod6bz@inn2.lkp.intel.com>
Date: Thu, 6 Jun 2019 00:22:39 +0800
From: kernel test robot <lkp@...el.com>
To: Marcelo Tosatti <mtosatti@...hat.com>
Cc: 0day robot <lkp@...el.com>, LKML <linux-kernel@...r.kernel.org>,
lkp@...org
Subject: [drivers/cpuidle] be4d068f71: WARNING:suspicious_RCU_usage
FYI, we noticed the following commit (built with gcc-7):
commit: be4d068f71e6509913afa59d1174ee59108569e7 ("drivers/cpuidle: add cpuidle-haltpoll driver")
https://github.com/0day-ci/linux UPDATE-20190605-044611/Marcelo-Tosatti/cpuidle-haltpoll-driver-v2/20190604-085852
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 2G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------------------------+------------+------------+
| | 94830f188a | be4d068f71 |
+-----------------------------------------------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 0 | 4 |
| WARNING:suspicious_RCU_usage | 0 | 4 |
| drivers/cpuidle/cpuidle-haltpoll-trace.h:#suspicious_rcu_dereference_check()usage | 0 | 4 |
+-----------------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <lkp@...el.com>
[ 23.942552] WARNING: suspicious RCU usage
[ 23.943158] 5.2.0-rc1-00004-gbe4d068 #1 Not tainted
[ 23.943886] -----------------------------
[ 23.944519] drivers/cpuidle/cpuidle-haltpoll-trace.h:54 suspicious rcu_dereference_check() usage!
[ 23.946173]
[ 23.946173] other info that might help us debug this:
[ 23.946173]
[ 23.947451]
[ 23.947451] RCU used illegally from idle CPU!
[ 23.947451] rcu_scheduler_active = 2, debug_locks = 1
[ 23.949050] RCU used illegally from extended quiescent state!
[ 23.949971] no locks held by swapper/0/0.
[ 23.950614]
[ 23.950614] stack backtrace:
[ 23.951309] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.2.0-rc1-00004-gbe4d068 #1
[ 23.952406] Call Trace:
[ 23.952826] dump_stack+0x9a/0xde
[ 23.953342] haltpoll_enter_idle+0x479/0x498
[ 23.954000] cpuidle_enter_state+0xd0/0x31a
[ 23.954661] ? ftrace_likely_update+0x51/0x5c
[ 23.955419] ? ftrace_likely_update+0x51/0x5c
[ 23.956103] cpuidle_enter+0x2f/0x3b
[ 23.956674] do_idle+0x223/0x2e7
[ 23.957171] ? trace_event_define_fields_vector_alloc_managed+0xff/0xff
[ 23.958143] cpu_startup_entry+0x1d/0x1f
[ 23.958765] start_kernel+0x7a9/0x7e1
[ 23.959343] secondary_startup_64+0xb6/0xc0
[ 23.989616]
[ 23.989932] =============================
[ 23.990591] WARNING: suspicious RCU usage
[ 23.991240] 5.2.0-rc1-00004-gbe4d068 #1 Not tainted
[ 23.992013] -----------------------------
[ 23.992672] drivers/cpuidle/cpuidle-haltpoll-trace.h:29 suspicious rcu_dereference_check() usage!
[ 23.994357]
[ 23.994357] other info that might help us debug this:
[ 23.994357]
[ 23.995647]
[ 23.995647] RCU used illegally from idle CPU!
[ 23.995647] rcu_scheduler_active = 2, debug_locks = 1
[ 23.997355] RCU used illegally from extended quiescent state!
[ 23.998280] no locks held by swapper/0/0.
[ 23.998918]
[ 23.998918] stack backtrace:
[ 23.999613] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.2.0-rc1-00004-gbe4d068 #1
[ 24.000810] Call Trace:
[ 24.001228] dump_stack+0x9a/0xde
[ 24.001792] haltpoll_enter_idle+0x260/0x498
[ 24.002484] cpuidle_enter_state+0xd0/0x31a
[ 24.003172] ? ftrace_likely_update+0x51/0x5c
[ 24.003868] ? ftrace_likely_update+0x51/0x5c
[ 24.004581] cpuidle_enter+0x2f/0x3b
[ 24.005141] do_idle+0x223/0x2e7
[ 24.005670] ? trace_event_define_fields_vector_alloc_managed+0xff/0xff
[ 24.006736] cpu_startup_entry+0x1d/0x1f
[ 24.007378] start_kernel+0x7a9/0x7e1
[ 24.007977] secondary_startup_64+0xb6/0xc0
[ 24.135159] IP-Config: Got DHCP answer from 10.0.2.2, my address is 10.0.2.15
[ 24.136408] IP-Config: Complete:
[ 24.137974] device=eth0, hwaddr=52:54:00:12:34:56, ipaddr=10.0.2.15, mask=255.255.255.0, gw=10.0.2.2
[ 24.140083] host=vm-snb-quantal-x86_64-710, domain=, nis-domain=(none)
[ 24.141179] bootserver=10.0.2.2, rootserver=10.0.2.2, rootpath=
[ 24.141183] nameserver0=10.0.2.3
[ 24.147041] Unregister pv shared memory for cpu 0
[ 24.170916] DEBUG_HOTPLUG_CPU0: CPU 0 is now offline
[ 24.193063] Freeing unused kernel image memory: 4016K
[ 24.193972] Write protecting the kernel read-only data: 30720k
[ 24.200275] Freeing unused kernel image memory: 2036K
[ 24.201246] Freeing unused kernel image memory: 80K
[ 24.202715] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[ 24.203697] rodata_test: all tests were successful
[ 24.204390] Run /init as init process
[ 24.238969] random: init: uninitialized urandom read (12 bytes read)
[ 24.347624] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[ 24.873797] random: mountall: uninitialized urandom read (12 bytes read)
LKP: HOSTNAME vm-snb-quantal-x86_64-710, MAC 52:54:00:12:34:56, kernel 5.2.0-rc1-00004-gbe4d068 1, serial console /dev/ttyS0
[ 25.187823] Kernel tests: Boot OK!
[ 25.187833]
[ 25.200608] hostname: the specified hostname is invalid
[ 25.200616]
[ 25.474810] /lkp/lkp/src/bin/run-lkp
[ 25.474819]
[ 25.770881] udevd[363]: starting version 175
[ 25.984983] RESULT_ROOT=/result/trinity/300s/vm-snb-quantal-x86_64/quantal-core-x86_64-2019-04-26.cgz/x86_64-randconfig-a0-06050844/gcc-7/be4d068f71e6509913afa59d1174ee59108569e7/3
[ 25.984993]
[ 26.007136] job=/lkp/jobs/scheduled/vm-snb-quantal-x86_64-710/trinity-300s-quantal-core-x86_64-2019-04-26.cgz-be4d068-20190605-40165-1n2sy7-3.yaml
[ 26.007146]
[ 26.268751] result_service=raw_upload, RESULT_MNT=/inn/result, RESULT_ROOT=/inn/result/trinity/300s/vm-snb-quantal-x86_64/quantal-core-x86_64-2019-04-26.cgz/x86_64-randconfig-a0-06050844/gcc-7/be4d068f71e6509913afa59d1174ee59108569e7/3
[ 26.268761]
[ 26.454639] run-job /lkp/jobs/scheduled/vm-snb-quantal-x86_64-710/trinity-300s-quantal-core-x86_64-2019-04-26.cgz-be4d068-20190605-40165-1n2sy7-3.yaml
[ 26.454649]
[ 27.255453] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/vm-snb-quantal-x86_64-710/trinity-300s-quantal-core-x86_64-2019-04-26.cgz-be4d068-20190605-40165-1n2sy7-3.yaml&job_state=running -O /dev/null
[ 27.255463]
[ 27.362475] init: udev-fallback-graphics main process (492) terminated with status 1
[ 27.419356] target ucode:
[ 27.419365]
[ 27.778437] init: networking main process (509) terminated with status 1
[ 28.096245] init: failsafe main process (505) killed by TERM signal
[ 28.415332] random: fast init done
[ 29.325378] random: dd: uninitialized urandom read (4096 bytes read)
[ 29.491877] Seeding trinity based on x86_64-randconfig-a0-06050844
[ 29.491887]
[ 29.584973] groupadd: group 'nogroup' already exists
[ 29.584982]
[ 29.644203] 2019-06-05 15:07:59 chroot --userspec nobody:nogroup / trinity -q -q -l off -s 2862873013 -x get_robust_list -x remap_file_pages -N 999999999
[ 29.644213]
[ 29.888839] Trinity 1.8 Dave Jones <davej@...emonkey.org.uk>
[ 29.888849]
[ 29.891751] shm:0x7f2616b28000-0x7f2623724d00 (4 pages)
[ 29.891760]
[ 29.903899] [main] Marking syscall get_robust_list (64bit:274 32bit:312) as to be disabled.
[ 29.903908]
[ 29.916703] [main] Marking syscall remap_file_pages (64bit:216 32bit:257) as to be disabled.
[ 29.916713]
[ 29.931041] [main] Couldn't chmod tmp/ to 0777.
[ 29.931051]
[ 29.946597] [main] Using user passed random seed: 2862873013.
[ 29.946606]
[ 29.948906] Marking all syscalls as enabled.
[ 29.948914]
[ 29.962311] [main] Disabling syscalls marked as disabled by command line options
[ 29.962320]
[ 29.970484] [main] Marked 64-bit syscall remap_file_pages (216) as deactivated.
[ 29.970504]
[ 29.978376] [main] Marked 64-bit syscall get_robust_list (274) as deactivated.
[ 29.978384]
[ 29.994251] [main] Marked 32-bit syscall remap_file_pages (257) as deactivated.
[ 29.994260]
[ 30.002082] [main] Marked 32-bit syscall get_robust_list (312) as deactivated.
[ 30.002091]
[ 30.010917] [main] 32-bit syscalls: 382 enabled, 2 disabled. 64-bit syscalls: 331 enabled, 2 disabled.
To reproduce:
# build kernel
cd linux
cp config-5.2.0-rc1-00004-gbe4d068 .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 prepare
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 modules_prepare
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 SHELL=/bin/bash
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 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,
lkp
View attachment "config-5.2.0-rc1-00004-gbe4d068" of type "text/plain" (135997 bytes)
View attachment "job-script" of type "text/plain" (4345 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (23104 bytes)
View attachment "trinity" of type "text/plain" (34121 bytes)
Powered by blists - more mailing lists