syzbot


INFO: task hung in inode_sleep_on_writeback (2)

Status: auto-closed as invalid on 2022/02/05 13:28
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 384d, last: 384d
similar bugs (1):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in inode_sleep_on_writeback 8 1414d 1700d 0/24 closed as dup on 2019/02/06 13:32

Sample crash report:
INFO: task kworker/u4:3:54 blocked for more than 143 seconds.
      Not tainted 5.15.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:3    state:D stack:24000 pid:   54 ppid:     2 flags:0x00004000
Workqueue: writeback wb_workfn (flush-0:75)
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4969 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6250
 schedule+0xd2/0x260 kernel/sched/core.c:6323
 inode_sleep_on_writeback+0x162/0x180 fs/fs-writeback.c:1522
 wb_writeback+0x401/0xc30 fs/fs-writeback.c:2084
 wb_check_old_data_flush fs/fs-writeback.c:2156 [inline]
 wb_do_writeback fs/fs-writeback.c:2209 [inline]
 wb_workfn+0x8cf/0x12d0 fs/fs-writeback.c:2238
 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>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8b983a20 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6461
2 locks held by kworker/u4:3/54:
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:635 [inline]
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:662 [inline]
 #0: ffff8880133dc138 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2269
 #1: ffffc90001a2fdb0 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2273
1 lock held by in:imklog/6170:
 #0: ffff8880199a8d70 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:990

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.15.0-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:105
 nmi_trigger_cpumask_backtrace+0x1ae/0x220 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 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 2924 Comm: systemd-journal Not tainted 5.15.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:lock_is_held_type+0xe/0x140 kernel/locking/lockdep.c:5668
Code: 89 44 24 04 e8 2a 9a bc ff 0f 0b 8b 44 24 04 eb bd 66 66 2e 0f 1f 84 00 00 00 00 00 41 57 41 56 41 55 41 bd ff ff ff ff 41 54 <55> 53 48 83 ec 08 8b 0d 92 bf 36 04 85 c9 0f 84 d9 00 00 00 65 8b
RSP: 0018:ffffc90001a6f8c8 EFLAGS: 00000202
RAX: 0000000000000001 RBX: 1ffff9200034df22 RCX: ffffffff815cdfc8
RDX: 1ffffffff17318fe RSI: 00000000ffffffff RDI: ffffffff8b983960
RBP: 0000000000000001 R08: 0000000000000000 R09: ffffffff8d6fc1d7
R10: fffffbfff1adf83a R11: 0000000000000000 R12: 0000000000000001
R13: 00000000ffffffff R14: ffffffff8baa7f00 R15: 0000000000000000
FS:  00007f11aedd78c0(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f11ac223010 CR3: 000000007b6c7000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
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:5611
 __fs_reclaim_acquire mm/page_alloc.c:4535 [inline]
 fs_reclaim_acquire+0x115/0x160 mm/page_alloc.c:4549
 might_alloc include/linux/sched/mm.h:227 [inline]
 slab_pre_alloc_hook mm/slab.h:492 [inline]
 slab_alloc_node mm/slub.c:3148 [inline]
 slab_alloc mm/slub.c:3242 [inline]
 kmem_cache_alloc+0x3e/0x3a0 mm/slub.c:3247
 kmem_cache_zalloc include/linux/slab.h:714 [inline]
 lsm_file_alloc security/security.c:572 [inline]
 security_file_alloc+0x34/0x170 security/security.c:1516
 __alloc_file+0xd8/0x280 fs/file_table.c:106
 alloc_empty_file+0x6d/0x170 fs/file_table.c:150
 path_openat+0xe1/0x2750 fs/namei.c:3545
 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:0x7f11ae366840
Code: 73 01 c3 48 8b 0d 68 77 20 00 f7 d8 64 89 01 48 83 c8 ff c3 66 0f 1f 44 00 00 83 3d 89 bb 20 00 00 75 10 b8 02 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 1e f6 ff ff 48 89 04 24
RSP: 002b:00007ffd0df45418 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 00007ffd0df45720 RCX: 00007f11ae366840
RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 0000556a10609180
RBP: 000000000000000d R08: 000000000000c0ff R09: 00000000ffffffff
R10: 0000000000000069 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000556a105fb040 R14: 00007ffd0df456e0 R15: 0000556a10608fa0
 </TASK>
----------------
Code disassembly (best guess):
   0:	89 44 24 04          	mov    %eax,0x4(%rsp)
   4:	e8 2a 9a bc ff       	callq  0xffbc9a33
   9:	0f 0b                	ud2
   b:	8b 44 24 04          	mov    0x4(%rsp),%eax
   f:	eb bd                	jmp    0xffffffce
  11:	66 66 2e 0f 1f 84 00 	data16 nopw %cs:0x0(%rax,%rax,1)
  18:	00 00 00 00
  1c:	41 57                	push   %r15
  1e:	41 56                	push   %r14
  20:	41 55                	push   %r13
  22:	41 bd ff ff ff ff    	mov    $0xffffffff,%r13d
  28:	41 54                	push   %r12
* 2a:	55                   	push   %rbp <-- trapping instruction
  2b:	53                   	push   %rbx
  2c:	48 83 ec 08          	sub    $0x8,%rsp
  30:	8b 0d 92 bf 36 04    	mov    0x436bf92(%rip),%ecx        # 0x436bfc8
  36:	85 c9                	test   %ecx,%ecx
  38:	0f 84 d9 00 00 00    	je     0x117
  3e:	65                   	gs
  3f:	8b                   	.byte 0x8b

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce 2021/11/07 13:19 upstream b5013d084e03 4c1be0be .config log report info INFO: task hung in inode_sleep_on_writeback
* Struck through repros no longer work on HEAD.