syzbot


INFO: task hung in nilfs_detach_log_writer

Status: upstream: reported C repro on 2022/10/24 10:07
Reported-by: syzbot+e3973c409251e136fdd0@syzkaller.appspotmail.com
First crash: 44d, last: 17h52m

Cause bisection: the issue happens on the oldest tested release (bisect log)
Crash: WARNING in account_page_dirtied (log)
Repro: C syz .config

Sample crash report:
INFO: task syz-executor368:3640 blocked for more than 143 seconds.
      Not tainted 6.1.0-rc3-syzkaller-00288-gb208b9fbbcba #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor368 state:D stack:26632 pid:3640  ppid:3638   flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5191 [inline]
 __schedule+0xae9/0x53f0 kernel/sched/core.c:6503
 schedule+0xda/0x1b0 kernel/sched/core.c:6579
 schedule_timeout+0x1db/0x2a0 kernel/time/timer.c:1911
 do_wait_for_common kernel/sched/completion.c:85 [inline]
 __wait_for_common+0x1ca/0x5c0 kernel/sched/completion.c:106
 __flush_work+0x58d/0xae0 kernel/workqueue.c:3073
 nilfs_segctor_destroy fs/nilfs2/segment.c:2730 [inline]
 nilfs_detach_log_writer+0x366/0x9f0 fs/nilfs2/segment.c:2813
 nilfs_put_super+0x3f/0x1a0 fs/nilfs2/super.c:468
 generic_shutdown_super+0x154/0x410 fs/super.c:492
 kill_block_super+0x97/0xf0 fs/super.c:1428
 deactivate_locked_super+0x94/0x160 fs/super.c:332
 deactivate_super+0xad/0xd0 fs/super.c:363
 cleanup_mnt+0x2ae/0x3d0 fs/namespace.c:1186
 task_work_run+0x16b/0x270 kernel/task_work.c:179
 resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:171 [inline]
 exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:203
 __syscall_exit_to_user_mode_work kernel/entry/common.c:285 [inline]
 syscall_exit_to_user_mode+0x19/0x50 kernel/entry/common.c:296
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fce2370bf27
RSP: 002b:00007ffd9e7016e8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fce2370bf27
RDX: 00007ffd9e7017ab RSI: 000000000000000a RDI: 00007ffd9e7017a0
RBP: 00007ffd9e7017a0 R08: 00000000ffffffff R09: 00007ffd9e701580
R10: 0000555555b76653 R11: 0000000000000206 R12: 00007ffd9e702810
R13: 0000555555b765f0 R14: 00007ffd9e701710 R15: 0000000000000154
 </TASK>

Showing all locks held in the system:
1 lock held by rcu_tasks_kthre/12:
 #0: ffffffff8bf87df0 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x26/0xc70 kernel/rcu/tasks.h:507
1 lock held by rcu_tasks_trace/13:
 #0: ffffffff8bf87af0 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x26/0xc70 kernel/rcu/tasks.h:507
1 lock held by khungtaskd/28:
 #0: ffffffff8bf88940 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6494
3 locks held by kworker/1:2/142:
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:636 [inline]
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:663 [inline]
 #0: ffff888011864d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x86d/0x1710 kernel/workqueue.c:2260
 #1: ffffc90002d5fda8 ((work_completion)(&sci->sc_iput_work)){+.+.}-{0:0}, at: process_one_work+0x8a1/0x1710 kernel/workqueue.c:2264
 #2: ffff88801d884650 (sb_internal#2){.+.+}-{0:0}, at: nilfs_evict_inode+0x137/0x440 fs/nilfs2/inode.c:928
2 locks held by getty/3284:
 #0: ffff88814b900098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc900031262f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xef0/0x13e0 drivers/tty/n_tty.c:2177
1 lock held by syz-executor368/3640:
 #0: ffff88801d8840e0 (&type->s_umount_key#42){+.+.}-{3:3}, at: deactivate_super+0xa5/0xd0 fs/super.c:362
6 locks held by kworker/u4:5/4266:
 #0: ffff8880b9b3a118 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:537
 #1: ffff8880b9b277c8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x212/0x930 kernel/sched/psi.c:897
 #2: ffff8880b9b283d8 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x5a/0x1f0 kernel/time/timer.c:999
 #3: ffffffff913c3da8 (&obj_hash[i].lock){-.-.}-{2:2}, at: debug_object_activate+0x12e/0x3e0 lib/debugobjects.c:658
 #4: ffffffff8be50628 (text_mutex){+.+.}-{3:3}, at: arch_jump_label_transform_apply+0xe/0x20 arch/x86/kernel/jump_label.c:145
 #5: ffff8880119c8138 (ptlock_ptr(page)#2){+.+.}-{2:2}, at: spin_lock include/linux/spinlock.h:350 [inline]
 #5: ffff8880119c8138 (ptlock_ptr(page)#2){+.+.}-{2:2}, at: __get_locked_pte+0x154/0x270 mm/memory.c:1845

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

