lkml.org 
[lkml]   [2012]   [May]   [25]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
SubjectRe: 3.4+ tty lockdep trace
On Fri, May 25, 2012 at 10:30 AM, Ming Lei <tom.leiming@gmail.com> wrote:
> On Fri, May 25, 2012 at 4:07 PM, Sasha Levin <levinsasha928@gmail.com> wrote:
>> On Fri, May 25, 2012 at 4:32 AM, Steven Rostedt <rostedt@goodmis.org> 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@gmail.com> 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
\
 
 \ /
  Last update: 2012-05-25 12:41    [from the cache]
©2003-2011 Jasper Spaans