Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1654480 > unrolled thread

tty lockdep trace

Started byDave Jones <davej@codemonkey.org.uk>
First post2017-05-31 19:30 +0200
Last post2017-06-05 09:20 +0200
Articles 11 — 5 participants

Back to article view | Back to linux.kernel


Contents

  tty lockdep trace Dave Jones <davej@codemonkey.org.uk> - 2017-05-31 19:30 +0200
    [bisected] Re: tty lockdep trace Mike Galbraith <efault@gmx.de> - 2017-06-03 08:40 +0200
      Re: [bisected] Re: tty lockdep trace Greg Kroah-Hartman <gregkh@linuxfoundation.org> - 2017-06-04 10:40 +0200
        Re: [bisected] Re: tty lockdep trace Mike Galbraith <efault@gmx.de> - 2017-06-04 11:10 +0200
          Re: [bisected] Re: tty lockdep trace Vegard Nossum <vegard.nossum@oracle.com> - 2017-06-04 12:10 +0200
            Re: [bisected] Re: tty lockdep trace Mike Galbraith <efault@gmx.de> - 2017-06-04 13:40 +0200
              Re: [bisected] Re: tty lockdep trace Alan Cox <gnomes@lxorguk.ukuu.org.uk> - 2017-06-05 17:10 +0200
                Re: [bisected] Re: tty lockdep trace Mike Galbraith <efault@gmx.de> - 2017-06-05 17:50 +0200
            [patch] tty: fix port buffer locking V2 Mike Galbraith <efault@gmx.de> - 2017-06-05 07:00 +0200
              Re: [patch] tty: fix port buffer locking V2 Greg Kroah-Hartman <gregkh@linuxfoundation.org> - 2017-06-05 08:50 +0200
                Re: [patch] tty: fix port buffer locking V2 Mike Galbraith <efault@gmx.de> - 2017-06-05 09:20 +0200

#1654480 — tty lockdep trace

FromDave Jones <davej@codemonkey.org.uk>
Date2017-05-31 19:30 +0200
Subjecttty lockdep trace
Message-ID<tNfBw-7MH-9@gated-at.bofh.it>
Just hit this during a trinity run.  sidenote: why is KERN_CONT buggered?

======================================================
WARNING: possible circular locking dependency detected
4.12.0-rc3-think+ #1 Not tainted
------------------------------------------------------
kworker/u8:1/15007 is trying to acquire lock:
 (
&buf->lock
){+.+...}
, at: [<ffffffff815cad67>] tty_buffer_flush+0x37/0xa0

but task is already holding lock:
 (
&o_tty->termios_rwsem
/1
){++++..}
, at: [<ffffffff815c5441>] isig+0x41/0xf0

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2
 (
&o_tty->termios_rwsem
/1
){++++..}
:
       lock_acquire+0xe7/0x1e0
       down_read+0x48/0xb0
       n_tty_write+0x9f/0x490
       tty_write+0x1b8/0x320
       __vfs_write+0x37/0x140
       vfs_write+0xca/0x1c0
       SyS_write+0x58/0xc0
       do_syscall_64+0x66/0x190
       return_from_SYSCALL_64+0x0/0x7a

-> #1
 (
&tty->atomic_write_lock
){+.+.+.}
:
       lock_acquire+0xe7/0x1e0
       __mutex_lock+0x97/0x9d0
       mutex_lock_nested+0x1b/0x20
       tty_port_default_receive_buf+0x48/0x90
       flush_to_ldisc+0xa1/0xb0
       process_one_work+0x24d/0x680
       worker_thread+0x4e/0x3b0
       kthread+0x117/0x150
       ret_from_fork+0x27/0x40

-> #0
 (
&buf->lock
){+.+...}
:
       __lock_acquire+0x11a2/0x1360
       lock_acquire+0xe7/0x1e0
       __mutex_lock+0x97/0x9d0
       mutex_lock_nested+0x1b/0x20
       tty_buffer_flush+0x37/0xa0
       pty_flush_buffer+0x27/0x80
       tty_driver_flush_buffer+0x1b/0x20
       isig+0x95/0xf0
       n_tty_receive_signal_char+0x1c/0x60
       n_tty_receive_char_special+0x834/0xac0
       n_tty_receive_buf_common+0xa29/0xc80
       n_tty_receive_buf2+0x14/0x20
       tty_ldisc_receive_buf+0x22/0x50
       tty_port_default_receive_buf+0x59/0x90
       flush_to_ldisc+0xa1/0xb0
       process_one_work+0x24d/0x680
       worker_thread+0x4e/0x3b0
       kthread+0x117/0x150
       ret_from_fork+0x27/0x40

other info that might help us debug this:

Chain exists of:
  
&buf->lock
 --> 
&tty->atomic_write_lock
 --> 
&o_tty->termios_rwsem
/1


 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(
&o_tty->termios_rwsem
/1
);
                               lock(
&tty->atomic_write_lock
);
                               lock(
&o_tty->termios_rwsem
/1
);
  lock(
&buf->lock
);

 *** DEADLOCK ***

