Messages in this thread | | | Date | Mon, 16 Feb 2015 11:30:38 -0800 | From | "Paul E. McKenney" <> | Subject | Re: [torture] INFO: task killall5:262 blocked for more than 120 seconds. |
| |
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@linux.vnet.ibm.com> > AuthorDate: Tue Mar 4 11:03:21 2014 -0800 > Commit: Paul E. McKenney <paulmck@linux.vnet.ibm.com> > 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@linux.vnet.ibm.com> > Reviewed-by: Josh Triplett <josh@joshtriplett.org> > > +---------------------------------------------------------------+------------+------------+------------+ > | | 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 >
| |