[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180907045041.GF1110@shao2-debian>
Date: Fri, 7 Sep 2018 12:50:41 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Dmitry Safonov <dima@...sta.com>
Cc: linux-kernel@...r.kernel.org,
Dmitry Safonov <0x7f454c46@...il.com>,
Dmitry Safonov <dima@...sta.com>,
Daniel Axtens <dja@...ens.net>,
Dmitry Vyukov <dvyukov@...gle.com>,
Michael Neuling <mikey@...ling.org>,
Mikulas Patocka <mpatocka@...hat.com>,
Pasi Kärkkäinen <pasik@....fi>,
Peter Hurley <peter@...leysoftware.com>,
Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
Tan Xiaojun <tanxiaojun@...wei.com>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Jiri Slaby <jslaby@...e.com>, stable@...r.kernel.org,
lkp@...org
Subject: [LKP] [tty] 0b4f83d510: INFO:task_blocked_for_more_than#seconds
FYI, we noticed the following commit (built with gcc-7):
commit: 0b4f83d510f6fef6bb9da25f122c8d733d50516f ("[PATCH 2/4] tty: Hold tty_ldisc_lock() during tty_reopen()")
url: https://github.com/0day-ci/linux/commits/Dmitry-Safonov/tty-Hold-write-ldisc-sem-in-tty_reopen/20180829-165618
base: https://git.kernel.org/cgit/linux/kernel/git/gregkh/tty.git tty-testing
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------+------------+------------+
| | 58dd163974 | 0b4f83d510 |
+--------------------------------------------------+------------+------------+
| boot_successes | 14 | 4 |
| boot_failures | 0 | 6 |
| INFO:task_blocked_for_more_than#seconds | 0 | 6 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 6 |
+--------------------------------------------------+------------+------------+
[ 244.816801] INFO: task validate_data:655 blocked for more than 120 seconds.
[ 244.818833] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.820028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.826965] validate_data D 0 655 623 0x20020000
[ 244.828279] Call Trace:
[ 244.828958] ? __schedule+0x843/0x950
[ 244.830173] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.834903] schedule+0x31/0x70
[ 244.835665] schedule_timeout+0x34/0x760
[ 244.836613] ? ftrace_likely_update+0x35/0x60
[ 244.837683] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.838818] ? ftrace_likely_update+0x35/0x60
[ 244.840127] ? ftrace_likely_update+0x35/0x60
[ 244.845947] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.847882] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.849886] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.853807] tty_ldisc_ref_wait+0x25/0x50
[ 244.854946] tty_compat_ioctl+0x8a/0x120
[ 244.855928] ? this_tty+0x80/0x80
[ 244.856742] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.857981] do_int80_syscall_32+0x1d2/0x5f0
[ 244.859003] entry_INT80_compat+0x88/0xa0
[ 244.859972] INFO: task dnsmasq:668 blocked for more than 120 seconds.
[ 244.868315] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.869583] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.871744] dnsmasq D 0 668 1 0x20020000
[ 244.873063] Call Trace:
[ 244.873697] ? __schedule+0x843/0x950
[ 244.874572] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.875725] schedule+0x31/0x70
[ 244.876576] schedule_timeout+0x34/0x760
[ 244.877573] ? ftrace_likely_update+0x35/0x60
[ 244.878660] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.879872] ? ftrace_likely_update+0x35/0x60
[ 244.890522] ? ftrace_likely_update+0x35/0x60
[ 244.891572] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.892746] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.893861] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.894841] tty_ldisc_ref_wait+0x25/0x50
[ 244.895911] tty_compat_ioctl+0x8a/0x120
[ 244.896916] ? this_tty+0x80/0x80
[ 244.897717] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.898821] do_int80_syscall_32+0x1d2/0x5f0
[ 244.899830] entry_INT80_compat+0x88/0xa0
[ 244.909466] INFO: task dropbear:734 blocked for more than 120 seconds.
[ 244.911173] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.912394] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.914176] dropbear D 0 734 1 0x20020000
[ 244.915446] Call Trace:
[ 244.916068] ? __schedule+0x843/0x950
[ 244.916945] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.918076] schedule+0x31/0x70
[ 244.918832] schedule_timeout+0x34/0x760
[ 244.919781] ? ftrace_likely_update+0x35/0x60
[ 244.921104] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.922304] ? ftrace_likely_update+0x35/0x60
[ 244.923347] ? ftrace_likely_update+0x35/0x60
[ 244.924369] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.925496] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.926598] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.927578] tty_ldisc_ref_wait+0x25/0x50
[ 244.928526] tty_compat_ioctl+0x8a/0x120
[ 244.929449] ? this_tty+0x80/0x80
[ 244.930240] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.940083] do_int80_syscall_32+0x1d2/0x5f0
[ 244.941310] entry_INT80_compat+0x88/0xa0
[ 244.944070]
[ 244.944070] Showing all locks held in the system:
[ 244.945558] 1 lock held by khungtaskd/18:
[ 244.946495] #0: (____ptrval____) (rcu_read_lock){....}, at: debug_show_all_locks+0x16/0x190
[ 244.948503] 2 locks held by askfirst/235:
[ 244.949439] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.951762] #1: (____ptrval____) (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x13d/0xa00
[ 244.953799] 1 lock held by validate_data/655:
[ 244.954814] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.956764] 1 lock held by dnsmasq/668:
[ 244.957649] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.959598] 1 lock held by dropbear/734:
[ 244.967564] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.969581]
[ 244.969975] =============================================
[ 244.969975]
[ 244.971833] NMI backtrace for cpu 0
[ 244.972696] CPU: 0 PID: 18 Comm: khungtaskd Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.974371] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 244.976260] Call Trace:
[ 244.976895] dump_stack+0xb9/0x10e
[ 244.977723] ? lapic_can_unplug_cpu+0xa0/0xa0
[ 244.978735] nmi_cpu_backtrace+0x13a/0x150
[ 244.979697] ? lapic_can_unplug_cpu+0xa0/0xa0
[ 244.980713] nmi_trigger_cpumask_backtrace+0x188/0x280
[ 244.981899] watchdog+0x83b/0x880
[ 244.982683] ? reset_hung_task_detector+0x20/0x20
[ 244.983762] kthread+0x170/0x180
[ 244.984509] ? kthread_create_worker_on_cpu+0x70/0x70
[ 244.985659] ret_from_fork+0x24/0x30
[ 244.990807] Kernel panic - not syncing: hung_task: blocked tasks
[ 244.992205] CPU: 0 PID: 18 Comm: khungtaskd Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.993881] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 244.995769] Call Trace:
[ 244.996362] dump_stack+0xb9/0x10e
[ 244.997166] panic+0xfd/0x2bb
[ 244.997878] ? nmi_trigger_cpumask_backtrace+0x269/0x280
[ 244.999097] ? watchdog+0x83b/0x880
[ 244.999982] watchdog+0x847/0x880
[ 245.000782] ? reset_hung_task_detector+0x20/0x20
[ 245.001862] kthread+0x170/0x180
[ 245.002613] ? kthread_create_worker_on_cpu+0x70/0x70
[ 245.003785] ret_from_fork+0x24/0x30
[ 245.004646] Kernel Offset: 0x10800000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[ 245.007065] Rebooting in 3 seconds..
Elapsed time: 250
#!/bin/bash
# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH
kernel=$1
initrds=(
/osimage/openwrt/openwrt-i386-2016-03-16.cgz
/lkp/lkp/lkp-i386.cgz
/osimage/pkg/debian-x86_64-2016-08-31.cgz/trinity-static-i386-x86_64-6ddabfd2_2017-11-10.cgz
)
HTTP_PREFIX=https://download.01.org/0day-ci/lkp-qemu
wget --timestamping "${initrds[@]/#/$HTTP_PREFIX}"
{
cat "${initrds[@]//*\//}"
[[ $INSTALL_MOD_PATH ]] && (
cd "$INSTALL_MOD_PATH"
find lib | cpio -o -H newc --quiet | gzip
)
echo job-script | cpio -o -H newc --quiet | gzip
} > initrd.img
qemu-img create -f qcow2 disk-vm-lkp-hsw-4ep1-openwrt-ia32-13-0 256G
qemu-img create -f qcow2 disk-vm-lkp-hsw-4ep1-openwrt-ia32-13-1 256G
kvm=(
qemu-system-x86_64
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Rong, Chen
View attachment "config-4.18.0-11684-g0b4f83d" of type "text/plain" (87319 bytes)
View attachment "job-script" of type "text/plain" (4066 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (17852 bytes)
Powered by blists - more mailing lists