6 locks held by kworker/u8:1/15007:
 #0: 
 (
"events_unbound"
){.+.+.+}
, at: [<ffffffff810a6522>] process_one_work+0x1c2/0x680
 #1: 
 (
(&buf->work)
){+.+...}
, at: [<ffffffff810a6522>] process_one_work+0x1c2/0x680
 #2: 
 (
&port->buf.lock
/1
){+.+...}
, at: [<ffffffff815ca825>] flush_to_ldisc+0x25/0xb0
 #3: 
 (
&tty->ldisc_sem
){++++.+}
, at: [<ffffffff815c9b9f>] tty_ldisc_ref+0x1f/0x60
 #4: 
 (
&tty->atomic_write_lock
){+.+.+.}
, at: [<ffffffff815cb198>] tty_port_default_receive_buf+0x48/0x90
 #5: 
 (
&o_tty->termios_rwsem
/1
){++++..}
, at: [<ffffffff815c5441>] isig+0x41/0xf0

stack backtrace:
CPU: 0 PID: 15007 Comm: kworker/u8:1 Not tainted 4.12.0-rc3-think+ #1 
Workqueue: events_unbound flush_to_ldisc
Call Trace:
 dump_stack+0x68/0x9f
 print_circular_bug+0x1be/0x210
 __lock_acquire+0x11a2/0x1360
 lock_acquire+0xe7/0x1e0
 ? lock_acquire+0xe7/0x1e0
 ? tty_buffer_flush+0x37/0xa0
 ? tty_buffer_flush+0x37/0xa0
 __mutex_lock+0x97/0x9d0
 ? tty_buffer_flush+0x37/0xa0
 ? debug_lockdep_rcu_enabled+0x1d/0x20
 ? tty_buffer_flush+0x37/0xa0
 ? isig+0x8d/0xf0
 mutex_lock_nested+0x1b/0x20
 ? mutex_lock_nested+0x1b/0x20
 tty_buffer_flush+0x37/0xa0
 pty_flush_buffer+0x27/0x80
 tty_driver_flush_buffer+0x1b/0x20
 isig+0x95/0xf0
 n_tty_receive_signal_char+0x1c/0x60
 n_tty_receive_char_special+0x834/0xac0
 n_tty_receive_buf_common+0xa29/0xc80
 n_tty_receive_buf2+0x14/0x20
 tty_ldisc_receive_buf+0x22/0x50
 ? mutex_lock_nested+0x1b/0x20
 tty_port_default_receive_buf+0x59/0x90
 flush_to_ldisc+0xa1/0xb0
 process_one_work+0x24d/0x680
 worker_thread+0x4e/0x3b0
 kthread+0x117/0x150
 ? process_one_work+0x680/0x680
 ? kthread_create_on_node+0x70/0x70
 ret_from_fork+0x27/0x40

[toc] | [next] | [standalone]


#1656728 — [bisected] Re: tty lockdep trace

FromMike Galbraith <efault@gmx.de>
Date2017-06-03 08:40 +0200
Subject[bisected] Re: tty lockdep trace
Message-ID<tOaT7-3vS-3@gated-at.bofh.it>
In reply to#1654480
On Wed, 2017-05-31 at 13:21 -0400, Dave Jones wrote:
> Just hit this during a trinity run.

925bb1ce47f429f69aad35876df7ecd8c53deb7e is the first bad commit
commit 925bb1ce47f429f69aad35876df7ecd8c53deb7e
Author: Vegard Nossum <vegard.nossum@oracle.com>
Date:   Thu May 11 12:18:52 2017 +0200

    tty: fix port buffer locking
    
    tty_insert_flip_string_fixed_flag() is racy against itself when called
    from the ioctl(TCXONC, TCION/TCIOFF) path [1] and the flush_to_ldisc()
    workqueue path [2].
    
    The problem is that port->buf.tail->used is modified without consistent
    locking; the ioctl path takes tty->atomic_write_lock, whereas the workqueue
    path takes ldata->output_lock.
    
    We cannot simply take ldata->output_lock, since that is specific to the
    N_TTY line discipline.
    
    It might seem natural to try to take port->buf.lock inside
    tty_insert_flip_string_fixed_flag() and friends (where port->buf is
    actually used/modified), but this creates problems for flush_to_ldisc()
    which takes it before grabbing tty->ldisc_sem, o_tty->termios_rwsem,
    and ldata->output_lock.
    
    Therefore, the simplest solution for now seems to be to take
    tty->atomic_write_lock inside tty_port_default_receive_buf(). This lock
    is also used in the write path [3] with a consistent ordering.
    
    [1]: Call Trace:
     tty_insert_flip_string_fixed_flag
     pty_write
     tty_send_xchar                     // down_read(&o_tty->termios_rwsem)
                                        // mutex_lock(&tty->atomic_write_lock)
     n_tty_ioctl_helper
     n_tty_ioctl
     tty_ioctl                          // down_read(&tty->ldisc_sem)
     do_vfs_ioctl
     SyS_ioctl
    
    [2]: Workqueue: events_unbound flush_to_ldisc
    Call Trace:
     tty_insert_flip_string_fixed_flag
     pty_write
     tty_put_char
     __process_echoes
     commit_echoes                      // mutex_lock(&ldata->output_lock)
     n_tty_receive_buf_common
     n_tty_receive_buf2
     tty_ldisc_receive_buf              // down_read(&o_tty->termios_rwsem)
     tty_port_default_receive_buf       // down_read(&tty->ldisc_sem)
     flush_to_ldisc                     // mutex_lock(&port->buf.lock)
     process_one_work
    
    [3]: Call Trace:
     tty_insert_flip_string_fixed_flag
     pty_write
     n_tty_write                        // mutex_lock(&ldata->output_lock)
                                        // down_read(&tty->termios_rwsem)
     do_tty_write (inline)              // mutex_lock(&tty->atomic_write_lock)
     tty_write                          // down_read(&tty->ldisc_sem)
     __vfs_write
     vfs_write
     SyS_write
    
    The bug can result in about a dozen different crashes depending on what
    exactly gets corrupted when port->buf.tail->used points outside the
    buffer.
    
    The patch passes my LOCKDEP/PROVE_LOCKING testing but more testing is
    always welcome.
    
    Found using syzkaller.
    
    Cc: <stable@vger.kernel.org>
    Signed-off-by: Vegard Nossum <vegard.nossum@oracle.com>
    Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

