syzbot


INFO: task hung in btree_write_buffer_flush_seq

Status: upstream: reported C repro on 2024/11/10 08:33
Subsystems: bcachefs
[Documentation on labels]
Reported-by: syzbot+cf3d1015b55ff73dcdc8@syzkaller.appspotmail.com
First crash: 79d, last: 7d20h
Cause bisection: introduced by (bisect log) :
commit 49fd90b2cc332b8607a616d99d4bb792f18208b9
Author: Kent Overstreet <kent.overstreet@linux.dev>
Date: Wed Sep 25 22:17:31 2024 +0000

  bcachefs: Fix unlocked access to c->disk_sb.sb in bch2_replicas_entry_validate()

Crash: INFO: task hung in bch2_replicas_entry_validate (log)
Repro: C syz .config
  
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [bcachefs?] INFO: task hung in btree_write_buffer_flush_seq 0 (1) 2024/11/10 08:33
Last patch testing requests (1)
Created Duration User Patch Repo Result
2024/11/20 10:08 26m retest repro upstream OK log

Sample crash report:
INFO: task bch-reclaim/loo:7180 blocked for more than 143 seconds.
      Not tainted 6.12.0-syzkaller-09837-g798bb342e041 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:bch-reclaim/loo state:D stack:24880 pid:7180  tgid:7180  ppid:2      flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5369 [inline]
 __schedule+0x17fb/0x4be0 kernel/sched/core.c:6756
 __schedule_loop kernel/sched/core.c:6833 [inline]
 schedule+0x14b/0x320 kernel/sched/core.c:6848
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6905
 __mutex_lock_common kernel/locking/mutex.c:665 [inline]
 __mutex_lock+0x7e7/0xee0 kernel/locking/mutex.c:735
 btree_write_buffer_flush_seq+0x1b19/0x1cc0 fs/bcachefs/btree_write_buffer.c:516
 bch2_btree_write_buffer_journal_flush+0xc7/0x150 fs/bcachefs/btree_write_buffer.c:533
 journal_flush_pins+0x5f7/0xb20 fs/bcachefs/journal_reclaim.c:565
 __bch2_journal_reclaim+0x789/0xdc0 fs/bcachefs/journal_reclaim.c:698
 bch2_journal_reclaim_thread+0x174/0x560 fs/bcachefs/journal_reclaim.c:740
 kthread+0x2f0/0x390 kernel/kthread.c:389
 ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/30:
 #0: ffffffff8e93c520 (rcu_read_lock){....}-{1:3}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
 #0: ffffffff8e93c520 (rcu_read_lock){....}-{1:3}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
 #0: ffffffff8e93c520 (rcu_read_lock){....}-{1:3}, at: debug_show_all_locks+0x55/0x2a0 kernel/locking/lockdep.c:6744
2 locks held by kworker/u8:3/52:
 #0: ffff88801ac89148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88801ac89148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc90000bc7d00 ((reaper_work).work){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc90000bc7d00 ((reaper_work).work){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
2 locks held by kworker/u8:4/81:
 #0: ffff88801ac89148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88801ac89148 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc9000214fd00 (connector_reaper_work){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc9000214fd00 (connector_reaper_work){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
5 locks held by kworker/u8:5/202:
3 locks held by kworker/u8:7/1315:
 #0: ffff8880b873e758 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2a/0x140 kernel/sched/core.c:598
 #1: ffff8880b8728948 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x41d/0x7a0 kernel/sched/psi.c:987
 #2: ffff8880b872a718 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x112/0x240 kernel/time/timer.c:1050
3 locks held by kworker/u8:9/3551:
 #0: ffff88814d019148 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
 #0: ffff88814d019148 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_scheduled_works+0x93b/0x1850 kernel/workqueue.c:3310
 #1: ffffc9000cc57d00 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
 #1: ffffc9000cc57d00 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_scheduled_works+0x976/0x1850 kernel/workqueue.c:3310
 #2: ffffffff8fcd76c8 (rtnl_mutex){+.+.}-{4:4}, at: addrconf_dad_work+0xd0/0x16f0 net/ipv6/addrconf.c:4196
