tty: deadlock between tty_buffer_flush/n_tracesink_open

From: Dmitry Vyukov
Date: Sun Feb 14 2016 - 13:21:33 EST

Next message: Clemens Gruber: "Re: [PATCH] Revert "net: phy: turn carrier off on phy attach""
Previous message: Linus Walleij: "Re: [lkp] [gpio] 3c702e9987: kmsg.user_verbs:couldn't_register_device_number"
Next in thread: Dmitry Vyukov: "Re: tty: deadlock between tty_buffer_flush/n_tracesink_open"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hello,

I've finally got the tty deadlock report with lockdep stack collection
bug fixed. This is on commit 388f7b1d6e8ca06762e2454d28d6c3c55ad0fe95
(4.5-rc3).

======================================================
[ INFO: possible circular locking dependency detected ]
4.5.0-rc3+ #326 Not tainted
-------------------------------------------------------
syz-executor/337 is trying to acquire lock:
(&port->buf.lock/1){+.+...}, at: [<ffffffff82f9f1bf>]
tty_buffer_flush+0xbf/0x3c0 drivers/tty/tty_buffer.c:244

but task is already holding lock:
(writelock){+.+...}, at: [<ffffffff82fb7703>]
n_tracesink_open+0x23/0xf0 drivers/tty/n_tracesink.c:78

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #4 (writelock){+.+...}:
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430
kernel/locking/lockdep.c:3589
[< inline >] __mutex_lock_common kernel/locking/mutex.c:518
[<ffffffff86657751>] mutex_lock_nested+0xb1/0xa50
kernel/locking/mutex.c:618
[<ffffffff82fb75c4>] n_tracesink_datadrain+0x24/0xc0
drivers/tty/n_tracesink.c:173
[<ffffffff82fb716b>] n_tracerouter_receivebuf+0x2b/0x40
drivers/tty/n_tracerouter.c:176
[< inline >] receive_buf drivers/tty/tty_buffer.c:454
[<ffffffff82f9eb34>] flush_to_ldisc+0x584/0x7f0
drivers/tty/tty_buffer.c:517
[<ffffffff813a3eb6>] process_one_work+0x796/0x1440
kernel/workqueue.c:2037
[<ffffffff813a4c3b>] worker_thread+0xdb/0xfc0 kernel/workqueue.c:2171
[<ffffffff813b7edf>] kthread+0x23f/0x2d0 drivers/block/aoe/aoecmd.c:1303
[<ffffffff866617af>] ret_from_fork+0x3f/0x70
arch/x86/entry/entry_64.S:468

-> #3 (routelock){+.+...}:
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430
kernel/locking/lockdep.c:3589
[< inline >] __mutex_lock_common kernel/locking/mutex.c:518
[<ffffffff86657751>] mutex_lock_nested+0xb1/0xa50
kernel/locking/mutex.c:618
[<ffffffff82fb7160>] n_tracerouter_receivebuf+0x20/0x40
drivers/tty/n_tracerouter.c:175
[< inline >] receive_buf drivers/tty/tty_buffer.c:454
[<ffffffff82f9eb34>] flush_to_ldisc+0x584/0x7f0
drivers/tty/tty_buffer.c:517
[<ffffffff813a3eb6>] process_one_work+0x796/0x1440
kernel/workqueue.c:2037
[<ffffffff813a4c3b>] worker_thread+0xdb/0xfc0 kernel/workqueue.c:2171
[<ffffffff813b7edf>] kthread+0x23f/0x2d0 drivers/block/aoe/aoecmd.c:1303
[<ffffffff866617af>] ret_from_fork+0x3f/0x70
arch/x86/entry/entry_64.S:468

