syzbot


INFO: task hung in bchfs_truncate

Status: auto-obsoleted due to no activity on 2024/12/27 20:40
Subsystems: mm bcachefs
[Documentation on labels]
First crash: 227d, last: 114d

Sample crash report:
INFO: task syz.5.213:6614 blocked for more than 143 seconds.
      Not tainted 6.11.0-syzkaller-11993-g3efc57369a0c #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz.5.213       state:D stack:25568 pid:6614  tgid:6594  ppid:6085   flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5315 [inline]
 __schedule+0x1895/0x4b30 kernel/sched/core.c:6675
 __schedule_loop kernel/sched/core.c:6752 [inline]
 schedule+0x14b/0x320 kernel/sched/core.c:6767
 io_schedule+0x8d/0x110 kernel/sched/core.c:7552
 folio_wait_bit_common+0x882/0x12b0 mm/filemap.c:1309
 folio_wait_writeback+0xe7/0x1e0 mm/page-writeback.c:3189
 __filemap_fdatawait_range+0x17c/0x2b0 mm/filemap.c:533
 filemap_write_and_wait_range+0x1e3/0x280 mm/filemap.c:694
 bch2_extend fs/bcachefs/fs-io.c:378 [inline]
 bchfs_truncate+0x64b/0xc70 fs/bcachefs/fs-io.c:431
 notify_change+0xbcc/0xe90 fs/attr.c:503
 do_truncate+0x220/0x310 fs/open.c:65
 vfs_truncate+0x2e1/0x3b0 fs/open.c:111
 do_sys_truncate+0xdb/0x190 fs/open.c:134
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f71b897dff9
RSP: 002b:00007f71b97c3038 EFLAGS: 00000246 ORIG_RAX: 000000000000004c
RAX: ffffffffffffffda RBX: 00007f71b8b36130 RCX: 00007f71b897dff9
RDX: 0000000000000000 RSI: 000000000000f000 RDI: 0000000020000080
RBP: 00007f71b89f0296 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 00007f71b8b36130 R15: 00007ffd83ed6858
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/30:
 #0: ffffffff8e937da0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
 #0: ffffffff8e937da0 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
 #0: ffffffff8e937da0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x2a0 kernel/locking/lockdep.c:6701
5 locks held by kworker/u8:4/62:
 #0: ffff88801bae5948 ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88801bae5948 ((wq_completion)netns){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc900015d7d00 (net_cleanup_work){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc900015d7d00 (net_cleanup_work){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
 #2: ffffffff8fcc49d0 (pernet_ops_rwsem){++++}-{3:3}, at: cleanup_net+0x16a/0xcc0 net/core/net_namespace.c:580
 #3: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: default_device_exit_batch+0xe9/0xaa0 net/core/dev.c:11930
 #4: ffffffff8e93d338 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:329 [inline]
 #4: ffffffff8e93d338 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x451/0x830 kernel/rcu/tree_exp.h:976
3 locks held by kworker/u8:5/1808:
 #0: ffff88814baa0148 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88814baa0148 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc9000481fd00 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc9000481fd00 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
 #2: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: addrconf_dad_work+0xd0/0x16f0 net/ipv6/addrconf.c:4196
3 locks held by kworker/u8:8/2983:
 #0: ffff88801ac81148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88801ac81148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc90009d37d00 ((linkwatch_work).work){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc90009d37d00 ((linkwatch_work).work){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
 #2: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: linkwatch_event+0xe/0x60 net/core/link_watch.c:276
2 locks held by getty/4985:
 #0: ffff88814b7900a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
 #1: ffffc90002f062f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6a6/0x1e00 drivers/tty/n_tty.c:2211
1 lock held by syz.5.213/6595:
 #0: ffff88805d2ec420 (sb_writers#29){.+.+}-{0:0}, at: direct_splice_actor+0x49/0x220 fs/splice.c:1163
2 locks held by syz.5.213/6614:
 #0: ffff88805d2ec420 (sb_writers#29){.+.+}-{0:0}, at: mnt_want_write+0x3f/0x90 fs/namespace.c:515
 #1: ffff88805b0b88c0 (&sb->s_type->i_mutex_key#35){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:815 [inline]
 #1: ffff88805b0b88c0 (&sb->s_type->i_mutex_key#35){+.+.}-{3:3}, at: do_truncate+0x20c/0x310 fs/open.c:63
1 lock held by bch-copygc/loop/6611:
2 locks held by syz.3.329/7089:
 #0: ffff88805d2ec0e0 (&type->s_umount_key#86){.+.+}-{3:3}, at: __super_lock fs/super.c:58 [inline]
 #0: ffff88805d2ec0e0 (&type->s_umount_key#86){.+.+}-{3:3}, at: super_lock+0x27c/0x400 fs/super.c:120
 #1: ffff88805d2ec938 (&s->s_sync_lock){+.+.}-{3:3}, at: wait_sb_inodes fs/fs-writeback.c:2619 [inline]
 #1: ffff88805d2ec938 (&s->s_sync_lock){+.+.}-{3:3}, at: sync_inodes_sb+0x32e/0xb50 fs/fs-writeback.c:2802
