syzbot


possible deadlock in start_transaction

Status: auto-closed as invalid on 2022/05/14 23:34
Reported-by: syzbot+ae8dac1771dece65ee4d@syzkaller.appspotmail.com
First crash: 1054d, last: 1054d
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 possible deadlock in start_transaction (2) btrfs C 424 639d 738d 0/1 upstream: reported C repro on 2022/11/27 06:33
upstream possible deadlock in start_transaction btrfs 2 1526d 1522d 0/28 auto-closed as invalid on 2021/01/28 08:05
linux-4.14 possible deadlock in start_transaction btrfs syz 6 665d 707d 0/1 upstream: reported syz repro on 2022/12/27 19:04

Sample crash report:
BTRFS: device fsid f90cac8b-044b-4fa8-8bee-4b8d3da88dc2 devid 1 transid 7 /dev/loop1
BTRFS info (device loop1): disk space caching is enabled
BTRFS info (device loop1): has skinny extents
======================================================
WARNING: possible circular locking dependency detected
4.19.211-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.1/9696 is trying to acquire lock:
00000000262f3290 (sb_internal#2){.+.+}, at: sb_start_intwrite include/linux/fs.h:1626 [inline]
00000000262f3290 (sb_internal#2){.+.+}, at: start_transaction+0xa37/0xf90 fs/btrfs/transaction.c:528

but task is already holding lock:
0000000043753794 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #7 (&mm->mmap_sem){++++}:
       _copy_from_iter_full+0x256/0x7c0 lib/iov_iter.c:723
       copy_from_iter_full include/linux/uio.h:124 [inline]
       skb_do_copy_data_nocache include/net/sock.h:1971 [inline]
       skb_add_data_nocache include/net/sock.h:1982 [inline]
       tcp_sendmsg_locked+0x194d/0x2f60 net/ipv4/tcp.c:1339
       tcp_sendmsg+0x2b/0x40 net/ipv4/tcp.c:1462
       inet_sendmsg+0x132/0x5a0 net/ipv4/af_inet.c:798
       sock_sendmsg_nosec net/socket.c:651 [inline]
       sock_sendmsg+0xc3/0x120 net/socket.c:661
       sock_write_iter+0x287/0x3c0 net/socket.c:966
       call_write_iter include/linux/fs.h:1821 [inline]
       new_sync_write fs/read_write.c:474 [inline]
       __vfs_write+0x51b/0x770 fs/read_write.c:487
       vfs_write+0x1f3/0x540 fs/read_write.c:549
       ksys_write+0x12b/0x2a0 fs/read_write.c:599
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #6 (sk_lock-AF_INET){+.+.}:
       lock_sock include/net/sock.h:1512 [inline]
       inet_shutdown+0x7d/0x3a0 net/ipv4/af_inet.c:852
       nbd_mark_nsock_dead+0xae/0x5b0 drivers/block/nbd.c:255
       sock_shutdown+0x163/0x240 drivers/block/nbd.c:340
       nbd_clear_sock drivers/block/nbd.c:1146 [inline]
       nbd_config_put+0x17a/0x870 drivers/block/nbd.c:1162
       nbd_release+0xf4/0x170 drivers/block/nbd.c:1461
       __blkdev_put+0x636/0x870 fs/block_dev.c:1819
       blkdev_close+0x86/0xb0 fs/block_dev.c:1888
       __fput+0x2ce/0x890 fs/file_table.c:278
       task_work_run+0x148/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:193 [inline]
       exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
       prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
       do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #5 (&nsock->tx_lock){+.+.}:
       sock_shutdown+0x156/0x240 drivers/block/nbd.c:339
       nbd_clear_sock drivers/block/nbd.c:1146 [inline]
       nbd_config_put+0x17a/0x870 drivers/block/nbd.c:1162
       nbd_release+0xf4/0x170 drivers/block/nbd.c:1461
       __blkdev_put+0x636/0x870 fs/block_dev.c:1819
       blkdev_close+0x86/0xb0 fs/block_dev.c:1888
       __fput+0x2ce/0x890 fs/file_table.c:278
       task_work_run+0x148/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:193 [inline]
       exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
       prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
       do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #4 (&nbd->config_lock){+.+.}:
       nbd_open+0x2e2/0x6f0 drivers/block/nbd.c:1428
       __blkdev_get+0x372/0x1480 fs/block_dev.c:1494
       blkdev_get+0xb0/0x940 fs/block_dev.c:1627
       blkdev_open+0x202/0x290 fs/block_dev.c:1788
       do_dentry_open+0x4aa/0x1160 fs/open.c:796
       do_last fs/namei.c:3421 [inline]
       path_openat+0x793/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_sys_open+0x3b3/0x520 fs/open.c:1085
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #3 (nbd_index_mutex){+.+.}:
       nbd_open+0x73/0x6f0 drivers/block/nbd.c:1415
       __blkdev_get+0x372/0x1480 fs/block_dev.c:1494
       blkdev_get+0xb0/0x940 fs/block_dev.c:1627
       blkdev_open+0x202/0x290 fs/block_dev.c:1788
       do_dentry_open+0x4aa/0x1160 fs/open.c:796
       do_last fs/namei.c:3421 [inline]
       path_openat+0x793/0x2df0 fs/namei.c:3537
       do_filp_open+0x18c/0x3f0 fs/namei.c:3567
       do_sys_open+0x3b3/0x520 fs/open.c:1085
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #2 (&bdev->bd_mutex){+.+.}:
       blkdev_put+0x30/0x520 fs/block_dev.c:1839
       btrfs_close_bdev fs/btrfs/volumes.c:1033 [inline]
       btrfs_close_one_device fs/btrfs/volumes.c:1057 [inline]
       close_fs_devices.part.0+0x24d/0x8e0 fs/btrfs/volumes.c:1085
       close_fs_devices fs/btrfs/volumes.c:1117 [inline]
       btrfs_close_devices+0x95/0x1f0 fs/btrfs/volumes.c:1103
       open_ctree+0x26b/0x61e0 fs/btrfs/disk-io.c:3326
       btrfs_fill_super fs/btrfs/super.c:1209 [inline]
       btrfs_mount_root+0x12e5/0x1830 fs/btrfs/super.c:1613
       mount_fs+0xa3/0x310 fs/super.c:1261
       vfs_kern_mount.part.0+0x68/0x470 fs/namespace.c:961
       vfs_kern_mount+0x3c/0x60 fs/namespace.c:951
       btrfs_mount+0x23a/0xaa0 fs/btrfs/super.c:1681
       mount_fs+0xa3/0x310 fs/super.c:1261
       vfs_kern_mount.part.0+0x68/0x470 fs/namespace.c:961
       vfs_kern_mount fs/namespace.c:951 [inline]
       do_new_mount fs/namespace.c:2492 [inline]
       do_mount+0x115c/0x2f50 fs/namespace.c:2822
       ksys_mount+0xcf/0x130 fs/namespace.c:3038
       __do_sys_mount fs/namespace.c:3052 [inline]
       __se_sys_mount fs/namespace.c:3049 [inline]
       __x64_sys_mount+0xba/0x150 fs/namespace.c:3049
       do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #1 (&fs_devs->device_list_mutex){+.+.}:
       btrfs_finish_chunk_alloc+0x27b/0xf90 fs/btrfs/volumes.c:4938
       btrfs_create_pending_block_groups+0x242/0x590 fs/btrfs/extent-tree.c:10134
       __btrfs_end_transaction+0x21a/0xb00 fs/btrfs/transaction.c:855
       flush_space+0xa41/0xee0 fs/btrfs/extent-tree.c:4861
       btrfs_async_reclaim_metadata_space+0x466/0x1050 fs/btrfs/extent-tree.c:4977
       process_one_work+0x864/0x1570 kernel/workqueue.c:2153
       worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
       kthread+0x33f/0x460 kernel/kthread.c:259
       ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

-> #0 (sb_internal#2){.+.+}:
       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+0x6e/0x2a0 fs/super.c:1366
       sb_start_intwrite include/linux/fs.h:1626 [inline]
       start_transaction+0xa37/0xf90 fs/btrfs/transaction.c:528
       btrfs_dirty_inode+0xe3/0x210 fs/btrfs/inode.c:6165
       btrfs_update_time+0x33b/0x3d0 fs/btrfs/inode.c:6207
       update_time fs/inode.c:1675 [inline]
       touch_atime+0x23c/0x2a0 fs/inode.c:1746
       file_accessed include/linux/fs.h:2123 [inline]
       btrfs_file_mmap+0x11b/0x160 fs/btrfs/file.c:2274
       call_mmap include/linux/fs.h:1826 [inline]
       mmap_region+0xc94/0x16b0 mm/mmap.c:1757
       do_mmap+0x8e8/0x1080 mm/mmap.c:1530
       do_mmap_pgoff include/linux/mm.h:2329 [inline]
       vm_mmap_pgoff+0x197/0x200 mm/util.c:357
       ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
       do_syscall_64+0xf9/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:
  sb_internal#2 --> sk_lock-AF_INET --> &mm->mmap_sem

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&mm->mmap_sem);
                               lock(sk_lock-AF_INET);
                               lock(&mm->mmap_sem);
  lock(sb_internal#2);

 *** DEADLOCK ***

2 locks held by syz-executor.1/9696:
 #0: 0000000043753794 (&mm->mmap_sem){++++}, at: vm_mmap_pgoff+0x152/0x200 mm/util.c:355
 #1: 000000007c61480a (sb_writers#29){.+.+}, at: sb_start_write_trylock include/linux/fs.h:1584 [inline]
 #1: 000000007c61480a (sb_writers#29){.+.+}, at: touch_atime+0x152/0x2a0 fs/inode.c:1731

stack backtrace:
CPU: 1 PID: 9696 Comm: syz-executor.1 Not tainted 4.19.211-syzkaller #0
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+0x1fc/0x2ef lib/dump_stack.c:118
 print_circular_bug.constprop.0.cold+0x2d7/0x41e kernel/locking/lockdep.c:1222
 check_prev_add kernel/locking/lockdep.c:1866 [inline]
 check_prevs_add kernel/locking/lockdep.c:1979 [inline]
 validate_chain kernel/locking/lockdep.c:2420 [inline]
 __lock_acquire+0x30c9/0x3ff0 kernel/locking/lockdep.c:3416
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 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+0x6e/0x2a0 fs/super.c:1366
 sb_start_intwrite include/linux/fs.h:1626 [inline]
 start_transaction+0xa37/0xf90 fs/btrfs/transaction.c:528
 btrfs_dirty_inode+0xe3/0x210 fs/btrfs/inode.c:6165
 btrfs_update_time+0x33b/0x3d0 fs/btrfs/inode.c:6207
 update_time fs/inode.c:1675 [inline]
 touch_atime+0x23c/0x2a0 fs/inode.c:1746
 file_accessed include/linux/fs.h:2123 [inline]
 btrfs_file_mmap+0x11b/0x160 fs/btrfs/file.c:2274
 call_mmap include/linux/fs.h:1826 [inline]
 mmap_region+0xc94/0x16b0 mm/mmap.c:1757
 do_mmap+0x8e8/0x1080 mm/mmap.c:1530
 do_mmap_pgoff include/linux/mm.h:2329 [inline]
 vm_mmap_pgoff+0x197/0x200 mm/util.c:357
 ksys_mmap_pgoff+0x298/0x5a0 mm/mmap.c:1580
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7ff8ab957fe9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 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 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007ff8aa2cd168 EFLAGS: 00000246 ORIG_RAX: 0000000000000009
RAX: ffffffffffffffda RBX: 00007ff8aba6af60 RCX: 00007ff8ab957fe9
RDX: 0000000000000002 RSI: 0000000000b36000 RDI: 0000000020000000
RBP: 00007ff8ab9b208d R08: 0000000000000004 R09: 0000000000000000
R10: 0000000000028011 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffd15680dbf R14: 00007ff8aa2cd300 R15: 0000000000022000
BTRFS info (device loop1): disk space caching is enabled
BTRFS info (device loop1): has skinny extents
BTRFS info (device loop1): disk space caching is enabled
BTRFS info (device loop1): has skinny extents
audit: type=1804 audit(1642203229.810:519): pid=9872 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir197513914/syzkaller.WLP7Wr/2562/file0" dev="sda1" ino=13877 res=1
audit: type=1804 audit(1642203230.650:520): pid=9898 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir197513914/syzkaller.WLP7Wr/2563/file0" dev="sda1" ino=14547 res=1
audit: type=1804 audit(1642203232.791:521): pid=9920 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=invalid_pcr cause=open_writers comm="syz-executor.0" name="/root/syzkaller-testdir197513914/syzkaller.WLP7Wr/2564/file0" dev="sda1" ino=14257 res=1

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/01/14 23:33 linux-4.19.y 3f8a27f9e27b 53e00b45 .config console log report info ci2-linux-4-19 possible deadlock in start_transaction
* Struck through repros no longer work on HEAD.