[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20150615124402.GA25015@wfg-t540p.sh.intel.com>
Date: Mon, 15 Jun 2015 20:44:02 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: Miroslav Benes <mbenes@...e.cz>
Cc: fengguang.wu@...el.com,
"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>,
linux-kernel@...r.kernel.org, LKP <lkp@...org>
Subject: [rcu] INFO: rcu_sched stall on CPU (30000 ticks this GP)
idle=140000000000001 (t=30000 jiffies q=1)
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit ec1fe396ff42e240c9b32111ee53665c5916fe5e
Author: Miroslav Benes <mbenes@...e.cz>
AuthorDate: Mon Dec 22 11:10:12 2014 -0800
Commit: Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
CommitDate: Thu Jan 15 23:33:16 2015 -0800
rcu: Fix RCU CPU stall detection in tiny implementation
The tiny RCU CPU stall detection depends on *rcp->curtail not being
NULL. It is however a tail pointer and thus NULL by definition. Instead we
should check rcp->rcucblist for the presence of pending callbacks which
need to be processed. With this fix INFO about the stall is printed and
jiffies_stall (jiffies at next stall) correctly updated.
Note that the check for pending callback is necessary to avoid spurious
warnings if there are no pendings callbacks.
Signed-off-by: Miroslav Benes <mbenes@...e.cz>
[ paulmck: Fused identical "if" statements, ported to -rcu. ]
Signed-off-by: Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
+-------------------------------------------------------------------+------------+------------+---------------+
| | fb81a44b88 | ec1fe396ff | next-20150603 |
+-------------------------------------------------------------------+------------+------------+---------------+
| boot_successes | 203 | 44 | 21 |
| boot_failures | 1017 | 266 | 13 |
| BUG:kernel_test_hang | 452 | 202 | 2 |
| Out_of_memory:Kill_process | 3 | | |
| BUG:kernel_test_crashed | 538 | 56 | 1 |
| INFO:task_blocked_for_more_than#seconds | 8 | 1 | |
| RIP:flat_send_IPI_mask | 8 | 1 | |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 8 | 1 | |
| backtrace:ring_buffer_producer_thread | 8 | 1 | |
| backtrace:watchdog | 8 | 1 | |
| WARNING:at_drivers/block/floppy.c:#schedule_bh() | 18 | 2 | |
| backtrace:user_reset_fdc | 18 | 2 | |
| backtrace:floppy_async_init | 18 | 2 | |
| backtrace:async_run_entry_fn | 18 | 2 | |
| BUG:kernel_boot_crashed | 1 | | |
| INFO:rcu_sched_stall_on_CPU(#ticks_this_GP)idle=#(t=#jiffies_q=#) | 0 | 9 | 9 |
| backtrace:print_ICs | 0 | 9 | 9 |
| backtrace:kernel_init_freeable | 0 | 9 | 9 |
| IP-Config:Auto-configuration_of_network_failed | 0 | 0 | 1 |
+-------------------------------------------------------------------+------------+------------+---------------+
[ 562.081441] IRQ7 -> 0:7
[ 563.699875] IRQ8 -> 0:8
[ 565.408902] IRQ9 -> 0:9
[ 566.726987] INFO: rcu_sched stall on CPU (30000 ticks this GP) idle=140000000000001 (t=30000 jiffies q=1)
[ 566.726992] CPU: 0 PID: 1 Comm: swapper Not tainted 3.19.0-rc1-00010-gec1fe39 #1
[ 566.726994] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 566.727000] 0000000000000000 ffffffff836dfed8 ffffffff8297e6d5 ffffffff836dfef8
[ 566.727004] ffffffff8112f00e 0000000000000001 0000000000000000 ffffffff836dff18
[ 566.727007] ffffffff8112fc68 ffff88000ee48010 ffff88000ee48010 ffffffff836dff38
[ 566.727008] Call Trace:
[ 566.727032] <IRQ> [<ffffffff8297e6d5>] dump_stack+0x19/0x1b
[ 566.727041] [<ffffffff8112f00e>] check_cpu_stall+0x8e/0xf0
[ 566.727044] [<ffffffff8112fc68>] rcu_check_callbacks+0x28/0xa0
[ 566.727048] [<ffffffff811353e8>] update_process_times+0x38/0x80
[ 566.727052] [<ffffffff811471f3>] tick_periodic+0xc3/0xd0
[ 566.727055] [<ffffffff811473d6>] ? tick_handle_periodic+0x96/0xb0
[ 566.727059] [<ffffffff811473d6>] tick_handle_periodic+0x96/0xb0
[ 566.727063] [<ffffffff8105705e>] local_apic_timer_interrupt+0x3e/0x70
[ 566.727068] [<ffffffff829b672f>] smp_apic_timer_interrupt+0x3f/0x60
[ 566.727071] [<ffffffff829b4bd0>] apic_timer_interrupt+0x70/0x80
[ 566.727077] <EOI> [<ffffffff8111cadd>] ? console_unlock+0x6dd/0x720
[ 566.727080] [<ffffffff8111b0b0>] ? __down_trylock_console_sem+0x60/0x70
[ 566.727083] [<ffffffff8111cf17>] ? vprintk_emit+0x3f7/0x860
[ 566.727086] [<ffffffff8111cf4c>] vprintk_emit+0x42c/0x860
[ 566.727091] [<ffffffff843eba0c>] ? apic_set_eoi_write+0x72/0x90
[ 566.727093] [<ffffffff8111d56f>] vprintk_default+0x1f/0x30
[ 566.727096] [<ffffffff8297809f>] printk+0x45/0x47
[ 566.727099] [<ffffffff843ed13c>] print_IO_APICs+0x37a/0x3a6
[ 566.727102] [<ffffffff8114fa00>] ? free_dma+0x70/0x80
[ 566.727104] [<ffffffff843eba0c>] ? apic_set_eoi_write+0x72/0x90
[ 566.727107] [<ffffffff843ebdae>] print_ICs+0x305/0x316
[ 566.727109] [<ffffffff843ebaa9>] ? setup_show_lapic+0x7f/0x7f
[ 566.727113] [<ffffffff843d277e>] do_one_initcall+0x1b9/0x2d6
[ 566.727117] [<ffffffff810efd00>] ? parse_args+0x520/0x750
[ 566.727121] [<ffffffff843d29b1>] kernel_init_freeable+0x116/0x1db
[ 566.727125] [<ffffffff829694e0>] ? rest_init+0xd0/0xd0
[ 566.727128] [<ffffffff829694ee>] kernel_init+0xe/0x180
[ 566.727130] [<ffffffff829b3aba>] ret_from_fork+0x7a/0xb0
[ 566.727133] [<ffffffff829694e0>] ? rest_init+0xd0/0xd0
[ 623.386382] IRQ10 -> 0:10
[ 624.646358] IRQ11 -> 0:11
[ 625.988923] IRQ12 -> 0:12
git bisect start v4.0 v2.6.39 --
git bisect good 5abcd76f5d896de014bd8d1486107c483659d40d # 20:35 148+ 1048 Merge branch 'x86-boot-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 6a4d07f85ba9da5b6eab6e60a493d459c4296176 # 08:16 148+ 856 Merge branch 'for-3.14-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/cgroup
git bisect good 9f47112975fdc32e545e079f42a17bbd0be236fc # 09:28 148+ 761 Merge branch 'upstream' of git://git.linux-mips.org/pub/scm/ralf/upstream-linus
git bisect good c0f486fde3f353232c1cc2fd4d62783ac782a467 # 11:06 148+ 81 Merge tag 'pm+acpi-3.19-rc1-2' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm
git bisect bad a42cf70eb81558082e9a26fe8541d160b6c2a694 # 12:10 56- 28 Merge tag 'modules-next-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/rusty/linux
git bisect good b8de08da0402b1cbc3ce1963929161d141d2f933 # 00:38 300+ 239 Merge tag 'devicetree-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/glikely/linux
git bisect good b0c1936c4497d7f06b143241614d85a41fec12cd # 12:25 300+ 233 Merge tag 'spi-v3.20' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/spi
git bisect bad 3e63430a5cc26bc90a6e33ab33f901196b7b63ac # 01:03 166- 76 Merge tag 'media/v3.20-1' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
git bisect bad 44dbf058de9f46cf112518c99bb1352e8350ceb3 # 02:17 88- 32 Merge branch 'for-3.20' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
git bisect bad 80f33a5fdf66d4338789e8aa80589bda088cb35d # 03:33 47- 15 Merge branch 'x86-cleanups-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad a4cbbf549a9be10b7583c44249efccd64839533d # 06:02 73- 25 Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 23e8fe2e16587494268510c1bc9f6952f50f0311 # 08:25 61- 15 Merge branch 'core-rcu-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 30d46827c2744f56bb31460007f2d16455f10720 # 22:52 309+ 91 Merge tag 'regulator-v3.20' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/regulator
git bisect good ab954c167ed9ac107a8beb1d6e1745ae698a3421 # 00:31 306+ 206 rcu: Remove redundant callback-list initialization
git bisect good 7602de4af192b1527767538454557cb7564bae60 # 01:49 306+ 207 rcutorture: Add more diagnostics in rcu_barrier() test failure case
git bisect good 60479676eb6e9913176d93ebad194e3dc167bc63 # 03:17 304+ 244 ksoftirqd: Use new cond_resched_rcu_qs() function
git bisect bad ec1fe396ff42e240c9b32111ee53665c5916fe5e # 04:22 100- 60 rcu: Fix RCU CPU stall detection in tiny implementation
git bisect good 6ccd2ecd422644277b7d8b37222e3af3f43ea9ae # 05:41 300+ 172 rcu: Improve diagnostics for spurious RCU CPU stall warnings
git bisect good a94844b22a2e2b9155bbc0878c507850477221c2 # 07:21 303+ 261 rcu: Optionally run grace-period kthreads at real-time priority
git bisect good fb81a44b88e6173ed0f6e9d6a1afa5305fb63f6e # 08:58 300+ 254 rcu: Add GP-kthread-starvation checks to CPU stall warnings
# first bad commit: [ec1fe396ff42e240c9b32111ee53665c5916fe5e] rcu: Fix RCU CPU stall detection in tiny implementation
git bisect good fb81a44b88e6173ed0f6e9d6a1afa5305fb63f6e # 11:31 902+ 999 rcu: Add GP-kthread-starvation checks to CPU stall warnings
# extra tests with DEBUG_INFO
git bisect bad ec1fe396ff42e240c9b32111ee53665c5916fe5e # 12:39 213- 181 rcu: Fix RCU CPU stall detection in tiny implementation
# extra tests on HEAD of next/master
git bisect bad 273de33838674768a625ee3cb6d68c909370ae43 # 12:40 0- 13 Add linux-next specific files for 20150603
# extra tests on tree/branch linus/master
git bisect bad 0f57d86787d8b1076ea8f9cbdddda2a46d534a27 # 13:50 91- 76 Linux 4.1-rc8
# extra tests with first bad commit reverted
git bisect good 09f72f6350a74276673a7d3179591067299fa125 # 17:53 900+ 727 Revert "rcu: Fix RCU CPU stall detection in tiny implementation"
# extra tests on tree/branch linus/master
git bisect bad 0f57d86787d8b1076ea8f9cbdddda2a46d534a27 # 17:53 0- 820 Linux 4.1-rc8
# extra tests on tree/branch next/master
git bisect bad 26f2a66080ffa553c4d1254766c91cae0b056bda # 19:02 228- 213 Add linux-next specific files for 20150615
This script may reproduce the error.
----------------------------------------------------------------------------
#!/bin/bash
kernel=$1
initrd=yocto-minimal-x86_64.cgz
wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu Haswell,+smep,+smap
-kernel $kernel
-initrd $initrd
-m 256
-smp 1
-device e1000,netdev=net0
-netdev user,id=net0
-boot order=nc
-no-reboot
-watchdog i6300esb
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
hung_task_panic=1
earlyprintk=ttyS0,115200
systemd.log_level=err
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
console=ttyS0,115200
console=tty0
vga=normal
root=/dev/ram0
rw
drbd.minor_count=8
)
"${kvm[@]}" --append "${append[*]}"
----------------------------------------------------------------------------
Thanks,
Fengguang
View attachment "dmesg-yocto-kbuild-22:20150615042135:x86_64-randconfig-n0-06041011:3.19.0-rc1-00010-gec1fe39:1" of type "text/plain" (163939 bytes)
View attachment "config-3.19.0-rc1-00010-gec1fe39" of type "text/plain" (95398 bytes)
Powered by blists - more mailing lists