syzbot


possible deadlock in pipe_lock

Status: auto-closed as invalid on 2020/02/21 12:40
Reported-by: syzbot+194a64fb76f9ddeb512c@syzkaller.appspotmail.com
First crash: 1959d, last: 1677d
Similar bugs (8)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in pipe_lock fs 50806 2352d 2400d 0/26 closed as invalid on 2018/02/14 14:20
upstream possible deadlock in pipe_lock (4) overlayfs 1 1119d 1115d 0/26 auto-closed as invalid on 2021/07/03 13:02
upstream possible deadlock in pipe_lock (2) overlayfs 3 1863d 1933d 0/26 auto-closed as invalid on 2019/10/18 15:02
linux-4.19 possible deadlock in pipe_lock (2) C error 155 448d 1614d 0/1 upstream: reported C repro on 2019/12/26 07:17
upstream possible deadlock in pipe_lock (5) overlayfs C done 5 1038d 1038d 20/26 fixed on 2021/11/10 00:50
linux-4.19 possible deadlock in pipe_lock C done 2 1856d 1859d 1/1 fixed on 2019/11/29 10:34
android-44 possible deadlock in pipe_lock C 82 1637d 1870d 0/2 public: reported C repro on 2019/04/14 08:51
upstream possible deadlock in pipe_lock (3) overlayfs C inconclusive done 4 1576d 1613d 15/26 fixed on 2020/08/18 22:40

Sample crash report:
======================================================
[ INFO: possible circular locking dependency detected ]
4.9.141+ #1 Not tainted
-------------------------------------------------------
syz-executor.5/12101 is trying to acquire lock:
 (&p->lock
but task is already holding lock:
 (&pipe->mutex/1){+.+.+.}, at: [<ffffffff81523c1e>] pipe_lock_nested fs/pipe.c:66 [inline]
 (&pipe->mutex/1){+.+.+.}, at: [<ffffffff81523c1e>] pipe_lock+0x5e/0x70 fs/pipe.c:74
which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2
 (&pipe->mutex/1){+.+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:521 [inline]
       mutex_lock_nested+0xc0/0x900 kernel/locking/mutex.c:621
       __pipe_lock fs/pipe.c:87 [inline]
       fifo_open+0x15c/0x9e0 fs/pipe.c:921
       do_dentry_open+0x3ef/0xc90 fs/open.c:766
       vfs_open+0x11c/0x210 fs/open.c:879
       do_last fs/namei.c:3410 [inline]
       path_openat+0x542/0x2790 fs/namei.c:3534
       do_filp_open+0x197/0x270 fs/namei.c:3568
       do_open_execat+0x10f/0x640 fs/exec.c:844
       do_execveat_common.isra.14+0x687/0x1ed0 fs/exec.c:1723
       do_execve fs/exec.c:1829 [inline]
       SYSC_execve fs/exec.c:1910 [inline]
       SyS_execve+0x42/0x50 fs/exec.c:1905
       do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
       entry_SYSCALL_64_after_swapgs+0x5d/0xdb

-> #1
 (&sig->cred_guard_mutex){+.+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:521 [inline]
       mutex_lock_killable_nested+0xcc/0x9f0 kernel/locking/mutex.c:641
       do_io_accounting+0x1fb/0x7e0 fs/proc/base.c:2690
       proc_tgid_io_accounting+0x22/0x30 fs/proc/base.c:2739
       proc_single_show+0xfd/0x170 fs/proc/base.c:785
       seq_read+0x4b6/0x12d0 fs/seq_file.c:240
       __vfs_read+0x115/0x560 fs/read_write.c:449
       vfs_read+0x124/0x390 fs/read_write.c:472
       SYSC_pread64 fs/read_write.c:626 [inline]
       SyS_pread64+0x145/0x170 fs/read_write.c:613
       do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
       entry_SYSCALL_64_after_swapgs+0x5d/0xdb

-> #0
 (&p->lock){+.+.+.}:
       lock_acquire+0x130/0x3e0 kernel/locking/lockdep.c:3756
       __mutex_lock_common kernel/locking/mutex.c:521 [inline]
       mutex_lock_nested+0xc0/0x900 kernel/locking/mutex.c:621
       seq_read+0xdd/0x12d0 fs/seq_file.c:178
       proc_reg_read+0xfd/0x180 fs/proc/inode.c:203
       do_loop_readv_writev.part.1+0xd5/0x280 fs/read_write.c:718
       do_loop_readv_writev fs/read_write.c:707 [inline]
       do_readv_writev+0x56e/0x7b0 fs/read_write.c:873
       vfs_readv+0x84/0xc0 fs/read_write.c:897
       kernel_readv fs/splice.c:363 [inline]
       default_file_splice_read+0x451/0x7f0 fs/splice.c:435
       do_splice_to+0x10c/0x170 fs/splice.c:899
       do_splice fs/splice.c:1192 [inline]
       SYSC_splice fs/splice.c:1416 [inline]
       SyS_splice+0x10d2/0x14d0 fs/splice.c:1399
       do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
       entry_SYSCALL_64_after_swapgs+0x5d/0xdb

other info that might help us debug this:

Chain exists of:
  
&p->lock --> &sig->cred_guard_mutex --> &pipe->mutex/1


       CPU0                    CPU1
       ----                    ----
  lock(
&pipe->mutex/1);
&sig->cred_guard_mutex);
&pipe->mutex/1);
&p->lock);
 *** DEADLOCK ***

