On Fri, 2012-08-31 at 00:21 -0700, Fengguang Wu wrote:
> [ 3.267585] Testing tracer function: [ 4.282931] tsc: Refined TSC
> clocksource calibration: 2833.332 MHz
> PASSED
> [ 13.392541] Testing tracer irqsoff: PASSED
> [ 13.428537] Testing tracer branch: [ 20.093074] ------------[ cut here
> ]------------
> [ 20.093861] WARNING: at /c/kernel-tests/src/stable/kernel/lockdep.c:3493
> check_flags+0x166/0x386()
> [ 20.093861] Pid: 0, comm: swapper/0 Not tainted 3.6.0-rc1-00102-ga184d4e #7
> [ 20.093861] Call Trace:
>
> [ 20.093861] [<41064af3>] warn_slowpath_common+0x8e/0xcd
> [ 20.093861] [<410f1372>] ? check_flags+0x166/0x386
> [ 20.093861] [<41064c6b>] warn_slowpath_null+0x30/0x45
> [ 20.093861] [<410f1372>] check_flags+0x166/0x386
> [ 20.093861] [<410f7cc5>] lock_acquire+0x5b/0x24a
> [ 20.093861] [<4107f7d8>] run_timer_softirq+0x2a6/0x77d
> [ 20.093861] [<4107f72f>] ? run_timer_softirq+0x1fd/0x77d
> [ 20.093861] [<4107f449>] ? spin_unlock_irqrestore+0x26/0x26
> [ 20.093861] [<41075293>] __do_softirq+0x234/0x5d6
> [ 20.093861] [<4107505f>] ? local_bh_enable_ip+0x2b/0x2b
> [ 20.093861] <IRQ> [<41075adf>] ? irq_exit+0x9d/0x14b
> [ 20.093861] [<4103b1b7>] ? smp_apic_timer_interrupt+0xe1/0xfd
> [ 20.093861] [<41a75bc7>] ? apic_timer_interrupt+0x2f/0x34
> [ 20.093861] [<41151975>] ? ftrace_likely_update+0x3bb/0x446
> [ 20.093861] [<41102e17>] ? arch_local_irq_enable+0x6b/0x80
> [ 20.093861] [<41a74287>] ? _raw_spin_unlock_irq+0x80/0xc5
> [ 20.093861] [<410babf0>] ? finish_task_switch+0x109/0x1df
> [ 20.093861] [<410bab8a>] ? finish_task_switch+0xa3/0x1df
> [ 20.093861] [<41a7222b>] ? __schedule+0xb89/0xd51
> [ 20.093861] [<4112efbe>] ? rcu_idle_exit+0x1d0/0x26c
> [ 20.093861] [<4112efd3>] ? rcu_idle_exit+0x1e5/0x26c
> [ 20.093861] [<41a7252f>] ? schedule+0x13c/0x14c
> [ 20.093861] [<41014615>] ? cpu_idle+0x1d5/0x1fd
> [ 20.093861] [<41a01c3d>] ? rest_init+0x319/0x32c
> [ 20.093861] [<4216637a>] ? start_kernel+0x84c/0x85f
> [ 20.093861] [<42165322>] ? i386_start_kernel+0xf8/0x10b
> [ 20.093861] ---[ end trace 39036f94f86e3090 ]---
> [ 20.093861] possible reason: unannotated irqs-on.
> [ 20.093861] irq event stamp: 36791
> [ 20.093861] hardirqs last enabled at (36790): [<41a74274>]
> _raw_spin_unlock_irq+0x6d/0xc5
> [ 20.093861] hardirqs last disabled at (36791): [<41151700>]
> ftrace_likely_update+0x146/0x446
> [ 20.093861] softirqs last enabled at (34274): [<41074fe8>]
> _local_bh_enable+0x20/0x30
> [ 20.093861] softirqs last disabled at (34275): [<41007553>]
> call_on_stack+0x20/0x34
I suspect its because of a 'fun' combination of paravirt and
trace_branch, although I can't seem to make it stick.. the trace
includes the best of both worlds although its rather uncertain of
itself :/
_raw_spin_unlock_irq()
__raw_spin_unlock_irq()
spin_release() <-- tell lockdep you release the lock
do_raw_spin_unlock() <-- actually release the lock
local_irq_enable()
trace_hardirqs_on() <-- tell lockdep IRQs are on
raw_local_irq_enable()
arch_local_irq_enable()
PVOP_VCALLEE0(pv_irq_ops.irq_enable);
*magic*
ftrace_likely_update()
local_irq_save() <-- as per the hardirq last disable
* note that hardirq last enable doesn't appear to be the _restore() ?! *
<IRQ> <-- which would be impossible give the above state ?
__irqexit
__do_softirq()
run_timer_softirq()
lock_acquire() <-- assuming its spin_lock_irq(&base->lock) in
__run_timers
*confused*
Anybody got clue?
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
