syzbot


INFO: task hung in __writeback_inodes_sb_nr (5)

Status: internal: reported C repro on 2022/02/12 04:17
Reported-by: syzbot+@syzkaller.appspotmail.com
Fix commit: 7d9b1b578d67 ip6mr: fix use-after-free in ip6mr_sk_done()
Patched on: [ci-qemu-upstream ci-qemu-upstream-386 ci-qemu2-arm32 ci-qemu2-arm64 ci-qemu2-arm64-compat ci-qemu2-arm64-mte ci-upstream-bpf-kasan-gce ci-upstream-bpf-next-kasan-gce ci-upstream-gce-leak ci-upstream-kasan-gce ci-upstream-kasan-gce-386 ci-upstream-kasan-gce-root ci-upstream-kasan-gce-selinux-root ci-upstream-kasan-gce-smack-root ci-upstream-kmsan-gce ci-upstream-kmsan-gce-386 ci-upstream-linux-next-kasan-gce-root ci-upstream-net-kasan-gce ci-upstream-net-this-kasan-gce ci2-upstream-kcsan-gce ci2-upstream-usb], missing on: [ci-qemu2-riscv64]
First crash: 137d, last: 4d19h

Cause bisection: introduced by (bisect log) :
commit f2f2325ec79970807012dfc9e716cdbb02d9b574
Author: Eric Dumazet <edumazet@google.com>
Date: Fri Feb 4 20:15:46 2022 +0000

  ip6mr: ip6mr_sk_done() can exit early in common cases

Crash: KASAN: use-after-free Read in ip6mr_sk_done (log)
Repro: C syz .config
similar bugs (7):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in __writeback_inodes_sb_nr 53 1261d 1524d 0/22 closed as dup on 2018/09/08 15:33
android-49 INFO: task hung in __writeback_inodes_sb_nr 26 1357d 1500d 0/3 auto-closed as invalid on 2019/04/08 13:33
android-414 INFO: task hung in __writeback_inodes_sb_nr 1 1295d 1172d 0/1 auto-closed as invalid on 2019/06/09 16:55
upstream INFO: task hung in __writeback_inodes_sb_nr (4) 4 144d 199d 0/22 closed as invalid on 2022/02/08 10:10
upstream INFO: task hung in __writeback_inodes_sb_nr (3) 2 411d 508d 0/22 auto-closed as invalid on 2021/08/11 17:49
upstream INFO: task hung in __writeback_inodes_sb_nr (2) 1 692d 692d 0/22 auto-closed as invalid on 2020/11/03 06:13
linux-4.14 INFO: task hung in __writeback_inodes_sb_nr 1 759d 759d 0/1 auto-closed as invalid on 2020/09/27 19:31

Sample crash report:
INFO: task syz-executor378:3799 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00650-g5a8fb33e5305 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor378 state:D stack:27168 pid: 3799 ppid:  3634 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 wb_wait_for_completion+0x17e/0x240 fs/fs-writeback.c:190
 __writeback_inodes_sb_nr+0x1d7/0x280 fs/fs-writeback.c:2623
 try_to_writeback_inodes_sb+0x94/0xc0 fs/fs-writeback.c:2671
 ext4_nonda_switch+0x1aa/0x1f0 fs/ext4/inode.c:2894
 ext4_da_write_begin+0x176/0xad0 fs/ext4/inode.c:2921
 generic_perform_write+0x205/0x510 mm/filemap.c:3765
 ext4_buffered_write_iter+0x1a2/0x390 fs/ext4/file.c:268
 ext4_file_write_iter+0x423/0x14d0 fs/ext4/file.c:677
 call_write_iter include/linux/fs.h:2074 [inline]
 new_sync_write+0x431/0x660 fs/read_write.c:503
 vfs_write+0x7cd/0xae0 fs/read_write.c:590
 ksys_write+0x12d/0x250 fs/read_write.c:643
 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:0x7f83f83657f9
