apparmor: WARNING: suspicious RCU usage

apparmor: WARNING: suspicious RCU usage

[Thomas Gleixner]

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

which is pretty obvious because aa_replace_profile() invokes:

    __lookup_replace()
      __lookup_profile()
        __strn_find_child()
          __policy_strn_find()
            list_for_each_entry_rcu()  <- Splat

The 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

Re: apparmor: WARNING: suspicious RCU usage

[John Johansen]

On 9/21/21 1:32 AM, Thomas Gleixner wrote:
> 
> 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/0xae
> 
> which is pretty obvious because aa_replace_profile() invokes:
> 
>     __lookup_replace()
>       __lookup_profile()
>         __strn_find_child()
>           __policy_strn_find()
>             list_for_each_entry_rcu()  <- Splat
> 
> The 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 Thomas, I look into it