| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Mon, 9 Jul 2012 21:56:37 +0800 From: wfg@...ux.intel.com To: "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com> Cc: Josh Triplett <josh@...htriplett.org>, Lai Jiangshan <laijs@...fujitsu.com>, LKML <linux-kernel@...r.kernel.org> Subject: rcu_dyntick and suspicious RCU usage Hi Paul, I kicked off boot testing for dozens of randconfigs and got some few runtime errors. Here is one of them. It's very reproducible in kvm, and obviously only triggers on the attached config. [ 5.335062] Testing event rcu_dyntick: [ 5.336515] [ 5.336953] =============================== [ 5.338124] [ INFO: suspicious RCU usage. ] [ 5.338573] 3.5.0-rc6+ #3 Not tainted [ 5.338573] ------------------------------- [ 5.338573] /c/kernel-tests/net/include/trace/events/rcu.h:275 suspicious rcu_dereference_check() usage! [ 5.338573] [ 5.338573] other info that might help us debug this: [ 5.338573] [ 5.338573] [ 5.338573] RCU used illegally from idle CPU! [ 5.338573] rcu_scheduler_active = 1, debug_locks = 0 [ 5.338573] RCU used illegally from extended quiescent state! [ 5.338573] no locks held by swapper/0. [ 5.338573] [ 5.338573] stack backtrace: [ 5.338573] Pid: 0, comm: swapper Not tainted 3.5.0-rc6+ #3 [ 5.338573] Call Trace: [ 5.338573] [ 5.338573] [<c10bb3a2>] lockdep_rcu_suspicious+0x1de/0x1f4 [ 5.338573] [<c1102a0e>] trace_rcu_dyntick+0xd9/0x167 [ 5.338573] [<c1105329>] rcu_idle_enter_common+0x84/0x22d [ 5.338573] [<c10b9fea>] ? trace_hardirqs_off_caller+0x97/0x167 [ 5.338573] [<c110585c>] rcu_idle_enter+0x16d/0x274 [ 5.338573] [<c100fbdb>] cpu_idle+0x159/0x220 [ 5.338573] [<c141616f>] rest_init+0x2db/0x2ef [ 5.338573] [<c1415e94>] ? reciprocal_value+0x64/0x64 [ 5.338573] [<c1721456>] start_kernel+0x8eb/0x8ff [ 5.338573] [<c172062f>] ? repair_env_string+0xd3/0xd3 [ 5.338573] [<c1720342>] i386_start_kernel+0xf8/0x10b [ 5.372219] OK [ 5.372708] Testing event rcu_prep_idle: OK And I find the somehow disordered output (the timestamp at the end of line and the blank line etc.) is indeed a very stable pattern. For example, here is another trace: [ 4.573142] Testing event rcu_dyntick: [ 4.574028] [ 4.574307] =============================== [ 4.575072] [ INFO: suspicious RCU usage. ] [ 4.575832] 3.5.0-rc5+ #15 Not tainted [ 4.576475] ------------------------------- [ 4.576896] /c/kernel-tests/net/include/trace/events/rcu.h:275 suspicious rcu_dereference_check() usage! [ 4.576896] [ 4.576896] other info that might help us debug this: [ 4.576896] [ 4.576896] [ 4.576896] RCU used illegally from idle CPU! [ 4.576896] rcu_scheduler_active = 1, debug_locks = 0 [ 4.576896] RCU used illegally from extended quiescent state! [ 4.576896] no locks held by swapper/0. [ 4.576896] [ 4.576896] stack backtrace: [ 4.576896] Pid: 0, comm: swapper Not tainted 3.5.0-rc5+ #15 [ 4.576896] Call Trace: [ 4.576896] [ 4.576896] [<c10bb3a2>] lockdep_rcu_suspicious+0x1de/0x1f4 [ 4.576896] [<c1102a0e>] trace_rcu_dyntick+0xd9/0x167 [ 4.576896] [<c1105329>] rcu_idle_enter_common+0x84/0x22d [ 4.576896] [<c10b9fea>] ? trace_hardirqs_off_caller+0x97/0x167 [ 4.576896] [<c110585c>] rcu_idle_enter+0x16d/0x274 [ 4.576896] [<c100fbdb>] cpu_idle+0x159/0x220 [ 4.576896] [<c1415fbf>] rest_init+0x2db/0x2ef [ 4.576896] [<c1415ce4>] ? reciprocal_value+0x64/0x64 [ 4.576896] [<c1721456>] start_kernel+0x8eb/0x8ff [ 4.576896] [<c172062f>] ? repair_env_string+0xd3/0xd3 [ 4.576896] [<c1720342>] i386_start_kernel+0xf8/0x10b [ 4.596538] OK [ 4.596920] Testing event rcu_prep_idle: OK Thanks, Fengguang Download attachment "dmesg-kvm-xgwo-6794-2012-07-09-08-16-05" of type "application/octet-stream" (39439 bytes) View attachment "config-3.5.0-rc6+" of type "text/plain" (56946 bytes)
Powered by blists - more mailing lists