RSP: 002b:00007f83f830a1f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f83f83e84a8 RCX: 00007f83f83657f9
RDX: 00000000ffffff6a RSI: 0000000020000000 RDI: 0000000000000003
RBP: 00007f83f83e84a0 R08: 0000000000000012 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f83f83e84ac
R13: 00007ffe639c4cbf R14: 00007f83f830a300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor378:3800 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00650-g5a8fb33e5305 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor378 state:D stack:25912 pid: 3800 ppid:  3634 flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 rwsem_down_write_slowpath+0x634/0x1110 kernel/locking/rwsem.c:1142
 __down_write_common kernel/locking/rwsem.c:1259 [inline]
 __down_write_common kernel/locking/rwsem.c:1256 [inline]
 __down_write kernel/locking/rwsem.c:1268 [inline]
 down_write+0x135/0x150 kernel/locking/rwsem.c:1515
 inode_lock include/linux/fs.h:777 [inline]
 lock_two_nondirectories+0xec/0x110 fs/inode.c:1122
 ext4_move_extents+0x369/0x3ee0 fs/ext4/move_extent.c:603
 __ext4_ioctl+0x33e3/0x57e0 fs/ext4/ioctl.c:1285
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 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:0x7f83f83657f9
RSP: 002b:00007f83f82e91f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f83f83e84b8 RCX: 00007f83f83657f9
RDX: 0000000020000180 RSI: 00000000c028660f RDI: 0000000000000024
RBP: 00007f83f83e84b0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f83f83e84bc
R13: 00007ffe639c4cbf R14: 00007f83f82e9300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor378:3801 blocked for more than 143 seconds.
      Not tainted 5.17.0-rc2-syzkaller-00650-g5a8fb33e5305 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor378 state:D stack:27768 pid: 3801 ppid:  3634 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 rwsem_down_write_slowpath+0x634/0x1110 kernel/locking/rwsem.c:1142
 __down_write_common kernel/locking/rwsem.c:1259 [inline]
 __down_write_common kernel/locking/rwsem.c:1256 [inline]
 __down_write kernel/locking/rwsem.c:1268 [inline]
 down_write+0x135/0x150 kernel/locking/rwsem.c:1515
 inode_lock include/linux/fs.h:777 [inline]
 process_measurement+0x17c0/0x1920 security/integrity/ima/ima_main.c:241
 ima_file_check+0xac/0x100 security/integrity/ima/ima_main.c:516
 do_open fs/namei.c:3478 [inline]
 path_openat+0x1647/0x2940 fs/namei.c:3609
 do_filp_open+0x1aa/0x400 fs/namei.c:3636
 do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
 do_sys_open fs/open.c:1230 [inline]
 __do_sys_openat fs/open.c:1246 [inline]
 __se_sys_openat fs/open.c:1241 [inline]
 __x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
 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:0x7f83f83657f9
RSP: 002b:00007f83f82c81f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f83f83e84c8 RCX: 00007f83f83657f9
RDX: 000000000000275a RSI: 0000000020000280 RDI: 00000000ffffff9c
RBP: 00007f83f83e84c0 R08: 00007f83f82c8700 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f83f83e84cc
R13: 00007ffe639c4cbf R14: 00007f83f82c8300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
4 locks held by kworker/u4:1/10:
1 lock held by khungtaskd/26:
 #0: ffffffff8bb83c20 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
2 locks held by getty/3277:
 #0: ffff888023719098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc90002b662e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
1 lock held by syz-executor378/3798:
 #0: ffff88814b5c2bd8 (&sbi->s_writepages_rwsem){.+.+}-{0:0}, at: do_writepages+0x1ab/0x690 mm/page-writeback.c:2364
4 locks held by syz-executor378/3799:
 #0: ffff8880772799f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:1034
 #1: ffff88814b5c0460 (sb_writers#5){.+.+}-{0:0}, at: ksys_write+0x12d/0x250 fs/read_write.c:643
 #2: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:777 [inline]
 #2: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: ext4_buffered_write_iter+0xb0/0x390 fs/ext4/file.c:262
 #3: ffff88814b5c00e0 (&type->s_umount_key#32){++++}-{3:3}, at: try_to_writeback_inodes_sb+0x1d/0xc0 fs/fs-writeback.c:2668
2 locks held by syz-executor378/3800:
 #0: ffff88814b5c0460 (sb_writers#5){.+.+}-{0:0}, at: __ext4_ioctl+0x3399/0x57e0 fs/ext4/ioctl.c:1281
 #1: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:777 [inline]
 #1: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: lock_two_nondirectories+0xec/0x110 fs/inode.c:1122
2 locks held by syz-executor378/3801:
 #0: ffff88814b5c0460 (sb_writers#5){.+.+}-{0:0}, at: do_open fs/namei.c:3469 [inline]
 #0: ffff88814b5c0460 (sb_writers#5){.+.+}-{0:0}, at: path_openat+0x1b69/0x2940 fs/namei.c:3609
 #1: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:777 [inline]
 #1: ffff88806b8aabd0 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x17c0/0x1920 security/integrity/ima/ima_main.c:241

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

