apparmor: WARNING: suspicious RCU usage
Running with CONFIG_PROVE_RCU_LIST triggers the following splat:
[ 6.805926] =============================
[ 6.806848] WARNING: suspicious RCU usage
[ 6.807738] 5.15.0-rc2+ #24 Tainted: G E
[ 6.808860] -----------------------------
[ 6.809734] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!!
[ 6.811508]
other info that might help us debug this:[ 6.811516]
rcu_scheduler_active = 2, debug_locks = 1
[ 6.811527] 2 locks held by apparmor_parser/1897:
[ 6.811530] #0: ffff88885f139450 (sb_writers#7){.+.+}-{0:0}, at: ksys_write+0x68/0xe0
[ 6.816110] #1: ffff8881000578a0 (&ns->lock){+.+.}-{3:3}, at: aa_replace_profiles+0x16d/0x11e0
[ 6.817418]
stack backtrace:
[ 6.818086] CPU: 38 PID: 1897 Comm: apparmor_parser Tainted: G E 5.15.0-rc2+ #24
[ 6.819359] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014
[ 6.820536] Call Trace:
[ 6.820918] dump_stack_lvl+0x57/0x72
[ 6.821499] __lookupn_profile+0x193/0x1a0
[ 6.822461] aa_replace_profiles+0x395/0x11e0
[ 6.823448] policy_update+0x13f/0x240
[ 6.824326] profile_replace+0xb1/0x120
[ 6.825213] vfs_write+0xe4/0x3b0
[ 6.826027] ksys_write+0x68/0xe0
[ 6.826576] do_syscall_64+0x3b/0x90
[ 6.827099] entry_SYSCALL_64_after_hwframe+0x44/0xaewhich is pretty obvious because aa_replace_profile() invokes:
__lookup_replace()
__lookup_profile()
__strn_find_child()
__policy_strn_find()
list_for_each_entry_rcu() <- SplatThe code is "correct" as this is the writer side and holding ns->lock, but it's incorrect to use list_for_each_entry_rcu() without being in a read side critical section unless it is properly annotated.
Same problem in the same function vs. __lookup_parent() and there are more issues of that sort, e.g. vs. __lookup_profile() in aa_remove_profiles().
Thanks,
tglx
Quoted 39 lines · Thomas Gleixner
Running with
CONFIG_PROVE_RCU_LISTtriggers the following splat:[ 6.805926] ============================= [ 6.806848] WARNING: suspicious RCU usage [ 6.807738] 5.15.0-rc2+ #24 Tainted: G E [ 6.808860] ----------------------------- [ 6.809734] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!! [ 6.811508] other info that might help us debug this:[ 6.811516] rcu_scheduler_active = 2, debug_locks = 1 [ 6.811527] 2 locks held by apparmor_parser/1897: [ 6.811530] #0: ffff88885f139450 (sb_writers#7){.+.+}-{0:0}, at: ksys_write+0x68/0xe0 [ 6.816110] #1: ffff8881000578a0 (&ns->lock){+.+.}-{3:3}, at: aa_replace_profiles+0x16d/0x11e0 [ 6.817418] stack backtrace: [ 6.818086] CPU: 38 PID: 1897 Comm: apparmor_parser Tainted: G E 5.15.0-rc2+ #24 [ 6.819359] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014 [ 6.820536] Call Trace: [ 6.820918] dump_stack_lvl+0x57/0x72 [ 6.821499] __lookupn_profile+0x193/0x1a0 [ 6.822461] aa_replace_profiles+0x395/0x11e0 [ 6.823448] policy_update+0x13f/0x240 [ 6.824326] profile_replace+0xb1/0x120 [ 6.825213] vfs_write+0xe4/0x3b0 [ 6.826027] ksys_write+0x68/0xe0 [ 6.826576] do_syscall_64+0x3b/0x90 [ 6.827099] entry_SYSCALL_64_after_hwframe+0x44/0xaewhich is pretty obvious because
aa_replace_profile()invokes:__lookup_replace() __lookup_profile() __strn_find_child() __policy_strn_find() list_for_each_entry_rcu() <- Splat
Quoted 8 lines
The code is "correct" as this is the writer side and holding
ns->lock, but it's incorrect to uselist_for_each_entry_rcu()without being in a read side critical section unless it is properly annotated.Same problem in the same function vs.
__lookup_parent()and there are more issues of that sort, e.g. vs.__lookup_profile()inaa_remove_profiles().
thanks Thomas, I look into it
Quoted 44 lines · John Johansen
Quoted 43 lines · Thomas Gleixner
Running with
CONFIG_PROVE_RCU_LISTtriggers the following splat:[ 6.805926] ============================= [ 6.806848] WARNING: suspicious RCU usage [ 6.807738] 5.15.0-rc2+ #24 Tainted: G E [ 6.808860] ----------------------------- [ 6.809734] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!! [ 6.811508] other info that might help us debug this:[ 6.811516] rcu_scheduler_active = 2, debug_locks = 1 [ 6.811527] 2 locks held by apparmor_parser/1897: [ 6.811530] #0: ffff88885f139450 (sb_writers#7){.+.+}-{0:0}, at: ksys_write+0x68/0xe0 [ 6.816110] #1: ffff8881000578a0 (&ns->lock){+.+.}-{3:3}, at: aa_replace_profiles+0x16d/0x11e0 [ 6.817418] stack backtrace: [ 6.818086] CPU: 38 PID: 1897 Comm: apparmor_parser Tainted: G E 5.15.0-rc2+ #24 [ 6.819359] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014 [ 6.820536] Call Trace: [ 6.820918] dump_stack_lvl+0x57/0x72 [ 6.821499] __lookupn_profile+0x193/0x1a0 [ 6.822461] aa_replace_profiles+0x395/0x11e0 [ 6.823448] policy_update+0x13f/0x240 [ 6.824326] profile_replace+0xb1/0x120 [ 6.825213] vfs_write+0xe4/0x3b0 [ 6.826027] ksys_write+0x68/0xe0 [ 6.826576] do_syscall_64+0x3b/0x90 [ 6.827099] entry_SYSCALL_64_after_hwframe+0x44/0xaewhich is pretty obvious because
aa_replace_profile()invokes:__lookup_replace() __lookup_profile() __strn_find_child() __policy_strn_find() list_for_each_entry_rcu() <- SplatThe code is "correct" as this is the writer side and holding
ns->lock, but it's incorrect to uselist_for_each_entry_rcu()without being in a read side critical section unless it is properly annotated.
Quoted 5 lines
Quoted 4 lines
Same problem in the same function vs.
__lookup_parent()and there are more issues of that sort, e.g. vs.__lookup_profile()inaa_remove_profiles().thanks Thomas, I look into it
I just hit this issue as well, and I got the same feeling as Thomas.
Quickly looking at the code, I think you need to pass an extra argument to list_for_each_entry_rcu() that the ns->lock is held, silenting the warning.
Maybe being able to get "struct aa_ns *ns" in __policy_strn_find() and pass a lockdep_is_held(ns->lock) might be the most straight-forward solution.