possible deadlock in do_io_accounting

Status: fixed on 2019/12/10 20:49
Reported-by: syzbot+41049bff8bbf2e607bf0@syzkaller.appspotmail.com
Fix commit: 146d62e5a586 ovl: detect overlapping layers
First crash: 2621d, last: 2509d
Fix bisection: fixed by (bisect log) :
commit f1c5aa5eda08710c2ba619d93126380881fa1114
Author: Amir Goldstein <amir73il@gmail.com>
Date: Thu Apr 18 14:42:08 2019 +0000

  ovl: detect overlapping layers

  
▶ ▼ Similar bugs (8)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
android-49 possible deadlock in do_io_accounting 4 syz, C 4521 2445d 2681d 0/3 public: reported C repro on 2019/04/12 00:00
android-44 possible deadlock in do_io_accounting 4 syz, C 28 2446d 2681d 0/2 public: reported C repro on 2019/04/11 08:44
upstream possible deadlock in do_io_accounting (3) fs 4 syz, C inconclusive done 39 2331d 2422d 15/29 fixed on 2020/08/18 22:40
linux-4.19 possible deadlock in do_io_accounting (2) 4 syz error 26 2162d 2424d 0/1 upstream: reported syz repro on 2019/12/24 07:12
upstream possible deadlock in do_io_accounting fs 4 syz 1003 2696d 3174d 0/29 closed as dup on 2017/12/12 21:27
upstream possible deadlock in do_io_accounting (2) fs 4 1 2669d 2667d 0/29 auto-closed as invalid on 2019/10/20 09:03
android-414 possible deadlock in do_io_accounting 4 syz 70 2697d 2681d 0/1 public: reported syz repro on 2019/04/12 00:01
linux-4.14 possible deadlock in do_io_accounting 4 syz, C error 56 1659d 2608d 0/1 upstream: reported C repro on 2019/06/24 03:04

Sample crash report:
audit: type=1400 audit(1560431785.190:36): avc:  denied  { map } for  pid=7516 comm="syz-executor499" path="/root/syz-executor499006658" dev="sda1" ino=16483 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
======================================================
WARNING: possible circular locking dependency detected
4.19.50 #22 Not tainted
------------------------------------------------------
syz-executor499/7516 is trying to acquire lock:
0000000022e241f1 (&sig->cred_guard_mutex){+.+.}, at: do_io_accounting+0x1f4/0x830 fs/proc/base.c:2704