NMI backtrace for cpu 0
CPU: 0 PID: 26 Comm: khungtaskd Not tainted 5.17.0-rc2-syzkaller-00650-g5a8fb33e5305 #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:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
 watchdog+0xc1d/0xf50 kernel/hung_task.c:369
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 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: 3652 Comm: kworker/u4:3 Not tainted 5.17.0-rc2-syzkaller-00650-g5a8fb33e5305 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:preempt_count arch/x86/include/asm/preempt.h:27 [inline]
RIP: 0010:check_kcov_mode kernel/kcov.c:166 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60 kernel/kcov.c:200
Code: 48 89 ef 5d e9 41 e2 46 00 5d be 03 00 00 00 e9 06 47 66 02 66 0f 1f 44 00 00 48 8b be b0 01 00 00 e8 b4 ff ff ff 31 c0 c3 90 <65> 8b 05 29 f7 89 7e 89 c1 48 8b 34 24 81 e1 00 01 00 00 65 48 8b
RSP: 0018:ffffc9000283f970 EFLAGS: 00000002
RAX: 0000000000000000 RBX: ffffffff8b88e000 RCX: 000000000b88e000
RDX: 0000000000000000 RSI: ffff88801bc18000 RDI: 0000000000000003
RBP: 000000000b88e000 R08: ffffffff8b88e000 R09: ffffffff8bcb4b98
R10: ffffffff81356848 R11: 000000000000003f R12: 0000000000000001
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000001
FS:  0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5614595680 CR3: 00000001406f5000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 __phys_addr+0xda/0x140 arch/x86/mm/physaddr.c:21
 build_cr3 arch/x86/mm/tlb.c:162 [inline]
 build_cr3 arch/x86/mm/tlb.c:156 [inline]
 load_new_mm_cr3+0xa2/0x130 arch/x86/mm/tlb.c:282
 switch_mm_irqs_off+0x498/0xa10 arch/x86/mm/tlb.c:627
 unuse_temporary_mm arch/x86/kernel/alternative.c:946 [inline]
 __text_poke+0x544/0x8c0 arch/x86/kernel/alternative.c:1042
 text_poke_bp_batch+0x2aa/0x510 arch/x86/kernel/alternative.c:1313
 text_poke_flush arch/x86/kernel/alternative.c:1470 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1467 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1477
 arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
 jump_label_update+0x1da/0x400 kernel/jump_label.c:830
 static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
 static_key_enable+0x16/0x20 kernel/jump_label.c:190
 toggle_allocation_gate mm/kfence/core.c:734 [inline]
 toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:726
 process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
 worker_thread+0x657/0x1110 kernel/workqueue.c:2454
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	48 89 ef             	mov    %rbp,%rdi
   3:	5d                   	pop    %rbp
   4:	e9 41 e2 46 00       	jmpq   0x46e24a
   9:	5d                   	pop    %rbp
   a:	be 03 00 00 00       	mov    $0x3,%esi
   f:	e9 06 47 66 02       	jmpq   0x266471a
  14:	66 0f 1f 44 00 00    	nopw   0x0(%rax,%rax,1)
  1a:	48 8b be b0 01 00 00 	mov    0x1b0(%rsi),%rdi
  21:	e8 b4 ff ff ff       	callq  0xffffffda
  26:	31 c0                	xor    %eax,%eax
  28:	c3                   	retq
  29:	90                   	nop
* 2a:	65 8b 05 29 f7 89 7e 	mov    %gs:0x7e89f729(%rip),%eax        # 0x7e89f75a <-- trapping instruction
  31:	89 c1                	mov    %eax,%ecx
  33:	48 8b 34 24          	mov    (%rsp),%rsi
  37:	81 e1 00 01 00 00    	and    $0x100,%ecx
  3d:	65                   	gs
  3e:	48                   	rex.W
  3f:	8b                   	.byte 0x8b

Crashes (3):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-net-kasan-gce 2022/02/12 04:13 net-next 5a8fb33e5305 8b9ca619 .config log report syz C INFO: task hung in __writeback_inodes_sb_nr
ci-upstream-kasan-gce-selinux-root 2022/06/24 10:02 upstream 92f20ff72066 a5dbd430 .config log report info INFO: task hung in __writeback_inodes_sb_nr
ci-upstream-net-kasan-gce 2022/02/11 22:42 net-next 5a8fb33e5305 8b9ca619 .config log report info INFO: task hung in __writeback_inodes_sb_nr