1 lock held by syz-executor.5/12101:
 #0: 
 (&pipe->mutex/1){+.+.+.}, at: [<ffffffff81523c1e>] pipe_lock_nested fs/pipe.c:66 [inline]
 (&pipe->mutex/1){+.+.+.}, at: [<ffffffff81523c1e>] pipe_lock+0x5e/0x70 fs/pipe.c:74
stack backtrace:
CPU: 1 PID: 12101 Comm: syz-executor.5 Not tainted 4.9.141+ #1
 ffff8801c9c0f278
 ffffffff81b42e79 ffffffff83ca2fd0 ffffffff83ca9f30 ffffffff83ca4920
 ffff88019fe208d0 ffff88019fe20000 ffff8801c9c0f2c0 ffffffff813fee40
 0000000000000001 000000009fe208b0 0000000000000001Call Trace:
 [<ffffffff81b42e79>] __dump_stack lib/dump_stack.c:15 [inline]
 [<ffffffff81b42e79>] dump_stack+0xc1/0x128 lib/dump_stack.c:51
 [<ffffffff813fee40>] print_circular_bug.cold.36+0x2f7/0x432 kernel/locking/lockdep.c:1202
 [<ffffffff8120a539>] check_prev_add kernel/locking/lockdep.c:1828 [inline]
 [<ffffffff8120a539>] check_prevs_add kernel/locking/lockdep.c:1938 [inline]
 [<ffffffff8120a539>] validate_chain kernel/locking/lockdep.c:2265 [inline]
 [<ffffffff8120a539>] __lock_acquire+0x3189/0x4a10 kernel/locking/lockdep.c:3345
 [<ffffffff8120c8d0>] lock_acquire+0x130/0x3e0 kernel/locking/lockdep.c:3756
 [<ffffffff8280b250>] __mutex_lock_common kernel/locking/mutex.c:521 [inline]
 [<ffffffff8280b250>] mutex_lock_nested+0xc0/0x900 kernel/locking/mutex.c:621
 [<ffffffff8158080d>] seq_read+0xdd/0x12d0 fs/seq_file.c:178
 [<ffffffff8165c00d>] proc_reg_read+0xfd/0x180 fs/proc/inode.c:203
 [<ffffffff81509df5>] do_loop_readv_writev.part.1+0xd5/0x280 fs/read_write.c:718
 [<ffffffff8150b49e>] do_loop_readv_writev fs/read_write.c:707 [inline]
 [<ffffffff8150b49e>] do_readv_writev+0x56e/0x7b0 fs/read_write.c:873
 [<ffffffff8150b764>] vfs_readv+0x84/0xc0 fs/read_write.c:897
 [<ffffffff815ac2a1>] kernel_readv fs/splice.c:363 [inline]
 [<ffffffff815ac2a1>] default_file_splice_read+0x451/0x7f0 fs/splice.c:435
 [<ffffffff815ab39c>] do_splice_to+0x10c/0x170 fs/splice.c:899
 [<ffffffff815b08f2>] do_splice fs/splice.c:1192 [inline]
 [<ffffffff815b08f2>] SYSC_splice fs/splice.c:1416 [inline]
 [<ffffffff815b08f2>] SyS_splice+0x10d2/0x14d0 fs/splice.c:1399
 [<ffffffff810056ef>] do_syscall_64+0x19f/0x550 arch/x86/entry/common.c:285
 [<ffffffff82817893>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
audit_printk_skb: 990 callbacks suppressed
audit: type=1400 audit(1567059962.226:173721): avc:  denied  { net_admin } for  pid=12102 comm="syz-executor.4" capability=12  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.266:173722): avc:  denied  { dac_override } for  pid=12110 comm="syz-executor.1" capability=1  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.266:173723): avc:  denied  { sys_admin } for  pid=12110 comm="syz-executor.1" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.266:173724): avc:  denied  { sys_admin } for  pid=12110 comm="syz-executor.1" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.286:173725): avc:  denied  { sys_admin } for  pid=12110 comm="syz-executor.1" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.286:173726): avc:  denied  { dac_override } for  pid=12114 comm="syz-executor.1" capability=1  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.296:173727): avc:  denied  { sys_admin } for  pid=2094 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.296:173728): avc:  denied  { sys_admin } for  pid=2094 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.306:173729): avc:  denied  { sys_admin } for  pid=2094 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059962.306:173730): avc:  denied  { net_admin } for  pid=2094 comm="syz-executor.5" capability=12  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit_printk_skb: 966 callbacks suppressed
audit: type=1400 audit(1567059968.266:174053): avc:  denied  { sys_admin } for  pid=2101 comm="syz-executor.1" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.286:174054): avc:  denied  { setgid } for  pid=12250 comm="syz-executor.5" capability=6  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.286:174055): avc:  denied  { sys_admin } for  pid=12250 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.286:174056): avc:  denied  { sys_admin } for  pid=12250 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.296:174057): avc:  denied  { setgid } for  pid=12250 comm="syz-executor.5" capability=6  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.296:174058): avc:  denied  { sys_admin } for  pid=12250 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.296:174059): avc:  denied  { sys_admin } for  pid=2094 comm="syz-executor.5" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.306:174060): avc:  denied  { sys_admin } for  pid=9425 comm="syz-executor.4" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.316:174061): avc:  denied  { sys_admin } for  pid=9425 comm="syz-executor.4" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
audit: type=1400 audit(1567059968.316:174062): avc:  denied  { sys_admin } for  pid=9425 comm="syz-executor.4" capability=21  scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023 tclass=cap_userns permissive=1
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.1'.
netlink: 8 bytes leftover after parsing attributes in process `syz-executor.1'.
sock: sock_set_timeout: `syz-executor.5' (pid 12396) tries to set negative timeout
sock: sock_set_timeout: `syz-executor.5' (pid 12399) tries to set negative timeout

Crashes (5):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/08/29 06:26 https://android.googlesource.com/kernel/common android-4.9 8fe428403e30 fd37b39e .config console log report ci-android-49-kasan-gce
2019/04/07 18:02 https://android.googlesource.com/kernel/common android-4.9 8fe428403e30 c34fde03 .config console log report ci-android-49-kasan-gce
2019/01/15 18:31 https://android.googlesource.com/kernel/common android-4.9 8fe428403e30 79cb1a7c .config console log report ci-android-49-kasan-gce
2019/10/24 12:39 https://android.googlesource.com/kernel/common android-4.9 8fe428403e30 d01bb02a .config console log report ci-android-49-kasan-gce-386
2019/01/16 07:22 https://android.googlesource.com/kernel/common android-4.9 8fe428403e30 b47fa78d .config console log report ci-android-49-kasan-gce-386
* Struck through repros no longer work on HEAD.