Re: yama_ptrace_access_check(): possible recursive locking detected

Fengguang Wu
2012-08-15T03:01:18Z

On Tue, Aug 14, 2012 at 02:16:52PM -0700, Kees Cook wrote:
> On Thu, Aug 9, 2012 at 6:52 PM, Fengguang Wu <fengguang.wu@intel.com> wrote:
> > On Thu, Aug 09, 2012 at 06:39:34PM -0700, Kees Cook wrote:
> >> Hi,
> >>
> >> So, after taking a closer look at this, I cannot understand how it's
> >> possible. Yama's task_lock call is against "current", not "child",
> >> which is what ptrace_may_access() is locking. And the same code makes
> >> sure that current != child. Yama would never get called if current ==
> >> child.
> >>
> >> How did you reproduce this situation?
> >
> > This warning can be triggered with Dave Jones' trinity tool:
> >
> > git://git.codemonkey.org.uk/trinity
> >
> > That's a very dangerous tool, please only run it as normal user in a
> > backed up and chrooted test box. I personally run it inside an initrd.
> > If you are interested in reproducing this, I can send you the ready
> > made initrd in private email.
>
> Well, even with your initrd, I can't reproduce this. You're running
> this against a stock kernel? I can't see how the path you've shown can

Yes, it happens on 3.6-rc1.

