lkml.org 
[lkml]   [2009]   [Aug]   [19]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [circular locking bug] Re: [patch 00/15] clocksource / timekeeping rework V4 (resend V3 + bug fix)

ok, with all the latest patches i re-added these bits to
-tip, and it triggered this lockdep assert on a testbox:

=================================
[ INFO: inconsistent lock state ]
2.6.31-rc6-tip-01234-gcc9be0e-dirty #1054
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/1 [HC0[0]:SC1[1]:HE0:SE0] takes:
(clocksource_mutex){+.?.+.}, at: [<c10664d7>] clocksource_unregister+0x17/0x50
{SOFTIRQ-ON-W} state was registered at:
[<c106fb77>] mark_irqflags+0xf7/0x190
[<c107177a>] __lock_acquire+0x29a/0x520
[<c1071a6a>] lock_acquire+0x6a/0xc0
[<c175719b>] __mutex_lock_common+0x3b/0x340
[<c1757551>] mutex_lock_nested+0x31/0x40
[<c10666b7>] clocksource_register+0x17/0x40
[<c1bc68bd>] init_jiffies_clocksource+0xd/0x10
see fuller log below.

Ingo

Switching to clocksource acpi_pm
initcall init_acpi_pm_clocksource+0x0/0x1a0 returned 0 after 38256 usecs

=================================
[ INFO: inconsistent lock state ]
2.6.31-rc6-tip-01234-gcc9be0e-dirty #1054
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/1 [HC0[0]:SC1[1]:HE0:SE0] takes:
(clocksource_mutex){+.?.+.}, at: [<c10664d7>] clocksource_unregister+0x17/0x50
{SOFTIRQ-ON-W} state was registered at:
[<c106fb77>] mark_irqflags+0xf7/0x190
[<c107177a>] __lock_acquire+0x29a/0x520
[<c1071a6a>] lock_acquire+0x6a/0xc0
[<c175719b>] __mutex_lock_common+0x3b/0x340
[<c1757551>] mutex_lock_nested+0x31/0x40
[<c10666b7>] clocksource_register+0x17/0x40
[<c1bc68bd>] init_jiffies_clocksource+0xd/0x10
[<c1001129>] do_one_initcall+0x29/0x160
[<c1bb33f7>] do_initcalls+0x27/0x40
[<c1bb3436>] do_basic_setup+0x26/0x30
[<c1bb3b17>] kernel_init+0x57/0xa0
[<c1003ae7>] kernel_thread_helper+0x7/0x10
irq event stamp: 1135959
hardirqs last enabled at (1135958): [<c1045810>] __do_softirq+0x60/0x1d0
hardirqs last disabled at (1135959): [<c105e328>] hrtimer_switch_to_hres+0x48/0x100
softirqs last enabled at (1135840): [<c10458d1>] __do_softirq+0x121/0x1d0
softirqs last disabled at (1135957): [<c1005b22>] call_on_stack+0x12/0x20
other info that might help us debug this:
1 lock held by swapper/1:
#0: (i8253_lock){-.-...}, at: [<c1008ba8>] init_pit_timer+0x18/0xb0
stack backtrace:
Pid: 1, comm: swapper Not tainted 2.6.31-rc6-tip-01234-gcc9be0e-dirty #1054
Call Trace:
[<c106f430>] print_usage_bug+0x130/0x180
[<c106f5eb>] mark_lock_irq+0x16b/0x260
[<c106f240>] ? check_usage_forwards+0x0/0xc0
[<c106f7fe>] mark_lock+0x11e/0x3a0
[<c106fbff>] mark_irqflags+0x17f/0x190
[<c107177a>] __lock_acquire+0x29a/0x520
[<c1071a6a>] lock_acquire+0x6a/0xc0
[<c10664d7>] ? clocksource_unregister+0x17/0x50
[<c175719b>] __mutex_lock_common+0x3b/0x340
[<c10664d7>] ? clocksource_unregister+0x17/0x50
[<c1757551>] mutex_lock_nested+0x31/0x40
[<c10664d7>] ? clocksource_unregister+0x17/0x50
[<c10664d7>] clocksource_unregister+0x17/0x50
[<c1008b3a>] pit_disable_clocksource+0x2a/0x40
[<c1008bb9>] init_pit_timer+0x29/0xb0
[<c106825a>] clockevents_set_mode+0x1a/0x50
[<c1069a96>] tick_switch_to_oneshot+0x96/0xc0
[<c1069ad2>] tick_init_highres+0x12/0x20
[<c105e32d>] hrtimer_switch_to_hres+0x4d/0x100
[<c105ebbd>] hrtimer_run_pending+0x4d/0x50
[<c104bb85>] run_timer_softirq+0x25/0x230
[<c1092df4>] ? cpu_quiet+0x54/0x90
[<c1092968>] ? cpu_has_callbacks_ready_to_invoke+0x8/0x20
[<c10932d5>] ? rcu_do_batch+0x15/0x190
[<c1092ed3>] ? rcu_check_quiescent_state+0x33/0x50
[<c1045810>] ? __do_softirq+0x60/0x1d0
[<c10457b0>] ? __do_softirq+0x0/0x1d0
[<c106fe6a>] ? trace_hardirqs_on_caller+0x7a/0x1b0
[<c1045868>] __do_softirq+0xb8/0x1d0
[<c10457b0>] ? __do_softirq+0x0/0x1d0
<IRQ> [<c10459f5>] ? irq_exit+0x75/0x80
[<c175906e>] ? do_IRQ+0x4e/0xb0
[<c100356e>] ? common_interrupt+0x2e/0x40
[<c1758b94>] ? _spin_unlock_irqrestore+0x34/0x50
[<c103007b>] ? set_curr_task_fair+0xb/0x40
[<c10401c4>] ? vprintk+0x114/0x2a0
[<c1756f25>] ? __mutex_unlock_slowpath+0xa5/0x160
[<c106ff4c>] ? trace_hardirqs_on_caller+0x15c/0x1b0
[<c106ffab>] ? trace_hardirqs_on+0xb/0x10
[<c1756fed>] ? mutex_unlock+0xd/0x10
[<c1be9320>] ? init_acpi_pm_clocksource+0x0/0x1a0
[<c104036b>] ? printk+0x1b/0x20
[<c1001200>] ? do_one_initcall+0x100/0x160
[<c1be9320>] ? init_acpi_pm_clocksource+0x0/0x1a0
[<c1138a45>] ? create_proc_entry+0x65/0xc0
[<c1092383>] ? register_irq_proc+0xa3/0xc0
[<c1138981>] ? proc_create_data+0x71/0xd0
[<c1bb33f7>] ? do_initcalls+0x27/0x40
[<c1bb3436>] ? do_basic_setup+0x26/0x30
[<c1bb3b17>] ? kernel_init+0x57/0xa0
[<c1bb3ac0>] ? kernel_init+0x0/0xa0
[<c1003ae7>] ? kernel_thread_helper+0x7/0x10
Switched to high resolution mode on CPU 0
calling ssb_modinit+0x0/0x60 @ 1



\
 
 \ /
  Last update: 2009-08-19 22:29    [from the cache]
©2003-2011 Jasper Spaans