NMI backtrace for cpu 0
CPU: 0 PID: 28 Comm: khungtaskd Not tainted 6.1.0-rc3-syzkaller-00288-gb208b9fbbcba #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
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+0x24/0x18a lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x32f/0x3c0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:220 [inline]
 watchdog+0xc71/0xfc0 kernel/hung_task.c:377
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 4266 Comm: kworker/u4:5 Not tainted 6.1.0-rc3-syzkaller-00288-gb208b9fbbcba #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:__insn_get_emulate_prefix arch/x86/lib/insn.c:91 [inline]
RIP: 0010:insn_get_emulate_prefix arch/x86/lib/insn.c:106 [inline]
RIP: 0010:insn_get_prefixes.part.0+0x119/0x1200 arch/x86/lib/insn.c:134
Code: 45 38 fd 75 3b e8 27 28 34 f8 4c 89 e6 bf 05 00 00 00 48 83 c3 01 e8 06 25 34 f8 49 83 fc 05 0f 84 30 08 00 00 e8 07 28 34 f8 <49> 83 c4 01 49 89 ed 48 83 c5 01 48 39 6c 24 10 0f 83 6b ff ff ff
RSP: 0018:ffffc90004b9f910 EFLAGS: 00000293
RAX: 0000000000000000 RBX: ffffffff8b23f4a1 RCX: 0000000000000000
RDX: ffff8880246b57c0 RSI: ffffffff89488479 RDI: 0000000000000007
RBP: ffffffff89e6b66b R08: 0000000000000007 R09: 0000000000000005
R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000001
R13: 000000000000000f R14: dffffc0000000000 R15: 000000000000000f
FS:  0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000558758d0c680 CR3: 000000000bc8e000 CR4: 0000000000350ee0
Call Trace:
 <TASK>
 insn_get_prefixes arch/x86/lib/insn.c:131 [inline]
 insn_get_opcode arch/x86/lib/insn.c:272 [inline]
 insn_get_modrm+0x646/0x7c0 arch/x86/lib/insn.c:343
 insn_get_sib+0x29c/0x330 arch/x86/lib/insn.c:421
 insn_get_displacement+0x346/0x6c0 arch/x86/lib/insn.c:464
 insn_get_immediate arch/x86/lib/insn.c:632 [inline]
 insn_get_length arch/x86/lib/insn.c:707 [inline]
 insn_decode+0x35b/0x3b0 arch/x86/lib/insn.c:747
 text_poke_loc_init+0xa6/0x450 arch/x86/kernel/alternative.c:1590
 arch_jump_label_transform_queue+0x94/0x100 arch/x86/kernel/jump_label.c:138
 __jump_label_update+0x12e/0x410 kernel/jump_label.c:447
 jump_label_update+0x32f/0x410 kernel/jump_label.c:801
 static_key_disable_cpuslocked+0x152/0x1b0 kernel/jump_label.c:207
 static_key_disable+0x16/0x20 kernel/jump_label.c:215
 toggle_allocation_gate mm/kfence/core.c:814 [inline]
 toggle_allocation_gate+0x183/0x390 mm/kfence/core.c:792
 process_one_work+0x9bf/0x1710 kernel/workqueue.c:2289
 worker_thread+0x665/0x1080 kernel/workqueue.c:2436
 kthread+0x2e4/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
 </TASK>

Crashes (10):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-root 2022/11/06 05:34 upstream b208b9fbbcba 6d752409 .config log report syz C INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/10/27 19:14 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 86777b7f .config log report syz C INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/10/25 02:50 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 ff2fe65d .config log report syz C INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/10/24 23:31 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 ff2fe65d .config log report syz C INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/10/20 10:04 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 b31320fc .config log report syz C INFO: task hung in nilfs_detach_log_writer
ci2-upstream-fs 2022/12/02 21:14 upstream a4412fdd49dc e080de16 .config log report info INFO: task hung in nilfs_detach_log_writer
ci2-upstream-fs 2022/11/28 09:26 upstream cf562a45a0d5 f4470a7b .config log report info INFO: task hung in nilfs_detach_log_writer
ci2-upstream-fs 2022/11/26 01:10 upstream 08ad43d554ba f4470a7b .config log report info INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/11/05 11:06 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 6d752409 .config log report info INFO: task hung in nilfs_detach_log_writer
ci-upstream-gce-arm64 2022/10/27 01:30 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci bbed346d5a96 86777b7f .config log report info INFO: task hung in nilfs_detach_log_writer
* Struck through repros no longer work on HEAD.