On 8/29/20 3:13 PM, Yonghong Song wrote:
When running selftest, I hit the following kernel warning:
[ 250.871267] ============================================
[ 250.871902] WARNING: possible recursive locking detected
[ 250.872561] 5.9.0-rc1+ #830 Not tainted
[ 250.873166] --------------------------------------------
[ 250.873991] true/2053 is trying to acquire lock:
[ 250.874715] ffff8fc1f9cd2068 (&mm->mmap_lock#2){++++}-{3:3}, at:
__might_fault+0x3e/0x90
[ 250.875943]
[ 250.875943] but task is already holding lock:
[ 250.876688] ffff8fc1f9cd2068 (&mm->mmap_lock#2){++++}-{3:3}, at:
do_mprotect_pkey+0xb5/0x2f0
[ 250.877978]
[ 250.877978] other info that might help us debug this:
[ 250.878797] Possible unsafe locking scenario:
[ 250.878797]
[ 250.879708] CPU0
[ 250.880095] ----
[ 250.880482] lock(&mm->mmap_lock#2);
[ 250.881063] lock(&mm->mmap_lock#2);
[ 250.881645]
[ 250.881645] *** DEADLOCK ***
[ 250.881645]
[ 250.882559] May be due to missing lock nesting notation
[ 250.882559]
[ 250.883613] 2 locks held by true/2053:
[ 250.884194] #0: ffff8fc1f9cd2068 (&mm->mmap_lock#2){++++}-{3:3}, at:
do_mprotect_pkey+0xb5/0x2f0
[ 250.885558] #1: ffffffffbc47b8a0 (rcu_read_lock_trace){....}-{0:0},
at: __bpf_prog_enter_sleepable+0x0/0x40
[ 250.887062]
[ 250.887062] stack backtrace:
[ 250.887583] CPU: 1 PID: 2053 Comm: true Not tainted 5.9.0-rc1+ #830
[ 250.888546] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3-1.el7.centos 04/01/2014
[ 250.889896] Call Trace:
[ 250.890222] dump_stack+0x78/0xa0
[ 250.890644] __lock_acquire.cold.74+0x209/0x2e3
[ 250.891350] lock_acquire+0xba/0x380
[ 250.891919] ? __might_fault+0x3e/0x90
[ 250.892510] ? __lock_acquire+0x639/0x20c0
[ 250.893150] __might_fault+0x68/0x90
[ 250.893717] ? __might_fault+0x3e/0x90
[ 250.894325] _copy_from_user+0x1e/0xa0
[ 250.894946] bpf_copy_from_user+0x22/0x50
[ 250.895581] bpf_prog_3717002769f30998_test_int_hook+0x76/0x60c
[ 250.896446] ? __bpf_prog_enter_sleepable+0x3c/0x40
[ 250.897207] ? __bpf_prog_exit+0xa0/0xa0
[ 250.897819] bpf_trampoline_18669+0x29/0x1000
[ 250.898476] bpf_lsm_file_mprotect+0x5/0x10
[ 250.899133] security_file_mprotect+0x32/0x50
[ 250.899816] do_mprotect_pkey+0x18a/0x2f0
[ 250.900472] __x64_sys_mprotect+0x1b/0x20
[ 250.901107] do_syscall_64+0x33/0x40
[ 250.901670] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 250.902450] RIP: 0033:0x7fd95c141ef7
[ 250.903014] Code: ff 66 90 b8 0b 00 00 00 0f 05 48 3d 01 f0 ff ff 73
01 c3 48 8d 0d 21 c2 2
0 00 f7 d8 89 01 48 83 c8 ff c3 b8 0a 00 00 00 0f 05 <48> 3d 01 f0 ff ff
73 01 c3 48 8d 0d 01
c2 20 00 f7 d8 89 01 48 83
[ 250.905732] RSP: 002b:00007ffd4c291fe8 EFLAGS: 00000246 ORIG_RAX:
000000000000000a
[ 250.906773] RAX: ffffffffffffffda RBX: 0000000000000005 RCX:
00007fd95c141ef7
[ 250.907866] RDX: 0000000000000000 RSI: 00000000001ff000 RDI:
00007fd95bf20000
[ 250.908906] RBP: 00007ffd4c292320 R08: 0000000000000000 R09:
0000000000000000
[ 250.909915] R10: 00007ffd4c291ff0 R11: 0000000000000246 R12:
00007fd95c341000
[ 250.910919] R13: 00007ffd4c292408 R14: 0000000000000002 R15:
0000000000000801
Could this be an real issue here?
do_mprotect_pkey() gets a lock of current->mm->mmap_lock
before calling security_file_mprotect(bpf_lsm_file_mprotect).
Later on, when do _copy_to_user(), page fault may happen
and current->mm->mmap_lock might be acquired again and may
have a deadlock here?
Hmm. It does sound like dead_lock.
But I don't understand why I don't see this splat.
I have
LOCKDEP=y
DEBUG_ATOMIC_SLEEP=y
LOCK_DEBUGGING_SUPPORT=y
KASAN=y
in my .config and don't see it :(
Could pls send me your .config?
I'll analyze further.
Thanks for the reporting!
