On 08/05/2015 03:30 PM, Daniel Wagner wrote:
> My test system didn't crash or showed any obvious defects, so I
> decided to apply some benchmarks utilizing mmtests. I have picked some
As it turns out, this is not really true. I forgot to enable lockdep:
[ 0.053193] =================================
[ 0.053490] [ INFO: inconsistent lock state ]
[ 0.053790] 4.2.0-rc5-00022-g6d2f78c #63 Not tainted
[ 0.054000] ---------------------------------
[ 0.054000] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
[ 0.054000] rcu_preempt/7 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 0.054000] (rcu_node_0){+.?...}, at: [<ffffffff81133643>] rcu_gp_kthread+0xfe3/0x2390
[ 0.054000] {IN-SOFTIRQ-W} state was registered at:
[ 0.054000] [<ffffffff81108a6c>] __lock_acquire+0xbfc/0x2050
[ 0.054000] [<ffffffff8110acbf>] lock_acquire+0xdf/0x2b0
[ 0.054000] [<ffffffff81913b19>] _raw_spin_lock_irqsave+0x59/0xa0
[ 0.054000] [<ffffffff811357e9>] rcu_process_callbacks+0x109/0xf00
[ 0.054000] [<ffffffff810b195d>] __do_softirq+0x14d/0x670
[ 0.054000] [<ffffffff810b20d1>] irq_exit+0x101/0x110
[ 0.054000] [<ffffffff81916d16>] smp_apic_timer_interrupt+0x46/0x60
[ 0.054000] [<ffffffff81914cf0>] apic_timer_interrupt+0x70/0x80
[ 0.054000] [<ffffffff814d7a97>] vsnprintf+0x367/0x530
[ 0.054000] [<ffffffff814d7d03>] snprintf+0x43/0x60
[ 0.054000] [<ffffffff810d90cf>] register_sched_domain_sysctl+0xdf/0x670
[ 0.054000] [<ffffffff8217c74d>] sched_init_smp+0x524/0x5d7
[ 0.054000] [<ffffffff8215a1e8>] kernel_init_freeable+0x171/0x28f
[ 0.054000] [<ffffffff818fe3be>] kernel_init+0xe/0xe0
[ 0.054000] [<ffffffff8191419f>] ret_from_fork+0x3f/0x70
[ 0.054000] irq event stamp: 46
[ 0.054000] hardirqs last enabled at (45): [<ffffffff819131a0>] _raw_spin_unlock_irq+0x30/0x60
[ 0.054000] hardirqs last disabled at (46): [<ffffffff81912ebf>] _raw_spin_lock_irq+0x1f/0x90
[ 0.054000] softirqs last enabled at (0): [<ffffffff810a8c98>] copy_process.part.26+0x628/0x1ce0
[ 0.054000] softirqs last disabled at (0): [< (null)>] (null)
[ 0.054000]
[ 0.054000] other info that might help us debug this:
[ 0.054000] Possible unsafe locking scenario:
[ 0.054000]
[ 0.054000] CPU0
[ 0.054000] ----
[ 0.054000] lock(rcu_node_0);
[ 0.054000] <Interrupt>
[ 0.054000] lock(rcu_node_0);
[ 0.054000]
[ 0.054000] *** DEADLOCK ***
[ 0.054000]
[ 0.054000] 1 lock held by rcu_preempt/7:
[ 0.054000] #0: (rcu_node_0){+.?...}, at: [<ffffffff81133643>] rcu_gp_kthread+0xfe3/0x2390
[ 0.054000]
[ 0.054000] stack backtrace:
[ 0.054000] CPU: 0 PID: 7 Comm: rcu_preempt Not tainted 4.2.0-rc5-00022-g6d2f78c #63
[ 0.054000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.8.1-20150318_183358- 04/01/2014
[ 0.054000] 0000000000000000 00000000be272de7 ffff88007c0e7b98 ffffffff81908ed7
[ 0.054000] 0000000000000000 ffff88007c0e8000 ffff88007c0e7bf8 ffffffff81107195
[ 0.054000] 0000000000000000 ffff880000000001 ffff880000000001 ffffffff8102fa9f
[ 0.054000] Call Trace:
[ 0.054000] [<ffffffff81908ed7>] dump_stack+0x4f/0x7b
[ 0.054000] [<ffffffff81107195>] print_usage_bug+0x215/0x240
[ 0.054000] [<ffffffff8102fa9f>] ? save_stack_trace+0x2f/0x50
[ 0.054000] [<ffffffff81107767>] mark_lock+0x5a7/0x670
[ 0.054000] [<ffffffff811066d0>] ? check_usage_forwards+0x150/0x150
[ 0.054000] [<ffffffff811078ad>] mark_held_locks+0x7d/0xb0
[ 0.054000] [<ffffffff819131a0>] ? _raw_spin_unlock_irq+0x30/0x60
[ 0.054000] [<ffffffff81107a48>] trace_hardirqs_on_caller+0x168/0x220
[ 0.054000] [<ffffffff81107b0d>] trace_hardirqs_on+0xd/0x10
[ 0.054000] [<ffffffff819131a0>] _raw_spin_unlock_irq+0x30/0x60
[ 0.054000] [<ffffffff810fc0bb>] swake_up_all+0xbb/0xe0
[ 0.054000] [<ffffffff811336cd>] rcu_gp_kthread+0x106d/0x2390
[ 0.054000] [<ffffffff819131a0>] ? _raw_spin_unlock_irq+0x30/0x60
[ 0.054000] [<ffffffff8190c575>] ? __schedule+0x885/0x9e0
[ 0.054000] [<ffffffff810d2329>] ? kthread+0xd9/0x120
[ 0.054000] [<ffffffff81132660>] ? rcu_barrier+0x20/0x20
[ 0.054000] [<ffffffff810d2354>] kthread+0x104/0x120
[ 0.054000] [<ffffffff819131a0>] ? _raw_spin_unlock_irq+0x30/0x60
[ 0.054000] [<ffffffff810d2250>] ? kthread_create_on_node+0x260/0x260
[ 0.054000] [<ffffffff8191419f>] ret_from_fork+0x3f/0x70
[ 0.054000] [<ffffffff810d2250>] ? kthread_create_on_node+0x260/0x260
If I decoded this correctly the call to rcu_future_gp_cleanup() is
supposed to run with IRQs disabled. swake_up_all() though will reenable the
IRQs:
rcu_gp_cleanup()
rcu_for_each_node_breadth_first(rsp, rnp) {
raw_spin_lock_irq(&rnp->lock);
nocb += rcu_future_gp_cleanup(rsp, rnp);
raw_spin_unlock_irq(&rnp->lock);
}
rcu_future_gp_cleanup()
rcu_nocb_gp_cleanup()
swake_up_all()
With IRQs enabled again and we end up in rcu_process_callbacks
under SOFTIRQ. rcu_process_callbacks aquires the RCU lock again.
Not sure what to do here.
cheers,
daniel
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
