syzbot

 sign-in | mailing list | source | docs
🐞 Open [872] ≡ Subsystems 🐞 Fixed [4871] 🐞 Invalid [11621] ⬇ Missing Backports [67] 📈 Kernel Health 📈 Bug Lifetimes 📈 Fuzzing 📈 Crashes 💬 Send us feedback

INFO: task hung in do_truncate (2)

Status: upstream: reported C repro on 2020/06/11 04:48
Subsystems: fs
[Documentation on labels]
Reported-by: syzbot+18b2ab4c697021ee8369@syzkaller.appspotmail.com
First crash: 1269d, last: 61d
Cause bisection: the issue happens on the oldest tested release (bisect log)
Crash: WARNING in sysfs_warn_dup (log)
Repro: C syz .config
  
Fix bisection: fixed by (bisect log) :
commit dfefd226b0bf7c435a58d75a0ce2f9273b9825f6
Author: Alexey Dobriyan <adobriyan@gmail.com>
Date: Tue Dec 15 03:15:03 2020 +0000

  mm: cleanup kstrto*() usage

  
▶ ▼ Discussions (1)
Title Replies (including bot) Last reply
INFO: task hung in do_truncate (2) 1 (3) 2023/05/01 18:59
▶ ▼ Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-5.15 INFO: task hung in do_truncate 1 253d 253d 0/3 auto-obsoleted due to no activity on 2023/07/17 23:13
linux-5.15 INFO: task hung in do_truncate (2) 1 101d 101d 0/3 auto-obsoleted due to no activity on 2023/11/27 08:00
upstream INFO: task hung in do_truncate ext4 C 7 1838d 2002d 0/25 closed as dup on 2018/09/08 15:38
▶ ▼ Last patch testing requests (3)
Created Duration User Patch Repo Result
2023/08/22 03:38 44m retest repro upstream OK log
2023/03/17 13:32 20m retest repro upstream report log
2022/10/03 14:30 18m retest repro upstream report log
▶ ▼ Fix bisection attempts (6)
Created Duration User Patch Repo Result
2021/01/07 02:56 4h05m bisect fix upstream job log (1)
2020/12/06 23:59 29m bisect fix upstream job log (0) log
2020/11/05 01:48 27m bisect fix upstream job log (0) log
2020/10/06 01:19 28m bisect fix upstream job log (0) log
2020/08/26 04:50 26m bisect fix upstream job log (0) log
2020/07/26 07:30 29m bisect fix upstream job log (0) log

Sample crash report:
INFO: task syz-executor283:6874 blocked for more than 143 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6874   6804 0x00004004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 do_truncate+0x125/0x1f0 fs/open.c:62
 handle_truncate fs/namei.c:2887 [inline]
 do_open fs/namei.c:3233 [inline]
 path_openat+0x1f28/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000
INFO: task syz-executor283:6877 blocked for more than 143 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6877   6805 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
 ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:440
 do_open fs/namei.c:3231 [inline]
 path_openat+0x1997/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000
INFO: task syz-executor283:6880 blocked for more than 144 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6880   6803 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
 ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:440
 do_open fs/namei.c:3231 [inline]
 path_openat+0x1997/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000
INFO: task syz-executor283:6882 blocked for more than 144 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6882   6800 0x00004004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
 ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:440
 do_open fs/namei.c:3231 [inline]
 path_openat+0x1997/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000
INFO: task syz-executor283:6889 blocked for more than 144 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6889   6807 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
 ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:440
 do_open fs/namei.c:3231 [inline]
 path_openat+0x1997/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000
INFO: task syz-executor283:6890 blocked for more than 145 seconds.
      Not tainted 5.7.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor283 D28400  6890   6801 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3430 [inline]
 __schedule+0x8f3/0x1fc0 kernel/sched/core.c:4156
 schedule+0xd0/0x2a0 kernel/sched/core.c:4231
 rwsem_down_write_slowpath+0x706/0xf90 kernel/locking/rwsem.c:1235
 __down_write kernel/locking/rwsem.c:1389 [inline]
 down_write+0x137/0x150 kernel/locking/rwsem.c:1532
 inode_lock include/linux/fs.h:799 [inline]
 process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
 ima_file_check+0xb9/0x100 security/integrity/ima/ima_main.c:440
 do_open fs/namei.c:3231 [inline]
 path_openat+0x1997/0x27d0 fs/namei.c:3346
 do_filp_open+0x192/0x260 fs/namei.c:3373
 do_sys_openat2+0x585/0x7d0 fs/open.c:1179
 do_sys_open+0xc3/0x140 fs/open.c:1195
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:295
 entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x4468f9