:040000 040000 6df9d7d2f22ff6ac1ad265869c1cb0d15621a0eb 56e5e66a5e451bf55857025899f4a092b51dca6e M      drivers

git bisect start
# good: [a351e9b9fc24e982ec2f0e76379a49826036da12] Linux 4.11
git bisect good a351e9b9fc24e982ec2f0e76379a49826036da12
# bad: [104c08ba8e921ef97abfdc10408d54921a6d9003] Merge tag 'acpi-4.12-rc4' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm
git bisect bad 104c08ba8e921ef97abfdc10408d54921a6d9003
# good: [16a12fa9aed176444fc795b09e796be41902bb08] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/dtor/input
git bisect good 16a12fa9aed176444fc795b09e796be41902bb08
# good: [2d3e4866dea96b0506395b47bfefb234f2088dac] Merge tag 'for-linus' of git://git.kernel.org/pub/scm/virt/kvm/kvm
git bisect good 2d3e4866dea96b0506395b47bfefb234f2088dac
# good: [f94c128eefcce2e3448d543f13cd7d7b8aa660a5] Merge tag 'metag-for-v4.12' of git://git.kernel.org/pub/scm/linux/kernel/git/jhogan/metag
git bisect good f94c128eefcce2e3448d543f13cd7d7b8aa660a5
# good: [18365225f0440d09708ad9daade2ec11275c3df9] hwpoison, memcg: forcibly uncharge LRU pages
git bisect good 18365225f0440d09708ad9daade2ec11275c3df9
# good: [5bbecdbc8e7ffaaf47ac1f02014bf3bedda3fd11] nvme_fc: Support ctrl_loss_tmo
git bisect good 5bbecdbc8e7ffaaf47ac1f02014bf3bedda3fd11
# good: [d024baa58a4a7e5eb6058017771d15b9e47b56db] Merge branch 'core-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good d024baa58a4a7e5eb6058017771d15b9e47b56db
# bad: [393bcfaeb8be7f46a4cd7d673e33541ebee76b12] Merge git://git.kernel.org/pub/scm/linux/kernel/git/nab/target-pending
git bisect bad 393bcfaeb8be7f46a4cd7d673e33541ebee76b12
# bad: [b0f5a8f32e8bbdaae1abb8abe2d3cbafaba57e08] kthread: fix boot hang (regression) on MIPS/OpenRISC
git bisect bad b0f5a8f32e8bbdaae1abb8abe2d3cbafaba57e08
# good: [6f68a6ae1f0ea2fd87e26dc345866e928b5850a8] Merge tag 'powerpc-4.12-4' of git://git.kernel.org/pub/scm/linux/kernel/git/powerpc/linux
git bisect good 6f68a6ae1f0ea2fd87e26dc345866e928b5850a8
# bad: [da4c279942b05727088774df224c0734688b4cbc] serial: enable serdev support
git bisect bad da4c279942b05727088774df224c0734688b4cbc
# good: [5c9d6abed9e0a061de252a53ab687a1171502e81] serial: altera_jtaguart: adding iounmap()
git bisect good 5c9d6abed9e0a061de252a53ab687a1171502e81
# bad: [925bb1ce47f429f69aad35876df7ecd8c53deb7e] tty: fix port buffer locking
git bisect bad 925bb1ce47f429f69aad35876df7ecd8c53deb7e
# good: [11d4d32158eeaf36fe1073a4a260193d7a19ccf1] tty: ehv_bytechan: clean up init error handling
git bisect good 11d4d32158eeaf36fe1073a4a260193d7a19ccf1
# first bad commit: [925bb1ce47f429f69aad35876df7ecd8c53deb7e] tty: fix port buffer locking

[   56.727594] ======================================================
[   56.728482] WARNING: possible circular locking dependency detected
[   56.729318] 4.12.0-master #108 Tainted: G            E  
[   56.730125] ------------------------------------------------------
[   56.731024] kworker/u8:3/329 is trying to acquire lock:
[   56.731774]  (&buf->lock){+.+...}, at: [<ffffffff81423e97>] tty_buffer_flush+0x37/0xa0
[   56.732773] 
               but task is already holding lock:
[   56.733444]  (&o_tty->termios_rwsem/1){++++..}, at: [<ffffffff8141fb91>] isig+0x41/0xf0
[   56.734303] 
               which lock already depends on the new lock.

[   56.734868] 
               the existing dependency chain (in reverse order) is:
[   56.735377] 
               -> #2 (&o_tty->termios_rwsem/1){++++..}:
[   56.735799]        lock_acquire+0xbd/0x200
[   56.736071]        down_read+0x4c/0x70
[   56.736323]        n_tty_write+0x90/0x450
[   56.736584]        tty_write+0x159/0x2e0
[   56.736844]        __vfs_write+0x28/0x140
[   56.737119]        vfs_write+0xc4/0x1c0
[   56.737376]        redirected_tty_write+0x5c/0xa0
[   56.737681]        __do_readv_writev+0x2b4/0x350
[   56.737980]        do_readv_writev+0x63/0x80
[   56.738263]        vfs_writev+0x3c/0x50
[   56.738513]        do_writev+0x55/0xd0
[   56.738758]        SyS_writev+0x10/0x20
[   56.739009]        entry_SYSCALL_64_fastpath+0x1f/0xbe
[   56.739345] 
               -> #1 (&tty->atomic_write_lock){+.+.+.}:
[   56.739760]        lock_acquire+0xbd/0x200
[   56.740026]        __mutex_lock+0x75/0x8e0
[   56.740297]        mutex_lock_nested+0x1b/0x20
[   56.740585]        tty_port_default_receive_buf+0x48/0x90
[   56.740932]        flush_to_ldisc+0x7f/0xa0
[   56.741233]        process_one_work+0x1c5/0x5c0
[   56.741528]        worker_thread+0x4d/0x3c0
[   56.741800]        kthread+0x114/0x150
[   56.742046]        ret_from_fork+0x2a/0x40
[   56.742318] 
               -> #0 (&buf->lock){+.+...}:
[   56.742664]        __lock_acquire+0x13e1/0x1400
[   56.742957]        lock_acquire+0xbd/0x200
[   56.743228]        __mutex_lock+0x75/0x8e0
[   56.743496]        mutex_lock_nested+0x1b/0x20
[   56.743784]        tty_buffer_flush+0x37/0xa0
[   56.744068]        pty_flush_buffer+0x27/0x80
[   56.744462]        tty_driver_flush_buffer+0x1b/0x20
[   56.744776]        isig+0x95/0xf0
[   56.744999]        n_tty_receive_signal_char+0x1c/0x70
[   56.745338]        n_tty_receive_char_special+0x863/0xb00
[   56.745660]        n_tty_receive_buf_common+0x7ae/0xac0
[   56.746013]        n_tty_receive_buf2+0x14/0x20
[   56.746311]        tty_ldisc_receive_buf+0x23/0x50
[   56.746598]        tty_port_default_receive_buf+0x59/0x90
[   56.746960]        flush_to_ldisc+0x7f/0xa0
[   56.747237]        process_one_work+0x1c5/0x5c0
[   56.747509]        worker_thread+0x4d/0x3c0
[   56.747761]        kthread+0x114/0x150
[   56.748016]        ret_from_fork+0x2a/0x40
[   56.748300] 
               other info that might help us debug this:

[   56.748835] Chain exists of:
                 &buf->lock --> &tty->atomic_write_lock --> &o_tty->termios_rwsem/1

[   56.749581]  Possible unsafe locking scenario:

[   56.749994]        CPU0                    CPU1
[   56.750294]        ----                    ----
[   56.750564]   lock(&o_tty->termios_rwsem/1);
[   56.750855]                                lock(&tty->atomic_write_lock);
[   56.751314]                                lock(&o_tty->termios_rwsem/1);
[   56.751808]   lock(&buf->lock);
[   56.752021] 
                *** DEADLOCK ***

[   56.752380] 6 locks held by kworker/u8:3/329:
[   56.752641]  #0:  ("events_unbound"){.+.+.+}, at: [<ffffffff8108861f>] process_one_work+0x13f/0x5c0
[   56.753203]  #1:  ((&buf->work)){+.+...}, at: [<ffffffff8108861f>] process_one_work+0x13f/0x5c0
[   56.753717]  #2:  (&port->buf.lock/1){+.+...}, at: [<ffffffff81423935>] flush_to_ldisc+0x25/0xa0
[   56.754243]  #3:  (&tty->ldisc_sem){++++.+}, at: [<ffffffff81422ccf>] tty_ldisc_ref+0x1f/0x60
[   56.754748]  #4:  (&tty->atomic_write_lock){+.+.+.}, at: [<ffffffff814242b8>] tty_port_default_receive_buf+0x48/0x90
[   56.755373]  #5:  (&o_tty->termios_rwsem/1){++++..}, at: [<ffffffff8141fb91>] isig+0x41/0xf0
[   56.755875] 
               stack backtrace:
[   56.756139] CPU: 2 PID: 329 Comm: kworker/u8:3 Tainted: G            E   4.12.0-master #108
[   56.756637] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org 04/01/2014
[   56.757327] Workqueue: events_unbound flush_to_ldisc
[   56.757629] Call Trace:
[   56.757830]  dump_stack+0x85/0xc9
[   56.758048]  print_circular_bug+0x1f9/0x207
[   56.758315]  __lock_acquire+0x13e1/0x1400
[   56.758564]  ? check_irq_usage+0x83/0xb0
[   56.758882]  lock_acquire+0xbd/0x200
[   56.759113]  ? tty_buffer_flush+0x37/0xa0
[   56.759463]  ? tty_buffer_flush+0x37/0xa0
[   56.759737]  __mutex_lock+0x75/0x8e0
[   56.759998]  ? tty_buffer_flush+0x37/0xa0
[   56.760250]  ? isig+0x5e/0xf0
[   56.760433]  ? tty_buffer_flush+0x37/0xa0
[   56.760677]  ? find_held_lock+0x35/0xa0
[   56.760957]  ? isig+0x8d/0xf0
[   56.761140]  mutex_lock_nested+0x1b/0x20
[   56.761383]  tty_buffer_flush+0x37/0xa0
[   56.761617]  pty_flush_buffer+0x27/0x80
[   56.761870]  tty_driver_flush_buffer+0x1b/0x20
[   56.762162]  isig+0x95/0xf0
[   56.762340]  n_tty_receive_signal_char+0x1c/0x70
[   56.762619]  n_tty_receive_char_special+0x863/0xb00
[   56.762960]  n_tty_receive_buf_common+0x7ae/0xac0
[   56.763250]  ? tty_ldisc_ref+0x1f/0x60
[   56.763478]  n_tty_receive_buf2+0x14/0x20
[   56.763721]  tty_ldisc_receive_buf+0x23/0x50
[   56.763983]  ? mutex_lock_nested+0x1b/0x20
[   56.764238]  tty_port_default_receive_buf+0x59/0x90
[   56.764533]  flush_to_ldisc+0x7f/0xa0
[   56.764756]  process_one_work+0x1c5/0x5c0
[   56.765075]  ? process_one_work+0x13f/0x5c0
[   56.765366]  worker_thread+0x4d/0x3c0
[   56.765590]  kthread+0x114/0x150
[   56.765787]  ? process_one_work+0x5c0/0x5c0
[   56.766094]  ? kthread_create_on_node+0x40/0x40
[   56.766374]  ret_from_fork+0x2a/0x40

[toc] | [prev] | [next] | [standalone]


#1657028 — Re: [bisected] Re: tty lockdep trace

FromGreg Kroah-Hartman <gregkh@linuxfoundation.org>
Date2017-06-04 10:40 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tOzeO-2mD-3@gated-at.bofh.it>
In reply to#1656728
On Sat, Jun 03, 2017 at 08:33:52AM +0200, Mike Galbraith wrote:
> On Wed, 2017-05-31 at 13:21 -0400, Dave Jones wrote:
> > Just hit this during a trinity run.
> 
> 925bb1ce47f429f69aad35876df7ecd8c53deb7e is the first bad commit
> commit 925bb1ce47f429f69aad35876df7ecd8c53deb7e
> Author: Vegard Nossum <vegard.nossum@oracle.com>
> Date:   Thu May 11 12:18:52 2017 +0200
> 
>     tty: fix port buffer locking

Now reverting this.  Oops, sorry, forgot to add Dave and your names to
the patch revert.  The list of people who reported this was really long,
many thanks for this.

greg k-h

[toc] | [prev] | [next] | [standalone]


#1657029 — Re: [bisected] Re: tty lockdep trace

FromMike Galbraith <efault@gmx.de>
Date2017-06-04 11:10 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tOzHQ-2Og-5@gated-at.bofh.it>
In reply to#1657028
On Sun, 2017-06-04 at 10:32 +0200, Greg Kroah-Hartman wrote:
> On Sat, Jun 03, 2017 at 08:33:52AM +0200, Mike Galbraith wrote:
> > On Wed, 2017-05-31 at 13:21 -0400, Dave Jones wrote:
> > > Just hit this during a trinity run.
> > 
> > 925bb1ce47f429f69aad35876df7ecd8c53deb7e is the first bad commit
> > commit 925bb1ce47f429f69aad35876df7ecd8c53deb7e
> > Author: Vegard Nossum <vegard.nossum@oracle.com>
> > Date:   Thu May 11 12:18:52 2017 +0200
> > 
> >     tty: fix port buffer locking
> 
> Now reverting this.  Oops, sorry, forgot to add Dave and your names to
> the patch revert.  The list of people who reported this was really long,
> many thanks for this.

If flush_to_ldisc() is the problem, and taking atomic_write_lock in
that path an acceptable solution, how about do that a bit differently
instead.  Lockdep stopped grumbling, vbox seems happy.

925bb1ce47f4 (tty: fix port buffer locking) upset lockdep by holding buf->lock
while acquiring tty->atomic_write_lock.  Move acquisition to flush_to_ldisc(),
taking it prior to taking buf->lock.  Costs a reference, but appeases lockdep.

Not-so-signed-off-by: /me
---
 drivers/tty/tty_buffer.c |   10 ++++++++++
 drivers/tty/tty_port.c   |    2 --
 2 files changed, 10 insertions(+), 2 deletions(-)

