Re: possible deadlock in process_measurement

From: Mimi Zohar
Date: Thu Jul 11 2019 - 10:14:59 EST


Hi Eric,

On Mon, 2019-06-03 at 09:35 -0700, syzbot wrote:
> syzbot has found a reproducer for the following crash on:
>
> HEAD commit: 3c09c195 Add linux-next specific files for 20190531
> git tree: linux-next
> console output: https://syzkaller.appspot.com/x/log.txt?x=10f61a0ea00000
> kernel config: https://syzkaller.appspot.com/x/.config?x=6cfb24468280cd5c
> dashboard link: https://syzkaller.appspot.com/bug?extid=5ab61747675a87ea359d
> compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=177c3d16a00000
> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=14ec01baa00000
>

This reproducer seems like it is similar, but the cause is different
than the original report. ÂOne has to do with overlayfs, while the
other has to do with ext4, mprotect/mmap. ÂI assume in both cases an
IMA policy was required to trigger the locking bug. ÂWhat type of IMA
policy are you using?

Do we need to differentiate the two reports? ÂIs the "last occurred"
notification for the overlay, for mprotect, or both? ÂPlease Cc the
overlay mailing list on the overlay aspect.

thanks,

Mimi

> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+5ab61747675a87ea359d@xxxxxxxxxxxxxxxxxxxxxxxxx
>
> get_swap_device: Bad swap file entry 6000000000000001
> get_swap_device: Bad swap file entry 6400000000000001
> get_swap_device: Bad swap file entry 6800000000000001
> get_swap_device: Bad swap file entry 6c00000000000001
> get_swap_device: Bad swap file entry 7000000000000001
> get_swap_device: Bad swap file entry 7400000000000001
> ======================================================
> WARNING: possible circular locking dependency detected
> 5.2.0-rc2-next-20190531 #4 Not tainted
> ------------------------------------------------------
> syz-executor395/17373 is trying to acquire lock:
> 000000003d1a4a53 (&sb->s_type->i_mutex_key#10){+.+.}, at: inode_lock
> include/linux/fs.h:778 [inline]
> 000000003d1a4a53 (&sb->s_type->i_mutex_key#10){+.+.}, at:
> process_measurement+0x15ae/0x15e0 security/integrity/ima/ima_main.c:228
>
> but task is already holding lock:
> 00000000e0714fc5 (&mm->mmap_sem#2){++++}, at: do_mprotect_pkey+0x1f6/0xa30
> mm/mprotect.c:485
>
> which lock already depends on the new lock.
>
>
> the existing dependency chain (in reverse order) is:
>
> -> #1 (&mm->mmap_sem#2){++++}:
> down_read+0x3f/0x1e0 kernel/locking/rwsem.c:24
> get_user_pages_unlocked+0xfc/0x4a0 mm/gup.c:1174
> __gup_longterm_unlocked mm/gup.c:2193 [inline]
> get_user_pages_fast+0x43f/0x530 mm/gup.c:2245
> iov_iter_get_pages+0x2c2/0xf80 lib/iov_iter.c:1287
> dio_refill_pages fs/direct-io.c:171 [inline]
> dio_get_page fs/direct-io.c:215 [inline]
> do_direct_IO fs/direct-io.c:983 [inline]
> do_blockdev_direct_IO+0x3f7b/0x8e00 fs/direct-io.c:1336
> __blockdev_direct_IO+0xa1/0xca fs/direct-io.c:1422
> ext4_direct_IO_write fs/ext4/inode.c:3782 [inline]
> ext4_direct_IO+0xaa7/0x1bb0 fs/ext4/inode.c:3909
> generic_file_direct_write+0x20a/0x4a0 mm/filemap.c:3110
> __generic_file_write_iter+0x2ee/0x630 mm/filemap.c:3293
> ext4_file_write_iter+0x332/0x1070 fs/ext4/file.c:266
> call_write_iter include/linux/fs.h:1870 [inline]
> new_sync_write+0x4d3/0x770 fs/read_write.c:483
> __vfs_write+0xe1/0x110 fs/read_write.c:496
> vfs_write+0x268/0x5d0 fs/read_write.c:558
> ksys_write+0x14f/0x290 fs/read_write.c:611
> __do_sys_write fs/read_write.c:623 [inline]
> __se_sys_write fs/read_write.c:620 [inline]
> __x64_sys_write+0x73/0xb0 fs/read_write.c:620
> do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
>
> -> #0 (&sb->s_type->i_mutex_key#10){+.+.}:
> lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4300
> down_write+0x38/0xa0 kernel/locking/rwsem.c:66
> inode_lock include/linux/fs.h:778 [inline]
> process_measurement+0x15ae/0x15e0
> security/integrity/ima/ima_main.c:228
> ima_file_mmap+0x11a/0x130 security/integrity/ima/ima_main.c:370
> security_file_mprotect+0xd5/0x100 security/security.c:1430
> do_mprotect_pkey+0x537/0xa30 mm/mprotect.c:550
> __do_sys_pkey_mprotect mm/mprotect.c:590 [inline]
> __se_sys_pkey_mprotect mm/mprotect.c:587 [inline]
> __x64_sys_pkey_mprotect+0x97/0xf0 mm/mprotect.c:587
> do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
>
> other info that might help us debug this:
>
> Possible unsafe locking scenario:
>
> CPU0 CPU1
> ---- ----
> lock(&mm->mmap_sem#2);
> lock(&sb->s_type->i_mutex_key#10);
> lock(&mm->mmap_sem#2);
> lock(&sb->s_type->i_mutex_key#10);
>
> *** DEADLOCK ***
>
> 1 lock held by syz-executor395/17373:
> #0: 00000000e0714fc5 (&mm->mmap_sem#2){++++}, at:
> do_mprotect_pkey+0x1f6/0xa30 mm/mprotect.c:485
>
> stack backtrace:
> CPU: 1 PID: 17373 Comm: syz-executor395 Not tainted 5.2.0-rc2-next-20190531
> #4
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> Google 01/01/2011
> Call Trace:
> __dump_stack lib/dump_stack.c:77 [inline]
> dump_stack+0x172/0x1f0 lib/dump_stack.c:113
> print_circular_bug.cold+0x1cc/0x28f kernel/locking/lockdep.c:1566
> check_prev_add kernel/locking/lockdep.c:2311 [inline]
> check_prevs_add kernel/locking/lockdep.c:2419 [inline]
> validate_chain kernel/locking/lockdep.c:2801 [inline]
> __lock_acquire+0x3755/0x5490 kernel/locking/lockdep.c:3790
> lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4300
> down_write+0x38/0xa0 kernel/locking/rwsem.c:66
> inode_lock include/linux/fs.h:778 [inline]
> process_measurement+0x15ae/0x15e0 security/integrity/ima/ima_main.c:228
> ima_file_mmap+0x11a/0x130 security/integrity/ima/ima_main.c:370
> security_file_mprotect+0xd5/0x100 security/security.c:1430
> do_mprotect_pkey+0x537/0xa30 mm/mprotect.c:550
> __do_sys_pkey_mprotect mm/mprotect.c:590 [inline]
> __se_sys_pkey_mprotect mm/mprotect.c:587 [inline]
> __x64_sys_pkey_mprotect+0x97/0xf0 mm/mprotect.c:587
> do_syscall_64+0xfd/0x680 arch/x86/entry/common.c:301
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
> RIP: 0033:0x440279
> Code: 18 89 d0 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 48 89 f8 48 89 f7
> 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff
> ff 0f 83 fb 13 fc ff c3 66 2e 0f 1f 84 00 00 00 00
> RSP: 002b:00007ffeec2f48d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000149
> RAX: ffffffffffffffda RBX: 00000000004002c8 RCX: 0000000000440279
> RDX: 000000000000000
>