Code: Bad RIP value.
RSP: 002b:00007f3df9c40db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 00000000004468f9
RDX: 000000000000275a RSI: 00000000200001c0 RDI: 00000000ffffff9c
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffe3e295ecf R14: 00007f3df9c419c0 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1149:
 #0: ffffffff899bdd80 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:5779
1 lock held by in:imklog/6461:
 #0: ffff88809231e0f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:826
2 locks held by syz-executor283/6874:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: do_truncate+0x125/0x1f0 fs/open.c:62
2 locks held by syz-executor283/6877:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
2 locks held by syz-executor283/6880:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
2 locks held by syz-executor283/6882:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
3 locks held by syz-executor283/6881:
 #0: ffff88809ef500f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:826
 #1: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: file_start_write include/linux/fs.h:2930 [inline]
 #1: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: vfs_write+0x4cf/0x5d0 fs/read_write.c:558
 #2: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #2: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: ext4_buffered_write_iter+0xb3/0x450 fs/ext4/file.c:264
2 locks held by syz-executor283/6889:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228
2 locks held by syz-executor283/6890:
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: sb_start_write include/linux/fs.h:1661 [inline]
 #0: ffff88809950a450 (sb_writers#3){.+.+}-{0:0}, at: mnt_want_write+0x3a/0xb0 fs/namespace.c:354
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:799 [inline]
 #1: ffff888086683a48 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: process_measurement+0x15ec/0x1750 security/integrity/ima/ima_main.c:228

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

NMI backtrace for cpu 1
CPU: 1 PID: 1149 Comm: khungtaskd Not tainted 5.7.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x188/0x20d lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x70/0xb1 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1e6/0x221 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:205 [inline]
 watchdog+0xa8c/0x1010 kernel/hung_task.c:289
 kthread+0x388/0x470 kernel/kthread.c:268
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:351
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:60

Crashes (11):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/06/07 04:44 upstream 7ae77150d94d e6b89e4e .config console log report syz C ci-upstream-kasan-gce-root
2023/09/28 04:41 upstream 633b47cb009d c2ab1e5d .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in do_truncate
2023/04/18 04:44 upstream 6a8f57ae2eb0 436577a9 .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in do_truncate
2022/12/07 12:41 upstream 8ed710da2873 d88f3abb .config console log report info [disk image] [vmlinux] [kernel image] ci2-upstream-fs INFO: task hung in do_truncate
2021/12/28 16:13 upstream a8ad9a2434dc 6b3c5e64 .config console log report info ci-upstream-kasan-gce-smack-root INFO: task hung in do_truncate
2021/08/26 10:47 upstream 73f3af7b4611 b599f2fc .config console log report info ci-upstream-kasan-gce-selinux-root INFO: task hung in do_truncate
2021/07/30 02:35 upstream 7e96bf476270 c585c7b0 .config console log report info ci-upstream-kasan-gce-smack-root INFO: task hung in do_truncate
2021/07/19 23:00 upstream 2734d6c1b1a0 bc48c9ab .config console log report info ci-upstream-kasan-gce-selinux-root INFO: task hung in do_truncate
2021/07/01 23:36 upstream e04360a2ea01 658ebc66 .config console log report info ci-upstream-kasan-gce-selinux-root INFO: task hung in do_truncate
2023/06/26 04:53 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci e40939bbfc68 09ffe269 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 INFO: task hung in do_truncate
2023/03/19 05:30 git://git.kernel.org/pub/scm/linux/kernel/git/arm64/linux.git for-kernelci fe15c26ee26e 7939252e .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-gce-arm64 INFO: task hung in do_truncate
* Struck through repros no longer work on HEAD.