Re: Inconsistent lock state - finish_task_switch/sched.c

[Michal Simek]

Peter Zijlstra wrote:
> On Thu, 2009-12-03 at 17:26 +0100, Michal Simek wrote:
>
> > =================================
> > [ INFO: inconsistent lock state ]
> > 2.6.32-00043-g62a59b0 #12
> > ---------------------------------
> > inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
> > swapper/1 [HC0[0]:SC0[0]:HE0:SE1] takes:
> >   (&rq->lock){?.-...}, at: [<c000f148>] finish_task_switch+0x0/0x178
> > {IN-HARDIRQ-W} state was registered at:
> >    [<c0016478>] release_console_sem+0x50/0x2d8
> >    [<c0046214>] mark_lock+0x2f4/0x6ac
> >    [<c00492f8>] __lock_acquire+0x908/0xbb8
> >    [<c001707c>] vprintk+0x2a4/0x550
> >    [<c0048cfc>] __lock_acquire+0x30c/0xbb8
> >    [<c00495f8>] lock_acquire+0x50/0x80
> >    [<c0024374>] do_timer+0x40/0x68
> >    [<c0048bfc>] __lock_acquire+0x20c/0xbb8
> >    [<c0280d3c>] _spin_lock+0x38/0x64
> >    [<c00120f0>] scheduler_tick+0x2c/0x13c
> >    [<c00120e8>] scheduler_tick+0x24/0x13c
> >    [<c00243b8>] run_local_timers+0x1c/0x44
> >    [<c00120f0>] scheduler_tick+0x2c/0x13c
> >    [<c0024438>] update_process_times+0x58/0x88
> >    [<c002442c>] update_process_times+0x4c/0x88
> >    [<c0042d30>] tick_periodic+0x30/0x110
> >    [<c0042dec>] tick_periodic+0xec/0x110
> >    [<c0042dc4>] tick_periodic+0xc4/0x110
> >    [<c0042e3c>] tick_handle_periodic+0x2c/0x150
> >    [<c00495f8>] lock_acquire+0x50/0x80
> >    [<c0280af4>] _spin_unlock_irqrestore+0x2c/0x90
> >    [<c0005ff4>] timer_interrupt+0x30/0x50
> >    [<c0050f58>] handle_IRQ_event+0x58/0x1e8
> >    [<c0280b88>] _spin_unlock+0x30/0x50
> >    [<c00540d8>] handle_level_irq+0xa4/0x16c
> >    [<c00540c8>] handle_level_irq+0x94/0x16c
> >    [<c0001b2c>] do_IRQ+0x7c/0x108
> >    [<c0001ae0>] do_IRQ+0x30/0x108
> >    [<c0008b20>] irq_call+0x0/0x8
> >    [<c0280e90>] _spin_lock_irqsave+0x30/0x8c
> >    [<c0280b1c>] _spin_unlock_irqrestore+0x54/0x90
> >    [<c0042628>] clockevents_register_device+0xf8/0x194
> >    [<c00425a8>] clockevents_register_device+0x78/0x194
> >    [<c0042630>] clockevents_register_device+0x100/0x194
> >    [<c0339a6c>] start_kernel+0x2d4/0x4e4
> >    [<c0339a74>] start_kernel+0x2dc/0x4e4
> >    [<c0339a7c>] start_kernel+0x2e4/0x4e4
> >    [<c00065b0>] machine_halt+0x0/0x24
> >    [<c001667c>] release_console_sem+0x254/0x2d8
> > irq event stamp: 0
> > hardirqs last  enabled at (0): [<(null)>] (null)
> > hardirqs last disabled at (0): [<c001358c>] copy_process+0x33c/0x1200
> > softirqs last  enabled at (0): [<c001358c>] copy_process+0x33c/0x1200
> > softirqs last disabled at (0): [<(null)>] (null)
> >
> > other info that might help us debug this:
> > no locks held by swapper/1.
> >
> > stack backtrace:
> >
> > Stack:
> >    cf833de8 00000000 cf833e00 c028ee58 cf833e08 cf833e00 c0046594 c028e584
> >    c02b7568 c001667c 00000000 00000002 00000000 00000000 00000000 00000001
> >    cf833e3c 00000000 00000000 00000002 cf8313b4 c00490c4 cf83111c cf831210
> > Call Trace:
> >
> > [<c0046594>] mark_lock+0x674/0x6ac
> > [<c001667c>] release_console_sem+0x254/0x2d8
> > [<c00490c4>] __lock_acquire+0x6d4/0xbb8
> > [<c001a24c>] do_exit+0xcc/0x7a4
> > [<c0280d1c>] _spin_lock+0x18/0x64
> > [<c001a2b0>] do_exit+0x130/0x7a4
> > [<c00495f8>] lock_acquire+0x50/0x80
> > [<c000f1a8>] finish_task_switch+0x60/0x178
> > [<c000f148>] finish_task_switch+0x0/0x178
> > [<c0010aa4>] schedule_tail+0x18/0x88
> > [<c0018620>] exit_mm+0x248/0x268
> > [<c000f148>] finish_task_switch+0x0/0x178
> > [<c0007e94>] ret_from_fork+0x4/0x20
> > [<c0007f88>] full_exception_trap+0x28/0x210
> > [<c03391c0>] kernel_init+0x0/0x194
> > [<c0002628>] kernel_thread_helper+0x0/0x28
>
> So we schedule while holding rq->lock (for obvious reasons), but since
> lockdep tracks held locks per tasks, we need to transfer the held state
> from the prev to the next task. We do this by explicity calling
> spin_release(&rq->lock) in context_switch() right before switch_to(),
> and calling spin_acquire(&rq->lock) in
> finish_task_switch()->finish_lock_switch().
>
> Now, for some reason lockdep thinks that interrupts got enabled over the
> context switch (git grep __ARCH_WANTS_INTERRUPTS_ON_CTSW arch/microblaze
> doesn't seem to turn up anything).
>
> Clearly trying to acquire the rq->lock with interrupts enabled is a bad
> idea and lockdep warns you about this.

it works. I looked that only arm have it.

Thanks for your help,
Michal

>


--
Michal Simek, Ing. (M.Eng)
PetaLogix - Linux Solutions for a Reconfigurable World
w: www.petalogix.com p: +61-7-30090663,+42-0-721842854 f: +61-7-30090663
--
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/