RCU idle CPU detection is broken in linux-next

From: Sasha Levin
Date: Wed Sep 12 2012 - 13:56:15 EST


Hi Paul,

While fuzzing using trinity inside a KVM tools guest, I've managed to trigger
"RCU used illegally from idle CPU!" warnings several times.

There are a bunch of traces which seem to pop exactly at the same time and from
different places around the kernel. Here are several of them:

(1):

[ 29.006532] ===============================
[ 29.007033] [ INFO: suspicious RCU usage. ]
[ 29.007033] 3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331 Tainted:
G W
[ 29.007033] -------------------------------
[ 29.007033] include/linux/rcupdate.h:737 rcu_read_lock() used illegally while
idle!
[ 29.007033]
[ 29.007033] other info that might help us debug this:
[ 29.007033]
[ 29.007033]
[ 29.007033] RCU used illegally from idle CPU!
[ 29.007033] rcu_scheduler_active = 1, debug_locks = 1
[ 29.007033] RCU used illegally from extended quiescent state!
[ 29.007033] 2 locks held by rcu_preempt/11:
[ 29.007033] #0: (&rq->lock){-.-.-.}, at: [<ffffffff83742f50>]
__schedule+0x180/0x8f0
[ 29.007033] #1: (rcu_read_lock){.+.+..}, at: [<ffffffff8114ff1e>]
cpuacct_charge+0xe/0x200
[ 29.007033]
[ 29.007033] stack backtrace:
[ 29.007033] Pid: 11, comm: rcu_preempt Tainted: G W
3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331
[ 29.007033] Call Trace:
[ 29.007033] [<ffffffff8117eaeb>] lockdep_rcu_suspicious+0x10b/0x120
[ 29.007033] [<ffffffff8114ffa0>] cpuacct_charge+0x90/0x200
[ 29.007033] [<ffffffff8114ff1e>] ? cpuacct_charge+0xe/0x200
[ 29.007033] [<ffffffff811548a3>] update_curr+0x1a3/0x270
[ 29.007033] [<ffffffff8115527a>] dequeue_entity+0x2a/0x210
[ 29.007033] [<ffffffff811556b5>] dequeue_task_fair+0x45/0x130
[ 29.007033] [<ffffffff81148149>] dequeue_task+0x89/0xa0
[ 29.007033] [<ffffffff81148ebe>] deactivate_task+0x1e/0x20
[ 29.007033] [<ffffffff83743649>] __schedule+0x879/0x8f0
[ 29.007033] [<ffffffff8117a60d>] ? trace_hardirqs_on+0xd/0x10
[ 29.007033] [<ffffffff83743715>] schedule+0x55/0x60
[ 29.007033] [<ffffffff811c672d>] rcu_gp_kthread+0xdd/0xed0
[ 29.007033] [<ffffffff83744ebb>] ? _raw_spin_unlock_irq+0x2b/0x80
[ 29.007033] [<ffffffff81137210>] ? abort_exclusive_wait+0xb0/0xb0
[ 29.007033] [<ffffffff811c6650>] ? rcu_gp_fqs+0x80/0x80
[ 29.007033] [<ffffffff81135e43>] kthread+0xe3/0xf0
[ 29.007033] [<ffffffff83747a84>] kernel_thread_helper+0x4/0x10
[ 29.007033] [<ffffffff83745df4>] ? retint_restore_args+0x13/0x13
[ 29.007033] [<ffffffff81135d60>] ? insert_kthread_work+0x90/0x90
[ 29.007033] [<ffffffff83747a80>] ? gs_change+0x13/0x13

(2):

