Re: [PATCH] Fix suspicious RCU usage in nfs_idmap_get_key.

From: Artem Savkov
Date: Tue Oct 04 2016 - 11:53:04 EST

On Tue, Oct 04, 2016 at 04:45:14PM +0100, David Howells wrote:
> Artem Savkov <asavkov@xxxxxxxxxx> wrote:
>
> > nfs_idmap_get_key doesn't hold rkey->sem when calling user_key_payload
> > resulting in a "suspicious RCU usage" lockdep splat. It does, however hold
> > rcu_read_lock, so it either needs to use unprotected rcu_dereference, or take
> > rkey->sem instead of rcu_read_lock.
>
> This shouldn't be using rkey->sem. user_key_payload() should do sufficient
> RCU magic that rcu_read_lock() is sufficient. Can you please include the RCU
> splat? It's possible user_key_payload() is wrong.

Below is the splat I get sometimes while running nfs connectathon
testsuite:

[ 711.360321] ===============================
[ 711.364658] [ INFO: suspicious RCU usage. ]
[ 711.369065] 4.8.0-9.el7.upstream.x86_64.debug #1 Not tainted
[ 711.374930] -------------------------------
[ 711.379271] ./include/keys/user-type.h:53 suspicious rcu_dereference_protected() usage!
[ 711.387669]
[ 711.387669] other info that might help us debug this:
[ 711.387669]
[ 711.396058]
[ 711.396058] rcu_scheduler_active = 1, debug_locks = 0
[ 711.402838] 1 lock held by mount.nfs4/29135:
[ 711.407272] #0: (rcu_read_lock){......}, at: [<ffffffffa0a88558>] nfs_idmap_get_key+0xe8/0x2f0 [nfsv4]
[ 711.417187]
[ 711.417187] stack backtrace:
[ 711.421712] CPU: 3 PID: 29135 Comm: mount.nfs4 Not tainted 4.8.0-9.el7.upstream.x86_64.debug #1
[ 711.430848] Hardware name: Dell Inc. PowerEdge T310/0P673K, BIOS 1.12.0 09/06/2013
[ 711.438702] 0000000000000286 000000005a15e544 ffff880800e4f4c0 ffffffff813e95cc
[ 711.446458] ffff8807f5e70000 0000000000000001 ffff880800e4f4f0 ffffffff811023b7
[ 711.454197] 0000000000000000 ffff8808137fd040 ffff8807d1383383 ffff8808137fd040
[ 711.461920] Call Trace:
[ 711.464445] [<ffffffff813e95cc>] dump_stack+0x85/0xc9
[ 711.469825] [<ffffffff811023b7>] lockdep_rcu_suspicious+0xe7/0x120
[ 711.476356] [<ffffffffa0a885ed>] nfs_idmap_get_key+0x17d/0x2f0 [nfsv4]
[ 711.483273] [<ffffffffa0a88558>] ? nfs_idmap_get_key+0xe8/0x2f0 [nfsv4]
[ 711.490275] [<ffffffffa0a88dfe>] nfs_map_name_to_uid+0x18e/0x2a0 [nfsv4]
[ 711.497357] [<ffffffff810edef2>] ? pick_next_task_fair+0x1b2/0x7c0
[ 711.503917] [<ffffffff81041399>] ? sched_clock+0x9/0x10
[ 711.509471] [<ffffffffa0a7e43c>] decode_getfattr_attrs+0xdcc/0x1500 [nfsv4]
[ 711.516844] [<ffffffffa0a7ec0b>] decode_getfattr_generic.constprop.111+0x9b/0x100 [nfsv4]
[ 711.525467] [<ffffffffa0a7f550>] ? nfs4_xdr_dec_lookup+0xc0/0xc0 [nfsv4]
[ 711.532532] [<ffffffffa0a7f5ee>] nfs4_xdr_dec_lookup_root+0x9e/0xb0 [nfsv4]
[ 711.539987] [<ffffffffa0486d47>] rpcauth_unwrap_resp+0xa7/0xe0 [sunrpc]
[ 711.547041] [<ffffffffa0a7f550>] ? nfs4_xdr_dec_lookup+0xc0/0xc0 [nfsv4]
[ 711.554102] [<ffffffffa0472f13>] call_decode+0x1f3/0x870 [sunrpc]
[ 711.560566] [<ffffffffa0472d20>] ? call_refreshresult+0x140/0x140 [sunrpc]
[ 711.567869] [<ffffffffa0472d20>] ? call_refreshresult+0x140/0x140 [sunrpc]
[ 711.575127] [<ffffffffa0484ac5>] __rpc_execute+0xc5/0x6a0 [sunrpc]
[ 711.581613] [<ffffffff810f64d5>] ? wake_up_bit+0x25/0x30
[ 711.587269] [<ffffffffa04853f1>] rpc_execute+0x91/0x200 [sunrpc]
[ 711.593646] [<ffffffffa0476d49>] rpc_run_task+0x109/0x150 [sunrpc]
[ 711.600180] [<ffffffffa0a5e393>] nfs4_call_sync_sequence+0x63/0xa0 [nfsv4]
[ 711.607478] [<ffffffffa0a6164d>] _nfs4_lookup_root.isra.68+0xdd/0x100 [nfsv4]
[ 711.615055] [<ffffffffa04868d6>] ? rpcauth_create+0xb6/0x110 [sunrpc]
[ 711.621870] [<ffffffffa0a6b639>] nfs4_lookup_root+0x99/0x260 [nfsv4]
[ 711.628528] [<ffffffffa0a6b860>] nfs4_lookup_root_sec+0x60/0x90 [nfsv4]
[ 711.635582] [<ffffffffa0a6b8cc>] nfs4_find_root_sec+0x3c/0xb0 [nfsv4]
[ 711.642437] [<ffffffffa0a70661>] nfs4_proc_get_rootfh+0x31/0x80 [nfsv4]
[ 711.649477] [<ffffffffa0a8e42f>] nfs4_get_rootfh+0x5f/0x130 [nfsv4]
[ 711.656120] [<ffffffff811249e3>] ? rcu_read_lock_sched_held+0x93/0xa0
[ 711.662951] [<ffffffff8125ea68>] ? kmem_cache_alloc_trace+0x298/0x340
[ 711.669748] [<ffffffffa09fdb7f>] ? nfs_alloc_fattr+0x1f/0x70 [nfs]
[ 711.676292] [<ffffffffa0a8e82f>] nfs4_server_common_setup+0x9f/0x1d0 [nfsv4]
[ 711.683737] [<ffffffffa0a9049a>] nfs4_create_server+0x24a/0x390 [nfsv4]
[ 711.690731] [<ffffffffa0a84d7e>] nfs4_remote_mount+0x2e/0x60 [nfsv4]
[ 711.697432] [<ffffffff81297959>] mount_fs+0x39/0x170
[ 711.702700] [<ffffffff812b90ab>] vfs_kern_mount+0x6b/0x150
[ 711.708557] [<ffffffffa0a84ca6>] nfs_do_root_mount+0x86/0xc0 [nfsv4]
[ 711.715263] [<ffffffffa0a85084>] nfs4_try_mount+0x44/0xc0 [nfsv4]
[ 711.721735] [<ffffffffa09f4497>] ? get_nfs_version+0x27/0x90 [nfs]
[ 711.728298] [<ffffffffa0a0497c>] nfs_fs_mount+0x4ac/0xd80 [nfs]
[ 711.734524] [<ffffffff81101162>] ? lockdep_init_map+0x92/0x200
[ 711.740699] [<ffffffffa0a054b0>] ? nfs_clone_super+0x130/0x130 [nfs]
[ 711.747441] [<ffffffffa0a02bd0>] ? param_set_portnr+0x70/0x70 [nfs]
[ 711.754092] [<ffffffff81297959>] mount_fs+0x39/0x170
[ 711.759344] [<ffffffff812b90ab>] vfs_kern_mount+0x6b/0x150
[ 711.765176] [<ffffffff812bbcb1>] do_mount+0x1f1/0xd10
[ 711.770523] [<ffffffff811249e3>] ? rcu_read_lock_sched_held+0x93/0xa0
[ 711.777352] [<ffffffff812bcae3>] SyS_mount+0x83/0xd0
[ 711.782640] [<ffffffff81003c4c>] do_syscall_64+0x6c/0x1e0
[ 711.788351] [<ffffffff817e45bf>] entry_SYSCALL64_slow_path+0x25/0x25

--
Regards,
Artem