-> #2 (&buf->lock){+.+...}:
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430
kernel/locking/lockdep.c:3589
[< inline >] __mutex_lock_common kernel/locking/mutex.c:518
[<ffffffff86657751>] mutex_lock_nested+0xb1/0xa50
kernel/locking/mutex.c:618
[<ffffffff82f9f1bf>] tty_buffer_flush+0xbf/0x3c0
drivers/tty/tty_buffer.c:244
[<ffffffff82fa345c>] pty_flush_buffer+0x5c/0x180 drivers/tty/pty.c:225
[<ffffffff82f97b35>] tty_driver_flush_buffer+0x65/0x80
drivers/tty/tty_ioctl.c:94
[<ffffffff82f8d292>] isig+0x172/0x2c0 drivers/tty/n_tty.c:1148
[<ffffffff82f8ff82>] n_tty_receive_signal_char+0x22/0xf0
drivers/tty/n_tty.c:1249
[<ffffffff82f93b9d>] n_tty_receive_char_special+0x128d/0x2b30
drivers/tty/n_tty.c:1298
[< inline >] n_tty_receive_buf_fast drivers/tty/n_tty.c:1618
[< inline >] __receive_buf drivers/tty/n_tty.c:1652
[<ffffffff82f96de3>] n_tty_receive_buf_common+0x19a3/0x2400
drivers/tty/n_tty.c:1750
[<ffffffff82f97873>] n_tty_receive_buf2+0x33/0x40
drivers/tty/n_tty.c:1785
[< inline >] receive_buf drivers/tty/tty_buffer.c:450
[<ffffffff82f9e96f>] flush_to_ldisc+0x3bf/0x7f0
drivers/tty/tty_buffer.c:517
[<ffffffff813a3eb6>] process_one_work+0x796/0x1440
kernel/workqueue.c:2037
[<ffffffff813a4c3b>] worker_thread+0xdb/0xfc0 kernel/workqueue.c:2171
[<ffffffff813b7edf>] kthread+0x23f/0x2d0 drivers/block/aoe/aoecmd.c:1303
[<ffffffff866617af>] ret_from_fork+0x3f/0x70
arch/x86/entry/entry_64.S:468

-> #1 (&o_tty->termios_rwsem/1){++++..}:
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430
kernel/locking/lockdep.c:3589
[<ffffffff8665cb97>] down_read+0x47/0x60 kernel/locking/rwsem.c:22
[<ffffffff82f954cd>] n_tty_receive_buf_common+0x8d/0x2400
drivers/tty/n_tty.c:1713
[<ffffffff82f97873>] n_tty_receive_buf2+0x33/0x40
drivers/tty/n_tty.c:1785
[< inline >] receive_buf drivers/tty/tty_buffer.c:450
[<ffffffff82f9e96f>] flush_to_ldisc+0x3bf/0x7f0
drivers/tty/tty_buffer.c:517
[<ffffffff813a3eb6>] process_one_work+0x796/0x1440
kernel/workqueue.c:2037
[<ffffffff813a4c3b>] worker_thread+0xdb/0xfc0 kernel/workqueue.c:2171
[<ffffffff813b7edf>] kthread+0x23f/0x2d0 drivers/block/aoe/aoecmd.c:1303
[<ffffffff866617af>] ret_from_fork+0x3f/0x70
arch/x86/entry/entry_64.S:468