[ 28.876466] ===============================
[ 28.876466] [ INFO: suspicious RCU usage. ]
[ 28.876466] 3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331 Tainted:
G W
[ 28.876466] -------------------------------
[ 28.876466] include/linux/rcupdate.h:758 rcu_read_unlock() used illegally
while idle!
[ 28.876466]
[ 28.876466] other info that might help us debug this:
[ 28.876466]
[ 28.876466]
[ 28.876466] RCU used illegally from idle CPU!
[ 28.876466] rcu_scheduler_active = 1, debug_locks = 1
[ 28.876466] RCU used illegally from extended quiescent state!
[ 28.876466] 2 locks held by trinity-child58/5966:
[ 28.876466] #0: (&(&sighand->siglock)->rlock){-.-...}, at:
[<ffffffff8111f548>] force_sig_info+0x38/0x100
[ 28.876466] #1: (rcu_read_lock){.+.+..}, at: [<ffffffff8111d410>]
__sigqueue_alloc+0x0/0x230
[ 28.876466]
[ 28.876466] stack backtrace:
[ 28.876466] Pid: 5966, comm: trinity-child58 Tainted: G W
3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331
[ 28.876466] Call Trace:
[ 28.876466] [<ffffffff8117eaeb>] lockdep_rcu_suspicious+0x10b/0x120
[ 28.876466] [<ffffffff8111d558>] __sigqueue_alloc+0x148/0x230
[ 28.876466] [<ffffffff8111d410>] ? check_kill_permission+0x220/0x220
[ 28.876466] [<ffffffff8111e91a>] __send_signal+0x51a/0x580
[ 28.876466] [<ffffffff8111f500>] ? do_signal_stop+0x2c0/0x2d0
[ 28.876466] [<ffffffff8111e9c0>] send_signal+0x40/0x80
[ 28.876466] [<ffffffff8111f548>] ? force_sig_info+0x38/0x100
[ 28.876466] [<ffffffff811c38ad>] ? rcu_user_enter+0xed/0x110
[ 28.876466] [<ffffffff8111f5d3>] force_sig_info+0xc3/0x100
[ 28.876466] [<ffffffff811203a1>] force_sig+0x11/0x20
[ 28.876466] [<ffffffff8106da1d>] do_general_protection+0xfd/0x170
[ 28.876466] [<ffffffff83746075>] general_protection+0x25/0x30

(3):

[ 28.876466] ===============================
[ 28.876466] [ INFO: suspicious RCU usage. ]
[ 28.876466] 3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331 Tainted:
G W
[ 28.876466] -------------------------------
[ 28.876466] kernel/signal.c:366 suspicious rcu_dereference_check() usage!
[ 28.876466]
[ 28.876466] other info that might help us debug this:
[ 28.876466]
[ 28.876466]
[ 28.876466] RCU used illegally from idle CPU!
[ 28.876466] rcu_scheduler_active = 1, debug_locks = 1
[ 28.876466] RCU used illegally from extended quiescent state!
[ 28.876466] 2 locks held by trinity-child58/5966:
[ 28.876466] #0: (&(&sighand->siglock)->rlock){-.-...}, at:
[<ffffffff8111f548>] force_sig_info+0x38/0x100
[ 28.876466] #1: (rcu_read_lock){.+.+..}, at: [<ffffffff8111d410>]
__sigqueue_alloc+0x0/0x230
[ 28.876466]
[ 28.876466] stack backtrace:
[ 28.876466] Pid: 5966, comm: trinity-child58 Tainted: G W
3.6.0-rc5-next-20120912-sasha-00001-gb0c9916-dirty #331
[ 28.876466] Call Trace:
[ 28.876466] [<ffffffff8117eaeb>] lockdep_rcu_suspicious+0x10b/0x120
[ 28.876466] [<ffffffff8111d50f>] __sigqueue_alloc+0xff/0x230
[ 28.876466] [<ffffffff8111d410>] ? check_kill_permission+0x220/0x220
[ 28.876466] [<ffffffff8111e91a>] __send_signal+0x51a/0x580
[ 28.876466] [<ffffffff8111f500>] ? do_signal_stop+0x2c0/0x2d0
[ 28.876466] [<ffffffff8111e9c0>] send_signal+0x40/0x80
[ 28.876466] [<ffffffff8111f548>] ? force_sig_info+0x38/0x100
[ 28.876466] [<ffffffff811c38ad>] ? rcu_user_enter+0xed/0x110
[ 28.876466] [<ffffffff8111f5d3>] force_sig_info+0xc3/0x100
[ 28.876466] [<ffffffff811203a1>] force_sig+0x11/0x20
[ 28.876466] [<ffffffff8106da1d>] do_general_protection+0xfd/0x170
[ 28.876466] [<ffffffff83746075>] general_protection+0x25/0x30
--
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/