Re: [linux next] tty/pty: possible circular locking dependency detected

From: Sergey Senozhatsky
Date: Fri Mar 29 2019 - 03:58:50 EST

Cc-ing Sahara

On (03/29/19 16:35), Sergey Senozhatsky wrote:
> 5.1.0-rc2-next-20190329
>
> [ 8.168722] ======================================================
> [ 8.168723] WARNING: possible circular locking dependency detected
> [ 8.168724] 5.1.0-rc2-next-20190329-dbg-00014-g4d25d68aaf88-dirty #3228 Not tainted
> [ 8.168725] ------------------------------------------------------
> [ 8.168726] bash/380 is trying to acquire lock:
> [ 8.168727] 00000000acce3dce (tty_mutex){+.+.}, at: pty_write+0x31/0xd0
> [ 8.168730]
> but task is already holding lock:
> [ 8.168731] 00000000c4f3448a (&ldata->output_lock){+.+.}, at: n_tty_write+0x1b9/0x4a0
> [ 8.168733]
> which lock already depends on the new lock.
>

Reverting b9ca5f8560af244 (tty: pty: Fix race condition between
release_one_tty and pty_write) fixes the warning.

Looking at b9ca5f8560af244, so all pty writes are serialized with
a global lock? Is this really a great idea?


I'll keep the lockdep splat for Sahara.

