syzbot


INFO: task hung in ni_readpage_cmpr

Status: upstream: reported C repro on 2024/02/13 07:32
Bug presence: origin:lts-only
[Documentation on labels]
Reported-by: syzbot+4cc251673c16be47e2b1@syzkaller.appspotmail.com
First crash: 79d, last: 39d
Fix commit to backport (bisect log) :
tree: upstream
commit bfbe5b31caa74ab97f1784fe9ade5f45e0d3de91
Author: Konstantin Komarov <almaz.alexandrovich@paragon-software.com>
Date: Fri Jun 30 12:22:53 2023 +0000

  fs/ntfs3: fix deadlock in mark_as_free_ex

  
Fix bisection: the issue occurs on the latest tested release (bisect log)
Crash: INFO: task hung in ntfs_readpage (log)
Repro: C syz .config
  
Bug presence (2)
Date Name Commit Repro Result
2024/02/22 linux-5.15.y (ToT) 6139f2a02fe0 C [report] INFO: task hung in ni_readpage_cmpr
2024/02/22 upstream (ToT) 39133352cbed C Didn't crash
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in ni_readpage_cmpr ntfs3 C error 5 63d 287d 0/26 upstream: reported C repro on 2023/07/21 00:28
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2024/03/24 13:46 7h02m fix candidate upstream job log (1)
2024/03/24 02:12 2h32m bisect fix linux-5.15.y job log (0) log

Sample crash report:
INFO: task syz-executor362:3556 blocked for more than 143 seconds.
      Not tainted 5.15.148-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor362 state:D stack:23632 pid: 3556 ppid:  3546 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5030 [inline]
 __schedule+0x12c4/0x45b0 kernel/sched/core.c:6376
 schedule+0x11b/0x1f0 kernel/sched/core.c:6459
 io_schedule+0x88/0x100 kernel/sched/core.c:8484
 wait_on_page_bit_common+0xa13/0x1180 mm/filemap.c:1356
 __lock_page mm/filemap.c:1648 [inline]
 lock_page include/linux/pagemap.h:625 [inline]
 pagecache_get_page+0x5af/0x1010 mm/filemap.c:1910
 find_or_create_page include/linux/pagemap.h:420 [inline]
 ni_readpage_cmpr+0x2f2/0x8d0 fs/ntfs3/frecord.c:2087
 ntfs_readpage+0x19a/0x210 fs/ntfs3/inode.c:725
 filemap_read_page+0x166/0x4b0 mm/filemap.c:2386
 filemap_update_page mm/filemap.c:2464 [inline]
 filemap_get_pages mm/filemap.c:2574 [inline]
 filemap_read+0x15dc/0x2980 mm/filemap.c:2634
 call_read_iter include/linux/fs.h:2140 [inline]
 generic_file_splice_read+0x4ad/0x790 fs/splice.c:311
 do_splice_to fs/splice.c:796 [inline]
 splice_direct_to_actor+0x448/0xc10 fs/splice.c:870
 do_splice_direct+0x285/0x3d0 fs/splice.c:979
 do_sendfile+0x625/0xff0 fs/read_write.c:1249
 __do_sys_sendfile64 fs/read_write.c:1317 [inline]
 __se_sys_sendfile64+0x178/0x1e0 fs/read_write.c:1303
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7efd87229d49
RSP: 002b:00007efd871e6218 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007efd872d0708 RCX: 00007efd87229d49
RDX: 0000000000000000 RSI: 0000000000000005 RDI: 0000000000000004
RBP: 00007efd872d0700 R08: 0000000000000000 R09: 0000000000000000
R10: 0001000000201005 R11: 0000000000000246 R12: 00007efd872d070c
R13: 00007efd8729d4dc R14: 00007efd8727e0c0 R15: 0031656c69662f2e
 </TASK>
INFO: task syz-executor362:3566 blocked for more than 143 seconds.
      Not tainted 5.15.148-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor362 state:D stack:25400 pid: 3566 ppid:  3546 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5030 [inline]
 __schedule+0x12c4/0x45b0 kernel/sched/core.c:6376
 schedule+0x11b/0x1f0 kernel/sched/core.c:6459
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6518
 __mutex_lock_common+0xe34/0x25a0 kernel/locking/mutex.c:669
 __mutex_lock kernel/locking/mutex.c:729 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:743
 ni_lock fs/ntfs3/ntfs_fs.h:1110 [inline]
 ntfs_readpage+0x18f/0x210 fs/ntfs3/inode.c:724
 filemap_read_page+0x166/0x4b0 mm/filemap.c:2386
 filemap_update_page mm/filemap.c:2464 [inline]
 filemap_get_pages mm/filemap.c:2574 [inline]
 filemap_read+0x15dc/0x2980 mm/filemap.c:2634
 call_read_iter include/linux/fs.h:2140 [inline]
 generic_file_splice_read+0x4ad/0x790 fs/splice.c:311
 do_splice_to fs/splice.c:796 [inline]
 splice_direct_to_actor+0x448/0xc10 fs/splice.c:870
 do_splice_direct+0x285/0x3d0 fs/splice.c:979
 do_sendfile+0x625/0xff0 fs/read_write.c:1249
 __do_sys_sendfile64 fs/read_write.c:1317 [inline]
 __se_sys_sendfile64+0x178/0x1e0 fs/read_write.c:1303
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7efd87229d49
RSP: 002b:00007efd871c5218 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007efd872d0718 RCX: 00007efd87229d49
RDX: 0000000000000000 RSI: 0000000000000007 RDI: 0000000000000006
RBP: 00007efd872d0710 R08: 0000000000000000 R09: 0000000000000000
R10: 0001000000201005 R11: 0000000000000246 R12: 00007efd872d071c
R13: 00007efd8729d4dc R14: 00007efd8727e0c0 R15: 0031656c69662f2e
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8c91f220 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/3259:
 #0: ffff88802423a098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc9000249b2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6af/0x1db0 drivers/tty/n_tty.c:2158
