syzbot


INFO: task hung in btrfs_control_ioctl

Status: closed as invalid on 2022/02/07 18:59
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 377d, last: 371d

Sample crash report:
INFO: task systemd-udevd:13336 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:25928 pid:13336 ppid:  2966 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 btrfs_control_ioctl+0x115/0x2d0 fs/btrfs/super.c:2411
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f24fd001017
RSP: 002b:00007fffe1ca9598 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f24fd001017
RDX: 00007fffe1ca95b0 RSI: 0000000090009427 RDI: 000000000000000f
RBP: 00007fffe1ca95b0 R08: 0000000000000000 R09: 00007f24fd04dd90
R10: 0000000000000001 R11: 0000000000000246 R12: 000000000000000f
R13: 0000000000000000 R14: 00005635db35a790 R15: 00005635db349980
 </TASK>
INFO: task systemd-udevd:13342 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:25536 pid:13342 ppid:  2966 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 btrfs_control_ioctl+0x115/0x2d0 fs/btrfs/super.c:2411
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f24fd001017
RSP: 002b:00007fffe1ca9b88 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f24fd001017
RDX: 00007fffe1ca9ba0 RSI: 0000000090009427 RDI: 000000000000000f
RBP: 00007fffe1ca9ba0 R08: 0000000000000000 R09: 00007f24fd04dd90
R10: 0000000000000001 R11: 0000000000000246 R12: 000000000000000f
R13: 0000000000000000 R14: 00005635db3497c0 R15: 00005635db349980
 </TASK>
INFO: task systemd-udevd:13398 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:25240 pid:13398 ppid:  2966 flags:0x00000000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 blkdev_get_by_dev.part.0+0x9b/0xb50 block/bdev.c:819
 blkdev_get_by_dev+0x6b/0x80 block/bdev.c:859
 blkdev_open+0x154/0x2e0 block/fops.c:501
 do_dentry_open+0x4c8/0x1250 fs/open.c:822
 do_open fs/namei.c:3426 [inline]
 path_openat+0x1cad/0x2750 fs/namei.c:3559
 do_filp_open+0x1aa/0x400 fs/namei.c:3586
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1212
 do_sys_open fs/open.c:1228 [inline]
 __do_sys_open fs/open.c:1236 [inline]
 __se_sys_open fs/open.c:1232 [inline]
 __x64_sys_open+0x119/0x1c0 fs/open.c:1232
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f24fd2cf840
RSP: 002b:00007fffe1caf2f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00005635db35c380 RCX: 00007f24fd2cf840
RDX: 00005635daa95fe3 RSI: 00000000000a0800 RDI: 00005635db349930
RBP: 00007fffe1caf470 R08: 00005635daa95670 R09: 0000000000000010
R10: 00007f24fd049d70 R11: 0000000000000246 R12: 00007fffe1caf3c0
R13: 00005635db349580 R14: 0000000000000003 R15: 000000000000000e
 </TASK>
INFO: task syz-executor.0:31327 blocked for more than 144 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:26080 pid:31327 ppid:  2541 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 blk_mq_freeze_queue_wait+0x112/0x160 block/blk-mq.c:178
 lo_release+0x160/0x1f0 drivers/block/loop.c:1768
 blkdev_put_whole block/bdev.c:694 [inline]
 blkdev_put+0x2fb/0x9e0 block/bdev.c:956
 btrfs_close_bdev fs/btrfs/volumes.c:1114 [inline]
 btrfs_close_bdev fs/btrfs/volumes.c:1104 [inline]
 btrfs_close_one_device fs/btrfs/volumes.c:1135 [inline]
 close_fs_devices+0x24f/0xa60 fs/btrfs/volumes.c:1178
 btrfs_close_devices+0x8e/0x4b0 fs/btrfs/volumes.c:1193
 open_ctree+0x48af/0x4954 fs/btrfs/disk-io.c:3700
 btrfs_fill_super fs/btrfs/super.c:1359 [inline]
 btrfs_mount_root.cold+0x15/0x162 fs/btrfs/super.c:1726
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 fc_mount fs/namespace.c:994 [inline]
 vfs_kern_mount.part.0+0xd3/0x170 fs/namespace.c:1024
 vfs_kern_mount+0x3c/0x60 fs/namespace.c:1011
 btrfs_mount+0x234/0xa60 fs/btrfs/super.c:1786
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 do_new_mount fs/namespace.c:2988 [inline]
 path_mount+0x1320/0x1fa0 fs/namespace.c:3318
 do_mount fs/namespace.c:3331 [inline]
 __do_sys_mount fs/namespace.c:3539 [inline]
 __se_sys_mount fs/namespace.c:3516 [inline]
 __x64_sys_mount+0x27f/0x300 fs/namespace.c:3516
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ff99b50101a
RSP: 002b:00007ff998a74fa8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 0000000020000200 RCX: 00007ff99b50101a
RDX: 0000000020000000 RSI: 0000000020000100 RDI: 00007ff998a75000
RBP: 00007ff998a75040 R08: 00007ff998a75040 R09: 0000000020000000
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000020000000
R13: 0000000020000100 R14: 00007ff998a75000 R15: 0000000020020600
 </TASK>