> [ 8.168733]
> the existing dependency chain (in reverse order) is:
> [ 8.168734]
> -> #4 (&ldata->output_lock){+.+.}:
> [ 8.168737] __mutex_lock+0x7e/0x8c0
> [ 8.168738] n_tty_write+0x1b9/0x4a0
> [ 8.168739] tty_write+0x192/0x2a0
> [ 8.168741] vfs_write+0xb8/0x1a0
> [ 8.168742] ksys_write+0x45/0xb0
> [ 8.168744] do_syscall_64+0x59/0x3bb
> [ 8.168746] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 8.168746]
> -> #3 (&tty->termios_rwsem){++++}:
> [ 8.168748] down_write+0x38/0x70
> [ 8.168749] tty_unthrottle+0x19/0x60
> [ 8.168750] n_tty_open+0x86/0xa0
> [ 8.168751] tty_ldisc_open.isra.0+0x2b/0x40
> [ 8.168752] tty_ldisc_setup+0x1e/0x60
> [ 8.168753] tty_init_dev+0xd9/0x1c0
> [ 8.168754] tty_open+0x300/0x3c0
> [ 8.168756] chrdev_open+0x97/0x1c0
> [ 8.168757] do_dentry_open+0x12f/0x370
> [ 8.168758] path_openat+0x2ce/0xaa0
> [ 8.168759] do_filp_open+0x7e/0xd0
> [ 8.168760] do_sys_open+0x15d/0x210
> [ 8.168762] kernel_init_freeable+0x2ae/0x317
> [ 8.168764] kernel_init+0xa/0x101
> [ 8.168765] ret_from_fork+0x3a/0x50
> [ 8.168765]
> -> #2 (&tty->ldisc_sem){++++}:
> [ 8.168767] __ldsem_down_write_nested+0x55/0x280
> [ 8.168768] tty_ldisc_lock+0x4b/0x70
> [ 8.168770] tty_init_dev+0x93/0x1c0
> [ 8.168771] tty_open+0x300/0x3c0
> [ 8.168772] chrdev_open+0x97/0x1c0
> [ 8.168773] do_dentry_open+0x12f/0x370
> [ 8.168774] path_openat+0x2ce/0xaa0
> [ 8.168775] do_filp_open+0x7e/0xd0
> [ 8.168776] do_sys_open+0x15d/0x210
> [ 8.168777] kernel_init_freeable+0x2ae/0x317
> [ 8.168778] kernel_init+0xa/0x101
> [ 8.168779] ret_from_fork+0x3a/0x50
> [ 8.168780]
> -> #1 (&tty->legacy_mutex){+.+.}:
> [ 8.168781] __mutex_lock+0x7e/0x8c0
> [ 8.168782] tty_init_dev+0x50/0x1c0
> [ 8.168784] tty_open+0x300/0x3c0
> [ 8.168785] chrdev_open+0x97/0x1c0
> [ 8.168786] do_dentry_open+0x12f/0x370
> [ 8.168787] path_openat+0x2ce/0xaa0
> [ 8.168788] do_filp_open+0x7e/0xd0
> [ 8.168789] do_sys_open+0x15d/0x210
> [ 8.168790] kernel_init_freeable+0x2ae/0x317
> [ 8.168791] kernel_init+0xa/0x101
> [ 8.168792] ret_from_fork+0x3a/0x50
> [ 8.168793]
> -> #0 (tty_mutex){+.+.}:
> [ 8.168794] lock_acquire+0x9a/0x170
> [ 8.168795] __mutex_lock+0x7e/0x8c0
> [ 8.168796] pty_write+0x31/0xd0
> [ 8.168797] n_tty_write+0x130/0x4a0
> [ 8.168798] tty_write+0x192/0x2a0
> [ 8.168800] vfs_write+0xb8/0x1a0
> [ 8.168801] ksys_write+0x45/0xb0
> [ 8.168802] do_syscall_64+0x59/0x3bb
> [ 8.168803] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 8.168804]
> other info that might help us debug this:
>
> [ 8.168804] Chain exists of:
> tty_mutex --> &tty->termios_rwsem --> &ldata->output_lock
>
> [ 8.168806] Possible unsafe locking scenario:
>
> [ 8.168806] CPU0 CPU1
> [ 8.168807] ---- ----
> [ 8.168807] lock(&ldata->output_lock);
> [ 8.168808] lock(&tty->termios_rwsem);
> [ 8.168809] lock(&ldata->output_lock);
> [ 8.168810] lock(tty_mutex);
> [ 8.168810]
> *** DEADLOCK ***
>
> [ 8.168811] 4 locks held by bash/380:
> [ 8.168812] #0: 0000000022cdab25 (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x24/0x50
> [ 8.168814] #1: 00000000033fee14 (&tty->atomic_write_lock){+.+.}, at: tty_write_lock+0x18/0x50
> [ 8.168815] #2: 00000000135c3a23 (&o_tty->termios_rwsem/1){++++}, at: n_tty_write+0x8c/0x4a0
> [ 8.168817] #3: 00000000c4f3448a (&ldata->output_lock){+.+.}, at: n_tty_write+0x1b9/0x4a0
> [ 8.168819]
> stack backtrace:
> [ 8.168820] CPU: 1 PID: 380 Comm: bash Not tainted 5.1.0-rc2-next-20190329-dbg-00014-g4d25d68aaf88-dirty #3228
> [ 8.168821] Call Trace:
> [ 8.168823] dump_stack+0x67/0x90
> [ 8.168825] print_circular_bug.isra.0.cold+0x1c5/0x225
> [ 8.168826] check_prev_add.constprop.0+0x5f5/0xd20
> [ 8.168828] ? mutex_destroy+0x50/0x50
> [ 8.168829] __lock_acquire+0xc28/0xf90
> [ 8.168830] ? __lock_acquire+0xc28/0xf90
> [ 8.168831] lock_acquire+0x9a/0x170
> [ 8.168833] ? pty_write+0x31/0xd0
> [ 8.168834] ? pty_write+0x31/0xd0
> [ 8.168835] __mutex_lock+0x7e/0x8c0
> [ 8.168836] ? pty_write+0x31/0xd0
> [ 8.168837] ? n_tty_write+0x1b9/0x4a0
> [ 8.168838] ? __mutex_lock+0x7e/0x8c0
> [ 8.168839] ? pty_write+0x31/0xd0
> [ 8.168840] ? n_tty_write+0x1b9/0x4a0
> [ 8.168842] ? pty_write+0x31/0xd0
> [ 8.168843] pty_write+0x31/0xd0
> [ 8.168844] n_tty_write+0x130/0x4a0
> [ 8.168845] ? wait_woken+0xa0/0xa0
> [ 8.168846] tty_write+0x192/0x2a0
> [ 8.168847] ? n_tty_open+0xa0/0xa0
> [ 8.168849] vfs_write+0xb8/0x1a0
> [ 8.168850] ksys_write+0x45/0xb0
> [ 8.168851] do_syscall_64+0x59/0x3bb
> [ 8.168852] ? trace_hardirqs_off_thunk+0x1a/0x1c
> [ 8.168854] entry_SYSCALL_64_after_hwframe+0x49/0xbe

-ss