2 locks held by syz-executor/7173:
 #0: ffff88804c1c20e0 (&type->s_umount_key#61){+.+.}-{3:3}, at: __super_lock fs/super.c:56 [inline]
 #0: ffff88804c1c20e0 (&type->s_umount_key#61){+.+.}-{3:3}, at: __super_lock_excl fs/super.c:71 [inline]
 #0: ffff88804c1c20e0 (&type->s_umount_key#61){+.+.}-{3:3}, at: deactivate_super+0xb5/0xf0 fs/super.c:505
 #1: ffffffff8e93d338 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:329 [inline]
 #1: ffffffff8e93d338 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x451/0x830 kernel/rcu/tree_exp.h:976
2 locks held by syz.2.393/7373:
 #0: ffff88805d2ec0e0 (&type->s_umount_key#86){.+.+}-{3:3}, at: __super_lock fs/super.c:58 [inline]
 #0: ffff88805d2ec0e0 (&type->s_umount_key#86){.+.+}-{3:3}, at: super_lock+0x27c/0x400 fs/super.c:120
 #1: ffff88805d2ec938 (&s->s_sync_lock){+.+.}-{3:3}, at: wait_sb_inodes fs/fs-writeback.c:2619 [inline]
 #1: ffff88805d2ec938 (&s->s_sync_lock){+.+.}-{3:3}, at: sync_inodes_sb+0x32e/0xb50 fs/fs-writeback.c:2802
1 lock held by syz-executor/7611:
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x6e6/0xcf0 net/core/rtnetlink.c:6643
1 lock held by syz-executor/7945:
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x6e6/0xcf0 net/core/rtnetlink.c:6643
1 lock held by syz-executor/7962:
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
 #0: ffffffff8fcd14c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x6e6/0xcf0 net/core/rtnetlink.c:6643
3 locks held by syz.5.546/8061:
 #0: ffff888030d10d80 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close net/bluetooth/hci_core.c:481 [inline]
 #0: ffff888030d10d80 (&hdev->req_lock){+.+.}-{3:3}, at: hci_unregister_dev+0x203/0x510 net/bluetooth/hci_core.c:2698
 #1: ffff888030d10078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_close_sync+0x572/0x11a0 net/bluetooth/hci_sync.c:5183
 #2: ffffffff8fe3dd28 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1972 [inline]
 #2: ffffffff8fe3dd28 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xa6/0x240 net/bluetooth/hci_conn.c:2589

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

NMI backtrace for cpu 1
CPU: 1 UID: 0 PID: 30 Comm: khungtaskd Not tainted 6.11.0-syzkaller-11993-g3efc57369a0c #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:94 [inline]
 dump_stack_lvl+0x241/0x360 lib/dump_stack.c:120
 nmi_cpu_backtrace+0x49c/0x4d0 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x198/0x320 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:162 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:223 [inline]
 watchdog+0xff4/0x1040 kernel/hung_task.c:379
 kthread+0x2f2/0x390 kernel/kthread.c:389
 ret_from_fork+0x4d/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 UID: 0 PID: 6611 Comm: bch-copygc/loop Not tainted 6.11.0-syzkaller-11993-g3efc57369a0c #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
RIP: 0010:lockdep_enabled kernel/locking/lockdep.c:119 [inline]
RIP: 0010:lock_acquire+0x120/0x550 kernel/locking/lockdep.c:5798
Code: c0 3c 16 1d 90 48 c1 e8 03 42 0f b6 04 28 84 c0 0f 85 ff 02 00 00 83 3d 29 d1 ac 0e 00 0f 84 42 01 00 00 65 8b 05 60 45 92 7e <85> c0 0f 85 8f 01 00 00 65 48 8b 1c 25 c0 d7 03 00 48 81 c3 dc 0a
RSP: 0018:ffffc90004427220 EFLAGS: 00000202
RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff817044d4
RDX: 0000000000000000 RSI: ffffffff8c60f580 RDI: ffffffff8c60f540
RBP: ffffc90004427368 R08: ffffffff901ce3ef R09: 1ffffffff2039c7d
R10: dffffc0000000000 R11: fffffbfff2039c7e R12: 1ffff92000884e4c
R13: dffffc0000000000 R14: 0000000000000000 R15: 000000429416683a
FS:  0000000000000000(0000) GS:ffff8880b8600000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fa4e8805440 CR3: 000000000e734000 CR4: 0000000000350ef0
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 trans_set_locked fs/bcachefs/btree_locking.h:194 [inline]
 bch2_trans_begin+0x9c5/0x1c00 fs/bcachefs/btree_iter.c:3112
 bch2_copygc_get_buckets fs/bcachefs/movinggc.c:164 [inline]
 bch2_copygc+0x86b/0x4650 fs/bcachefs/movinggc.c:215
 bch2_copygc_thread+0x737/0xc20 fs/bcachefs/movinggc.c:375
 kthread+0x2f2/0x390 kernel/kthread.c:389
 ret_from_fork+0x4d/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>

Crashes (7):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/09/28 20:38 upstream 3efc57369a0c ba29ff75 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in bchfs_truncate
2024/09/26 18:18 upstream 11a299a7933e 0d19f247 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in bchfs_truncate
2024/09/26 11:37 upstream aa486552a110 0d19f247 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in bchfs_truncate
2024/09/26 11:31 upstream aa486552a110 0d19f247 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in bchfs_truncate
2024/07/08 01:27 upstream c6653f49e4fd 2a40360c .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in bchfs_truncate
2024/06/10 04:35 upstream 83a7eefedc9b 82c05ab8 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in bchfs_truncate
2024/06/07 13:35 upstream 8a92980606e3 121701b6 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in bchfs_truncate
* Struck through repros no longer work on HEAD.