New subject: [lkp] [mm: readahead] 99b902528e: INFO: task trinity-main:404 blocked for more than 120 seconds.

Friday, 26 February 2016

Greetings,

0day kernel testing robot got the below dmesg and the first bad commit is

https://github.com/0day-ci/linux
Johannes-Weiner/mm-readahead-do-not-cap-readahead-and-MADV_WILLNEED/20160224-094046

commit 99b902528e4e49cc02fcbc26cc0a10d0eaa70a3e
Author:     Johannes Weiner <hannes(a)cmpxchg.org&gt;
AuthorDate: Tue Feb 23 17:38:47 2016 -0800
Commit:     0day robot <fengguang.wu(a)intel.com&gt;
CommitDate: Wed Feb 24 09:40:49 2016 +0800

    mm: readahead: do not cap readahead() and MADV_WILLNEED

    All readahead is currently capped to a maximum of the device readahead
    limit, which defaults to 128k. For heuristics-based readahead this
    makes perfect sense, too, but unfortunately the limit is also applied
    to the explicit readahead() or madvise(MADV_WILLNEED) syscalls, and
    128k is an awfully low limit, particularly for bigger machines. It's
    not unreasonable for a user on a 100G machine to say, read this 1G
    file, and read it now, I'm going to access the whole thing shortly.

    Since both readahead() and MADV_WILLNEED take an explicit length
    parameter, it seems weird to truncate that request quietly. Just do
    what the user asked for and leave the limiting to the heuristics.

    Signed-off-by: Johannes Weiner <hannes(a)cmpxchg.org&gt;

+--------------------------------------------------+------------+------------+------------+
|                                                  | 4de8ebeff8 | 99b902528e | 44ec563f74
|
+--------------------------------------------------+------------+------------+------------+
| boot_successes                                   | 1919       | 902        | 230       
|
| boot_failures                                    | 4          | 12         | 8         
|
| IP-Config:Auto-configuration_of_network_failed   | 2          | 0          | 4         
|
| BUG:kernel_test_crashed                          | 2          |            |           
|
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks     | 0          | 3          | 1         
|
| INFO:task_blocked_for_more_than#seconds          | 0          | 12         |           
|
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0          | 12         | 4         
|
| backtrace:watchdog                               | 0          | 12         | 4         
|
| backtrace:vfs_kern_mount                         | 0          | 0          | 8         
|
| backtrace:mnt_init                               | 0          | 0          | 8         
|
| backtrace:vfs_caches_init                        | 0          | 0          | 8         
|
+--------------------------------------------------+------------+------------+------------+

error: 'rc.local' exited outside the expected code flow.

 (t=31501 jiffies g=353 c=352 q=12507)
[  241.872344] INFO: task trinity-main:404 blocked for more than 120 seconds.
[  241.872344] INFO: task trinity-main:404 blocked for more than 120 seconds.
[  241.874262]       Not tainted 4.5.0-rc5-00173-g99b9025 #1
[  241.874262]       Not tainted 4.5.0-rc5-00173-g99b9025 #1
[  241.875827] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  241.875827] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  241.887914] Kernel panic - not syncing: hung_task: blocked tasks
[  241.887914] Kernel panic - not syncing: hung_task: blocked tasks
[  241.889617] CPU: 0 PID: 16 Comm: khungtaskd Not tainted 4.5.0-rc5-00173-g99b9025 #1
[  241.889617] CPU: 0 PID: 16 Comm: khungtaskd Not tainted 4.5.0-rc5-00173-g99b9025 #1
[  241.891753]  0000000000000000
[  241.891753]  0000000000000000 ffff8800101c7d90 ffff8800101c7d90 ffffffff81817ca6
ffffffff81817ca6 ffffffff827c669a ffffffff827c669a

[  241.893907]  ffff8800101c7e20
[  241.893907]  ffff8800101c7e20 ffff8800101c7e10 ffff8800101c7e10 ffffffff81248e43
ffffffff81248e43 0000000000000008 0000000000000008

