3.4+ tty lockdep trace

DISCUSSION Dave Jones 6 participants 17 messages May 23, 2012 – May 25, 2012

lore

Share & tools

lore

Dave Jones

author

2012-05-23 00:26 UTC #0 lore raw

Quoted 1 line

From v3.4-4413-gfb09baf

[   43.374948] =============================================
[   43.374991] [ INFO: possible recursive locking detected ]
[   43.375035] 3.4.0+ #24 Not tainted
[   43.375065] ---------------------------------------------
[   43.375108] sshd/639 is trying to acquire lock:
[   43.375157]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80
[   43.375216] 
[   43.375216] but task is already holding lock:
[   43.375268]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80
[   43.375327] 
[   43.375327] other info that might help us debug this:
[   43.375378]  Possible unsafe locking scenario:
[   43.375378] 
[   43.375425]        CPU0
[   43.375447]        ----
[   43.375471]   lock(&tty->legacy_mutex);
[   43.375504]   lock(&tty->legacy_mutex);
[   43.375536] 
[   43.375536]  *** DEADLOCK ***
[   43.375536] 
[   43.375583]  May be due to missing lock nesting notation
[   43.375583] 
[   43.375637] 2 locks held by sshd/639:
[   43.375675]  #0:  (tty_mutex){+.+.+.}, at: [<ffffffff813b0243>] tty_release+0x1c3/0x5d0
[   43.375740]  #1:  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80
[   43.375802] 
[   43.375802] stack backtrace:
[   43.375841] Pid: 639, comm: sshd Not tainted 3.4.0+ #24
[   43.375882] Call Trace:
[   43.377572]  [<ffffffff810b4604>] __lock_acquire+0x1584/0x1aa0
[   43.379286]  [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
[   43.380995]  [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[   43.382700]  [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
[   43.384403]  [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[   43.386094]  [<ffffffff81085521>] ? get_parent_ip+0x11/0x50
[   43.387794]  [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[   43.389480]  [<ffffffff8165a68d>] ? sub_preempt_count+0x6d/0xd0
[   43.391176]  [<ffffffff813b0243>] ? tty_release+0x1c3/0x5d0
[   43.393003]  [<ffffffff81656d57>] tty_lock+0x37/0x80
[   43.394867]  [<ffffffff81656dc3>] tty_lock_pair+0x23/0x5c
[   43.396671]  [<ffffffff813b024e>] tty_release+0x1ce/0x5d0
[   43.398462]  [<ffffffff811a765c>] fput+0x12c/0x300
[   43.400292]  [<ffffffff811a23a9>] filp_close+0x69/0xa0
[   43.402084]  [<ffffffff811a2f2d>] sys_close+0xad/0x1a0
[   43.403871]  [<ffffffff8165e652>] system_call_fastpath+0x16/0x1b

Ming Lei

2012-05-23 01:06 UTC #1 lore raw

Hi Dave,

Quoted 39 lines · Dave Jones

From v3.4-4413-gfb09baf
[ 43.374948] =============================================
[ 43.374991] [ INFO: possible recursive locking detected ]
[ 43.375035] 3.4.0+ #24 Not tainted
[ 43.375065] ---------------------------------------------
[ 43.375108] sshd/639 is trying to acquire lock:
[ 43.375157] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375216]
[ 43.375216] but task is already holding lock:
[ 43.375268] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375327]
[ 43.375327] other info that might help us debug this:
[ 43.375378] Possible unsafe locking scenario:
[ 43.375378]
[ 43.375425] CPU0
[ 43.375447] ----
[ 43.375471] lock(&tty->legacy_mutex);
[ 43.375504] lock(&tty->legacy_mutex);
[ 43.375536]
[ 43.375536] *** DEADLOCK ***
[ 43.375536]
[ 43.375583] May be due to missing lock nesting notation
[ 43.375583]
[ 43.375637] 2 locks held by sshd/639:
[ 43.375675] #0: (tty_mutex){+.+.+.}, at: [<ffffffff813b0243>] tty_release+0x1c3/0x5d0 [ 43.375740] #1: (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375802]
[ 43.375802] stack backtrace:
[ 43.375841] Pid: 639, comm: sshd Not tainted 3.4.0+ #24
[ 43.375882] Call Trace:
[ 43.377572] [<ffffffff810b4604>] __lock_acquire+0x1584/0x1aa0
[ 43.379286] [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
[ 43.380995] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.382700] [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
[ 43.384403] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.386094] [<ffffffff81085521>] ? get_parent_ip+0x11/0x50
[ 43.387794] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.389480] [<ffffffff8165a68d>] ? sub_preempt_count+0x6d/0xd0

Quoted 8 lines

[ 43.391176] [<ffffffff813b0243>] ? tty_release+0x1c3/0x5d0 [ 43.393003] [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.394867] [<ffffffff81656dc3>] tty_lock_pair+0x23/0x5c [ 43.396671] [<ffffffff813b024e>] tty_release+0x1ce/0x5d0 [ 43.398462] [<ffffffff811a765c>] fput+0x12c/0x300
[ 43.400292] [<ffffffff811a23a9>] filp_close+0x69/0xa0 [ 43.402084] [<ffffffff811a2f2d>] sys_close+0xad/0x1a0 [ 43.403871] [<ffffffff8165e652>] system_call_fastpath+0x16/0x1b

We have one patch to address the problem, could you test it from the link below?

        http://marc.info/?l=linux-kernel&m=133765211309247&w=2

Thanks,

Signature · 1 line

Ming Lei

Dave Jones

author

2012-05-23 01:17 UTC #2 lore raw

Quoted 20 lines · Ming Lei

Quoted 11 lines
[ 43.375802] stack backtrace:
[ 43.375841] Pid: 639, comm: sshd Not tainted 3.4.0+ #24 [ 43.375882] Call Trace:
[ 43.377572] [<ffffffff810b4604>] __lock_acquire+0x1584/0x1aa0 [ 43.379286] [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0 [ 43.380995] [<ffffffff81656d57>] ? tty_lock+0x37/0x80 [ 43.382700] [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0 [ 43.384403] [<ffffffff81656d57>] ? tty_lock+0x37/0x80 [ 43.386094] [<ffffffff81085521>] ? get_parent_ip+0x11/0x50 [ 43.387794] [<ffffffff81656d57>] ? tty_lock+0x37/0x80 [ 43.389480] [<ffffffff8165a68d>] ? sub_preempt_count+0x6d/0xd0
Quoted 8 lines
[ 43.391176] [<ffffffff813b0243>] ? tty_release+0x1c3/0x5d0 [ 43.393003] [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.394867] [<ffffffff81656dc3>] tty_lock_pair+0x23/0x5c [ 43.396671] [<ffffffff813b024e>] tty_release+0x1ce/0x5d0 [ 43.398462] [<ffffffff811a765c>] fput+0x12c/0x300
[ 43.400292] [<ffffffff811a23a9>] filp_close+0x69/0xa0 [ 43.402084] [<ffffffff811a2f2d>] sys_close+0xad/0x1a0 [ 43.403871] [<ffffffff8165e652>] system_call_fastpath+0x16/0x1b

Quoted 3 lines

We have one patch to address the problem, could you test it from the link below?
        http://marc.info/?l=linux-kernel&m=133765211309247&w=2

Yes, that seems to fix it. Thanks.

Dave

Dave Jones

author

2012-05-23 02:05 UTC #3 lore raw

In reply to Ming Lei

A different one. This time with devpts. (With the patch Ming Lei pointed to on top of Linus current)

Dave

======================================================
[ INFO: possible circular locking dependency detected ] 3.4.0+ #25 Not tainted
-------------------------------------------------------
sshd/632 is trying to acquire lock:
(devpts_mutex){+.+.+.}, at: [<ffffffff813b9846>] pty_close+0x156/0x180

but task is already holding lock:
(&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #1 (&tty->legacy_mutex){+.+.+.}:

        [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
        [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
        [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90
        [<ffffffff81656d10>] tty_lock+0x10/0x20
        [<ffffffff813afe8f>] tty_init_dev+0x6f/0x140
        [<ffffffff813b9946>] ptmx_open+0xa6/0x180
        [<ffffffff811aa2fb>] chrdev_open+0x9b/0x1b0
        [<ffffffff811a289b>] __dentry_open+0x26b/0x380
        [<ffffffff811a3d64>] nameidata_to_filp+0x74/0x80
        [<ffffffff811b5af8>] do_last+0x468/0x900
        [<ffffffff811b60a2>] path_openat+0xd2/0x3f0
        [<ffffffff811b64e1>] do_filp_open+0x41/0xa0
        [<ffffffff811a3e5d>] do_sys_open+0xed/0x1c0
        [<ffffffff811a3f51>] sys_open+0x21/0x30
        [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

-> #0 (devpts_mutex){+.+.+.}:

        [<ffffffff810b43ae>] __lock_acquire+0x132e/0x1aa0
        [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
        [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
        [<ffffffff813b9846>] pty_close+0x156/0x180
        [<ffffffff813b0203>] tty_release+0x183/0x5d0
        [<ffffffff811a765c>] fput+0x12c/0x300
        [<ffffffff811a23a9>] filp_close+0x69/0xa0
        [<ffffffff811a2f2d>] sys_close+0xad/0x1a0
        [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

other info that might help us debug this:

  Possible unsafe locking scenario:

        CPU0                    CPU1
        ----                    ----
   lock(&tty->legacy_mutex);
                                lock(devpts_mutex);
                                lock(&tty->legacy_mutex);

lock(devpts_mutex);

*** DEADLOCK ***

1 lock held by sshd/632:
#0: (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90

 stack backtrace:
 Pid: 632, comm: sshd Not tainted 3.4.0+ #25
 Call Trace:
  [<ffffffff8164a64a>] print_circular_bug+0x1fb/0x20c
  [<ffffffff810b43ae>] __lock_acquire+0x132e/0x1aa0
  [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
  [<ffffffff813b9846>] ? pty_close+0x156/0x180
  [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
  [<ffffffff813b9846>] ? pty_close+0x156/0x180
  [<ffffffff8165a70d>] ? sub_preempt_count+0x6d/0xd0
  [<ffffffff813b9846>] ? pty_close+0x156/0x180
  [<ffffffff81656bd2>] ? _raw_spin_unlock_irqrestore+0x42/0x80
  [<ffffffff8107d9c3>] ? __wake_up+0x53/0x70
  [<ffffffff813b9846>] pty_close+0x156/0x180
  [<ffffffff813b0203>] tty_release+0x183/0x5d0
  [<ffffffff811c5670>] ? vfsmount_lock_local_unlock_cpu+0x70/0x70
  [<ffffffff811a765c>] fput+0x12c/0x300
  [<ffffffff811a23a9>] filp_close+0x69/0xa0
  [<ffffffff811a2f2d>] sys_close+0xad/0x1a0
  [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

Ming Lei

2012-05-23 02:45 UTC #4 lore raw

Quoted 1 line · Dave Jones

A different one. This time with devpts. (With the patch Ming Lei pointed to on top of Linus current)

It is another one, I saw it too when disconnecting a ssh shell and keep one console shell.

It need some tty knowledge to fix this one, so maybe tty guys can handle it.

Thanks,
--
Ming Lei

Quoted 83 lines

Dave

but task is already holding lock:
(&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #1 (&tty->legacy_mutex){+.+.+.}:

       [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
       [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
       [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90
       [<ffffffff81656d10>] tty_lock+0x10/0x20
       [<ffffffff813afe8f>] tty_init_dev+0x6f/0x140
       [<ffffffff813b9946>] ptmx_open+0xa6/0x180
       [<ffffffff811aa2fb>] chrdev_open+0x9b/0x1b0
       [<ffffffff811a289b>] __dentry_open+0x26b/0x380
       [<ffffffff811a3d64>] nameidata_to_filp+0x74/0x80
       [<ffffffff811b5af8>] do_last+0x468/0x900
       [<ffffffff811b60a2>] path_openat+0xd2/0x3f0
       [<ffffffff811b64e1>] do_filp_open+0x41/0xa0
       [<ffffffff811a3e5d>] do_sys_open+0xed/0x1c0
       [<ffffffff811a3f51>] sys_open+0x21/0x30
       [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

-> #0 (devpts_mutex){+.+.+.}:

       [<ffffffff810b43ae>] __lock_acquire+0x132e/0x1aa0
       [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
       [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
       [<ffffffff813b9846>] pty_close+0x156/0x180
       [<ffffffff813b0203>] tty_release+0x183/0x5d0
       [<ffffffff811a765c>] fput+0x12c/0x300
       [<ffffffff811a23a9>] filp_close+0x69/0xa0
       [<ffffffff811a2f2d>] sys_close+0xad/0x1a0
       [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

other info that might help us debug this:

 Possible unsafe locking scenario:

CPU0 CPU1
---- ---- lock(&tty->legacy_mutex);
lock(devpts_mutex); lock(&tty->legacy_mutex); lock(devpts_mutex);

*** DEADLOCK ***

1 lock held by sshd/632:
#0: (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656cb2>] tty_lock_nested+0x42/0x90

 stack backtrace:
 Pid: 632, comm: sshd Not tainted 3.4.0+ #25
 Call Trace:
 [<ffffffff8164a64a>] print_circular_bug+0x1fb/0x20c
 [<ffffffff810b43ae>] __lock_acquire+0x132e/0x1aa0
 [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
 [<ffffffff813b9846>] ? pty_close+0x156/0x180
 [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
 [<ffffffff813b9846>] ? pty_close+0x156/0x180
 [<ffffffff8165a70d>] ? sub_preempt_count+0x6d/0xd0
 [<ffffffff813b9846>] ? pty_close+0x156/0x180
 [<ffffffff81656bd2>] ? _raw_spin_unlock_irqrestore+0x42/0x80
 [<ffffffff8107d9c3>] ? __wake_up+0x53/0x70
 [<ffffffff813b9846>] pty_close+0x156/0x180
 [<ffffffff813b0203>] tty_release+0x183/0x5d0
 [<ffffffff811c5670>] ? vfsmount_lock_local_unlock_cpu+0x70/0x70
 [<ffffffff811a765c>] fput+0x12c/0x300
 [<ffffffff811a23a9>] filp_close+0x69/0xa0
 [<ffffffff811a2f2d>] sys_close+0xad/0x1a0
 [<ffffffff8165e6d2>] system_call_fastpath+0x16/0x1b

Signature · 1 line

Ming Lei

Alan Cox

2012-05-23 23:03 UTC #5 lore raw

In reply to Dave Jones

Quoted 1 line · On Tue, 22 May 2012 22:02:47 -0400 Dave Jones <[email protected]> wrote:

A different one. This time with devpts. (With the patch Ming Lei pointed to on top of Linus current)

That one loosk real - I'll go squash it tomorrow if I get time.

Alan

Sasha Levin

2012-05-24 06:14 UTC #6 lore raw

In reply to Ming Lei

Quoted 51 lines · Ming Lei

Hi Dave,
Quoted 39 lines · Dave Jones
From v3.4-4413-gfb09baf
[ 43.374948] =============================================
[ 43.374991] [ INFO: possible recursive locking detected ]
[ 43.375035] 3.4.0+ #24 Not tainted
[ 43.375065] ---------------------------------------------
[ 43.375108] sshd/639 is trying to acquire lock:
[ 43.375157] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375216]
[ 43.375216] but task is already holding lock:
[ 43.375268] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375327]
[ 43.375327] other info that might help us debug this:
[ 43.375378] Possible unsafe locking scenario:
[ 43.375378]
[ 43.375425] CPU0
[ 43.375447] ----
[ 43.375471] lock(&tty->legacy_mutex);
[ 43.375504] lock(&tty->legacy_mutex);
[ 43.375536]
[ 43.375536] *** DEADLOCK ***
[ 43.375536]
[ 43.375583] May be due to missing lock nesting notation
[ 43.375583]
[ 43.375637] 2 locks held by sshd/639:
[ 43.375675] #0: (tty_mutex){+.+.+.}, at: [<ffffffff813b0243>] tty_release+0x1c3/0x5d0 [ 43.375740] #1: (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.375802]
[ 43.375802] stack backtrace:
[ 43.375841] Pid: 639, comm: sshd Not tainted 3.4.0+ #24
[ 43.375882] Call Trace:
[ 43.377572] [<ffffffff810b4604>] __lock_acquire+0x1584/0x1aa0
[ 43.379286] [<ffffffff810b51e2>] lock_acquire+0x92/0x1f0
[ 43.380995] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.382700] [<ffffffff816534f1>] mutex_lock_nested+0x71/0x3b0
[ 43.384403] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.386094] [<ffffffff81085521>] ? get_parent_ip+0x11/0x50
[ 43.387794] [<ffffffff81656d57>] ? tty_lock+0x37/0x80
[ 43.389480] [<ffffffff8165a68d>] ? sub_preempt_count+0x6d/0xd0
Quoted 8 lines
[ 43.391176] [<ffffffff813b0243>] ? tty_release+0x1c3/0x5d0 [ 43.393003] [<ffffffff81656d57>] tty_lock+0x37/0x80 [ 43.394867] [<ffffffff81656dc3>] tty_lock_pair+0x23/0x5c [ 43.396671] [<ffffffff813b024e>] tty_release+0x1ce/0x5d0 [ 43.398462] [<ffffffff811a765c>] fput+0x12c/0x300
[ 43.400292] [<ffffffff811a23a9>] filp_close+0x69/0xa0 [ 43.402084] [<ffffffff811a2f2d>] sys_close+0xad/0x1a0 [ 43.403871] [<ffffffff8165e652>] system_call_fastpath+0x16/0x1b

Quoted 3 lines

We have one patch to address the problem, could you test it from the link below?
http://marc.info/?l=linux-kernel&m=133765211309247&w=2

I'm still seeing the warning with this patch:

[   83.032572] trinity (4823): Using mlock ulimits for SHM_HUGETLB is deprecated
[   83.060427] type=1400 audit(1.288:2): op=linkat action=denied
pid=4820 comm="trinity" path=2F7472696E6974792F746D702F03 dev="9p"
ino=104345
[   83.190164]
[   83.191412] =============================================
[   83.196004] [ INFO: possible recursive locking detected ]
[   83.196004] 3.4.0-next-20120523-sasha-00004-gc6cd556 #272 Tainted:
G        W
[   83.196004] ---------------------------------------------
[   83.196004] trinity/4823 is trying to acquire lock:
[   83.196004]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f6a5db>]
tty_lock_nested+0x7b/0x90
[   83.196004]
[   83.196004] but task is already holding lock:
[   83.196004]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f6a5db>]
tty_lock_nested+0x7b/0x90
[   83.196004]
[   83.196004] other info that might help us debug this:
[   83.196004]  Possible unsafe locking scenario:
[   83.196004]
[   83.196004]        CPU0
[   83.196004]        ----
[   83.196004]   lock(&tty->legacy_mutex);
[   83.196004]   lock(&tty->legacy_mutex);
[   83.196004]
[   83.196004]  *** DEADLOCK ***

Alan Cox

2012-05-24 11:08 UTC #7 lore raw

Quoted 1 line

I'm still seeing the warning with this patch:

Can you attach the trace that went with the trigger as well ?

Sasha Levin

2012-05-24 11:20 UTC #8 lore raw

Quoted 3 lines · Alan Cox

Quoted 1 line
I'm still seeing the warning with this patch:
Can you attach the trace that went with the trigger as well ?

Ofcourse, attached as a file.

[   36.332022] ======================================================
[   36.333749] [ INFO: possible circular locking dependency detected ]
[   36.333749] 3.4.0-next-20120524-sasha-00002-g11dc651 #273 Tainted: G        W   
[   36.333749] -------------------------------------------------------
[   36.333749] trinity/4980 is trying to acquire lock:
[   36.333749]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.333749] 
[   36.333749] but task is already holding lock:
[   36.333749]  (&tty->legacy_mutex/1){+.+...}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.333749] 
[   36.333749] which lock already depends on the new lock.
[   36.333749] 
[   36.333749] 
[   36.333749] the existing dependency chain (in reverse order) is:
[   36.333749] 
[   36.333749] -> #1 (&tty->legacy_mutex/1){+.+...}:
[   36.333749]        [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   36.333749]        [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   36.333749]        [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   36.333749]        [<ffffffff82f6e410>] __mutex_lock_common+0x60/0x590
[   36.333749]        [<ffffffff82f6ea70>] mutex_lock_nested+0x40/0x50
[   36.333749]        [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.333749]        [<ffffffff82f7202e>] tty_lock_pair+0x2e/0x70
[   36.333749]        [<ffffffff81b0f962>] tty_release+0x182/0x4d0
[   36.333749]        [<ffffffff81232d4a>] __fput+0x11a/0x2c0
[   36.333749]        [<ffffffff81232f05>] fput+0x15/0x20
[   36.333749]        [<ffffffff8122f212>] filp_close+0x82/0xa0
[   36.333749]        [<ffffffff810d6514>] close_files+0x1b4/0x200
[   36.333749]        [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   36.333749]        [<ffffffff810d672d>] exit_files+0x4d/0x60
[   36.333749]        [<ffffffff810d89f2>] do_exit+0x322/0x510
[   36.333749]        [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   36.333749]        [<ffffffff810ed5b8>] get_signal_to_deliver+0x4f8/0x580
[   36.333749]        [<ffffffff81065ae2>] do_signal+0x42/0x120
[   36.402106]        [<ffffffff81065c14>] do_notify_resume+0x54/0xb0
[   36.402106]        [<ffffffff82f723bb>] retint_signal+0x4d/0x92
[   36.402106] 
[   36.402106] -> #0 (&tty->legacy_mutex){+.+.+.}:
[   36.402106]        [<ffffffff811497ef>] check_prev_add+0x11f/0x4d0
[   36.402106]        [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   36.402106]        [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   36.402106]        [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   36.402106]        [<ffffffff82f6e410>] __mutex_lock_common+0x60/0x590
[   36.402106]        [<ffffffff82f6ea70>] mutex_lock_nested+0x40/0x50
[   36.402106]        [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.402106]        [<ffffffff82f71ffb>] tty_lock+0xb/0x10
[   36.402106]        [<ffffffff81b155f7>] tty_ldisc_release+0x47/0xb0
[   36.402106]        [<ffffffff81b0fc33>] tty_release+0x453/0x4d0
[   36.402106]        [<ffffffff81232d4a>] __fput+0x11a/0x2c0
[   36.402106]        [<ffffffff81232f05>] fput+0x15/0x20
[   36.402106]        [<ffffffff8122f212>] filp_close+0x82/0xa0
[   36.402106]        [<ffffffff810d6514>] close_files+0x1b4/0x200
[   36.402106]        [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   36.402106]        [<ffffffff810d672d>] exit_files+0x4d/0x60
[   36.402106]        [<ffffffff810d89f2>] do_exit+0x322/0x510
[   36.402106]        [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   36.402106]        [<ffffffff810ed5b8>] get_signal_to_deliver+0x4f8/0x580
[   36.402106]        [<ffffffff81065ae2>] do_signal+0x42/0x120
[   36.402106]        [<ffffffff81065c14>] do_notify_resume+0x54/0xb0
[   36.402106]        [<ffffffff82f723bb>] retint_signal+0x4d/0x92
[   36.402106] 
[   36.402106] other info that might help us debug this:
[   36.402106] 
[   36.402106]  Possible unsafe locking scenario:
[   36.402106] 
[   36.402106]        CPU0                    CPU1
[   36.402106]        ----                    ----
[   36.402106]   lock(&tty->legacy_mutex/1);
[   36.402106]                                lock(&tty->legacy_mutex);
[   36.402106]                                lock(&tty->legacy_mutex/1);
[   36.402106]   lock(&tty->legacy_mutex);
[   36.402106] 
[   36.402106]  *** DEADLOCK ***
[   36.402106] 
[   36.402106] 1 lock held by trinity/4980:
[   36.402106]  #0:  (&tty->legacy_mutex/1){+.+...}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.402106] 
[   36.402106] stack backtrace:
[   36.402106] Pid: 4980, comm: trinity Tainted: G        W    3.4.0-next-20120524-sasha-00002-g11dc651 #273
[   36.402106] Call Trace:
[   36.402106]  [<ffffffff811477d5>] print_circular_bug+0x105/0x120
[   36.402106]  [<ffffffff811497ef>] check_prev_add+0x11f/0x4d0
[   36.402106]  [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   36.402106]  [<ffffffff8111a5f8>] ? sched_clock_cpu+0x108/0x120
[   36.402106]  [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   36.402106]  [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   36.402106]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   36.402106]  [<ffffffff82f6e410>] __mutex_lock_common+0x60/0x590
[   36.402106]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   36.402106]  [<ffffffff8114aea2>] ? __lock_release+0x1c2/0x1e0
[   36.402106]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   36.402106]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   36.402106]  [<ffffffff82f6ea70>] mutex_lock_nested+0x40/0x50
[   36.402106]  [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   36.402106]  [<ffffffff82f71ffb>] tty_lock+0xb/0x10
[   36.402106]  [<ffffffff81b155f7>] tty_ldisc_release+0x47/0xb0
[   36.402106]  [<ffffffff81b0fc33>] tty_release+0x453/0x4d0
[   36.402106]  [<ffffffff812836cb>] ? vfs_lock_file+0x3b/0x40
[   36.402106]  [<ffffffff81232d4a>] __fput+0x11a/0x2c0
[   36.402106]  [<ffffffff81232f05>] fput+0x15/0x20
[   36.402106]  [<ffffffff8122f212>] filp_close+0x82/0xa0
[   36.402106]  [<ffffffff810d6514>] close_files+0x1b4/0x200
[   36.402106]  [<ffffffff810d6360>] ? wait_task_stopped+0x3d0/0x3d0
[   36.402106]  [<ffffffff810d6725>] ? exit_files+0x45/0x60
[   36.402106]  [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   36.402106]  [<ffffffff82f71a10>] ? _raw_spin_unlock+0x30/0x60
[   36.402106]  [<ffffffff810d672d>] exit_files+0x4d/0x60
[   36.402106]  [<ffffffff810d89f2>] do_exit+0x322/0x510
[   36.402106]  [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   36.402106]  [<ffffffff810ed5b8>] get_signal_to_deliver+0x4f8/0x580
[   36.402106]  [<ffffffff81065ae2>] do_signal+0x42/0x120
[   36.402106]  [<ffffffff81090000>] ? create_irq+0x10/0x30
[   36.402106]  [<ffffffff811ee78e>] ? might_fault+0x4e/0xa0
[   36.402106]  [<ffffffff82f7237f>] ? retint_signal+0x11/0x92
[   36.402106]  [<ffffffff81065c14>] do_notify_resume+0x54/0xb0
[   36.402106]  [<ffffffff82f723bb>] retint_signal+0x4d/0x92

Sasha Levin

2012-05-24 11:22 UTC #9 lore raw

Quoted 6 lines · Sasha Levin

Quoted 3 lines · Alan Cox
Quoted 1 line
I'm still seeing the warning with this patch:
Can you attach the trace that went with the trigger as well ?
Ofcourse, attached as a file.

Heh, this was a different one as well. I'll try to get the one I got in the morning again.

Sasha Levin

2012-05-24 11:25 UTC #10 lore raw

Quoted 10 lines · Sasha Levin

Quoted 6 lines · Sasha Levin
Quoted 3 lines · Alan Cox
Quoted 1 line
I'm still seeing the warning with this patch:
Can you attach the trace that went with the trigger as well ?
Ofcourse, attached as a file.
Heh, this was a different one as well. I'll try to get the one I got in the morning again.

And here is the second one attached as well, so these are two different warnings I get with the new version.

[   39.888115] =============================================
[   39.888115] [ INFO: possible recursive locking detected ]
[   39.888115] 3.4.0-next-20120524-sasha-00002-g11dc651 #273 Tainted: G        W   
[   39.888115] ---------------------------------------------
[   39.888115] trinity/4980 is trying to acquire lock:
[   39.888115]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   39.888115] 
[   39.888115] but task is already holding lock:
[   39.888115]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   39.888115] 
[   39.888115] other info that might help us debug this:
[   39.888115]  Possible unsafe locking scenario:
[   39.888115] 
[   39.888115]        CPU0
[   39.888115]        ----
[   39.888115]   lock(&tty->legacy_mutex);
[   39.888115]   lock(&tty->legacy_mutex);
[   39.888115] 
[   39.888115]  *** DEADLOCK ***
[   39.888115] 
[   39.888115]  May be due to missing lock nesting notation
[   39.888115] 
[   39.888115] 1 lock held by trinity/4980:
[   39.888115]  #0:  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   39.888115] 
[   39.888115] stack backtrace:
[   39.888115] Pid: 4980, comm: trinity Tainted: G        W    3.4.0-next-20120524-sasha-00002-g11dc651 #273
[   39.888115] Call Trace:
[   39.888115]  [<ffffffff81148019>] print_deadlock_bug+0x119/0x140
[   39.888115]  [<ffffffff8114a18e>] validate_chain+0x5ee/0x790
[   39.888115]  [<ffffffff8111a5f8>] ? sched_clock_cpu+0x108/0x120
[   39.973550]  [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   39.973550]  [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   39.973550]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   39.973550]  [<ffffffff82f6e410>] __mutex_lock_common+0x60/0x590
[   39.973550]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   39.973550]  [<ffffffff8114aea2>] ? __lock_release+0x1c2/0x1e0
[   39.973550]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   39.973550]  [<ffffffff82f71fdb>] ? tty_lock_nested+0x7b/0x90
[   39.973550]  [<ffffffff82f6ea70>] mutex_lock_nested+0x40/0x50
[   39.973550]  [<ffffffff82f71fdb>] tty_lock_nested+0x7b/0x90
[   39.973550]  [<ffffffff82f71ffb>] tty_lock+0xb/0x10
[   39.973550]  [<ffffffff81b155f7>] tty_ldisc_release+0x47/0xb0
[   39.973550]  [<ffffffff81b0fc33>] tty_release+0x453/0x4d0
[   39.973550]  [<ffffffff81232d4a>] __fput+0x11a/0x2c0
[   39.973550]  [<ffffffff81232f05>] fput+0x15/0x20
[   39.973550]  [<ffffffff8122f212>] filp_close+0x82/0xa0
[   39.973550]  [<ffffffff810d6514>] close_files+0x1b4/0x200
[   39.973550]  [<ffffffff810d6360>] ? wait_task_stopped+0x3d0/0x3d0
[   39.973550]  [<ffffffff810d6725>] ? exit_files+0x45/0x60
[   39.973550]  [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   39.973550]  [<ffffffff82f71a10>] ? _raw_spin_unlock+0x30/0x60
[   39.973550]  [<ffffffff810d672d>] exit_files+0x4d/0x60
[   39.973550]  [<ffffffff810d89f2>] do_exit+0x322/0x510
[   39.973550]  [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   39.973550]  [<ffffffff810d8cd2>] sys_exit_group+0x12/0x20
[   39.973550]  [<ffffffff82f72bb9>] system_call_fastpath+0x16/0x1b

Alan Cox

2012-05-24 14:39 UTC #11 lore raw

Quoted 10 lines · On Thu, 24 May 2012 13:24:56 +0200 Sasha Levin <[email protected]> wrote:

Quoted 8 lines · Sasha Levin
Quoted 6 lines · Sasha Levin
Quoted 3 lines · Alan Cox
Quoted 1 line
I'm still seeing the warning with this patch:
Can you attach the trace that went with the trigger as well ?

Quoted 7 lines

Quoted 4 lines
Quoted 1 line
Ofcourse, attached as a file.
Heh, this was a different one as well. I'll try to get the one I got in the morning again.
And here is the second one attached as well, so these are two different warnings I get with the new version.

I'm somewhat baffled by this one. Can lockdep be fooled by an object being freed and reallocated at the same address, Is there any markup that should be present to avoid that ?

Alan

Steven Rostedt

2012-05-25 02:32 UTC #12 lore raw

Quoted 10 lines · Alan Cox

Quoted 3 lines · On Thu, 24 May 2012 13:24:56 +0200 Sasha Levin <[email protected]> wrote:
And here is the second one attached as well, so these are two different warnings I get with the new version.
I'm somewhat baffled by this one. Can lockdep be fooled by an object being freed and reallocated at the same address, Is there any markup that should be present to avoid that ?

Sasha,

Did you apply Ming's second patch. His first patch (the one referenced in the email) didn't have the unlock fixup.

--Steve

Sasha Levin

2012-05-25 08:08 UTC #13 lore raw

Quoted 8 lines · Steven Rostedt

Quoted 7 lines · Alan Cox
Quoted 3 lines · On Thu, 24 May 2012 13:24:56 +0200 Sasha Levin <[email protected]> wrote:
And here is the second one attached as well, so these are two different warnings I get with the new version.

Quoted 8 lines

Quoted 3 lines
I'm somewhat baffled by this one. Can lockdep be fooled by an object being freed and reallocated at the same address, Is there any markup that should be present to avoid that ?
Sasha,
Did you apply Ming's second patch. His first patch (the one referenced in the email) didn't have the unlock fixup.

Nope, I just got the first one.

What's the right patchset to use atm? I know about these patches from Ming, and I see Alan sent out two patches yesterday. Which ones should I use for testing?

Ming Lei

2012-05-25 08:30 UTC #14 lore raw

Quoted 15 lines · Sasha Levin

Quoted 14 lines · Steven Rostedt
Quoted 10 lines · Alan Cox
Quoted 3 lines · On Thu, 24 May 2012 13:24:56 +0200 Sasha Levin <[email protected]> wrote:
And here is the second one attached as well, so these are two different warnings I get with the new version.
I'm somewhat baffled by this one. Can lockdep be fooled by an object being freed and reallocated at the same address, Is there any markup that should be present to avoid that ?
Sasha,

Quoted 8 lines

Quoted 2 lines
Did you apply Ming's second patch. His first patch (the one referenced in the email) didn't have the unlock fixup.
Nope, I just got the first one.
What's the right patchset to use atm? I know about these patches from Ming, and I see Alan sent out two patches yesterday. Which ones should I use for testing?

You can try to apply my 2nd patch against Alan's two patches for the tests.

Thanks,

Signature · 1 line

Ming Lei

Sasha Levin

2012-05-25 10:24 UTC #15 lore raw

Quoted 19 lines · Ming Lei

Quoted 18 lines · Sasha Levin
Quoted 16 lines · Steven Rostedt
Quoted 10 lines · Alan Cox
Quoted 3 lines · On Thu, 24 May 2012 13:24:56 +0200 Sasha Levin <[email protected]> wrote:
And here is the second one attached as well, so these are two different warnings I get with the new version.
I'm somewhat baffled by this one. Can lockdep be fooled by an object being freed and reallocated at the same address, Is there any markup that should be present to avoid that ?
Sasha,
Did you apply Ming's second patch. His first patch (the one referenced in the email) didn't have the unlock fixup.

Quoted 7 lines

Quoted 5 lines
Nope, I just got the first one.
What's the right patchset to use atm? I know about these patches from Ming, and I see Alan sent out two patches yesterday. Which ones should I use for testing?
You can try to apply my 2nd patch against Alan's two patches for the tests.

Applying Ming's patch over Alan's 2 patches from yesterday, I'm still seeing two lockdep warnings. Full trace attached.

[   40.627460] 
[   40.628014] =============================================
[   40.628014] [ INFO: possible recursive locking detected ]
[   40.628014] 3.4.0-next-20120524-sasha-00005-g9d5c83d #286 Tainted: G        W   
[   40.628014] ---------------------------------------------
[   40.628014] trinity-child1/4949 is trying to acquire lock:
[   40.628014]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.628014] 
[   40.628014] but task is already holding lock:
[   40.628014]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.628014] 
[   40.628014] other info that might help us debug this:
[   40.628014]  Possible unsafe locking scenario:
[   40.628014] 
[   40.628014]        CPU0
[   40.628014]        ----
[   40.628014]   lock(&tty->legacy_mutex);
[   40.628014]   lock(&tty->legacy_mutex);
[   40.628014] 
[   40.628014]  *** DEADLOCK ***
[   40.628014] 
[   40.628014]  May be due to missing lock nesting notation
[   40.628014] 
[   40.628014] 1 lock held by trinity-child1/4949:
[   40.628014]  #0:  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.628014] 
[   40.628014] stack backtrace:
[   40.628014] Pid: 4949, comm: trinity-child1 Tainted: G        W    3.4.0-next-20120524-sasha-00005-g9d5c83d #286
[   40.628014] Call Trace:
[   40.628014]  [<ffffffff81148019>] print_deadlock_bug+0x119/0x140
[   40.628014]  [<ffffffff8114a18e>] validate_chain+0x5ee/0x790
[   40.628014]  [<ffffffff8111a5f8>] ? sched_clock_cpu+0x108/0x120
[   40.628014]  [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   40.628014]  [<ffffffff8114444e>] ? put_lock_stats+0xe/0x40
[   40.628014]  [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   40.628014]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.628014]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   40.628014]  [<ffffffff82f6e430>] __mutex_lock_common+0x60/0x590
[   40.628014]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.628014]  [<ffffffff810f5405>] ? flush_work_sync+0x45/0x90
[   40.628014]  [<ffffffff8114aea2>] ? __lock_release+0x1c2/0x1e0
[   40.628014]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   40.628014]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.628014]  [<ffffffff82f6ea90>] mutex_lock_nested+0x40/0x50
[   40.628014]  [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.628014]  [<ffffffff82f72082>] tty_lock_pair+0x62/0x70
[   40.628014]  [<ffffffff81b1563a>] tty_ldisc_release+0x4a/0xb0
[   40.628014]  [<ffffffff81b1568b>] tty_ldisc_release+0x9b/0xb0
[   40.628014]  [<ffffffff81b0fc73>] tty_release+0x453/0x4d0
[   40.628014]  [<ffffffff82f6e365>] ? __mutex_unlock_slowpath+0x1a5/0x200
[   40.628014]  [<ffffffff82f6e3c9>] ? mutex_unlock+0x9/0x10
[   40.628014]  [<ffffffff82f720e4>] ? tty_unlock+0x54/0x60
[   40.628014]  [<ffffffff81232d9a>] __fput+0x11a/0x2c0
[   40.628014]  [<ffffffff81232f55>] fput+0x15/0x20
[   40.628014]  [<ffffffff8122f262>] filp_close+0x82/0xa0
[   40.823224]  [<ffffffff810d6514>] close_files+0x1b4/0x200
[   40.823224]  [<ffffffff810d6360>] ? wait_task_stopped+0x3d0/0x3d0
[   40.823224]  [<ffffffff810d6725>] ? exit_files+0x45/0x60
[   40.823224]  [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   40.823224]  [<ffffffff82f71a30>] ? _raw_spin_unlock+0x30/0x60
[   40.823224]  [<ffffffff810d672d>] exit_files+0x4d/0x60
[   40.823224]  [<ffffffff810d89f2>] do_exit+0x322/0x510
[   40.823224]  [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   40.823224]  [<ffffffff810d8cd2>] sys_exit_group+0x12/0x20
[   40.823224]  [<ffffffff82f72bf9>] system_call_fastpath+0x16/0x1b

===

[   40.941023] ======================================================
[   40.941691] [ INFO: possible circular locking dependency detected ]
[   40.941691] 3.4.0-next-20120524-sasha-00005-g9d5c83d #286 Tainted: G        W   
[   40.941691] -------------------------------------------------------
[   40.941691] trinity-child1/4988 is trying to acquire lock:
[   40.941691]  (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691] 
[   40.941691] but task is already holding lock:
[   40.941691]  (&tty->legacy_mutex/1){+.+...}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691] 
[   40.941691] which lock already depends on the new lock.
[   40.941691] 
[   40.941691] 
[   40.941691] the existing dependency chain (in reverse order) is:
[   40.941691] 
[   40.941691] -> #1 (&tty->legacy_mutex/1){+.+...}:
[   40.941691]        [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   40.941691]        [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   40.941691]        [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   40.941691]        [<ffffffff82f6e430>] __mutex_lock_common+0x60/0x590
[   40.941691]        [<ffffffff82f6ea90>] mutex_lock_nested+0x40/0x50
[   40.941691]        [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691]        [<ffffffff82f72082>] tty_lock_pair+0x62/0x70
[   40.941691]        [<ffffffff81b0f9a2>] tty_release+0x182/0x4d0
[   40.941691]        [<ffffffff81232d9a>] __fput+0x11a/0x2c0
[   40.941691]        [<ffffffff81232f55>] fput+0x15/0x20
[   40.941691]        [<ffffffff8122f262>] filp_close+0x82/0xa0
[   40.941691]        [<ffffffff810d6514>] close_files+0x1b4/0x200
[   40.941691]        [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   40.941691]        [<ffffffff810d672d>] exit_files+0x4d/0x60
[   40.941691]        [<ffffffff810d89f2>] do_exit+0x322/0x510
[   40.941691]        [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   40.941691]        [<ffffffff810d8cd2>] sys_exit_group+0x12/0x20
[   40.941691]        [<ffffffff82f72bf9>] system_call_fastpath+0x16/0x1b
[   40.941691] 
[   40.941691] -> #0 (&tty->legacy_mutex){+.+.+.}:
[   40.941691]        [<ffffffff811497ef>] check_prev_add+0x11f/0x4d0
[   40.941691]        [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   40.941691]        [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   40.941691]        [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   40.941691]        [<ffffffff82f6e430>] __mutex_lock_common+0x60/0x590
[   40.941691]        [<ffffffff82f6ea90>] mutex_lock_nested+0x40/0x50
[   40.941691]        [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691]        [<ffffffff82f72082>] tty_lock_pair+0x62/0x70
[   40.941691]        [<ffffffff81b1563a>] tty_ldisc_release+0x4a/0xb0
[   40.941691]        [<ffffffff81b1568b>] tty_ldisc_release+0x9b/0xb0
[   40.941691]        [<ffffffff81b0fc73>] tty_release+0x453/0x4d0
[   40.941691]        [<ffffffff81232d9a>] __fput+0x11a/0x2c0
[   40.941691]        [<ffffffff81232f55>] fput+0x15/0x20
[   40.941691]        [<ffffffff8122f262>] filp_close+0x82/0xa0
[   40.941691]        [<ffffffff810d6514>] close_files+0x1b4/0x200
[   40.941691]        [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   40.941691]        [<ffffffff810d672d>] exit_files+0x4d/0x60
[   40.941691]        [<ffffffff810d89f2>] do_exit+0x322/0x510
[   40.941691]        [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   40.941691]        [<ffffffff810d8cd2>] sys_exit_group+0x12/0x20
[   40.941691]        [<ffffffff82f72bf9>] system_call_fastpath+0x16/0x1b
[   40.941691] 
[   40.941691] other info that might help us debug this:
[   40.941691] 
[   40.941691]  Possible unsafe locking scenario:
[   40.941691] 
[   40.941691]        CPU0                    CPU1
[   40.941691]        ----                    ----
[   40.941691]   lock(&tty->legacy_mutex/1);
[   40.941691]                                lock(&tty->legacy_mutex);
[   40.941691]                                lock(&tty->legacy_mutex/1);
[   40.941691]   lock(&tty->legacy_mutex);
[   40.941691] 
[   40.941691]  *** DEADLOCK ***
[   40.941691] 
[   40.941691] 1 lock held by trinity-child1/4988:
[   40.941691]  #0:  (&tty->legacy_mutex/1){+.+...}, at: [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691] 
[   40.941691] stack backtrace:
[   40.941691] Pid: 4988, comm: trinity-child1 Tainted: G        W    3.4.0-next-20120524-sasha-00005-g9d5c83d #286
[   40.941691] Call Trace:
[   40.941691]  [<ffffffff811477d5>] print_circular_bug+0x105/0x120
[   40.941691]  [<ffffffff811497ef>] check_prev_add+0x11f/0x4d0
[   40.941691]  [<ffffffff82f71b4b>] ? _raw_spin_unlock_irq+0x2b/0x80
[   40.941691]  [<ffffffff8114a23e>] validate_chain+0x69e/0x790
[   40.941691]  [<ffffffff8111a5f8>] ? sched_clock_cpu+0x108/0x120
[   40.941691]  [<ffffffff8114a753>] __lock_acquire+0x423/0x4c0
[   40.941691]  [<ffffffff8114444e>] ? put_lock_stats+0xe/0x40
[   40.941691]  [<ffffffff8114a97a>] lock_acquire+0x18a/0x1e0
[   40.941691]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.941691]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   40.941691]  [<ffffffff82f6e430>] __mutex_lock_common+0x60/0x590
[   40.941691]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.941691]  [<ffffffff810f5405>] ? flush_work_sync+0x45/0x90
[   40.941691]  [<ffffffff8114aea2>] ? __lock_release+0x1c2/0x1e0
[   40.941691]  [<ffffffff810f5240>] ? flush_scheduled_work+0x20/0x20
[   40.941691]  [<ffffffff82f71ffb>] ? tty_lock_nested+0x7b/0x90
[   40.941691]  [<ffffffff82f6ea90>] mutex_lock_nested+0x40/0x50
[   40.941691]  [<ffffffff82f71ffb>] tty_lock_nested+0x7b/0x90
[   40.941691]  [<ffffffff82f72082>] tty_lock_pair+0x62/0x70
[   40.941691]  [<ffffffff81b1563a>] tty_ldisc_release+0x4a/0xb0
[   40.941691]  [<ffffffff81b1568b>] tty_ldisc_release+0x9b/0xb0
[   40.941691]  [<ffffffff81b0fc73>] tty_release+0x453/0x4d0
[   40.941691]  [<ffffffff81232d9a>] __fput+0x11a/0x2c0
[   40.941691]  [<ffffffff81232f55>] fput+0x15/0x20
[   40.941691]  [<ffffffff8122f262>] filp_close+0x82/0xa0
[   40.941691]  [<ffffffff810d6514>] close_files+0x1b4/0x200
[   40.941691]  [<ffffffff810d6360>] ? wait_task_stopped+0x3d0/0x3d0
[   40.941691]  [<ffffffff810d6725>] ? exit_files+0x45/0x60
[   40.941691]  [<ffffffff810d6581>] put_files_struct+0x21/0x180
[   40.941691]  [<ffffffff82f71a30>] ? _raw_spin_unlock+0x30/0x60
[   40.941691]  [<ffffffff810d672d>] exit_files+0x4d/0x60
[   40.941691]  [<ffffffff810d89f2>] do_exit+0x322/0x510
[   40.941691]  [<ffffffff810d8c81>] do_group_exit+0xa1/0xe0
[   40.941691]  [<ffffffff810d8cd2>] sys_exit_group+0x12/0x20
[   40.941691]  [<ffffffff82f72bf9>] system_call_fastpath+0x16/0x1b

Alan Cox

2012-05-25 10:46 UTC #16 lore raw

Quoted 2 lines

Applying Ming's patch over Alan's 2 patches from yesterday, I'm still seeing two lockdep warnings. Full trace attached.

In that code path we've just succesfully done

tty_lock_pair(tty, o_tty)

(no warning issued)

We've then called into tty_ldisc_release which has done

	tty_unlock_pair(tty, o_tty);

and then

	tty_lock_pair(tty, o_tty);

which can't error unless our locking hosed

and at that point we then then do a recursive

tty_ldisc_release(o_tty, NULL)

which embarrassingly already has a comment above it I put there saying

        /* This will need doing differently if we need to lock */

Let me go rewrite that particular routine to make sense with the locking in place.