Re: 3.4+ tty lockdep trace

[Sasha Levin]

On Fri, May 25, 2012 at 10:30 AM, Ming Lei <tom.leiming@xxxxxxxxx> wrote:
> On Fri, May 25, 2012 at 4:07 PM, Sasha Levin <levinsasha928@xxxxxxxxx> wrote:
>> On Fri, May 25, 2012 at 4:32 AM, Steven Rostedt <rostedt@xxxxxxxxxxx> 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 <levinsasha928@xxxxxxxxx> 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.
[   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