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

Powered by Openwall GNU/*/Linux Powered by OpenVZ