INFO: task hung in btrfs_do_write_iter

Status: auto-obsoleted due to no activity on 2024/04/09 08:20
Subsystems: btrfs
[Documentation on labels]
First crash: 947d, last: 947d

Sample crash report:
INFO: task syz-executor.1:30162 blocked for more than 143 seconds.
      Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:23792 pid:30162 tgid:30160 ppid:14471  flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5399 [inline]
 __schedule+0x177f/0x4960 kernel/sched/core.c:6726
 __schedule_loop kernel/sched/core.c:6801 [inline]
 schedule+0x149/0x260 kernel/sched/core.c:6816
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6873
 rwsem_down_read_slowpath kernel/locking/rwsem.c:1086 [inline]
 __down_read_common kernel/locking/rwsem.c:1250 [inline]
 __down_read kernel/locking/rwsem.c:1263 [inline]
 down_read+0x703/0xa40 kernel/locking/rwsem.c:1528
 inode_lock_shared include/linux/fs.h:812 [inline]
 btrfs_inode_lock+0x60/0xd0 fs/btrfs/inode.c:370
 btrfs_direct_write fs/btrfs/file.c:1484 [inline]
 btrfs_do_write_iter+0x4f9/0x1190 fs/btrfs/file.c:1684
 call_write_iter include/linux/fs.h:2085 [inline]
 iter_file_splice_write+0xa64/0x1320 fs/splice.c:743
 do_splice_from fs/splice.c:941 [inline]
 direct_splice_actor+0xf6/0x1e0 fs/splice.c:1164
 splice_direct_to_actor+0x54e/0xc80 fs/splice.c:1108
 do_splice_direct_actor fs/splice.c:1207 [inline]
 do_splice_direct+0x28c/0x3e0 fs/splice.c:1233
 do_sendfile+0x56d/0xdb0 fs/read_write.c:1295
 __do_sys_sendfile64 fs/read_write.c:1362 [inline]
 __se_sys_sendfile64+0x17c/0x1e0 fs/read_write.c:1348
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x230 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x63/0x6b
RIP: 0033:0x7f4f1027cd29
RSP: 002b:00007f4f10f7b0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007f4f103abf80 RCX: 00007f4f1027cd29
RDX: 0000000000000000 RSI: 0000000000000006 RDI: 0000000000000006
RBP: 00007f4f102c947a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000008800000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007f4f103abf80 R15: 00007ffcbb212d38
 </TASK>
INFO: task syz-executor.1:30196 blocked for more than 144 seconds.
      Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:23216 pid:30196 tgid:30160 ppid:14471  flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5399 [inline]
 __schedule+0x177f/0x4960 kernel/sched/core.c:6726
 __schedule_loop kernel/sched/core.c:6801 [inline]
 schedule+0x149/0x260 kernel/sched/core.c:6816
 io_schedule+0x8c/0x100 kernel/sched/core.c:9022
 folio_wait_bit_common+0x881/0x12b0 mm/filemap.c:1273
 folio_lock include/linux/pagemap.h:1031 [inline]
 extent_write_cache_pages fs/btrfs/extent_io.c:2082 [inline]
 extent_writepages+0xb47/0x26a0 fs/btrfs/extent_io.c:2230
 do_writepages+0x3a6/0x670 mm/page-writeback.c:2553
 filemap_fdatawrite_wbc+0x125/0x180 mm/filemap.c:387
 __filemap_fdatawrite_range mm/filemap.c:420 [inline]
 filemap_fdatawrite_range+0x16e/0x1e0 mm/filemap.c:438
 btrfs_start_ordered_extent+0x26e/0x5f0 fs/btrfs/ordered-data.c:797
 btrfs_lock_and_flush_ordered_range+0x115/0x220 fs/btrfs/ordered-data.c:1105
 btrfs_read_folio+0x10b/0x180 fs/btrfs/extent_io.c:1132
 prepare_uptodate_page+0xc8/0x5c0 fs/btrfs/file.c:855
 prepare_pages+0x215/0x3b0 fs/btrfs/file.c:943
 btrfs_buffered_write+0x7f1/0x1380 fs/btrfs/file.c:1316
 btrfs_do_write_iter+0x2bb/0x1190 fs/btrfs/file.c:1687
 call_write_iter include/linux/fs.h:2085 [inline]
 iter_file_splice_write+0xa64/0x1320 fs/splice.c:743
 do_splice_from fs/splice.c:941 [inline]
 direct_splice_actor+0xf6/0x1e0 fs/splice.c:1164
 splice_direct_to_actor+0x54e/0xc80 fs/splice.c:1108
 do_splice_direct_actor fs/splice.c:1207 [inline]
 do_splice_direct+0x28c/0x3e0 fs/splice.c:1233
 do_sendfile+0x56d/0xdb0 fs/read_write.c:1295
 __do_sys_sendfile64 fs/read_write.c:1362 [inline]
 __se_sys_sendfile64+0x17c/0x1e0 fs/read_write.c:1348
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x230 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x63/0x6b
RIP: 0033:0x7f4f1027cd29
RSP: 002b:00007f4f10f5a0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007f4f103ac050 RCX: 00007f4f1027cd29
RDX: 0000000000000000 RSI: 0000000000000005 RDI: 0000000000000004
RBP: 00007f4f102c947a R08: 0000000000000000 R09: 0000000000000000
R10: 0001000000201005 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f4f103ac050 R15: 00007ffcbb212d38
 </TASK>