2 locks held by getty/5603:
 #0: ffff8880317bd0a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
 #1: ffffc9000332b2f0 (&ldata->atomic_read_lock){+.+.}-{4:4}, at: n_tty_read+0x6a6/0x1e00 drivers/tty/n_tty.c:2211
5 locks held by syz-executor/5838:
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: __super_lock fs/super.c:56 [inline]
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: __super_lock_excl fs/super.c:71 [inline]
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: deactivate_super+0xb5/0xf0 fs/super.c:505
 #1: ffff888059a80278 (&c->state_lock){+.+.}-{4:4}, at: __bch2_fs_stop+0xfd/0x5c0 fs/bcachefs/super.c:620
 #2: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_lock_acquire include/linux/srcu.h:158 [inline]
 #2: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_read_lock include/linux/srcu.h:249 [inline]
 #2: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: __bch2_trans_get+0x7e1/0xd30 fs/bcachefs/btree_iter.c:3228
 #3: ffff888059a84740 (&wb->flushing.lock){+.+.}-{4:4}, at: btree_write_buffer_flush_seq+0x1b19/0x1cc0 fs/bcachefs/btree_write_buffer.c:516
 #4: ffff888059aa66d0 (&c->gc_lock){++++}-{4:4}, at: bch2_btree_update_start+0x682/0x14e0 fs/bcachefs/btree_update_interior.c:1197
3 locks held by bch-reclaim/loo/7180:
 #0: ffff888059acb0a8 (&j->reclaim_lock){+.+.}-{4:4}, at: bch2_journal_reclaim_thread+0x167/0x560 fs/bcachefs/journal_reclaim.c:739
 #1: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_lock_acquire include/linux/srcu.h:158 [inline]
 #1: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_read_lock include/linux/srcu.h:249 [inline]
 #1: ffff888059a84398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: __bch2_trans_get+0x7e1/0xd30 fs/bcachefs/btree_iter.c:3228
 #2: ffff888059a84740 (&wb->flushing.lock){+.+.}-{4:4}, at: btree_write_buffer_flush_seq+0x1b19/0x1cc0 fs/bcachefs/btree_write_buffer.c:516
1 lock held by syz-executor/7249:
 #0: ffffffff8e941ab8 (rcu_state.exp_mutex){+.+.}-{4:4}, at: exp_funnel_lock kernel/rcu/tree_exp.h:329 [inline]
 #0: ffffffff8e941ab8 (rcu_state.exp_mutex){+.+.}-{4:4}, at: synchronize_rcu_expedited+0x451/0x830 kernel/rcu/tree_exp.h:976
1 lock held by syz.9.336/8961:
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: __super_lock fs/super.c:58 [inline]
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: super_lock+0x27c/0x400 fs/super.c:120
1 lock held by syz.1.374/9324:
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: __super_lock fs/super.c:58 [inline]
 #0: ffff88807b37a0e0 (&type->s_umount_key#72){++++}-{4:4}, at: super_lock+0x27c/0x400 fs/super.c:120
3 locks held by syz-executor/9704:
 #0: ffffffff8fcd76c8 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
 #0: ffffffff8fcd76c8 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_nets_lock net/core/rtnetlink.c:326 [inline]
 #0: ffffffff8fcd76c8 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_newlink+0xd04/0x24f0 net/core/rtnetlink.c:4000
 #1: ffff88807a3614e8 (&wg->device_update_lock){+.+.}-{4:4}, at: wg_open+0x22d/0x420 drivers/net/wireguard/device.c:50
 #2: ffffffff8e941ab8 (rcu_state.exp_mutex){+.+.}-{4:4}, at: exp_funnel_lock kernel/rcu/tree_exp.h:329 [inline]
 #2: ffffffff8e941ab8 (rcu_state.exp_mutex){+.+.}-{4:4}, at: synchronize_rcu_expedited+0x451/0x830 kernel/rcu/tree_exp.h:976
2 locks held by syz.0.404/10051:
 #0: ffff8880404700e0 (&type->s_umount_key#50/1){+.+.}-{4:4}, at: alloc_super+0x221/0x9d0 fs/super.c:344
 #1: ffffffff8e7e6a68 (wq_pool_mutex){+.+.}-{4:4}, at: apply_wqattrs_lock kernel/workqueue.c:5166 [inline]
 #1: ffffffff8e7e6a68 (wq_pool_mutex){+.+.}-{4:4}, at: __alloc_workqueue+0xa55/0x1f20 kernel/workqueue.c:5720