but task is already holding lock:
000000001d704e75 (&p->lock){+.+.}, at: seq_read+0x71/0x1110 fs/seq_file.c:161

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&p->lock){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:925 [inline]
       __mutex_lock+0xf7/0x1300 kernel/locking/mutex.c:1072
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
       seq_read+0x71/0x1110 fs/seq_file.c:161
       do_loop_readv_writev fs/read_write.c:701 [inline]
       do_loop_readv_writev fs/read_write.c:688 [inline]
       do_iter_read+0x490/0x640 fs/read_write.c:925
       vfs_readv+0xf0/0x160 fs/read_write.c:987
       kernel_readv fs/splice.c:362 [inline]
       default_file_splice_read+0x478/0x890 fs/splice.c:417
       do_splice_to+0x127/0x180 fs/splice.c:881
       splice_direct_to_actor+0x256/0x890 fs/splice.c:953
       do_splice_direct+0x1da/0x2a0 fs/splice.c:1062
       do_sendfile+0x597/0xce0 fs/read_write.c:1447
       __do_sys_sendfile64 fs/read_write.c:1508 [inline]
       __se_sys_sendfile64 fs/read_write.c:1494 [inline]
       __x64_sys_sendfile64+0x1dd/0x220 fs/read_write.c:1494
       do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #2 (sb_writers#4){.+.+}:
       percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:36 [inline]
       percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
       __sb_start_write+0x20b/0x360 fs/super.c:1387
       sb_start_write include/linux/fs.h:1578 [inline]
       mnt_want_write+0x3f/0xc0 fs/namespace.c:360
       ovl_want_write+0x76/0xa0 fs/overlayfs/util.c:24
       ovl_xattr_set+0x53/0x5b0 fs/overlayfs/inode.c:332
       ovl_posix_acl_xattr_set+0x33a/0x9a0 fs/overlayfs/super.c:908
       __vfs_setxattr+0x11f/0x180 fs/xattr.c:149
       __vfs_setxattr_noperm+0x11c/0x410 fs/xattr.c:180
       vfs_setxattr+0xda/0x100 fs/xattr.c:223
       setxattr+0x26f/0x380 fs/xattr.c:450
       path_setxattr+0x197/0x1b0 fs/xattr.c:469
       __do_sys_setxattr fs/xattr.c:484 [inline]
       __se_sys_setxattr fs/xattr.c:480 [inline]
       __x64_sys_setxattr+0xc4/0x150 fs/xattr.c:480
       do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&ovl_i_mutex_dir_key[depth]){++++}:
       down_read+0x3b/0xb0 kernel/locking/rwsem.c:24
       inode_lock_shared include/linux/fs.h:757 [inline]
       do_last fs/namei.c:3323 [inline]
       path_openat+0x1e77/0x4690 fs/namei.c:3534
       do_filp_open+0x1a1/0x280 fs/namei.c:3564
       do_open_execat+0x140/0x660 fs/exec.c:853
       __do_execve_file.isra.0+0x15a4/0x2150 fs/exec.c:1755
       do_execveat_common fs/exec.c:1866 [inline]
       do_execveat fs/exec.c:1894 [inline]
       __do_sys_execveat fs/exec.c:1975 [inline]
       __se_sys_execveat fs/exec.c:1967 [inline]
       __x64_sys_execveat+0xed/0x130 fs/exec.c:1967
       do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 (&sig->cred_guard_mutex){+.+.}:
       lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:3900
       __mutex_lock_common kernel/locking/mutex.c:925 [inline]
       __mutex_lock+0xf7/0x1300 kernel/locking/mutex.c:1072
       mutex_lock_killable_nested+0x16/0x20 kernel/locking/mutex.c:1102
       do_io_accounting+0x1f4/0x830 fs/proc/base.c:2704
       proc_tid_io_accounting+0x20/0x30 fs/proc/base.c:2747
       proc_single_show+0xf0/0x180 fs/proc/base.c:737
       seq_read+0x4ca/0x1110 fs/seq_file.c:229
       do_loop_readv_writev fs/read_write.c:701 [inline]
       do_loop_readv_writev fs/read_write.c:688 [inline]
       do_iter_read+0x490/0x640 fs/read_write.c:925
       vfs_readv+0xf0/0x160 fs/read_write.c:987
       kernel_readv fs/splice.c:362 [inline]
       default_file_splice_read+0x478/0x890 fs/splice.c:417
       do_splice_to+0x127/0x180 fs/splice.c:881
       splice_direct_to_actor+0x256/0x890 fs/splice.c:953
       do_splice_direct+0x1da/0x2a0 fs/splice.c:1062
       do_sendfile+0x597/0xce0 fs/read_write.c:1447
       __do_sys_sendfile64 fs/read_write.c:1508 [inline]
       __se_sys_sendfile64 fs/read_write.c:1494 [inline]
       __x64_sys_sendfile64+0x1dd/0x220 fs/read_write.c:1494
       do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  &sig->cred_guard_mutex --> sb_writers#4 --> &p->lock

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&p->lock);
                               lock(sb_writers#4);
                               lock(&p->lock);
  lock(&sig->cred_guard_mutex);

 *** DEADLOCK ***

2 locks held by syz-executor499/7516:
 #0: 000000009e00f5b3 (sb_writers#4){.+.+}, at: file_start_write include/linux/fs.h:2773 [inline]
 #0: 000000009e00f5b3 (sb_writers#4){.+.+}, at: do_sendfile+0x9b9/0xce0 fs/read_write.c:1446
 #1: 000000001d704e75 (&p->lock){+.+.}, at: seq_read+0x71/0x1110 fs/seq_file.c:161

stack backtrace:
CPU: 0 PID: 7516 Comm: syz-executor499 Not tainted 4.19.50 #22
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.isra.0.cold+0x1cc/0x28f kernel/locking/lockdep.c:1221
 check_prev_add kernel/locking/lockdep.c:1861 [inline]
 check_prevs_add kernel/locking/lockdep.c:1974 [inline]
 validate_chain kernel/locking/lockdep.c:2415 [inline]
 __lock_acquire+0x2e6d/0x48f0 kernel/locking/lockdep.c:3411
 lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:3900
 __mutex_lock_common kernel/locking/mutex.c:925 [inline]
 __mutex_lock+0xf7/0x1300 kernel/locking/mutex.c:1072
 mutex_lock_killable_nested+0x16/0x20 kernel/locking/mutex.c:1102
 do_io_accounting+0x1f4/0x830 fs/proc/base.c:2704
 proc_tid_io_accounting+0x20/0x30 fs/proc/base.c:2747
 proc_single_show+0xf0/0x180 fs/proc/base.c:737
 seq_read+0x4ca/0x1110 fs/seq_file.c:229
 do_loop_readv_writev fs/read_write.c:701 [inline]
 do_loop_readv_writev fs/read_write.c:688 [inline]
 do_iter_read+0x490/0x640 fs/read_write.c:925
 vfs_readv+0xf0/0x160 fs/read_write.c:987
 kernel_readv fs/splice.c:362 [inline]
 default_file_splice_read+0x478/0x890 fs/splice.c:417
 do_splice_to+0x127/0x180 fs/splice.c:881
 splice_direct_to_actor+0x256/0x890 fs/splice.c:953
 do_splice_direct+0x1da/0x2a0 fs/splice.c:1062
 do_sendfile+0x597/0xce0 fs/read_write.c:1447
 __do_sys_sendfile64 fs/read_write.c:1508 [inline]
 __se_sys_sendfile64 fs/read_write.c:1494 [inline]
 __x64_sys_sendfile64+0x1dd/0x220 fs/read_write.c:1494
 do_syscall_64+0xfd/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x440489
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 5b 14 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffe57ac8268 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000006f69 RCX: 0000000000440489
RDX: 0000000000000000 RSI: 0000000000000004 RDI: 0000000000000005
RBP: 00000000006cb018 R08: 68742f636f72702f R09: 68742f

Crashes (4):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/06/13 13:20 linux-4.19.y 768292d05361 3f4e812b .config console log report syz C ci2-linux-4-19
2019/09/30 11:19 linux-4.19.y d573e8a79f70 c7a4fb99 .config console log report ci2-linux-4-19
2019/06/13 11:38 linux-4.19.y 768292d05361 3f4e812b .config console log report ci2-linux-4-19
2019/06/10 15:03 linux-4.19.y bb7b450e61a1 0159583c .config console log report ci2-linux-4-19
* Struck through repros no longer work on HEAD.