INFO: task syz-executor.1:31398 blocked for more than 144 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:26464 pid:31398 ppid: 11047 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 btrfs_mount_root+0x23b/0xc10 fs/btrfs/super.c:1681
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 fc_mount fs/namespace.c:994 [inline]
 vfs_kern_mount.part.0+0xd3/0x170 fs/namespace.c:1024
 vfs_kern_mount+0x3c/0x60 fs/namespace.c:1011
 btrfs_mount+0x234/0xa60 fs/btrfs/super.c:1786
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 do_new_mount fs/namespace.c:2988 [inline]
 path_mount+0x1320/0x1fa0 fs/namespace.c:3318
 do_mount fs/namespace.c:3331 [inline]
 __do_sys_mount fs/namespace.c:3539 [inline]
 __se_sys_mount fs/namespace.c:3516 [inline]
 __x64_sys_mount+0x27f/0x300 fs/namespace.c:3516
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3713f7601a
RSP: 002b:00007f37114e9fa8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 0000000020000200 RCX: 00007f3713f7601a
RDX: 0000000020000000 RSI: 0000000020000100 RDI: 00007f37114ea000
RBP: 00007f37114ea040 R08: 00007f37114ea040 R09: 0000000020000000
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000020000000
R13: 0000000020000100 R14: 00007f37114ea000 R15: 0000000020020600
 </TASK>
INFO: task syz-executor.5:31408 blocked for more than 145 seconds.
      Not tainted 5.16.0-rc1-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.5  state:D stack:27664 pid:31408 ppid: 15289 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6385
 __mutex_lock_common kernel/locking/mutex.c:680 [inline]
 __mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:740
 btrfs_mount_root+0x23b/0xc10 fs/btrfs/super.c:1681
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 fc_mount fs/namespace.c:994 [inline]
 vfs_kern_mount.part.0+0xd3/0x170 fs/namespace.c:1024
 vfs_kern_mount+0x3c/0x60 fs/namespace.c:1011
 btrfs_mount+0x234/0xa60 fs/btrfs/super.c:1786
 legacy_get_tree+0x105/0x220 fs/fs_context.c:610
 vfs_get_tree+0x89/0x2f0 fs/super.c:1500
 do_new_mount fs/namespace.c:2988 [inline]
 path_mount+0x1320/0x1fa0 fs/namespace.c:3318
 do_mount fs/namespace.c:3331 [inline]
 __do_sys_mount fs/namespace.c:3539 [inline]
 __se_sys_mount fs/namespace.c:3516 [inline]
 __x64_sys_mount+0x27f/0x300 fs/namespace.c:3516
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f4b2a8de01a
RSP: 002b:00007f4b27e51fa8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 0000000020000200 RCX: 00007f4b2a8de01a
RDX: 0000000020000000 RSI: 0000000020000100 RDI: 00007f4b27e52000
RBP: 00007f4b27e52040 R08: 00007f4b27e52040 R09: 0000000020000000
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000020000000
R13: 0000000020000100 R14: 00007f4b27e52000 R15: 0000000020020600
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8bb83b60 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458
1 lock held by systemd-udevd/2966:
1 lock held by in:imklog/6196:
 #0: ffff88801be8b270 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:990
2 locks held by rs:main Q:Reg/6197:
 #0: ffff88801be67770 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:990
 #1: ffff88814ae04460 (sb_writers#5){.+.+}-{0:0}, at: ksys_write+0x12d/0x250 fs/read_write.c:643
1 lock held by systemd-udevd/13336:
 #0: ffffffff8c265448 (uuid_mutex){+.+.}-{3:3}, at: btrfs_control_ioctl+0x115/0x2d0 fs/btrfs/super.c:2411
1 lock held by systemd-udevd/13342:
 #0: ffffffff8c265448 (uuid_mutex){+.+.}-{3:3}, at: btrfs_control_ioctl+0x115/0x2d0 fs/btrfs/super.c:2411
1 lock held by systemd-udevd/13398:
 #0: ffff88801abfc118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev.part.0+0x9b/0xb50 block/bdev.c:819
3 locks held by systemd-udevd/13512:
4 locks held by syz-executor.0/31327:
 #0: ffff88808b4c00e0 (&type->s_umount_key#85/1){+.+.}-{3:3}, at: alloc_super+0x1dd/0xac0 fs/super.c:229
 #1: ffffffff8c265448 (uuid_mutex){+.+.}-{3:3}, at: btrfs_close_devices+0x86/0x4b0 fs/btrfs/volumes.c:1192
 #2: ffff88801abfc118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0x97/0x9e0 block/bdev.c:914
 #3: ffff88814749ab60 (&lo->lo_mutex){+.+.}-{3:3}, at: lo_release+0x4d/0x1f0 drivers/block/loop.c:1748
