Re: 2.6.28-rc4: inconsistent lock state durin s2ram

[Rafael J. Wysocki]

On Thursday, 13 of November 2008, Matt Mackall wrote:
> Just noticed this while looking to see if my iwlagn regression was still
> around (doesn't seem to be):

Is this reproducible?

It seems to be related to the scheduler.

> [112342.899610] SMP alternatives: switching to UP code
> [112343.045933] 
> [112343.045935] =================================
> [112343.045937] [ INFO: inconsistent lock state ]
> [112343.045941] 2.6.28-rc4 #40
> [112343.045943] ---------------------------------
> [112343.045945] inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
> [112343.045949] ksoftirqd/0/4 [HC0[0]:SC1[1]:HE1:SE0] takes:
> [112343.045951]  (&rq->lock){++..}, at: [<ffffffff802493f5>]
> sched_rt_period_timer+0xb9/0x1c7
> [112343.045961] {in-hardirq-W} state was registered at:
> [112343.045963]   [<ffffffffffffffff>] 0xffffffffffffffff
> [112343.045969] irq event stamp: 4112884
> [112343.045972] hardirqs last  enabled at (4112884):
> [<ffffffff804ed8ca>] _spin_unlock_irq+0x24/0x2e
> [112343.045978] hardirqs last disabled at (4112883):
> [<ffffffff804eda92>] _spin_lock_irq+0x15/0x41
> [112343.045983] softirqs last  enabled at (4112876):
> [<ffffffff8022674c>] call_softirq+0x1c/0x28
> [112343.045989] softirqs last disabled at (4112881):
> [<ffffffff8022674c>] call_softirq+0x1c/0x28
> [112343.045994] 
> [112343.045995] other info that might help us debug this:
> [112343.045997] no locks held by ksoftirqd/0/4.
> [112343.045999] 
> [112343.046000] stack backtrace:
> [112343.046003] Pid: 4, comm: ksoftirqd/0 Not tainted 2.6.28-rc4 #40
> [112343.046006] Call Trace:
> [112343.046008]  <IRQ>  [<ffffffff8026e41f>] print_usage_bug+0x1a3/0x1b2
> [112343.046019]  [<ffffffff8022f1dd>] save_stack_trace+0x22/0x3e
> [112343.046023]  [<ffffffff8026ee45>] mark_lock+0x5a9/0x91f
> [112343.046028]  [<ffffffff80270369>] __lock_acquire+0x6c2/0x14b2
> [112343.046032]  [<ffffffff802711e6>] lock_acquire+0x8d/0xba
> [112343.046037]  [<ffffffff802493f5>] sched_rt_period_timer+0xb9/0x1c7
> [112343.046041]  [<ffffffff804eda37>] _spin_lock+0x29/0x36
> [112343.046045]  [<ffffffff802493f5>] sched_rt_period_timer+0xb9/0x1c7
> [112343.046050]  [<ffffffff80355db7>] __next_cpu+0x19/0x26
> [112343.046054]  [<ffffffff802493f5>] sched_rt_period_timer+0xb9/0x1c7
> [112343.046058]  [<ffffffff804ed8ca>] _spin_unlock_irq+0x24/0x2e
> [112343.046063]  [<ffffffff8024933c>] sched_rt_period_timer+0x0/0x1c7
> [112343.046068]  [<ffffffff80264c82>] run_hrtimer_pending+0x61/0x10b
> [112343.046073]  [<ffffffff80254c83>] __do_softirq+0x8e/0x163
> [112343.046077]  [<ffffffff8022674c>] call_softirq+0x1c/0x28
> [112343.046079]  <EOI>  [<ffffffff80227db5>] do_softirq+0x45/0xa5
> [112343.046086]  [<ffffffff8025452f>] ksoftirqd+0x56/0xcc
> [112343.046090]  [<ffffffff802544d9>] ksoftirqd+0x0/0xcc
> [112343.046095]  [<ffffffff8026257e>] kthread+0x47/0x73
> [112343.046101]  [<ffffffff804ed511>] trace_hardirqs_on_thunk+0x3a/0x3f
> [112343.046105]  [<ffffffff80226259>] child_rip+0xa/0x11
> [112343.046109]  [<ffffffff80225463>] restore_args+0x0/0x30
> [112343.046114]  [<ffffffff80262512>] kthreadd+0x187/0x1ac
> [112343.046118]  [<ffffffff80262537>] kthread+0x0/0x73
> [112343.046122]  [<ffffffff8022624f>] child_rip+0x0/0x11
> 



-- 
Everyone knows that debugging is twice as hard as writing a program
in the first place.  So if you're as clever as you can be when you write it,
how will you ever debug it? --- Brian Kernighan
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/