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

Powered by Openwall GNU/*/Linux Powered by OpenVZ