Hello,
With respect to the patch https://lore.kernel.org/patchwork/patch/1202512/
I boot tested with CONFIG_PROVE_RCU_LIST=y and encountered a susppicious RCU
usage warning in "security/apparmor/include/lib.h". I thought of going forward
and fix it myself, however, while going through the stack trace and the actual
code, I found that the function (__lookupn_profile) is required to be called
with rcu_read_locK() but the splat proves it otherwise.
[ 12.727582] =============================
[ 12.727599] WARNING: suspicious RCU usage
[ 12.727601] 5.5.4-stable #17 Tainted: G E
[ 12.727602] -----------------------------
[ 12.727604] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!!
[ 12.727605]
other info that might help us debug this:
[ 12.727606]
rcu_scheduler_active = 2, debug_locks = 1
[ 12.727608] 2 locks held by apparmor_parser/506:
[ 12.727609] #0: ffff9f0687562490 (sb_writers#10){.+.+}, at: vfs_write+0x140/0x1a0
[ 12.727614] #1: ffff9f0687f09ca8 (&ns->lock){+.+.}, at: aa_replace_profiles+0x17a/0xdd0
[ 12.727619]
stack backtrace:
[ 12.727621] CPU: 3 PID: 506 Comm: apparmor_parser Tainted: G E 5.5.4-stable #17
[ 12.727622] Hardware name: Gigabyte Technology Co., Ltd. Z170-D3H/Z170-D3H-CF, BIOS F21 03/06/2017
[ 12.727623] Call Trace:
[ 12.727627] dump_stack+0x8f/0xd0
[ 12.727630] __lookupn_profile+0x19c/0x1a0
[ 12.727632] ? aa_unpack+0x51b/0x580
[ 12.727636] __lookup_replace+0x34/0xc0
[ 12.727640] aa_replace_profiles+0x2a0/0xdd0
[ 12.727649] policy_update+0x106/0x370
[ 12.727653] profile_replace+0xa3/0x110
[ 12.727657] vfs_write+0xb9/0x1a0
[ 12.727661] ksys_write+0x68/0xe0
[ 12.727666] do_syscall_64+0x5c/0xe0
[ 12.727669] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 12.727671] RIP: 0033:0x7ff83fec7f93
[ 12.727673] Code: 75 05 48 83 c4 58 c3 e8 eb 41 ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
[ 12.727674] RSP: 002b:00007ffcebb5c398 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 12.727676] RAX: ffffffffffffffda RBX: 0000000000007131 RCX: 00007ff83fec7f93
[ 12.727677] RDX: 0000000000007131 RSI: 00005610fd804a40 RDI: 0000000000000006
[ 12.727678] RBP: 00005610fd804a40 R08: 0000000000007131 R09: 00005610fd802f38
[ 12.727680] R10: fffffffffffffa8a R11: 0000000000000246 R12: 0000000000000000
[ 12.727681] R13: 0000000000000006 R14: 00005610fd7dd490 R15: 0000000000007131
Thanks
Amol
On Mon, Apr 06, 2020 at 05:11:34PM +0530, Amol Grover wrote:
> Hello,
>
> With respect to the patch https://lore.kernel.org/patchwork/patch/1202512/
> I boot tested with CONFIG_PROVE_RCU_LIST=y and encountered a susppicious RCU
> usage warning in "security/apparmor/include/lib.h". I thought of going forward
> and fix it myself, however, while going through the stack trace and the actual
> code, I found that the function (__lookupn_profile) is required to be called
> with rcu_read_locK() but the splat proves it otherwise.
>
> [ 12.727582] =============================
> [ 12.727599] WARNING: suspicious RCU usage
> [ 12.727601] 5.5.4-stable #17 Tainted: G E
> [ 12.727602] -----------------------------
> [ 12.727604] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!!
> [ 12.727605]
> other info that might help us debug this:
>
> [ 12.727606]
> rcu_scheduler_active = 2, debug_locks = 1
> [ 12.727608] 2 locks held by apparmor_parser/506:
> [ 12.727609] #0: ffff9f0687562490 (sb_writers#10){.+.+}, at: vfs_write+0x140/0x1a0
> [ 12.727614] #1: ffff9f0687f09ca8 (&ns->lock){+.+.}, at: aa_replace_profiles+0x17a/0xdd0
> [ 12.727619]
> stack backtrace:
> [ 12.727621] CPU: 3 PID: 506 Comm: apparmor_parser Tainted: G E 5.5.4-stable #17
> [ 12.727622] Hardware name: Gigabyte Technology Co., Ltd. Z170-D3H/Z170-D3H-CF, BIOS F21 03/06/2017
> [ 12.727623] Call Trace:
> [ 12.727627] dump_stack+0x8f/0xd0
> [ 12.727630] __lookupn_profile+0x19c/0x1a0
> [ 12.727632] ? aa_unpack+0x51b/0x580
> [ 12.727636] __lookup_replace+0x34/0xc0
> [ 12.727640] aa_replace_profiles+0x2a0/0xdd0
> [ 12.727649] policy_update+0x106/0x370
> [ 12.727653] profile_replace+0xa3/0x110
> [ 12.727657] vfs_write+0xb9/0x1a0
> [ 12.727661] ksys_write+0x68/0xe0
> [ 12.727666] do_syscall_64+0x5c/0xe0
> [ 12.727669] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 12.727671] RIP: 0033:0x7ff83fec7f93
> [ 12.727673] Code: 75 05 48 83 c4 58 c3 e8 eb 41 ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
> [ 12.727674] RSP: 002b:00007ffcebb5c398 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> [ 12.727676] RAX: ffffffffffffffda RBX: 0000000000007131 RCX: 00007ff83fec7f93
> [ 12.727677] RDX: 0000000000007131 RSI: 00005610fd804a40 RDI: 0000000000000006
> [ 12.727678] RBP: 00005610fd804a40 R08: 0000000000007131 R09: 00005610fd802f38
> [ 12.727680] R10: fffffffffffffa8a R11: 0000000000000246 R12: 0000000000000000
> [ 12.727681] R13: 0000000000000006 R14: 00005610fd7dd490 R15: 0000000000007131
>
> Thanks
> Amol
Hello,
Just a friendly request to please go through the above _bug_.
Thanks
Amol
On 5/14/20 11:24 AM, Amol Grover wrote:
> On Mon, Apr 06, 2020 at 05:11:34PM +0530, Amol Grover wrote:
>> Hello,
>>
>> With respect to the patch https://lore.kernel.org/patchwork/patch/1202512/
>> I boot tested with CONFIG_PROVE_RCU_LIST=y and encountered a susppicious RCU
>> usage warning in "security/apparmor/include/lib.h". I thought of going forward
>> and fix it myself, however, while going through the stack trace and the actual
>> code, I found that the function (__lookupn_profile) is required to be called
>> with rcu_read_locK() but the splat proves it otherwise.
>>
>> [ 12.727582] =============================
>> [ 12.727599] WARNING: suspicious RCU usage
>> [ 12.727601] 5.5.4-stable #17 Tainted: G E
>> [ 12.727602] -----------------------------
>> [ 12.727604] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!!
>> [ 12.727605]
>> other info that might help us debug this:
>>
>> [ 12.727606]
>> rcu_scheduler_active = 2, debug_locks = 1
>> [ 12.727608] 2 locks held by apparmor_parser/506:
>> [ 12.727609] #0: ffff9f0687562490 (sb_writers#10){.+.+}, at: vfs_write+0x140/0x1a0
>> [ 12.727614] #1: ffff9f0687f09ca8 (&ns->lock){+.+.}, at: aa_replace_profiles+0x17a/0xdd0
>> [ 12.727619]
>> stack backtrace:
>> [ 12.727621] CPU: 3 PID: 506 Comm: apparmor_parser Tainted: G E 5.5.4-stable #17
>> [ 12.727622] Hardware name: Gigabyte Technology Co., Ltd. Z170-D3H/Z170-D3H-CF, BIOS F21 03/06/2017
>> [ 12.727623] Call Trace:
>> [ 12.727627] dump_stack+0x8f/0xd0
>> [ 12.727630] __lookupn_profile+0x19c/0x1a0
>> [ 12.727632] ? aa_unpack+0x51b/0x580
>> [ 12.727636] __lookup_replace+0x34/0xc0
>> [ 12.727640] aa_replace_profiles+0x2a0/0xdd0
>> [ 12.727649] policy_update+0x106/0x370
>> [ 12.727653] profile_replace+0xa3/0x110
>> [ 12.727657] vfs_write+0xb9/0x1a0
>> [ 12.727661] ksys_write+0x68/0xe0
>> [ 12.727666] do_syscall_64+0x5c/0xe0
>> [ 12.727669] entry_SYSCALL_64_after_hwframe+0x49/0xbe
>> [ 12.727671] RIP: 0033:0x7ff83fec7f93
>> [ 12.727673] Code: 75 05 48 83 c4 58 c3 e8 eb 41 ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
>> [ 12.727674] RSP: 002b:00007ffcebb5c398 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
>> [ 12.727676] RAX: ffffffffffffffda RBX: 0000000000007131 RCX: 00007ff83fec7f93
>> [ 12.727677] RDX: 0000000000007131 RSI: 00005610fd804a40 RDI: 0000000000000006
>> [ 12.727678] RBP: 00005610fd804a40 R08: 0000000000007131 R09: 00005610fd802f38
>> [ 12.727680] R10: fffffffffffffa8a R11: 0000000000000246 R12: 0000000000000000
>> [ 12.727681] R13: 0000000000000006 R14: 00005610fd7dd490 R15: 0000000000007131
>>
>> Thanks
>> Amol
>
> Hello,
>
> Just a friendly request to please go through the above _bug_.
>
yep, thanks. I am looking into to it now.
On 4/6/20 4:41 AM, Amol Grover wrote:
> Hello,
>
> With respect to the patch https://lore.kernel.org/patchwork/patch/1202512/
> I boot tested with CONFIG_PROVE_RCU_LIST=y and encountered a susppicious RCU
> usage warning in "security/apparmor/include/lib.h". I thought of going forward
> and fix it myself, however, while going through the stack trace and the actual
> code, I found that the function (__lookupn_profile) is required to be called
> with rcu_read_locK() but the splat proves it otherwise.
>
The comment could be updated to
* Requires: rcu_read_lock be held or the namespace->lock be held.
bascially there are reader paths which take the rcu_read_lock and then call
the __lookupn_profile() helper eg. aa_lookupn_profile() and the writer paths
the hold the ns lock, like in the splat
aa_replace_profiles() takes the ns lock
> [ 12.727582] =============================
> [ 12.727599] WARNING: suspicious RCU usage
> [ 12.727601] 5.5.4-stable #17 Tainted: G E
> [ 12.727602] -----------------------------
> [ 12.727604] security/apparmor/include/lib.h:191 RCU-list traversed in non-reader section!!
> [ 12.727605]
> other info that might help us debug this:
>
> [ 12.727606]
> rcu_scheduler_active = 2, debug_locks = 1
> [ 12.727608] 2 locks held by apparmor_parser/506:
> [ 12.727609] #0: ffff9f0687562490 (sb_writers#10){.+.+}, at: vfs_write+0x140/0x1a0
> [ 12.727614] #1: ffff9f0687f09ca8 (&ns->lock){+.+.}, at: aa_replace_profiles+0x17a/0xdd0
> [ 12.727619]
> stack backtrace:
> [ 12.727621] CPU: 3 PID: 506 Comm: apparmor_parser Tainted: G E 5.5.4-stable #17
> [ 12.727622] Hardware name: Gigabyte Technology Co., Ltd. Z170-D3H/Z170-D3H-CF, BIOS F21 03/06/2017
> [ 12.727623] Call Trace:
> [ 12.727627] dump_stack+0x8f/0xd0
> [ 12.727630] __lookupn_profile+0x19c/0x1a0
> [ 12.727632] ? aa_unpack+0x51b/0x580
> [ 12.727636] __lookup_replace+0x34/0xc0
> [ 12.727640] aa_replace_profiles+0x2a0/0xdd0
> [ 12.727649] policy_update+0x106/0x370
> [ 12.727653] profile_replace+0xa3/0x110
> [ 12.727657] vfs_write+0xb9/0x1a0
> [ 12.727661] ksys_write+0x68/0xe0
> [ 12.727666] do_syscall_64+0x5c/0xe0
> [ 12.727669] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [ 12.727671] RIP: 0033:0x7ff83fec7f93
> [ 12.727673] Code: 75 05 48 83 c4 58 c3 e8 eb 41 ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 55 c3 0f 1f 40 00 48 83 ec 28 48 89 54 24 18
> [ 12.727674] RSP: 002b:00007ffcebb5c398 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
> [ 12.727676] RAX: ffffffffffffffda RBX: 0000000000007131 RCX: 00007ff83fec7f93
> [ 12.727677] RDX: 0000000000007131 RSI: 00005610fd804a40 RDI: 0000000000000006
> [ 12.727678] RBP: 00005610fd804a40 R08: 0000000000007131 R09: 00005610fd802f38
> [ 12.727680] R10: fffffffffffffa8a R11: 0000000000000246 R12: 0000000000000000
> [ 12.727681] R13: 0000000000000006 R14: 00005610fd7dd490 R15: 0000000000007131
>
> Thanks
> Amol
>