INFO: task syz-executor.1:30197 blocked for more than 145 seconds.
      Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:26672 pid:30197 tgid:30160 ppid:14471  flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5399 [inline]
 __schedule+0x177f/0x4960 kernel/sched/core.c:6726
 __schedule_loop kernel/sched/core.c:6801 [inline]
 schedule+0x149/0x260 kernel/sched/core.c:6816
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6873
 rwsem_down_write_slowpath+0xeea/0x13b0 kernel/locking/rwsem.c:1178
 __down_write_common+0x1aa/0x200 kernel/locking/rwsem.c:1306
 inode_lock_nested include/linux/fs.h:837 [inline]
 lock_two_inodes fs/inode.c:1129 [inline]
 lock_two_nondirectories+0x1ae/0x270 fs/inode.c:1149
 btrfs_remap_file_range+0x165/0xeb0 fs/btrfs/reflink.c:896
 do_clone_file_range+0x19f/0x6d0 fs/remap_range.c:394
 vfs_clone_file_range+0x39e/0x730 fs/remap_range.c:420
 ioctl_file_clone fs/ioctl.c:240 [inline]
 ioctl_file_clone_range fs/ioctl.c:259 [inline]
 do_vfs_ioctl+0xfa1/0x2b40 fs/ioctl.c:824
 __do_sys_ioctl fs/ioctl.c:869 [inline]
 __se_sys_ioctl+0x81/0x170 fs/ioctl.c:857
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x230 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x63/0x6b
RIP: 0033:0x7f4f1027cd29
RSP: 002b:00007f4f10f390c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f4f103ac120 RCX: 00007f4f1027cd29
RDX: 0000000020000000 RSI: 000000004020940d RDI: 0000000000000008
RBP: 00007f4f102c947a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f4f103ac120 R15: 00007ffcbb212d38
 </TASK>
INFO: task syz-executor.1:30198 blocked for more than 145 seconds.
      Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:25968 pid:30198 tgid:30160 ppid:14471  flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5399 [inline]
 __schedule+0x177f/0x4960 kernel/sched/core.c:6726
 __schedule_loop kernel/sched/core.c:6801 [inline]
 schedule+0x149/0x260 kernel/sched/core.c:6816
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6873
 rwsem_down_write_slowpath+0xeea/0x13b0 kernel/locking/rwsem.c:1178
 __down_write_common+0x1aa/0x200 kernel/locking/rwsem.c:1306
 inode_lock include/linux/fs.h:802 [inline]
 process_measurement+0x450/0x21c0 security/integrity/ima/ima_main.c:248
 ima_file_check+0xf1/0x170 security/integrity/ima/ima_main.c:557
 do_open fs/namei.c:3624 [inline]
 path_openat+0x287a/0x31e0 fs/namei.c:3779
 do_filp_open+0x234/0x490 fs/namei.c:3806
 do_sys_openat2+0x13e/0x1d0 fs/open.c:1404
 do_sys_open fs/open.c:1419 [inline]
 __do_sys_open fs/open.c:1427 [inline]
 __se_sys_open fs/open.c:1423 [inline]
 __x64_sys_open+0x225/0x270 fs/open.c:1423
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x230 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x63/0x6b
RIP: 0033:0x7f4f1027cd29
RSP: 002b:00007f4f10f180c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007f4f103ac1f0 RCX: 00007f4f1027cd29
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020007f80
RBP: 00007f4f102c947a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f4f103ac1f0 R15: 00007ffcbb212d38
 </TASK>
