Re: -tip: WARNING: at kernel/lockdep.c:2738

From: Ingo Molnar
Date: Sun Jun 29 2008 - 09:07:10 EST



* Vegard Nossum <vegard.nossum@xxxxxxxxx> wrote:

> Hi,
>
> I just got this on the latest tip/master shortly after finishing initcalls:
>
> ------------[ cut here ]------------
> WARNING: at kernel/lockdep.c:2738 check_flags+0x142/0x160()
> Pid: 5, comm: watchdog/0 Not tainted 2.6.26-rc8-tip-00206-g3248a70-dirty #49
> [<c0139684>] warn_on_slowpath+0x54/0x70
> [<c015be00>] ? trace_hardirqs_off_caller+0x40/0xe0
> [<c010a7c5>] ? native_sched_clock+0xb5/0x110
> [<c018076e>] ? ftrace_record_ip+0x12e/0x240
> [<c05ab8c8>] ? _spin_unlock_irqrestore+0x48/0x80
> [<c029ffd3>] ? debug_locks_off+0x3/0x50
> [<c018076e>] ? ftrace_record_ip+0x12e/0x240
> [<c0104f6b>] ? mcount_call+0x5/0xa
> [<c015b322>] check_flags+0x142/0x160
> [<c015f6e9>] lock_acquire+0x59/0xd0
> [<c01769f1>] ? watchdog+0xb1/0x1e0
> [<c05ab2fd>] _read_lock+0x3d/0x70
> [<c01769f1>] ? watchdog+0xb1/0x1e0
> [<c01769f1>] watchdog+0xb1/0x1e0
> [<c05ab8c8>] ? _spin_unlock_irqrestore+0x48/0x80
> [<c012bae9>] ? complete+0x49/0x60
> [<c0176940>] ? watchdog+0x0/0x1e0
> [<c014e637>] kthread+0x47/0x80
> [<c014e5f0>] ? kthread+0x0/0x80
> [<c0104f53>] kernel_thread_helper+0x7/0x10
> =======================
> ---[ end trace 8e23f95b45fa05f7 ]---
> possible reason: unannotated irqs-on.
> irq event stamp: 18
> hardirqs last enabled at (17): [<c015e02b>] trace_hardirqs_on+0xb/0x10
> hardirqs last disabled at (18): [<c015beab>] trace_hardirqs_off+0xb/0x10
> softirqs last enabled at (0): [<c0137cd8>] copy_process+0x268/0x10b0
> softirqs last disabled at (0): [<00000000>] 0x0
>
> I hope this wasn't caused by any of my patches :-S
>
> $ addr2line -e vmlinux -i c01769f1
> kernel/softlockup.c:232
> kernel/softlockup.c:271
>
> It seems that Andrew reported this too,
> http://lkml.org/lkml/2008/6/9/41, but I already have the fix,
>
> commit 040ec23d07f95285e9777a85cda29cb339a3065b
> Author: Ingo Molnar <mingo@xxxxxxx>
> Date: Mon Jun 9 01:45:29 2008 -0700
>
> sched: sched_clock() lockdep fix
>
> so it can't be the same one.
>
> (It seems to be something ftrace-related, adding Steven to Cc.)

perhaps caused by this one:

| commit 76a2a6ee8a0660a29127f05989ac59ae1ce865fa
| Author: Peter Zijlstra <a.p.zijlstra@xxxxxxxxx>
| Date: Fri Jun 27 13:41:15 2008 +0200
|
| sched: sched_clock_cpu() based cpu_clock()

?

Does the patch below (or the tip/master i just pushed out) fix it?

Ingo

------------->
commit 2d452c9b10caeec455eb5e56a0ef4ed485178213
Author: Ingo Molnar <mingo@xxxxxxx>
Date: Sun Jun 29 15:01:59 2008 +0200

sched: sched_clock_cpu() based cpu_clock(), lockdep fix

Vegard Nossum reported:

> WARNING: at kernel/lockdep.c:2738 check_flags+0x142/0x160()

which happens due to:

unsigned long long cpu_clock(int cpu)
{
unsigned long long clock;
unsigned long flags;

raw_local_irq_save(flags);

as lower level functions can take locks, we must not do that, use
proper lockdep-annotated irq save/restore.

Reported-by: Vegard Nossum <vegard.nossum@xxxxxxxxx>
Signed-off-by: Ingo Molnar <mingo@xxxxxxx>

diff --git a/kernel/sched_clock.c b/kernel/sched_clock.c
index ed5a8c4..60094e2 100644
--- a/kernel/sched_clock.c
+++ b/kernel/sched_clock.c
@@ -250,9 +250,9 @@ unsigned long long cpu_clock(int cpu)
unsigned long long clock;
unsigned long flags;

- raw_local_irq_save(flags);
+ local_irq_save(flags);
clock = sched_clock_cpu(cpu);
- raw_local_irq_restore(flags);
+ local_irq_restore(flags);

return clock;
}
--
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/