[  241.910022]  ffff8800101c7e20
[  241.910022]  ffff8800101c7e20 ffff8800101c7db8 ffff8800101c7db8 ffffffff8181e3b6
ffffffff8181e3b6 0000000000000002 0000000000000002

[  241.912112] Call Trace:
[  241.912112] Call Trace:
[  241.912791]  [<ffffffff81817ca6>] dump_stack+0xea/0x154
[  241.912791]  [<ffffffff81817ca6>] dump_stack+0xea/0x154
[  241.914229]  [<ffffffff81248e43>] panic+0x11e/0x325
[  241.914229]  [<ffffffff81248e43>] panic+0x11e/0x325
[  241.915629]  [<ffffffff8181e3b6>] ? nmi_trigger_all_cpu_backtrace+0x206/0x530
[  241.915629]  [<ffffffff8181e3b6>] ? nmi_trigger_all_cpu_backtrace+0x206/0x530
[  241.938594]  [<ffffffff812237bc>] watchdog+0x67c/0x760
[  241.938594]  [<ffffffff812237bc>] watchdog+0x67c/0x760
[  241.940198]  [<ffffffff81223220>] ? watchdog+0xe0/0x760
[  241.940198]  [<ffffffff81223220>] ? watchdog+0xe0/0x760
[  241.941826]  [<ffffffff81223140>] ? hung_task_panic+0x20/0x20
[  241.941826]  [<ffffffff81223140>] ? hung_task_panic+0x20/0x20
[  241.964754]  [<ffffffff81160aba>] kthread+0x12a/0x160
[  241.964754]  [<ffffffff81160aba>] kthread+0x12a/0x160
[  241.966286]  [<ffffffff81160990>] ? __kthread_unpark+0xa0/0xa0
[  241.966286]  [<ffffffff81160990>] ? __kthread_unpark+0xa0/0xa0
[  241.967878]  [<ffffffff820d486f>] ret_from_fork+0x3f/0x70
[  241.967878]  [<ffffffff820d486f>] ret_from_fork+0x3f/0x70
[  241.969348]  [<ffffffff81160990>] ? __kthread_unpark+0xa0/0xa0
[  241.969348]  [<ffffffff81160990>] ? __kthread_unpark+0xa0/0xa0
[  241.982838] Kernel Offset: disabled
[  241.982838] Kernel Offset: disabled