INFO: lockdep is turned off.
NMI backtrace for cpu 1
CPU: 1 PID: 29 Comm: khungtaskd Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/17/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e7/0x2d0 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x498/0x4d0 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x198/0x310 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
 watchdog+0xfaf/0xff0 kernel/hung_task.c:379
 kthread+0x2d3/0x370 kernel/kthread.c:388
 ret_from_fork+0x48/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:242
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 8 Comm: kworker/0:0 Not tainted 6.7.0-syzkaller-01367-g35f11a3710cd #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/17/2023
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:stack_trace_consume_entry+0x12a/0x280 kernel/stacktrace.c:95
Code: 49 89 f5 e8 28 33 6f 00 4d 89 f9 4c 89 ee 4c 89 f2 48 89 33 41 8b 19 41 0f b6 04 14 84 c0 0f 85 30 01 00 00 3b 5d 00 0f 92 c0 <48> 83 c4 18 5b 41 5c 41 5d 41 5e 41 5f 5d c3 44 89 c9 80 e1 07 80
RSP: 0018:ffffc900000d75b0 EFLAGS: 00000283
RAX: 0000000000000001 RBX: 0000000000000008 RCX: ffff8880152cd940
RDX: dffffc0000000000 RSI: ffffffff86c58ed1 RDI: ffffc900000d76ec
RBP: ffffc900000d76e8 R08: 0000000000000007 R09: ffffc900000d76f0
R10: 0000000000000003 R11: ffff8880152cd940 R12: 1ffff9200001aedd
R13: 1ffff9200001aedd R14: 0000000000000008 R15: 1ffff9200001aede
FS:  0000000000000000(0000) GS:ffff8880b9800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055aac1f181f8 CR3: 000000000d732000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 arch_stack_walk+0x13a/0x1a0 arch/x86/kernel/stacktrace.c:27
 stack_trace_save+0x117/0x1c0 kernel/stacktrace.c:122
 kasan_save_stack mm/kasan/common.c:47 [inline]
 kasan_save_track+0x3f/0x70 mm/kasan/common.c:68
 kasan_save_free_info+0x4e/0x60 mm/kasan/generic.c:634
 poison_slab_object+0xa6/0xe0 mm/kasan/common.c:241
 __kasan_slab_free+0x34/0x60 mm/kasan/common.c:257
 kasan_slab_free include/linux/kasan.h:184 [inline]
 slab_free_hook mm/slub.c:2121 [inline]
 slab_free mm/slub.c:4299 [inline]
 kfree+0x14a/0x380 mm/slub.c:4409
 skb_kfree_head net/core/skbuff.c:950 [inline]
 skb_free_head net/core/skbuff.c:962 [inline]
 skb_release_data+0x660/0x850 net/core/skbuff.c:992
 skb_release_all net/core/skbuff.c:1058 [inline]
 __kfree_skb net/core/skbuff.c:1072 [inline]
 consume_skb+0xb3/0x150 net/core/skbuff.c:1288
 nsim_dev_trap_report drivers/net/netdevsim/dev.c:821 [inline]
 nsim_dev_trap_report_work+0x761/0xa90 drivers/net/netdevsim/dev.c:850
 process_one_work kernel/workqueue.c:2633 [inline]
 process_scheduled_works+0x90f/0x1420 kernel/workqueue.c:2706
 worker_thread+0xa5f/0x1000 kernel/workqueue.c:2787
 kthread+0x2d3/0x370 kernel/kthread.c:388
 ret_from_fork+0x48/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:242
 </TASK>

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/01/10 08:11 upstream 35f11a3710cd b438bd66 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btrfs_do_write_iter
* Struck through repros no longer work on HEAD.