2 locks held by cmp/10072:

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

NMI backtrace for cpu 0
CPU: 0 UID: 0 PID: 30 Comm: khungtaskd Not tainted 6.12.0-syzkaller-09837-g798bb342e041 #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:234 [inline]
 watchdog+0xffb/0x1040 kernel/hung_task.c:397
 kthread+0x2f0/0x390 kernel/kthread.c:389
 ret_from_fork+0x4b/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 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 UID: 0 PID: 5922 Comm: kworker/1:7 Not tainted 6.12.0-syzkaller-09837-g798bb342e041 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Workqueue: events free_obj_work
RIP: 0010:unwind_done arch/x86/include/asm/unwind.h:50 [inline]
RIP: 0010:unwind_get_return_address+0x22/0x90 arch/x86/kernel/unwind_orc.c:366
Code: 90 90 90 90 90 90 90 90 f3 0f 1e fa 41 57 41 56 53 48 89 fb 49 be 00 00 00 00 00 fc ff df 48 89 f8 48 c1 e8 03 42 0f b6 04 30 <84> c0 75 4b 83 3b 00 74 3a 48 83 c3 48 49 89 df 49 c1 ef 03 43 80
RSP: 0018:ffffc9000412f680 EFLAGS: 00000a06
RAX: 0000000000000000 RBX: ffffc9000412f6a0 RCX: 0000000080000000
RDX: dffffc0000000000 RSI: ffffc90004128000 RDI: ffffc9000412f6a0
RBP: ffffc9000412f730 R08: ffffc9000412fdc0 R09: 0000000000000000
R10: ffffc9000412f6f0 R11: fffff52000825ee0 R12: ffff88802c503c00
R13: ffffffff81819f40 R14: dffffc0000000000 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff8880b8700000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f07a1164000 CR3: 000000007caea000 CR4: 00000000003526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 arch_stack_walk+0xfd/0x150 arch/x86/kernel/stacktrace.c:26
 stack_trace_save+0x118/0x1d0 kernel/stacktrace.c:122
 kasan_save_stack mm/kasan/common.c:47 [inline]
 kasan_save_track+0x3f/0x80 mm/kasan/common.c:68
 kasan_save_free_info+0x40/0x50 mm/kasan/generic.c:582
 poison_slab_object mm/kasan/common.c:247 [inline]
 __kasan_slab_free+0x59/0x70 mm/kasan/common.c:264
 kasan_slab_free include/linux/kasan.h:233 [inline]
 slab_free_hook mm/slub.c:2338 [inline]
 slab_free mm/slub.c:4598 [inline]
 kmem_cache_free+0x195/0x410 mm/slub.c:4700
 free_object_list lib/debugobjects.c:326 [inline]
 free_obj_work+0x393/0x4e0 lib/debugobjects.c:513
 process_one_work kernel/workqueue.c:3229 [inline]
 process_scheduled_works+0xa63/0x1850 kernel/workqueue.c:3310
 worker_thread+0x870/0xd30 kernel/workqueue.c:3391
 kthread+0x2f0/0x390 kernel/kthread.c:389
 ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>

Crashes (6):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/11/27 15:41 upstream 798bb342e041 52b38cc1 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btree_write_buffer_flush_seq
2024/11/06 08:21 upstream 2e1b3cc9d7f7 3a465482 .config strace log report syz / log C [disk image] [vmlinux] [kernel image] [mounted in repro] ci-upstream-kasan-gce-root INFO: task hung in btree_write_buffer_flush_seq
2024/11/06 03:49 upstream 2e1b3cc9d7f7 3a465482 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in btree_write_buffer_flush_seq
2024/09/26 09:29 upstream aa486552a110 0d19f247 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btree_write_buffer_flush_seq
2024/09/17 07:19 upstream a430d95c5efa c673ca06 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btree_write_buffer_flush_seq
2024/09/16 17:37 upstream adfc3ded5c33 c673ca06 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in btree_write_buffer_flush_seq
* Struck through repros no longer work on HEAD.