> possible happen. It could only happen if "task" was "current", but
> there is an explicit test for that in ptrace_may_access(). Based on
> the traceback, this is from reading /proc/$pid/stack (or
> /proc/$pid/task/$tid/stack), rather than a direct ptrace() call, but
> the code path for task != current still stands.
>
> I've tried both normal and "trinity -c read" and I haven't seen the
> trace you found. :(
>
> If you can isolate the case further, I'm happy to fix it, but
> currently, I don't see a path where this can deadlock.

Even if it's proved to be a false warning, it's still very worthwhile
to apply Oleg's fix to quiet the warning. Such warnings will mislead
my bisect script. The sooner it's fixed, the better. And I like Oleg's
fix because it makes things more simple and a little bit faster.

btw, I see some different warnings when digging through the boot logs:

(x86_64-randconfig-b050)
[ 128.725667]
[ 128.728649] =============================================
[ 128.733989] [ INFO: possible recursive locking detected ]
[ 128.733989] 3.6.0-rc1 #1 Not tainted
[ 128.733989] ---------------------------------------------
[ 128.733989] trinity-child0/523 is trying to acquire lock:
[ 128.733989] (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff810e0481>] get_task_comm+0x20/0x47
[ 128.733989]
[ 128.733989] but task is already holding lock:
[ 128.733989] (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff810572ab>] sys_ptrace+0x158/0x313
[ 128.733989]
[ 128.733989] other info that might help us debug this:
[ 128.733989] Possible unsafe locking scenario:
[ 128.733989]
[ 128.733989] CPU0
[ 128.733989] ----
[ 128.733989] lock(&(&p->alloc_lock)->rlock);
[ 128.733989] lock(&(&p->alloc_lock)->rlock);
[ 128.733989]
[ 128.733989] *** DEADLOCK ***
[ 128.733989]
[ 128.733989] May be due to missing lock nesting notation
[ 128.733989]
[ 128.733989] 2 locks held by trinity-child0/523:
[ 128.733989] #0: (&sig->cred_guard_mutex){+.+.+.}, at: [<ffffffff81057290>] sys_ptrace+0x13d/0x313
[ 128.733989] #1: (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff810572ab>] sys_ptrace+0x158/0x313
[ 128.733989]
[ 128.733989] stack backtrace:
[ 128.733989] Pid: 523, comm: trinity-child0 Not tainted 3.6.0-rc1 #1
[ 128.733989] Call Trace:
[ 128.733989] [<ffffffff81085649>] __lock_acquire+0xbe0/0xcfb
[ 128.733989] [<ffffffff81084884>] ? mark_lock+0x2d/0x212
[ 128.733989] [<ffffffff81084884>] ? mark_lock+0x2d/0x212
[ 128.733989] [<ffffffff8108639d>] lock_acquire+0x82/0x9d
[ 128.733989] [<ffffffff810e0481>] ? get_task_comm+0x20/0x47
[ 128.733989] [<ffffffff81a35ddf>] _raw_spin_lock+0x3b/0x4a
[ 128.733989] [<ffffffff810e0481>] ? get_task_comm+0x20/0x47
[ 128.733989] [<ffffffff810e0481>] get_task_comm+0x20/0x47
[ 128.733989] [<ffffffff81392c01>] yama_ptrace_access_check+0x16a/0x1c7
[ 128.733989] [<ffffffff810864e3>] ? lock_release+0x12b/0x157
[ 128.733989] [<ffffffff81390bfb>] security_ptrace_access_check+0xe/0x10
[ 128.733989] [<ffffffff81056e2b>] __ptrace_may_access+0x109/0x11b
[ 128.733989] [<ffffffff810572b8>] sys_ptrace+0x165/0x313
[ 128.733989] [<ffffffff81a37079>] system_call_fastpath+0x16/0x1b
[ 128.823670] ptrace of pid 522 was attempted by: trinity-child0 (pid 523)

(x86_64-randconfig-k056)
[ 87.057392]
[ 87.058009] =============================================
[ 87.058009] [ INFO: possible recursive locking detected ]
[ 87.058009] 3.6.0-rc1-00011-gf8cdda8 #2 Not tainted
[ 87.058009] ---------------------------------------------
[ 87.058009] trinity-child0/328 is trying to acquire lock:
[ 87.058009] (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff81104632>] spin_lock+0x9/0xb
[ 87.058009]
[ 87.058009] but task is already holding lock:
[ 87.058009] (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff8106cb40>] ptrace_attach+0xa4/0x208
[ 87.058009]
[ 87.058009] other info that might help us debug this:
[ 87.058009] Possible unsafe locking scenario:
[ 87.058009]
[ 87.058009] CPU0
[ 87.058009] ----
[ 87.058009] lock(&(&p->alloc_lock)->rlock);
[ 87.058009] lock(&(&p->alloc_lock)->rlock);
[ 87.058009]
[ 87.058009] *** DEADLOCK ***
[ 87.058009]
[ 87.058009] May be due to missing lock nesting notation
[ 87.058009]
[ 87.058009] 2 locks held by trinity-child0/328:
[ 87.058009] #0: (&sig->cred_guard_mutex){+.+.+.}, at: [<ffffffff8106cb25>] ptrace_attach+0x89/0x208
[ 87.058009] #1: (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff8106cb40>] ptrace_attach+0xa4/0x208
[ 87.058009]
[ 87.058009] stack backtrace:
[ 87.058009] Pid: 328, comm: trinity-child0 Not tainted 3.6.0-rc1-00011-gf8cdda8 #2
[ 87.058009] Call Trace:
[ 87.058009] [<ffffffff810a104e>] __lock_acquire+0xbe0/0xcfb
[ 87.058009] [<ffffffff810a07d3>] ? __lock_acquire+0x365/0xcfb
[ 87.058009] [<ffffffff810a0289>] ? mark_lock+0x2d/0x212
[ 87.058009] [<ffffffff810a0289>] ? mark_lock+0x2d/0x212
[ 87.058009] [<ffffffff810a1da2>] lock_acquire+0x82/0x9d
[ 87.058009] [<ffffffff81104632>] ? spin_lock+0x9/0xb
[ 87.058009] [<ffffffff816848af>] _raw_spin_lock+0x3b/0x4a
[ 87.058009] [<ffffffff81104632>] ? spin_lock+0x9/0xb
[ 87.058009] [<ffffffff81684a42>] ? _raw_spin_unlock_irqrestore+0x48/0x5c
[ 87.058009] [<ffffffff81104632>] spin_lock+0x9/0xb
[ 87.058009] [<ffffffff811058f3>] get_task_comm+0x20/0x47
[ 87.058009] [<ffffffff81239447>] yama_ptrace_access_check+0x15b/0x1a4
[ 87.058009] [<ffffffff812379fb>] security_ptrace_access_check+0xe/0x10
[ 87.058009] [<ffffffff8106ca8a>] __ptrace_may_access+0x110/0x122
[ 87.058009] [<ffffffff8106cb4d>] ptrace_attach+0xb1/0x208
[ 87.058009] [<ffffffff8106cfd0>] sys_ptrace+0x5c/0xb9
[ 87.058009] [<ffffffff81685b79>] system_call_fastpath+0x16/0x1b
[ 87.122562] ptrace of pid 326 was attempted by: trinity-child0 (pid 328)
[ 90.259448] ptrace of pid 332 was attempted by: trinity-child0 (pid 335)

Thanks,
Fengguang