-> #0 (&port->buf.lock/1){+.+...}:
[< inline >] check_prev_add kernel/locking/lockdep.c:1853
[< inline >] check_prevs_add kernel/locking/lockdep.c:1963
[< inline >] validate_chain kernel/locking/lockdep.c:2148
[<ffffffff81459859>] __lock_acquire+0x31e9/0x4700
kernel/locking/lockdep.c:3210
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430
kernel/locking/lockdep.c:3589
[< inline >] __mutex_lock_common kernel/locking/mutex.c:518
[<ffffffff86657751>] mutex_lock_nested+0xb1/0xa50
kernel/locking/mutex.c:618
[<ffffffff82f9f1bf>] tty_buffer_flush+0xbf/0x3c0
drivers/tty/tty_buffer.c:244
[<ffffffff82fa345c>] pty_flush_buffer+0x5c/0x180 drivers/tty/pty.c:225
[<ffffffff82f97b35>] tty_driver_flush_buffer+0x65/0x80
drivers/tty/tty_ioctl.c:94
[<ffffffff82fb7775>] n_tracesink_open+0x95/0xf0
drivers/tty/n_tracesink.c:85
[<ffffffff82f9c028>] tty_ldisc_open.isra.2+0x78/0xd0
drivers/tty/tty_ldisc.c:454
[<ffffffff82f9c612>] tty_set_ldisc+0x292/0x8a0
drivers/tty/tty_ldisc.c:561
[< inline >] tiocsetd drivers/tty/tty_io.c:2655
[<ffffffff82f852ee>] tty_ioctl+0xb2e/0x2160 drivers/tty/tty_io.c:2910
[< inline >] vfs_ioctl fs/ioctl.c:43
[<ffffffff817fc26c>] do_vfs_ioctl+0x18c/0xfb0 fs/ioctl.c:674
[< inline >] SYSC_ioctl fs/ioctl.c:689
[<ffffffff817fd11f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:680
[<ffffffff866613f6>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185

other info that might help us debug this:

Chain exists of:
&port->buf.lock/1 --> routelock --> writelock
Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(writelock);
lock(routelock);
lock(writelock);
lock(&port->buf.lock/1);

*** DEADLOCK ***

4 locks held by syz-executor/337:
#0: (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff8666123a>]
tty_lock+0x6a/0xe0 drivers/tty/tty_mutex.c:18
#1: (&tty->ldisc_sem){++++++}, at: [<ffffffff866602d7>]
ldsem_down_write+0x37/0x3c drivers/tty/tty_ldsem.c:393
#2: (writelock){+.+...}, at: [<ffffffff82fb7703>]
n_tracesink_open+0x23/0xf0 drivers/tty/n_tracesink.c:78
#3: (&tty->ldisc_sem){++++++}, at: [<ffffffff82f9ba4b>]
tty_ldisc_ref+0x1b/0x80 drivers/tty/tty_ldisc.c:283

stack backtrace:
CPU: 3 PID: 337 Comm: syz-executor Not tainted 4.5.0-rc3+ #326
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
ffffffff87b05080 ffff88005e4e76e0 ffffffff82be461f ffffffff00000000
fffffbfff0f60a10 ffffffff895f0280 ffffffff895ac720 ffffffff895f4e70
ffff88006997a028 ffff8800699797c0 ffff88005e4e7730 ffffffff81452a88
Call Trace:
[< inline >] __dump_stack lib/dump_stack.c:15
[<ffffffff82be461f>] dump_stack+0x12e/0x18f lib/dump_stack.c:51
[<ffffffff81452a88>] print_circular_bug+0x288/0x340
kernel/locking/lockdep.c:1226
[< inline >] check_prev_add kernel/locking/lockdep.c:1853
[< inline >] check_prevs_add kernel/locking/lockdep.c:1963
[< inline >] validate_chain kernel/locking/lockdep.c:2148
[<ffffffff81459859>] __lock_acquire+0x31e9/0x4700 kernel/locking/lockdep.c:3210
[<ffffffff8145d1bc>] lock_acquire+0x1dc/0x430 kernel/locking/lockdep.c:3589
[< inline >] __mutex_lock_common kernel/locking/mutex.c:518
[<ffffffff86657751>] mutex_lock_nested+0xb1/0xa50 kernel/locking/mutex.c:618
[<ffffffff82f9f1bf>] tty_buffer_flush+0xbf/0x3c0 drivers/tty/tty_buffer.c:244
[<ffffffff82fa345c>] pty_flush_buffer+0x5c/0x180 drivers/tty/pty.c:225
[<ffffffff82f97b35>] tty_driver_flush_buffer+0x65/0x80
drivers/tty/tty_ioctl.c:94
[<ffffffff82fb7775>] n_tracesink_open+0x95/0xf0 drivers/tty/n_tracesink.c:85
[<ffffffff82f9c028>] tty_ldisc_open.isra.2+0x78/0xd0
drivers/tty/tty_ldisc.c:454
[<ffffffff82f9c612>] tty_set_ldisc+0x292/0x8a0 drivers/tty/tty_ldisc.c:561
[< inline >] tiocsetd drivers/tty/tty_io.c:2655
[<ffffffff82f852ee>] tty_ioctl+0xb2e/0x2160 drivers/tty/tty_io.c:2910
[< inline >] vfs_ioctl fs/ioctl.c:43
[<ffffffff817fc26c>] do_vfs_ioctl+0x18c/0xfb0 fs/ioctl.c:674
[< inline >] SYSC_ioctl fs/ioctl.c:689
[<ffffffff817fd11f>] SyS_ioctl+0x8f/0xc0 fs/ioctl.c:680
[<ffffffff866613f6>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185

Found with syzkaller fuzzer.

Next message: Clemens Gruber: "Re: [PATCH] Revert "net: phy: turn carrier off on phy attach""
Previous message: Linus Walleij: "Re: [lkp] [gpio] 3c702e9987: kmsg.user_verbs:couldn't_register_device_number"
Next in thread: Dmitry Vyukov: "Re: tty: deadlock between tty_buffer_flush/n_tracesink_open"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]