1 lock held by syz-executor.1/31398:
 #0: ffffffff8c265448 (uuid_mutex){+.+.}-{3:3}, at: btrfs_mount_root+0x23b/0xc10 fs/btrfs/super.c:1681
1 lock held by syz-executor.5/31408:
 #0: ffffffff8c265448 (uuid_mutex){+.+.}-{3:3}, at: btrfs_mount_root+0x23b/0xc10 fs/btrfs/super.c:1681

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xc1d/0xf50 kernel/hung_task.c:295
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 1972 Comm: kworker/u4:7 Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: bat_events batadv_nc_worker
RIP: 0010:native_irq_disable arch/x86/include/asm/irqflags.h:40 [inline]
RIP: 0010:arch_local_irq_disable arch/x86/include/asm/irqflags.h:75 [inline]
RIP: 0010:arch_local_irq_save arch/x86/include/asm/irqflags.h:107 [inline]
RIP: 0010:lock_is_held_type+0x54/0x140 kernel/locking/lockdep.c:5676
Code: c0 0f 85 ca 00 00 00 65 4c 8b 24 25 40 70 02 00 41 8b 94 24 5c 0a 00 00 85 d2 0f 85 b1 00 00 00 48 89 fd 41 89 f6 9c 8f 04 24 <fa> 48 c7 c7 20 10 ac 89 31 db e8 1d 0e 00 00 41 8b 84 24 58 0a 00
RSP: 0018:ffffc9000b65fb50 EFLAGS: 00000246
RAX: 0000000000000000 RBX: 1ffff920016cbf76 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff8bb83aa0
RBP: ffffffff8bb83aa0 R08: 0000000000000000 R09: ffffffff8d912497
R10: fffffbfff1b22492 R11: 0000000000000000 R12: ffff88808a2a8000
R13: 00000000ffffffff R14: 00000000ffffffff R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005635dc5c8028 CR3: 0000000018f94000 CR4: 0000000000350ef0
Call Trace:
 <TASK>
 lock_is_held include/linux/lockdep.h:283 [inline]
 rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
 trace_lock_acquire include/trace/events/lock.h:13 [inline]
 lock_acquire+0x442/0x510 kernel/locking/lockdep.c:5608
 rcu_lock_acquire include/linux/rcupdate.h:268 [inline]
 rcu_read_lock include/linux/rcupdate.h:688 [inline]
 batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:412 [inline]
 batadv_nc_worker+0x12d/0xfa0 net/batman-adv/network-coding.c:723
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	c0 0f 85             	rorb   $0x85,(%rdi)
   3:	ca 00 00             	lret   $0x0
   6:	00 65 4c             	add    %ah,0x4c(%rbp)
   9:	8b 24 25 40 70 02 00 	mov    0x27040,%esp
  10:	41 8b 94 24 5c 0a 00 	mov    0xa5c(%r12),%edx
  17:	00
  18:	85 d2                	test   %edx,%edx
  1a:	0f 85 b1 00 00 00    	jne    0xd1
  20:	48 89 fd             	mov    %rdi,%rbp
  23:	41 89 f6             	mov    %esi,%r14d
  26:	9c                   	pushfq
  27:	8f 04 24             	popq   (%rsp)
* 2a:	fa                   	cli <-- trapping instruction
  2b:	48 c7 c7 20 10 ac 89 	mov    $0xffffffff89ac1020,%rdi
  32:	31 db                	xor    %ebx,%ebx
  34:	e8 1d 0e 00 00       	callq  0xe56
  39:	41                   	rex.B
  3a:	8b                   	.byte 0x8b
  3b:	84 24 58             	test   %ah,(%rax,%rbx,2)
  3e:	0a 00                	or     (%rax),%al

Crashes (5):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-root 2021/11/20 05:58 upstream 9539ba4308ad 3a9d0024 .config log report info INFO: task hung in btrfs_control_ioctl
ci-upstream-kasan-gce-selinux-root 2021/11/18 20:54 upstream 42eb8fdac2fc 31a30fc0 .config log report info INFO: task hung in btrfs_control_ioctl
ci-upstream-kasan-gce-root 2021/11/16 16:05 upstream 8ab774587903 600426bd .config log report info INFO: task hung in btrfs_control_ioctl
ci-upstream-kasan-gce-root 2021/11/14 12:23 upstream ccfff0a2bd2a 83f5c9b5 .config log report info INFO: task hung in btrfs_control_ioctl
ci-upstream-linux-next-kasan-gce-root 2021/11/19 06:32 linux-next 5191249f8803 31a30fc0 .config log report info INFO: task hung in btrfs_control_ioctl
* Struck through repros no longer work on HEAD.