Re: [torture] INFO: task killall5:262 blocked for more than 120 seconds.

From: Paul E. McKenney
Date: Mon Feb 16 2015 - 14:30:50 EST

Next message: Casey Leedom: "RE: chelsio: Use a more common const struct pci_device_id foo[] style"
Previous message: Peter Meerwald: "Re: [PATCH v2 0/2] bmg160 driver optimizations"
In reply to: Fengguang Wu: "[torture] INFO: task killall5:262 blocked for more than 120 seconds."
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Mon, Feb 16, 2015 at 03:25:28PM +0800, Fengguang Wu wrote:
> Hi Paul,
>
> FYI, this may be very hard to reproduce.

Indeed, I have not seen it.

But was this on a CONFIG_PREEMPT=n kernel?

Thanx, Paul

> git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git revert-d347efeb16d3d5150cb7f8d50b05f388b572840e-ab7d45053f99f44f81a221eb5c9fbe253ee94524
>
> commit ab7d45053f99f44f81a221eb5c9fbe253ee94524
> Author: Paul E. McKenney <paulmck@xxxxxxxxxxxxxxxxxx>
> AuthorDate: Tue Mar 4 11:03:21 2014 -0800
> Commit: Paul E. McKenney <paulmck@xxxxxxxxxxxxxxxxxx>
> CommitDate: Wed May 14 09:46:02 2014 -0700
>
> torture: Increase stutter-end intensity
>
> Currently, all stuttered kthreads block a jiffy at a time, which can
> result in them starting at different times. (Note: This is not an
> energy-efficiency problem unless you run torture tests in production,
> in which case you have other problems!) This commit increases the
> intensity of the restart event by causing kthreads to spin through the
> last jiffy, restarting when they see the variable change.
>
> Signed-off-by: Paul E. McKenney <paulmck@xxxxxxxxxxxxxxxxxx>
> Reviewed-by: Josh Triplett <josh@xxxxxxxxxxxxxxxx>
>
> +---------------------------------------------------------------+------------+------------+------------+
> | | fff35c4e9f | ab7d45053f | 7afb8886a0 |
> +---------------------------------------------------------------+------------+------------+------------+
> | boot_successes | 1000 | 884 | 14 |
> | boot_failures | 0 | 16 | 2 |
> | INFO:task_blocked_for_more_than#seconds | 0 | 12 | 2 |
> | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 12 | 2 |
> | backtrace:watchdog | 0 | 12 | 2 |
> | WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_stats_print() | 0 | 4 | |
> | backtrace:rcu_torture_stats | 0 | 4 | |
> | backtrace:rcu_torture_boost | 0 | 0 | 2 |
> +---------------------------------------------------------------+------------+------------+------------+
>
> [ 183.290093] rcu-torture: Reader Batch: 7006877 238 0 0 0 0 0 0 0 0 0
> [ 183.290093] rcu-torture: Free-Block Circulation: 622 622 621 620 619 618 617 616 615 614 0
> [ 183.290093] ??? Writer stall state 5 g550 c550 f0x0
> [ 240.530125] INFO: task killall5:262 blocked for more than 120 seconds.
> [ 240.531833] Not tainted 3.15.0-rc1-00022-gab7d450 #5
> [ 240.550103] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 240.551948] CPU: 0 PID: 27 Comm: khungtaskd Not tainted 3.15.0-rc1-00022-gab7d450 #5
> [ 240.553610] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 240.555632] task: d1cea290 ti: d1d3e000 task.ti: d1d3e000
> [ 240.556741] Stack:
> [ 240.557395] Call Trace:
> [ 240.558122] Code: 81 00 d3 ff ff f6 c4 10 75 ed c1 e3 18 89 99 10 d3 ff ff 89 f0 09 d0 80 ce 04 83 fe 02 0f 45 d0 a1 6c 1b 06 c2 89 90 00 d3 ff ff <89> f8 50 9d 8d 74 26 00 83 c4 04 5b 5e 5f 5d c3 ba 70 00 00 00
> [ 240.560012] CPU: 1 PID: 64 Comm: rcu_torture_boo Not tainted 3.15.0-rc1-00022-gab7d450 #5
> [ 240.560012] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 240.560012] task: cc4d4310 ti: cc4d8000 task.ti: cc4d8000
> [ 240.560012] Stack:
> [ 240.560012] Call Trace:
> [ 240.560012] Code: 00 00 8b 00 85 c0 0f 85 85 00 00 00 a1 fc 85 7c c2 85 c0 74 46 a1 fc 85 7c c2 83 f8 01 74 5c a1 fc 85 7c c2 85 c0 74 23 8d 76 00 <31> c9 ba 1c 02 00 00 b8 ac d5 eb c1 e8 5f 12 fb ff e8 8a 0c b3
> [ 240.598110] Kernel panic - not syncing: hung_task: blocked tasks
> [ 240.599315] CPU: 0 PID: 27 Comm: khungtaskd Not tainted 3.15.0-rc1-00022-gab7d450 #5
> [ 240.600854] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
> [ 240.602788] 00007f95 00000000 d1d3fedc c1be7294 d29b6f60 d1d3fef4 c1be4f9d 00007f95
> [ 240.604992] d29b6f60 00007f95 d29b71c8 d1d3ff24 c10a7d1d c1eb744c 00000395 00000078
> [ 240.607268] 00000002 00007f95 d29b6f60 d29b71c8 d1d38e00 00000000 c10a7a50 d1d3ffac
> [ 240.607938] Call Trace:
> [ 240.607938] [<c1be7294>] dump_stack+0x48/0x69
> [ 240.607938] [<c1be4f9d>] panic+0x7c/0x184
> [ 240.607938] [<c10a7d1d>] watchdog+0x2cd/0x2d0
> [ 240.607938] [<c10a7a50>] ? hung_task_panic+0x20/0x20
> [ 240.607938] [<c105fb93>] kthread+0xa3/0xc0
> [ 240.607938] [<c1bf0701>] ret_from_kernel_thread+0x21/0x30
> [ 240.607938] [<c105faf0>] ? __kthread_unpark+0x50/0x50
> [ 240.607938] Kernel Offset: 0x0 from 0xc1000000 (relocation range: 0xc0000000-0xd47dffff)
>
> Elapsed time: 240
>
> git bisect start v3.16 v3.15 --
> git bisect bad 5170a3b24a9141e2349a3420448743b7c68f2223 # 06:12 0- 11 Merge branch 'akpm' (patches from Andrew Morton)
> git bisect bad 1ad96bb0a20fa26b952b2250e89d14b6397bf618 # 06:12 0- 17 Merge tag 'gpio-v3.16-2' of git://git.kernel.org/pub/scm/linux/kernel/git/linusw/linux-gpio
> git bisect bad 412dd3a6daf0cadce1b2d6a34fa3713f40255579 # 06:12 0- 46 Merge tag 'xfs-for-linus-3.16-rc1' of git://oss.sgi.com/xfs/xfs
> git bisect bad b1cce8032f6abe900b078d24f3c3938726528f97 # 06:20 281- 7 Merge branch 'for-next' of git://git.samba.org/sfrench/cifs-2.6
> git bisect bad da85d191f58a44e149a7c07dbae78b3042909798 # 06:36 416- 7 Merge branch 'for-3.16' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
> git bisect bad f8409abdc592e13cefbe4e4a24a84b3d5741e85f # 07:00 500- 13 Merge tag 'ext4_for_linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tytso/ext4
> git bisect bad ed81e780a7dd5698a986f246fad6a1d8d0b6f9ce # 07:17 680- 14 Merge branch 'x86-vdso-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect bad 3f17ea6dea8ba5668873afa54628a91aaa3fb1c0 # 07:32 772- 10 Merge branch 'next' (accumulated 3.16 merge window patches) into master
> git bisect good 49eb7b0750d9483c74e9c14ae6ea1e9d62481c3c # 07:54 900+ 6 Merge tag 'tty-3.16-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty into next
> git bisect bad 15b588303155b22edd559672905db8e59a44ef9a # 08:07 625- 13 Merge tag 'fbdev-omap-3.16' of git://git.kernel.org/pub/scm/linux/kernel/git/tomba/linux into next
> git bisect bad 776edb59317ada867dfcddde40b55648beeb0078 # 08:29 562- 12 Merge branch 'locking-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip into next
> git bisect good f456205265a61f1d649f8378eceaa163850cba4e # 08:46 900+ 2 Merge tag 'hwmon-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/groeck/linux-staging into next
> git bisect good e13cccfd86481bd4c0499577f44c570d334da79b # 08:59 900+ 2 Merge tag 'spi-v3.16' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/spi into next
> git bisect good ff806d034ef8e9a95ff0b0532104dd65332e446b # 09:15 900+ 0 Merge branch 'for-v3.16' of git://git.linaro.org/people/mszyprowski/linux-dma-mapping into next
> git bisect bad 6348675c4e3612e001860354fea78258e041d9a1 # 09:32 550- 8 torture: Remove unused definition
> git bisect bad ab7d45053f99f44f81a221eb5c9fbe253ee94524 # 09:40 438- 8 torture: Increase stutter-end intensity
> git bisect good a0edd47ca4f0ffa33df137c13a08189bae66bcc3 # 09:59 900+ 4 torture: Rename RCU_QEMU_INTERACTIVE to TORTURE_QEMU_INTERACTIVE
> git bisect good b3b8a4d42bba8e1fb1b91cc6fd53829d28a503de # 10:13 900+ 4 rcutorture: Mark function as static in kernel/rcu/torture.c
> git bisect good 589a8f59509dc4c68f9c1e2522c5b0b556009221 # 10:38 900+ 2 rcutorture: Print negatives for SRCU counter wraparound
> git bisect good fff35c4e9fbb0982aef6230cbf713c2492925eca # 10:55 900+ 0 torture: Report diagnostics from qemu
> # first bad commit: [ab7d45053f99f44f81a221eb5c9fbe253ee94524] torture: Increase stutter-end intensity
> git bisect good fff35c4e9fbb0982aef6230cbf713c2492925eca # 10:57 1000+ 0 torture: Report diagnostics from qemu
> # extra tests with DEBUG_INFO
> # extra tests on HEAD of net/master
> git bisect bad 7afb8886a05be68e376655539a064ec672de8a8e # 11:02 0- 2 rtnetlink: call ->dellink on failure when ->newlink exists
> # extra tests on tree/branch linus/master
> # extra tests with first bad commit reverted
> # extra tests on tree/branch linus/master
> # extra tests on tree/branch next/master
>
>
> This script may reproduce the error.
>
> ----------------------------------------------------------------------------
> #!/bin/bash
>
> kernel=$1
> initrd=quantal-core-i386.cgz
>
> wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd
>
> kvm=(
> qemu-system-x86_64
> -cpu kvm64
> -enable-kvm
> -kernel $kernel
> -initrd $initrd
> -m 320
> -smp 2
> -net nic,vlan=1,model=e1000
> -net user,vlan=1
> -boot order=nc
> -no-reboot
> -watchdog i6300esb
> -rtc base=localtime
> -serial stdio
> -display none
> -monitor null
> )
>
> append=(
> hung_task_panic=1
> earlyprintk=ttyS0,115200
> rd.udev.log-priority=err
> systemd.log_target=journal
> systemd.log_level=warning
> 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
>

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Casey Leedom: "RE: chelsio: Use a more common const struct pci_device_id foo[] style"
Previous message: Peter Meerwald: "Re: [PATCH v2 0/2] bmg160 driver optimizations"
In reply to: Fengguang Wu: "[torture] INFO: task killall5:262 blocked for more than 120 seconds."
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]