[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170607020738.GF2969@yexl-desktop>
Date: Wed, 7 Jun 2017 10:07:38 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Mike Galbraith <efault@....de>
Cc: Vegard Nossum <vegard.nossum@...cle.com>,
Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Dave Jones <davej@...emonkey.org.uk>,
Linux Kernel <linux-kernel@...r.kernel.org>,
Jiri Slaby <jslaby@...e.com>, lkp@...org
Subject: [lkp-robot] [tty] 52b03e644f: calltrace:flush_to_ldisc
FYI, we noticed the following commit:
commit: 52b03e644f702dbcb252f6aec92fc0f0d6e29f78 ("tty: fix port buffer locking V2")
url: https://github.com/0day-ci/linux/commits/Mike-Galbraith/tty-fix-port-buffer-locking-V2/20170605-134432
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 -cpu SandyBridge -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------+------------+------------+
| | 094094a937 | 52b03e644f |
+--------------------------------------------------+------------+------------+
| boot_successes | 4 | 2 |
| boot_failures | 4 | 4 |
| BUG:kernel_hang_in_test_stage | 4 | |
| calltrace:flush_to_ldisc | 0 | 4 |
| INFO:task_blocked_for_more_than#seconds | 0 | 4 |
| INFO:lockdep_is_turned_off | 0 | 4 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 4 |
+--------------------------------------------------+------------+------------+
[ 9.320461] WARNING: possible recursive locking detected
[ 9.321874] 4.12.0-rc3-00033-g52b03e6 #39 Not tainted
[ 9.323249] --------------------------------------------
[ 9.324663] kworker/u2:5/140 is trying to acquire lock:
[ 9.326056] (&tty->atomic_write_lock){+.+.+.}, at: [<ffffffffa4678e69>] tty_port_default_receive_buf+0x4e/0x81
[ 9.328716]
[ 9.328716] but task is already holding lock:
[ 9.330742] (&tty->atomic_write_lock){+.+.+.}, at: [<ffffffffa46788ed>] flush_to_ldisc+0x48/0xf6
[ 9.346254]
[ 9.346254] other info that might help us debug this:
[ 9.348393] Possible unsafe locking scenario:
[ 9.348393]
[ 9.350438] CPU0
[ 9.351425] ----
[ 9.352419] lock(&tty->atomic_write_lock);
[ 9.353679] lock(&tty->atomic_write_lock);
[ 9.354934]
[ 9.354934] *** DEADLOCK ***
[ 9.354934]
[ 9.357511] May be due to missing lock nesting notation
[ 9.357511]
[ 9.372673] 6 locks held by kworker/u2:5/140:
[ 9.373945] #0: ("events_unbound"){.+.+.+}, at: [<ffffffffa40b8d8b>] process_one_work+0x165/0x56d
[ 9.376458] #1: ((&buf->work)){+.+...}, at: [<ffffffffa40b8d8b>] process_one_work+0x165/0x56d
[ 9.378918] #2: (&tty->ldisc_sem){++++.+}, at: [<ffffffffa4677c39>] tty_ldisc_ref+0x1f/0x41
[ 9.381356] #3: (&tty->atomic_write_lock){+.+.+.}, at: [<ffffffffa46788ed>] flush_to_ldisc+0x48/0xf6
[ 9.383917] #4: (&buf->lock){+.+...}, at: [<ffffffffa46788fb>] flush_to_ldisc+0x56/0xf6
[ 9.399315] #5: (&tty->ldisc_sem){++++.+}, at: [<ffffffffa4677c39>] tty_ldisc_ref+0x1f/0x41
[ 9.401739]
[ 9.401739] stack backtrace:
[ 9.403544] CPU: 0 PID: 140 Comm: kworker/u2:5 Not tainted 4.12.0-rc3-00033-g52b03e6 #39
[ 9.405898] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 9.408556] Workqueue: events_unbound flush_to_ldisc
[ 9.409914] Call Trace:
[ 9.410910] dump_stack+0x86/0xc0
[ 9.412030] __lock_acquire+0x86b/0xe43
[ 9.413230] lock_acquire+0x142/0x1dd
[ 9.414401] ? tty_port_default_receive_buf+0x4e/0x81
[ 9.415769] __mutex_lock+0x8a/0x815
[ 9.416932] ? tty_port_default_receive_buf+0x4e/0x81
[ 9.418317] ? find_held_lock+0x31/0x73
[ 9.419517] ? tty_port_default_receive_buf+0x4e/0x81
[ 9.420888] ? tty_ldisc_ref+0x1f/0x41
[ 9.422076] mutex_lock_nested+0x1b/0x1d
[ 9.423290] ? mutex_lock_nested+0x1b/0x1d
[ 9.424525] tty_port_default_receive_buf+0x4e/0x81
[ 9.425880] flush_to_ldisc+0xba/0xf6
[ 9.427051] process_one_work+0x283/0x56d
[ 9.428277] worker_thread+0x1f3/0x2c5
[ 9.429460] ? rescuer_thread+0x2ca/0x2ca
[ 9.430682] kthread+0x134/0x13c
[ 9.431787] ? kthread_create_on_node+0x3f/0x3f
[ 9.433083] ret_from_fork+0x2a/0x40
[ 9.762099] random: dd: uninitialized urandom read (512 bytes read)
Poky (Yocto Project Reference Distro) 2.1 qemux86-64 /dev/ttyS0
[ 62.664612] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 62.666546] rcu-torture: Reader Batch: 1 1 0 0 0 0 0 0 0 0 0
[ 62.668279] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 124.100000] rcu-torture: rtc: ffffffffa67031e0 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 cbflood: 1
[ 124.104845] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 124.106669] rcu-torture: Reader Batch: 1 1 0 0 0 0 0 0 0 0 0
[ 124.108507] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 124.110337] ??? Writer stall state RTWS_STUTTER(8) g3977 c3976 f0x0 ->state 0x1
[ 124.112729] rcu_sched: wait state: 1 ->state: 0x1
[ 124.121003] rcu_bh: wait state: 1 ->state: 0x1
[ 124.122436] Dumping ftrace buffer:
[ 124.123613] (ftrace buffer empty)
[ 185.540010] rcu-torture: rtc: ffffffffa67031e0 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 cbflood: 1
[ 185.546024] rcu-torture: Reader Pipe: 2 0 0 0 0 0 0 0 0 0 0
[ 185.548198] rcu-torture: Reader Batch: 1 1 0 0 0 0 0 0 0 0 0
[ 185.550097] rcu-torture: Free-Block Circulation: 0 0 0 0 0 0 0 0 0 0 0
[ 185.552229] ??? Writer stall state RTWS_STUTTER(8) g3979 c3978 f0x0 ->state 0x1
[ 185.554941] rcu_sched: wait state: 1 ->state: 0x1
[ 185.556603] rcu_bh: wait state: 1 ->state: 0x1
[ 246.980009] rcu-torture: rtc: ffffffffa67031e0 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 cbflood: 1
[ 246.985336] INFO: task kworker/u2:5:140 blocked for more than 120 seconds.
[ 246.985338] Not tainted 4.12.0-rc3-00033-g52b03e6 #39
[ 246.985339] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 246.985341] kworker/u2:5 D13128 140 2 0x00000000
[ 246.985361] Workqueue: events_unbound flush_to_ldisc
[ 246.985363] Call Trace:
[ 246.985370] __schedule+0x8cd/0xa60
[ 246.985373] ? kvm_sched_clock_read+0x9/0x12
[ 246.985377] schedule+0x89/0x9a
[ 246.985379] schedule_preempt_disabled+0x15/0x1e
[ 246.985381] __mutex_lock+0x595/0x815
[ 246.985480] ? tty_port_default_receive_buf+0x4e/0x81
[ 246.985484] ? tty_ldisc_ref+0x1f/0x41
[ 246.985488] mutex_lock_nested+0x1b/0x1d
[ 246.985489] ? mutex_lock_nested+0x1b/0x1d
[ 246.985492] tty_port_default_receive_buf+0x4e/0x81
[ 246.985495] flush_to_ldisc+0xba/0xf6
[ 246.985499] process_one_work+0x283/0x56d
[ 246.985503] worker_thread+0x1f3/0x2c5
[ 246.985507] ? rescuer_thread+0x2ca/0x2ca
[ 246.985509] kthread+0x134/0x13c
[ 246.985511] ? kthread_create_on_node+0x3f/0x3f
[ 246.985514] ret_from_fork+0x2a/0x40
[ 246.985519] INFO: lockdep is turned off.
[ 246.985520] NMI backtrace for cpu 0
[ 246.985523] CPU: 0 PID: 672 Comm: khungtaskd Not tainted 4.12.0-rc3-00033-g52b03e6 #39
[ 246.985524] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 246.985525] Call Trace:
[ 246.985528] dump_stack+0x86/0xc0
[ 246.985530] nmi_cpu_backtrace+0x7f/0x9c
[ 246.985533] ? irq_force_complete_move+0xeb/0xeb
[ 246.985535] nmi_trigger_cpumask_backtrace+0x62/0xc6
[ 246.985538] arch_trigger_cpumask_backtrace+0x19/0x1b
[ 246.985540] watchdog+0x486/0x55d
[ 246.985543] ? reset_hung_task_detector+0x15/0x15
[ 246.985545] kthread+0x134/0x13c
[ 246.985547] ? kthread_create_on_node+0x3f/0x3f
[ 246.985549] ret_from_fork+0x2a/0x40
[ 246.985555] Kernel panic - not syncing: hung_task: blocked tasks
[ 246.985557] CPU: 0 PID: 672 Comm: khungtaskd Not tainted 4.12.0-rc3-00033-g52b03e6 #39
[ 246.985558] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 246.985559] Call Trace:
[ 246.985560] dump_stack+0x86/0xc0
[ 246.985563] panic+0xdd/0x221
[ 246.985568] watchdog+0x492/0x55d
[ 246.985570] ? reset_hung_task_detector+0x15/0x15
[ 246.985572] kthread+0x134/0x13c
[ 246.985574] ? kthread_create_on_node+0x3f/0x3f
[ 246.985577] ret_from_fork+0x2a/0x40
[ 246.985632] Kernel Offset: 0x23000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
Elapsed time: 250
initrds=(
/osimage/yocto/yocto-minimal-x86_64-2016-04-22.cgz
/lkp/scheduled/vm-kbuild-yocto-x86_64-4/trinity-300s-yocto-minimal-x86_64-2016-04-22.cgz-52b03e644f702dbcb252f6aec92fc0f0d6e29f78-20170606-60571-12g8yql-0.cgz
/lkp/lkp/lkp-x86_64.cgz
/osimage/pkg/static/trinity-x86_64.cgz
/pkg/linux/x86_64-nfsroot/gcc-6/52b03e644f702dbcb252f6aec92fc0f0d6e29f78/modules.cgz
)
cat "${initrds[@]}" > /fs/sdh1/initrd-vm-kbuild-yocto-x86_64-4
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel /pkg/linux/x86_64-nfsroot/gcc-6/52b03e644f702dbcb252f6aec92fc0f0d6e29f78/vmlinuz-4.12.0-rc3-00033-g52b03e6
-initrd /fs/sdh1/initrd-vm-kbuild-yocto-x86_64-4
-m 512
-smp 1
-device e1000,netdev=net0
-netdev user,id=net0
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-drive file=/fs/sdh1/disk0-vm-kbuild-yocto-x86_64-4,media=disk,if=virtio
-pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-x86_64-4
-serial file:/dev/shm/kboot/vm-kbuild-yocto-x86_64-4/serial
-serial file:/dev/shm/kboot/vm-kbuild-yocto-x86_64-4/kmsg
-daemonize
-display none
-monitor null
)
append=(
ip=::::vm-kbuild-yocto-x86_64-4::dhcp
root=/dev/ram0
user=lkp
job=/lkp/scheduled/vm-kbuild-yocto-x86_64-4/trinity-300s-yocto-minimal-x86_64-2016-04-22.cgz-52b03e644f702dbcb252f6aec92fc0f0d6e29f78-20170606-60571-12g8yql-0.yaml
ARCH=x86_64
kconfig=x86_64-nfsroot
branch=linux-devel/devel-catchup-201706051509
commit=52b03e644f702dbcb252f6aec92fc0f0d6e29f78
BOOT_IMAGE=/pkg/linux/x86_64-nfsroot/gcc-6/52b03e644f702dbcb252f6aec92fc0f0d6e29f78/vmlinuz-4.12.0-rc3-00033-g52b03e6
max_uptime=1500
RESULT_ROOT=/result/trinity/300s/vm-kbuild-yocto-x86_64/yocto-minimal-x86_64-2016-04-22.cgz/x86_64-nfsroot/gcc-6/52b03e644f702dbcb252f6aec92fc0f0d6e29f78/0
LKP_SERVER=inn
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
drbd.minor_count=8
systemd.log_level=err
ignore_loglevel
earlyprintk=ttyS0,115200
console=ttyS0,115200
console=tty0
vga=normal
rw
drbd.minor_count=8
)
"${kvm[@]}" -append "${append[*]}"
To reproduce:
git clone https://github.com/01org/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
View attachment "config-4.12.0-rc3-00033-g52b03e6" of type "text/plain" (117109 bytes)
View attachment "job-script" of type "text/plain" (3827 bytes)
Download attachment "dmesg.xz" of type "application/octet-stream" (15028 bytes)
Powered by blists - more mailing lists