All of lore.kernel.org
 help / color / mirror / Atom feed
From: Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU>
To: Peter Zijlstra <peterz@infradead.org>
Cc: Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU>,
	Thomas Gleixner <tglx@linutronix.de>,
	LKML <linux-kernel@vger.kernel.org>,
	linux-rt-users <linux-rt-users@vger.kernel.org>,
	"Paul E. McKenney" <paulmck@linux.vnet.ibm.com>,
	Steven Rostedt <rostedt@goodmis.org>,
	Jason Wessel <jason.wessel@windriver.com>,
	Pekka Enberg <penberg@kernel.org>
Subject: Re: [ANNOUNCE] 3.0-rt4
Date: Thu, 28 Jul 2011 17:17:59 -0700	[thread overview]
Message-ID: <4E31FC37.7080803@localhost> (raw)
In-Reply-To: <1311888176.2617.379.camel@laptop>

On 07/28/2011 02:22 PM, Peter Zijlstra wrote:
> On Thu, 2011-07-28 at 12:16 -0700, Fernando Lopez-Lezcano wrote:
>> [    0.000000] =============================================
>> [    0.000000] [ INFO: possible recursive locking detected ]
>> [    0.000000] 3.0.0-1.rt5.1.fc15.ccrma.i686.rtPAE #1
>> [    0.000000] ---------------------------------------------
>> [    0.000000] swapper/0 is trying to acquire lock:
>> [    0.000000]  (&parent->list_lock){+.+...}, at: [<c04fb406>] __cache_free+0x43/0xc3
>> [    0.000000]
>> [    0.000000] but task is already holding lock:
>> [    0.000000]  (&parent->list_lock){+.+...}, at: [<c04fc538>] do_tune_cpucache+0xf2/0x2bb
>> [    0.000000]
>> [    0.000000] other info that might help us debug this:
>> [    0.000000]  Possible unsafe locking scenario:
>> [    0.000000]
>> [    0.000000]        CPU0
>> [    0.000000]        ----
>> [    0.000000]   lock(&parent->list_lock);
>> [    0.000000]   lock(&parent->list_lock);
>> [    0.000000]
>> [    0.000000]  *** DEADLOCK ***
>> [    0.000000]
>> [    0.000000]  May be due to missing lock nesting notation
>> [    0.000000]
>> [    0.000000] 3 locks held by swapper/0:
>> [    0.000000]  #0:  (cache_chain_mutex){+.+...}, at: [<c0bd9d2b>] kmem_cache_init_late+0xe/0x61
>> [    0.000000]  #1:  (&per_cpu(slab_lock, __cpu).lock){+.+...}, at: [<c04faa65>] __local_lock_irq+0x1e/0x5b
>> [    0.000000]  #2:  (&parent->list_lock){+.+...}, at: [<c04fc538>] do_tune_cpucache+0xf2/0x2bb
>> [    0.000000]
>> [    0.000000] stack backtrace:
>> [    0.000000] Pid: 0, comm: swapper Not tainted 3.0.0-1.rt5.1.fc15.ccrma.i686.rtPAE #1
>> [    0.000000] Call Trace:
>> [    0.000000]  [<c0856355>] ? printk+0x2d/0x2f
>> [    0.000000]  [<c0474a4b>] __lock_acquire+0x805/0xb57
>> [    0.000000]  [<c0472604>] ? lock_release_holdtime.part.10+0x4b/0x51
>> [    0.000000]  [<c085ecb4>] ? _raw_spin_unlock+0x31/0x3d
>> [    0.000000]  [<c085dbc5>] ? rt_spin_lock_slowlock+0x75/0x190
>> [    0.000000]  [<c04720c3>] ? trace_hardirqs_off+0xb/0xd
>> [    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
>> [    0.000000]  [<c0475215>] lock_acquire+0xde/0x11d
>> [    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
>> [    0.000000]  [<c085e24f>] rt_spin_lock+0x50/0x56
>> [    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
>> [    0.000000]  [<c04fb406>] __cache_free+0x43/0xc3
>> [    0.000000]  [<c043646d>] ? test_ti_thread_flag+0x8/0x10
>> [    0.000000]  [<c04fb23f>] kmem_cache_free+0x6c/0xdc
>> [    0.000000]  [<c04fb2fe>] slab_destroy+0x4f/0x53
>> [    0.000000]  [<c04fb396>] free_block+0x94/0xc1
>> [    0.000000]  [<c04fc551>] do_tune_cpucache+0x10b/0x2bb
>> [    0.000000]  [<c04fc8dc>] enable_cpucache+0x7b/0xa7
>> [    0.000000]  [<c0bd9d3c>] kmem_cache_init_late+0x1f/0x61
>> [    0.000000]  [<c0bba687>] start_kernel+0x24c/0x363
>> [    0.000000]  [<c0bba1c4>] ? loglevel+0x18/0x18
>> [    0.000000]  [<c0bba0ba>] i386_start_kernel+0xa9/0xaf
>
> Ooh, fun.. one does wonder why mainline doesn't show this..
>
> This is the normal OFF_SLAB recursion, and the reason this shows up is
> because this is ran before we do the lockdep fixup.
>
> Fernando, does something like the below (not actually against -rt, but
> it shouldn't matter much) fix things?

Strange. Looks like it only happens on a cold start (I would have to 
test more to be sure), so far two warm starts and it is not there, one 
cold start and it is there - sorry, I have run out of time now for more 
tests... (I checked my build logs and the patch applied cleanly, no 
complains there). Come to think of it I think this was not always 
happening before the patch (ie: not getting the error on all boots).

-- Fernando


[    0.000000] =============================================
[    0.000000] [ INFO: possible recursive locking detected ]
[    0.000000] 3.0.0-1.rt6.1.fc15.ccrma.i686.rtPAE #1
[    0.000000] ---------------------------------------------
[    0.000000] swapper/0 is trying to acquire lock:
[    0.000000]  (&parent->list_lock){+.+...}, at: [<c04fb406>] 
__cache_free+0x43/0xc3
[    0.000000]
[    0.000000] but task is already holding lock:
[    0.000000]  (&parent->list_lock){+.+...}, at: [<c04fc538>] 
do_tune_cpucache+0xf2/0x2bb
[    0.000000]
[    0.000000] other info that might help us debug this:
[    0.000000]  Possible unsafe locking scenario:
[    0.000000]
[    0.000000]        CPU0
[    0.000000]        ----
[    0.000000]   lock(&parent->list_lock);
[    0.000000]   lock(&parent->list_lock);
[    0.000000]
[    0.000000]  *** DEADLOCK ***
[    0.000000]
[    0.000000]  May be due to missing lock nesting notation
[    0.000000]
[    0.000000] 3 locks held by swapper/0:
[    0.000000]  #0:  (cache_chain_mutex){+.+...}, at: [<c0bd9d3b>] 
kmem_cache_init_late+0x1e/0x6a
[    0.000000]  #1:  (&per_cpu(slab_lock, __cpu).lock){+.+...}, at: 
[<c04faa65>] __local_lock_irq+0x1e/0x5b
[    0.000000]  #2:  (&parent->list_lock){+.+...}, at: [<c04fc538>] 
do_tune_cpucache+0xf2/0x2bb
[    0.000000]
[    0.000000] stack backtrace:
[    0.000000] Pid: 0, comm: swapper Not tainted 
3.0.0-1.rt6.1.fc15.ccrma.i686.rtPAE #1
[    0.000000] Call Trace:
[    0.000000]  [<c0856355>] ? printk+0x2d/0x2f
[    0.000000]  [<c0474a5b>] __lock_acquire+0x805/0xb57
[    0.000000]  [<c0472614>] ? lock_release_holdtime.part.10+0x4b/0x51
[    0.000000]  [<c085ecb4>] ? _raw_spin_unlock+0x31/0x3d
[    0.000000]  [<c085dbc5>] ? rt_spin_lock_slowlock+0x75/0x190
[    0.000000]  [<c04720d3>] ? trace_hardirqs_off+0xb/0xd
[    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
[    0.000000]  [<c0475225>] lock_acquire+0xde/0x11d
[    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
[    0.000000]  [<c085e24f>] rt_spin_lock+0x50/0x56
[    0.000000]  [<c04fb406>] ? __cache_free+0x43/0xc3
[    0.000000]  [<c04fb406>] __cache_free+0x43/0xc3
[    0.000000]  [<c043646d>] ? test_ti_thread_flag+0x8/0x10
[    0.000000]  [<c04fb23f>] kmem_cache_free+0x6c/0xdc
[    0.000000]  [<c04fb2fe>] slab_destroy+0x4f/0x53
[    0.000000]  [<c04fb396>] free_block+0x94/0xc1
[    0.000000]  [<c04fc551>] do_tune_cpucache+0x10b/0x2bb
[    0.000000]  [<c04fc8dc>] enable_cpucache+0x7b/0xa7
[    0.000000]  [<c0bd9d4c>] kmem_cache_init_late+0x2f/0x6a
[    0.000000]  [<c0bba687>] start_kernel+0x24c/0x363
[    0.000000]  [<c0bba1c4>] ? loglevel+0x18/0x18
[    0.000000]  [<c0bba0ba>] i386_start_kernel+0xa9/0xaf
[    0.000000] Console: colour VGA+ 80x25




  parent reply	other threads:[~2011-07-29  0:18 UTC|newest]

Thread overview: 35+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2011-07-27 21:37 [ANNOUNCE] 3.0-rt4 Thomas Gleixner
2011-07-27 21:57 ` Frank Rowand
2011-07-27 22:05   ` Thomas Gleixner
2011-07-27 22:27     ` Frank Rowand
2011-07-28  7:33 ` Nikita V. Youshchenko
2011-07-28  8:06   ` Thomas Gleixner
2011-07-28  8:24     ` Nikita V. Youshchenko
2011-07-28  8:44       ` Peter Zijlstra
2011-07-28  8:51         ` Nikita V. Youshchenko
2011-07-28  9:21           ` Anca Emanuel
2011-07-28 16:10             ` Thomas Gleixner
2011-07-28  9:37           ` Thomas Gleixner
2011-07-28  8:43     ` Peter Zijlstra
2011-07-28  9:41 ` Yong Zhang
2011-07-28  9:41   ` Yong Zhang
2011-07-28  9:49   ` Thomas Gleixner
2011-07-28 11:22 ` N, Mugunthan V
2011-07-28 11:36   ` Thomas Gleixner
2011-07-28 15:59 ` hermann
2011-07-28 17:41 ` Paul E. McKenney
2011-07-28 17:43   ` Thomas Gleixner
2011-07-28 18:32     ` Paul E. McKenney
2011-07-28 19:05       ` Thomas Gleixner
2011-07-28 19:34         ` Paul E. McKenney
2011-07-28 20:29           ` Paul E. McKenney
2011-07-28 17:42 ` Jason Wessel
2011-07-28 17:49   ` Thomas Gleixner
2011-07-28 19:16 ` Fernando Lopez-Lezcano
2011-07-28 19:36   ` Thomas Gleixner
2011-07-29  0:13     ` Fernando Lopez-Lezcano
2011-07-28 21:22   ` Peter Zijlstra
2011-07-28 21:22     ` Peter Zijlstra
2011-07-28 22:55     ` Pekka Enberg
2011-07-29  0:17     ` Fernando Lopez-Lezcano [this message]
2011-08-04  8:36     ` [tip:core/urgent] slab, lockdep: Annotate the locks before using them tip-bot for Peter Zijlstra

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=4E31FC37.7080803@localhost \
    --to=nando@ccrma.stanford.edu \
    --cc=jason.wessel@windriver.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-rt-users@vger.kernel.org \
    --cc=paulmck@linux.vnet.ibm.com \
    --cc=penberg@kernel.org \
    --cc=peterz@infradead.org \
    --cc=rostedt@goodmis.org \
    --cc=tglx@linutronix.de \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.