--- a/drivers/tty/tty_buffer.c
+++ b/drivers/tty/tty_buffer.c
@@ -465,7 +465,13 @@ static void flush_to_ldisc(struct work_s
 {
 	struct tty_port *port = container_of(work, struct tty_port, buf.work);
 	struct tty_bufhead *buf = &port->buf;
+	struct tty_struct *tty = READ_ONCE(port->itty);
+	struct tty_ldisc *disc = NULL;
 
+	if (tty)
+		disc = tty_ldisc_ref(tty);
+	if (disc)
+		mutex_lock(&tty->atomic_write_lock);
 	mutex_lock(&buf->lock);
 
 	while (1) {
@@ -501,6 +507,10 @@ static void flush_to_ldisc(struct work_s
 	}
 
 	mutex_unlock(&buf->lock);
+	if (disc) {
+		mutex_unlock(&tty->atomic_write_lock);
+		tty_ldisc_deref(disc);
+	}
 
 }
 
--- a/drivers/tty/tty_port.c
+++ b/drivers/tty/tty_port.c
@@ -34,9 +34,7 @@ static int tty_port_default_receive_buf(
 	if (!disc)
 		return 0;
 
-	mutex_lock(&tty->atomic_write_lock);
 	ret = tty_ldisc_receive_buf(disc, p, (char *)f, count);
-	mutex_unlock(&tty->atomic_write_lock);
 
 	tty_ldisc_deref(disc);
 

[toc] | [prev] | [next] | [standalone]


#1657041 — Re: [bisected] Re: tty lockdep trace

FromVegard Nossum <vegard.nossum@oracle.com>
Date2017-06-04 12:10 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tOADT-3sO-3@gated-at.bofh.it>
In reply to#1657029
On 06/04/17 11:02, Mike Galbraith wrote:
> On Sun, 2017-06-04 at 10:32 +0200, Greg Kroah-Hartman wrote:
>> On Sat, Jun 03, 2017 at 08:33:52AM +0200, Mike Galbraith wrote:
>>> On Wed, 2017-05-31 at 13:21 -0400, Dave Jones wrote:
>>>> Just hit this during a trinity run.
>>>
>>> 925bb1ce47f429f69aad35876df7ecd8c53deb7e is the first bad commit
>>> commit 925bb1ce47f429f69aad35876df7ecd8c53deb7e
>>> Author: Vegard Nossum <vegard.nossum@oracle.com>
>>> Date:   Thu May 11 12:18:52 2017 +0200
>>>
>>>      tty: fix port buffer locking
>>
>> Now reverting this.  Oops, sorry, forgot to add Dave and your names to
>> the patch revert.  The list of people who reported this was really long,
>> many thanks for this.
> 
> If flush_to_ldisc() is the problem, and taking atomic_write_lock in
> that path an acceptable solution, how about do that a bit differently
> instead.  Lockdep stopped grumbling, vbox seems happy.
> 
> 925bb1ce47f4 (tty: fix port buffer locking) upset lockdep by holding buf->lock
> while acquiring tty->atomic_write_lock.  Move acquisition to flush_to_ldisc(),
> taking it prior to taking buf->lock.  Costs a reference, but appeases lockdep.
> 
> Not-so-signed-off-by: /me
> ---
>   drivers/tty/tty_buffer.c |   10 ++++++++++
>   drivers/tty/tty_port.c   |    2 --
>   2 files changed, 10 insertions(+), 2 deletions(-)
> 
> --- a/drivers/tty/tty_buffer.c
> +++ b/drivers/tty/tty_buffer.c
> @@ -465,7 +465,13 @@ static void flush_to_ldisc(struct work_s
>   {
>   	struct tty_port *port = container_of(work, struct tty_port, buf.work);
>   	struct tty_bufhead *buf = &port->buf;
> +	struct tty_struct *tty = READ_ONCE(port->itty);
> +	struct tty_ldisc *disc = NULL;
>   
> +	if (tty)
> +		disc = tty_ldisc_ref(tty);
> +	if (disc)
> +		mutex_lock(&tty->atomic_write_lock);
>   	mutex_lock(&buf->lock);
>   
>   	while (1) {
> @@ -501,6 +507,10 @@ static void flush_to_ldisc(struct work_s
>   	}
>   
>   	mutex_unlock(&buf->lock);
> +	if (disc) {
> +		mutex_unlock(&tty->atomic_write_lock);
> +		tty_ldisc_deref(disc);
> +	}
>   
>   }
>   
> --- a/drivers/tty/tty_port.c
> +++ b/drivers/tty/tty_port.c
> @@ -34,9 +34,7 @@ static int tty_port_default_receive_buf(
>   	if (!disc)
>   		return 0;
>   
> -	mutex_lock(&tty->atomic_write_lock);
>   	ret = tty_ldisc_receive_buf(disc, p, (char *)f, count);
> -	mutex_unlock(&tty->atomic_write_lock);
>   
>   	tty_ldisc_deref(disc);
>   
>
I don't know how you did it, but this passes my testing (reproducers for
both the original issue and the lockdep splat/hang). Although given the
track record I'm not sure how much that's worth :-/


Vegard

[toc] | [prev] | [next] | [standalone]


#1657058 — Re: [bisected] Re: tty lockdep trace

FromMike Galbraith <efault@gmx.de>
Date2017-06-04 13:40 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tOC2Z-4oc-9@gated-at.bofh.it>
In reply to#1657041
On Sun, 2017-06-04 at 12:00 +0200, Vegard Nossum wrote:
> 
> I don't know how you did it, but this passes my testing (reproducers for
> both the original issue and the lockdep splat/hang).

I suppose I can sign it off, see if that inspires anyone to come up
with something better.

drivers/tty: Fix 925bb1ce47f4 circular locking dependency

925bb1ce47f4 (tty: fix port buffer locking) upset lockdep by holding buf->lock
while acquiring tty->atomic_write_lock.  Move acquisition to flush_to_ldisc(),
taking it prior to taking buf->lock.  Costs a reference, but appeases lockdep.

Signed-off-by: Mike Galbraith <efault@gmx.de>
Fixes: 925bb1ce47f4 ("tty: fix port buffer locking")
---
 drivers/tty/tty_buffer.c |   10 ++++++++++
 drivers/tty/tty_port.c   |    2 --
 2 files changed, 10 insertions(+), 2 deletions(-)

--- a/drivers/tty/tty_buffer.c
+++ b/drivers/tty/tty_buffer.c
@@ -465,7 +465,13 @@ static void flush_to_ldisc(struct work_s
 {
 	struct tty_port *port = container_of(work, struct tty_port, buf.work);
 	struct tty_bufhead *buf = &port->buf;
+	struct tty_struct *tty = READ_ONCE(port->itty);
+	struct tty_ldisc *disc = NULL;
 
+	if (tty)
+		disc = tty_ldisc_ref(tty);
+	if (disc)
+		mutex_lock(&tty->atomic_write_lock);
 	mutex_lock(&buf->lock);
 
 	while (1) {
@@ -501,6 +507,10 @@ static void flush_to_ldisc(struct work_s
 	}
 
 	mutex_unlock(&buf->lock);
+	if (disc) {
+		mutex_unlock(&tty->atomic_write_lock);
+		tty_ldisc_deref(disc);
+	}
 
 }
 
--- a/drivers/tty/tty_port.c
+++ b/drivers/tty/tty_port.c
@@ -34,9 +34,7 @@ static int tty_port_default_receive_buf(
 	if (!disc)
 		return 0;
 
-	mutex_lock(&tty->atomic_write_lock);
 	ret = tty_ldisc_receive_buf(disc, p, (char *)f, count);
-	mutex_unlock(&tty->atomic_write_lock);
 
 	tty_ldisc_deref(disc);
 

[toc] | [prev] | [next] | [standalone]


#1657650 — Re: [bisected] Re: tty lockdep trace

FromAlan Cox <gnomes@lxorguk.ukuu.org.uk>
Date2017-06-05 17:10 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tP1NM-4wR-7@gated-at.bofh.it>
In reply to#1657058
On Sun, 04 Jun 2017 13:34:31 +0200
Mike Galbraith <efault@gmx.de> wrote:

> On Sun, 2017-06-04 at 12:00 +0200, Vegard Nossum wrote:
> > 
> > I don't know how you did it, but this passes my testing (reproducers for
> > both the original issue and the lockdep splat/hang).  
> 
> I suppose I can sign it off, see if that inspires anyone to come up
> with something better.
> 
> drivers/tty: Fix 925bb1ce47f4 circular locking dependency

This is still completely broken and has the same underlying flaw as the
original.

The tty->atomic_write_lock is solely meant to enforce the ordering of a
write() syscall. It can be held for an indefinite amount of time (it's
sometimes multiple seconds in normal flow). Your patch effectively breaks
full duplex support on the serial layer because the internal buffering is
designed to cope with tens of millisecond delays. If the receiver is
multithreaded as is normal then it's also going to wreck the throughput.

We can't defer receive processing indefintiely for transmit processing,
that isn't how RS232 works. If it needs a spinlock putting back to
protect those tty fields then so be it.

NAK

Alan

[toc] | [prev] | [next] | [standalone]


#1657681 — Re: [bisected] Re: tty lockdep trace

FromMike Galbraith <efault@gmx.de>
Date2017-06-05 17:50 +0200
SubjectRe: [bisected] Re: tty lockdep trace
Message-ID<tP2qt-4Jd-5@gated-at.bofh.it>
In reply to#1657650
On Mon, 2017-06-05 at 16:09 +0100, Alan Cox wrote:
> On Sun, 04 Jun 2017 13:34:31 +0200
> Mike Galbraith <efault@gmx.de> wrote:
> 
> > On Sun, 2017-06-04 at 12:00 +0200, Vegard Nossum wrote:
> > > 
> > > I don't know how you did it, but this passes my testing (reproducers for
> > > both the original issue and the lockdep splat/hang).  
> > 
> > I suppose I can sign it off, see if that inspires anyone to come up
> > with something better.
> > 
> > drivers/tty: Fix 925bb1ce47f4 circular locking dependency
> 
> This is still completely broken and has the same underlying flaw as the
> original.

Thanks for looking.  It didn't look the least bit lovely, it being
equally busted (well, ever so slightly less, lockdep did sthu;) is not
a shocker.  Off to the bin ya go little patchlet.

	-Mike

[toc] | [prev] | [next] | [standalone]


#1657270 — [patch] tty: fix port buffer locking V2

FromMike Galbraith <efault@gmx.de>
Date2017-06-05 07:00 +0200
Subject[patch] tty: fix port buffer locking V2
Message-ID<tOShs-6GX-11@gated-at.bofh.it>
In reply to#1657041
This is just in case.  While it works, I consider it to be diagnostic
data for those unfortunate enough to be intimate with tty locking :)
---

V1 (925bb1ce47f4) changelog:
tty_insert_flip_string_fixed_flag() is racy against itself when called
from the ioctl(TCXONC, TCION/TCIOFF) path [1] and the flush_to_ldisc()
workqueue path [2].

The problem is that port->buf.tail->used is modified without consistent
locking; the ioctl path takes tty->atomic_write_lock, whereas the workqueue
path takes ldata->output_lock.

We cannot simply take ldata->output_lock, since that is specific to the
N_TTY line discipline.

It might seem natural to try to take port->buf.lock inside
tty_insert_flip_string_fixed_flag() and friends (where port->buf is
actually used/modified), but this creates problems for flush_to_ldisc()
which takes it before grabbing tty->ldisc_sem, o_tty->termios_rwsem,
and ldata->output_lock.

Therefore, the simplest solution for now seems to be to take
tty->atomic_write_lock inside tty_port_default_receive_buf(). This lock
is also used in the write path [3] with a consistent ordering.

[1]: Call Trace:
 tty_insert_flip_string_fixed_flag
 pty_write
 tty_send_xchar                     // down_read(&o_tty->termios_rwsem)
                                    // mutex_lock(&tty->atomic_write_lock)
 n_tty_ioctl_helper
 n_tty_ioctl
 tty_ioctl                          // down_read(&tty->ldisc_sem)
 do_vfs_ioctl
 SyS_ioctl

[2]: Workqueue: events_unbound flush_to_ldisc
Call Trace:
 tty_insert_flip_string_fixed_flag
 pty_write
 tty_put_char
 __process_echoes
 commit_echoes                      // mutex_lock(&ldata->output_lock)
 n_tty_receive_buf_common
 n_tty_receive_buf2
 tty_ldisc_receive_buf              // down_read(&o_tty->termios_rwsem)
 tty_port_default_receive_buf       // down_read(&tty->ldisc_sem)
 flush_to_ldisc                     // mutex_lock(&port->buf.lock)
 process_one_work
    
[3]: Call Trace:
 tty_insert_flip_string_fixed_flag
 pty_write
 n_tty_write                        // mutex_lock(&ldata->output_lock)
                                    // down_read(&tty->termios_rwsem)
 do_tty_write (inline)              // mutex_lock(&tty->atomic_write_lock)
 tty_write                          // down_read(&tty->ldisc_sem)
 __vfs_write
 vfs_write
 SyS_write

The bug can result in about a dozen different crashes depending on what
exactly gets corrupted when port->buf.tail->used points outside the
buffer.

The patch passes my LOCKDEP/PROVE_LOCKING testing but more testing is
always welcome.

Found using syzkaller.

V2: The V1 solution induced an ordering issue, holding buf->lock while
acquiring tty->atomic_write_lock.  Resolve it by moving acquisition to
flush_to_ldisc(), prior to acquisition of buf->lock.

Credit to Vegard Nossum for problem analysis/resolution, blame to me for
trivial adaptation thereof.

Signed-off-by: Mike Galbraith <efault@gmx.de>
Cc: Vegard Nossum <vegard.nossum@oracle.com>
Cc: <stable@vger.kernel.org>
---
 drivers/tty/tty_buffer.c |   10 ++++++++++
 1 file changed, 10 insertions(+)

--- a/drivers/tty/tty_buffer.c
+++ b/drivers/tty/tty_buffer.c
@@ -465,7 +465,13 @@ static void flush_to_ldisc(struct work_s
 {
 	struct tty_port *port = container_of(work, struct tty_port, buf.work);
 	struct tty_bufhead *buf = &port->buf;
+	struct tty_struct *tty = READ_ONCE(port->itty);
+	struct tty_ldisc *disc = NULL;
 
+	if (tty)
+		disc = tty_ldisc_ref(tty);
+	if (disc)
+		mutex_lock(&tty->atomic_write_lock);
 	mutex_lock(&buf->lock);
 
 	while (1) {
@@ -501,6 +507,10 @@ static void flush_to_ldisc(struct work_s
 	}
 
 	mutex_unlock(&buf->lock);
+	if (disc) {
+		mutex_unlock(&tty->atomic_write_lock);
+		tty_ldisc_deref(disc);
+	}
 
 }
 

[toc] | [prev] | [next] | [standalone]


#1657309 — Re: [patch] tty: fix port buffer locking V2

FromGreg Kroah-Hartman <gregkh@linuxfoundation.org>
Date2017-06-05 08:50 +0200
SubjectRe: [patch] tty: fix port buffer locking V2
Message-ID<tOTZU-7QM-5@gated-at.bofh.it>
In reply to#1657270
On Mon, Jun 05, 2017 at 06:52:27AM +0200, Mike Galbraith wrote:
> This is just in case.  While it works, I consider it to be diagnostic
> data for those unfortunate enough to be intimate with tty locking :)

Can you redo this against 4.12-rc4 which has the original tty locking
patch reverted?

thanks,

greg k-h

[toc] | [prev] | [next] | [standalone]


#1657317 — Re: [patch] tty: fix port buffer locking V2

FromMike Galbraith <efault@gmx.de>
Date2017-06-05 09:20 +0200
SubjectRe: [patch] tty: fix port buffer locking V2
Message-ID<tOUsV-8gF-1@gated-at.bofh.it>
In reply to#1657309
On Mon, 2017-06-05 at 08:48 +0200, Greg Kroah-Hartman wrote:
> 
> Can you redo this against 4.12-rc4 which has the original tty locking
> patch reverted?

It's against 4.12-rc4.

	-Mike

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web