2 locks held by syz-executor362/3543:
 #0: ffff88801ae07118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff8881476e2468 (&lo->lo_mutex){+.+.}-{3:3}, at: __loop_clr_fd+0xa9/0xbe0 drivers/block/loop.c:1365
2 locks held by syz-executor362/3544:
 #0: ffff88801ae0b918 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff8881476e5468 (&lo->lo_mutex){+.+.}-{3:3}, at: __loop_clr_fd+0xa9/0xbe0 drivers/block/loop.c:1365
2 locks held by syz-executor362/3545:
 #0: ffff88801ae20118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff88801ae18468 (&lo->lo_mutex){+.+.}-{3:3}, at: __loop_clr_fd+0xa9/0xbe0 drivers/block/loop.c:1365
3 locks held by syz-executor362/3556:
 #0: ffff888078486460 (sb_writers#9){.+.+}-{0:0}, at: do_sendfile+0x600/0xff0 fs/read_write.c:1248
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:842 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_update_page mm/filemap.c:2435 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_get_pages mm/filemap.c:2574 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_read+0xaef/0x2980 mm/filemap.c:2634
 #2: ffff888070c54ac0 (&ni->ni_lock/4){+.+.}-{3:3}, at: ni_lock fs/ntfs3/ntfs_fs.h:1110 [inline]
 #2: ffff888070c54ac0 (&ni->ni_lock/4){+.+.}-{3:3}, at: ntfs_readpage+0x18f/0x210 fs/ntfs3/inode.c:724
3 locks held by syz-executor362/3566:
 #0: ffff888078486460 (sb_writers#9){.+.+}-{0:0}, at: do_sendfile+0x600/0xff0 fs/read_write.c:1248
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:842 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_update_page mm/filemap.c:2435 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_get_pages mm/filemap.c:2574 [inline]
 #1: ffff888070c54f00 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_read+0xaef/0x2980 mm/filemap.c:2634
 #2: ffff888070c54ac0 (&ni->ni_lock/4){+.+.}-{3:3}, at: ni_lock fs/ntfs3/ntfs_fs.h:1110 [inline]
 #2: ffff888070c54ac0 (&ni->ni_lock/4){+.+.}-{3:3}, at: ntfs_readpage+0x18f/0x210 fs/ntfs3/inode.c:724
3 locks held by syz-executor362/6361:
 #0: ffff88807a3c0460 (sb_writers#9){.+.+}-{0:0}, at: do_sendfile+0x600/0xff0 fs/read_write.c:1248
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:842 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_update_page mm/filemap.c:2435 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_get_pages mm/filemap.c:2574 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_read+0xaef/0x2980 mm/filemap.c:2634
 #2: ffff888070f0bc00 (&ni->ni_lock/4){+.+.}-{3:3}, at: ni_lock fs/ntfs3/ntfs_fs.h:1110 [inline]
 #2: ffff888070f0bc00 (&ni->ni_lock/4){+.+.}-{3:3}, at: ntfs_readpage+0x18f/0x210 fs/ntfs3/inode.c:724
3 locks held by syz-executor362/6368:
 #0: ffff88807a3c0460 (sb_writers#9){.+.+}-{0:0}, at: do_sendfile+0x600/0xff0 fs/read_write.c:1248
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:842 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_create_page mm/filemap.c:2498 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_get_pages mm/filemap.c:2558 [inline]
 #1: ffff888070f0c040 (mapping.invalidate_lock#3){.+.+}-{3:3}, at: filemap_read+0xd75/0x2980 mm/filemap.c:2634
 #2: ffff888070f0bc00 (&ni->ni_lock/4){+.+.}-{3:3}, at: ni_lock fs/ntfs3/ntfs_fs.h:1110 [inline]
 #2: ffff888070f0bc00 (&ni->ni_lock/4){+.+.}-{3:3}, at: ntfs_readpage+0x18f/0x210 fs/ntfs3/inode.c:724

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.148-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/25/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 nmi_cpu_backtrace+0x46a/0x4a0 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x181/0x2a0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xe72/0xeb0 kernel/hung_task.c:295
 kthread+0x3f6/0x4f0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 0 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 0 skipped: idling at acpi_safe_halt drivers/acpi/processor_idle.c:109 [inline]
NMI backtrace for cpu 0 skipped: idling at acpi_idle_do_entry+0x10f/0x340 drivers/acpi/processor_idle.c:570

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/02/22 16:23 linux-5.15.y 6139f2a02fe0 345111b5 .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan INFO: task hung in ni_readpage_cmpr
2024/02/13 07:31 linux-5.15.y 6139f2a02fe0 77b23aa1 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in ni_readpage_cmpr
* Struck through repros no longer work on HEAD.