Re: lockdep WARNING on check_critical_timing()

[Steven Rostedt]

On Wed, 2012-09-05 at 09:59 +0800, Fengguang Wu wrote:
> Greetings,
> 
> This is possibly an aged warning.
> 
>         if (!hardirq_count()) {
>                 if (softirq_count()) {
>                         /* like the above, but with softirqs */
> =>                      DEBUG_LOCKS_WARN_ON(current->softirqs_enabled);
> 
> [    3.600059] Testing tracer preemptoff: 
> [    3.760076] ------------[ cut here ]------------
> [    3.760866] WARNING: at /c/kernel-tests/src/stable/kernel/lockdep.c:3506 check_flags+0x125/0x154()
> [    3.762160] Modules linked in:
> [    3.762643] Pid: 1, comm: swapper/0 Not tainted 3.6.0-rc3-00013-g01f8a27 #158
> [    3.763679] Call Trace:
> [    3.764053]  [<c1020916>] warn_slowpath_common+0x4d/0x62
> [    3.764838]  [<c105c000>] ? check_flags+0x125/0x154
> [    3.765567]  [<c102093f>] warn_slowpath_null+0x14/0x18
> [    3.766317]  [<c105c000>] check_flags+0x125/0x154
> [    3.766998]  [<c105e02f>] lock_acquire+0x3b/0xef
> [    3.767689]  [<c12461ba>] _raw_spin_lock_irqsave+0x3e/0x4e
> [    3.768494]  [<c12404b8>] ? check_critical_timing+0x112/0x160
> [    3.769340]  [<c12404b8>] check_critical_timing+0x112/0x160
> [    3.770047]  [<c1027474>] ? __do_softirq+0x19b/0x1f9
> [    3.770047]  [<c1027474>] ? __do_softirq+0x19b/0x1f9
> [    3.770047]  [<c1088549>] trace_preempt_on+0x8d/0xc9
> [    3.770047]  [<c1027238>] ? __local_bh_enable+0x87/0x8a
> [    3.770047]  [<c1046c85>] sub_preempt_count+0x7f/0x9c
> [    3.770047]  [<c1027238>] __local_bh_enable+0x87/0x8a
> [    3.770047]  [<c1027474>] __do_softirq+0x19b/0x1f9
> [    3.770047]  [<c10272d9>] ? ftrace_define_fields_irq_handler_entry+0x45/0x45
> [    3.770047]  <IRQ>  [<c1027723>] ? irq_exit+0x4f/0xa9
> [    3.770047]  [<c1015e03>] ? smp_apic_timer_interrupt+0x70/0x7e
> [    3.770047]  [<c1246daf>] ? apic_timer_interrupt+0x2f/0x34
> [    3.770047]  [<c108007b>] ? ring_buffer_discard_commit+0x24c/0x24c
> [    3.770047]  [<c1139c87>] ? __const_udelay+0x1/0x1c
> [    3.770047]  [<c108566f>] ? trace_selftest_startup_preemptoff+0x74/0xed
> [    3.770047]  [<c1085b57>] ? register_tracer+0x11c/0x1f7
> [    3.770047]  [<c13c1bf3>] ? init_function_trace+0xf/0xf
> [    3.770047]  [<c13c1c00>] ? init_irqsoff_tracer+0xd/0x11
> [    3.770047]  [<c1001158>] ? do_one_initcall+0x70/0x118
> [    3.770047]  [<c13afa03>] ? kernel_init+0xec/0x169
> [    3.770047]  [<c13af917>] ? start_kernel+0x2f2/0x2f2
> [    3.770047]  [<c124773a>] ? kernel_thread_helper+0x6/0x10
> 

This is the same as a previous bug. It is caused by rcu doing the check
in the function tracer and then triggering a lockdep warning.

Paul,

Didn't we talk about having the rcu_dereference_raw() not do the check?
The function tracer is just too invasive to add work arounds to prevent
lockdep from screaming about it.

-- Steve


--
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/