2012-05-23 00:26:57

by Dave Jones

[permalink] [raw]
Subject: 3.4+ tty lockdep trace

>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


2012-05-23 01:06:24

by Ming Lei

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

Hi Dave,

On Wed, May 23, 2012 at 8:26 AM, Dave Jones <[email protected]> wrote:
> 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

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,
--
Ming Lei

2012-05-23 01:17:11

by Dave Jones

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Wed, May 23, 2012 at 09:06:22AM +0800, Ming Lei wrote:

> > [ ? 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
>
> 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




2012-05-23 02:05:52

by Dave Jones

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

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

2012-05-23 02:45:17

by Ming Lei

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Wed, May 23, 2012 at 10:02 AM, Dave Jones <[email protected]> wrote:
> 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

>
> ? ? ? ?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 23:03:04

by Alan

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

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

2012-05-24 06:14:19

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Wed, May 23, 2012 at 3:06 AM, Ming Lei <[email protected]> wrote:
> Hi Dave,
>
> On Wed, May 23, 2012 at 8:26 AM, Dave Jones <[email protected]> wrote:
>> 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
>
> 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 ***

2012-05-24 11:08:39

by Alan

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

> I'm still seeing the warning with this patch:

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

2012-05-24 11:20:26

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Thu, May 24, 2012 at 1:10 PM, Alan Cox <[email protected]> wrote:
>> 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.


Attachments:
tty_lockdep.txt (6.75 kB)

2012-05-24 11:22:10

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Thu, May 24, 2012 at 1:20 PM, Sasha Levin <[email protected]> wrote:
> On Thu, May 24, 2012 at 1:10 PM, Alan Cox <[email protected]> wrote:
>>> 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.

2012-05-24 11:25:19

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Thu, May 24, 2012 at 1:21 PM, Sasha Levin <[email protected]> wrote:
> On Thu, May 24, 2012 at 1:20 PM, Sasha Levin <[email protected]> wrote:
>> On Thu, May 24, 2012 at 1:10 PM, Alan Cox <[email protected]> wrote:
>>>> 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.


Attachments:
tty_lockdep2.txt (3.08 kB)

2012-05-24 14:39:24

by Alan

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

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

> On Thu, May 24, 2012 at 1:21 PM, Sasha Levin
> <[email protected]> wrote:
> > On Thu, May 24, 2012 at 1:20 PM, Sasha Levin
> > <[email protected]> wrote:
> >> On Thu, May 24, 2012 at 1:10 PM, Alan Cox
> >> <[email protected]> wrote:
> >>>> 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.


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

2012-05-25 02:32:27

by Steven Rostedt

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Thu, May 24, 2012 at 03:54:57PM +0100, Alan Cox wrote:
> 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

2012-05-25 08:08:11

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Fri, May 25, 2012 at 4:32 AM, Steven Rostedt <[email protected]> wrote:
> On Thu, May 24, 2012 at 03:54:57PM +0100, Alan Cox wrote:
>> 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.

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?

2012-05-25 08:30:59

by Ming Lei

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Fri, May 25, 2012 at 4:07 PM, Sasha Levin <[email protected]> wrote:
> On Fri, May 25, 2012 at 4:32 AM, Steven Rostedt <[email protected]> wrote:
>> On Thu, May 24, 2012 at 03:54:57PM +0100, Alan Cox wrote:
>>> 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.
>
> 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,
--
Ming Lei

2012-05-25 10:24:27

by Sasha Levin

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

On Fri, May 25, 2012 at 10:30 AM, Ming Lei <[email protected]> wrote:
> On Fri, May 25, 2012 at 4:07 PM, Sasha Levin <[email protected]> wrote:
>> On Fri, May 25, 2012 at 4:32 AM, Steven Rostedt <[email protected]> wrote:
>>> On Thu, May 24, 2012 at 03:54:57PM +0100, Alan Cox wrote:
>>>> 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.
>>
>> 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.


Attachments:
tty_lockdep3.txt (10.12 kB)

2012-05-25 10:46:42

by Alan

[permalink] [raw]
Subject: Re: 3.4+ tty lockdep trace

> 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.