git bisect start 44ec563f74e478ccd262b899fc404761bc5c6870
81f70ba233d5f660e1ea5fe23260ee323af5d53a --
git bisect  bad b9380b78ec52e5f8d842af61766e8e628bc7c845  # 08:00      0-      4  Merge
'pci/pci/vpd' into devel-spot-201602240957
git bisect  bad f510875390c26be8247645f3f6b11fe2a3d5d695  # 08:00      0-      6  Merge
'kees/seccomp/tests' into devel-spot-201602240957
git bisect  bad 165c8f1695d5783fb3abb35c2ba4006115a54da3  # 08:00      0-      3  Merge
'kbusch-nvme/master' into devel-spot-201602240957
git bisect  bad b554db13ba65be39df5672622a4c7df1933712f0  # 08:14    393-      3  Merge
'linux-review/Han-Xu/support-gpmi-on-i-MX6UL-7D-and-HW-bitflip-on-i-MX6QP-7D/20160224-085042'
into devel-spot-201602240957
git bisect  bad 9c5e6420f6f9f861a1b39ddb5db862c5d54cf9bc  # 08:29    134-      3  Merge
'linux-review/Johannes-Weiner/mm-readahead-do-not-cap-readahead-and-MADV_WILLNEED/20160224-094046'
into devel-spot-201602240957
git bisect good be8328a7aa06e70d4dedbf434f75df613181ea65  # 09:18    910+      2  Merge
'linux-review/Adam-Buchbinder/include-linux-Fix-misspellings-in-comments/20160224-094831'
into devel-spot-201602240957
git bisect good e8a91d281358dd8c80fc5c779ef68813ac019ad2  # 10:12    904+      2  Merge
'linux-review/Adam-Buchbinder/ext4-Fix-misspellings-in-comments/20160224-094938'
into devel-spot-201602240957
git bisect good 148f472da5db4d78fcfe61807c18f020eb5bd7fc  # 11:03    903+      1  mlxsw:
reg: Add the Switch Port Acceptable Frame Types register
git bisect good 3bd7594e69bd97c962faa6a5ae15dd8c6c082636  # 11:58    904+      0 
Bluetooth: hci_core: Avoid mixing up req_complete and req_complete_skb
git bisect good d856626d3b051a3ad7139ba59463b692c131f844  # 12:36    905+      0  Merge
tag 'linux-can-fixes-for-4.5-20160221' of
git://git.kernel.org/pub/scm/linux/kernel/git/mkl/linux-can
git bisect good dea08e604408d0303e2332896c5fdd8c1f7d79a2  # 12:56    905+      0  Merge
git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect good 2cfec6a2f989d5c921ba11a329ff8ea986702b9b  # 13:19    910+      0 
xen/pcifront: Report the errors better.
git bisect good 6e22c8366416251a3d88ba6c92d13d595089f0ed  # 13:35    907+      0  tracing,
kasan: Silence Kasan warning in check_stack of stack_tracer
git bisect good 692b8c663cbaf892d10106fbca543b4bbc3202ad  # 13:53    910+      2  Merge
tag 'for-linus-4.5-rc5-tag' of
git://git.kernel.org/pub/scm/linux/kernel/git/xen/tip
git bisect  bad 99b902528e4e49cc02fcbc26cc0a10d0eaa70a3e  # 14:08    326-      1  mm:
readahead: do not cap readahead() and MADV_WILLNEED
git bisect good 4de8ebeff8ddefaceeb7fc6a9b1a514fc9624509  # 14:21    909+      4  Merge
tag 'trace-fixes-v4.5-rc5' of
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
# first bad commit: [99b902528e4e49cc02fcbc26cc0a10d0eaa70a3e] mm: readahead: do not cap
readahead() and MADV_WILLNEED
git bisect good 4de8ebeff8ddefaceeb7fc6a9b1a514fc9624509  # 14:38   1010+      4  Merge
tag 'trace-fixes-v4.5-rc5' of
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
# extra tests with DEBUG_INFO
git bisect  bad 99b902528e4e49cc02fcbc26cc0a10d0eaa70a3e  # 14:56    314-      1  mm:
readahead: do not cap readahead() and MADV_WILLNEED
# extra tests on HEAD of linux-devel/devel-spot-201602240957
git bisect  bad 44ec563f74e478ccd262b899fc404761bc5c6870  # 14:56      0-      8  0day
head guard for 'devel-spot-201602240957'
# extra tests on tree/branch
linux-review/Johannes-Weiner/mm-readahead-do-not-cap-readahead-and-MADV_WILLNEED/20160224-094046
git bisect  bad 99b902528e4e49cc02fcbc26cc0a10d0eaa70a3e  # 14:56      0-     12  mm:
readahead: do not cap readahead() and MADV_WILLNEED
# extra tests with first bad commit reverted
git bisect good 19cfcdf584ce1f947c98be262ece8575438982a9  # 15:21   1010+      1  Revert
"mm: readahead: do not cap readahead() and MADV_WILLNEED"
# extra tests on tree/branch linus/master
git bisect good 29a9faa641857425af76e44f2fab22db53032401  # 15:37   1010+      5  Merge
branch 'for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/sage/ceph-client
# extra tests on tree/branch linux-next/master
git bisect good 4639ea604f53d9804b19ec75d13648c8be3698da  # 15:53   1006+      7  Add
linux-next specific files for 20160226

This script may reproduce the error.

----------------------------------------------------------------------------
#!/bin/bash

kernel=$1
initrd=quantal-core-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 kvm64
	-kernel $kernel
	-initrd $initrd
	-m 300
	-smp 2
	-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[*]}"
----------------------------------------------------------------------------

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/lkp                          Intel Corporation

2019

2018

2017

2016

2015

2014

2013

[mm: readahead] 99b902528e: INFO: task trinity-main:404 blocked for more than 120 seconds.