syzbot


INFO: task hung in page_cache_ra_unbounded

Status: closed as invalid on 2022/02/08 09:40
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 375d, last: 356d

Sample crash report:
INFO: task syz-executor.2:15177 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc5-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:24240 pid:15177 ppid:  3631 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6253
 schedule+0x12b/0x1f0 kernel/sched/core.c:6326
 rwsem_down_read_slowpath+0x5e2/0xb00 kernel/locking/rwsem.c:1041
 __down_read_common+0xaa/0x450 kernel/locking/rwsem.c:1223
 filemap_invalidate_lock_shared include/linux/fs.h:838 [inline]
 page_cache_ra_unbounded+0x1b8/0x9f0 mm/readahead.c:194
 page_cache_async_readahead include/linux/pagemap.h:1052 [inline]
 do_async_mmap_readahead+0x44b/0x5a0 mm/filemap.c:3023
 filemap_fault+0x22f/0x1630 mm/filemap.c:3079
 __do_fault+0x130/0x420 mm/memory.c:3849
 do_read_fault+0x3be/0x650 mm/memory.c:4164
 do_fault mm/memory.c:4293 [inline]
 handle_pte_fault mm/memory.c:4551 [inline]
 __handle_mm_fault mm/memory.c:4686 [inline]
 handle_mm_fault+0x1849/0x2560 mm/memory.c:4784
 faultin_page mm/gup.c:939 [inline]
 __get_user_pages+0x519/0x11f0 mm/gup.c:1160
 populate_vma_page_range+0x217/0x2a0 mm/gup.c:1492
 __mm_populate+0x2ea/0x4d0 mm/gup.c:1601
 mm_populate include/linux/mm.h:2734 [inline]
 vm_mmap_pgoff+0x241/0x2f0 mm/util.c:524
 ksys_mmap_pgoff+0x499/0x6f0 mm/mmap.c:1623
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ffbe8bbae99
RSP: 002b:00007ffbe7530168 EFLAGS: 00000246 ORIG_RAX: 0000000000000009
RAX: ffffffffffffffda RBX: 00007ffbe8ccdf60 RCX: 00007ffbe8bbae99
RDX: 0000000001000002 RSI: 0000000000b36000 RDI: 0000000020000000
RBP: 00007ffbe8c14ff1 R08: 0000000000000004 R09: 0000000000000000
R10: 0000000000028011 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffca95c8e8f R14: 00007ffbe7530300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor.4:15193 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc5-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4  state:D stack:28016 pid:15193 ppid:  3632 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6253
 schedule+0x12b/0x1f0 kernel/sched/core.c:6326
 rwsem_down_write_slowpath+0xdb7/0x1480 kernel/locking/rwsem.c:1151
 __down_write_common kernel/locking/rwsem.c:1268 [inline]
 __down_write kernel/locking/rwsem.c:1277 [inline]
 down_write+0x163/0x170 kernel/locking/rwsem.c:1524
 filemap_invalidate_lock include/linux/fs.h:828 [inline]
 blkdev_fallocate+0x21f/0x390 block/fops.c:625
 vfs_fallocate+0x54a/0x930 fs/open.c:307
 madvise_remove+0x221/0x290 mm/madvise.c:925
 madvise_vma mm/madvise.c:987 [inline]
 do_madvise+0x7f9/0x1610 mm/madvise.c:1202
 __do_sys_madvise mm/madvise.c:1228 [inline]
 __se_sys_madvise mm/madvise.c:1226 [inline]
 __x64_sys_madvise+0xa2/0xb0 mm/madvise.c:1226
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fc95894ee99
RSP: 002b:00007fc9572a3168 EFLAGS: 00000246 ORIG_RAX: 000000000000001c
RAX: ffffffffffffffda RBX: 00007fc958a62030 RCX: 00007fc95894ee99
RDX: 0000000000000009 RSI: 0000000000600003 RDI: 0000000020000000
RBP: 00007fc9589a8ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffea1dc8aaf R14: 00007fc9572a3300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8cb1de40 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
3 locks held by kworker/u4:4/961:
2 locks held by getty/3281:
 #0: ffff88814aa55098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc90002b962e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6c5/0x1c60 drivers/tty/n_tty.c:2113
1 lock held by syz-executor.2/15177:
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:838 [inline]
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: page_cache_ra_unbounded+0x1b8/0x9f0 mm/readahead.c:194
1 lock held by syz-executor.4/15186:
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: filemap_invalidate_lock_shared include/linux/fs.h:838 [inline]
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: page_cache_ra_unbounded+0x1b8/0x9f0 mm/readahead.c:194
1 lock held by syz-executor.4/15193:
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: filemap_invalidate_lock include/linux/fs.h:828 [inline]
 #0: ffff88801776e788 (mapping.invalidate_lock#2){++++}-{3:3}, at: blkdev_fallocate+0x21f/0x390 block/fops.c:625

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc5-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+0x1dc/0x2d8 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x16a/0x280 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+0xc82/0xcd0 kernel/hung_task.c:295
 kthread+0x468/0x490 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 2960 Comm: klogd Not tainted 5.16.0-rc5-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:unwind_next_frame+0x42/0x1fc0 arch/x86/kernel/unwind_orc.c:419
Code: 00 00 00 fc ff df 48 8d 5f 48 48 89 d8 48 c1 e8 03 48 89 44 24 38 42 80 3c 38 00 74 08 48 89 df e8 53 a9 95 00 48 89 5c 24 08 <4d> 8b 75 48 4d 8d 65 38 4c 89 e3 48 c1 eb 03 42 80 3c 3b 00 74 08
RSP: 0018:ffffc90001adef20 EFLAGS: 00000246
RAX: 1ffff9200035be05 RBX: ffffc90001adf028 RCX: ffffffff8f33c000
RDX: dffffc0000000000 RSI: ffffffff81d7497f RDI: ffffc90001adefe0
RBP: ffffc90001adf070 R08: 0000000000000000 R09: ffffc90001adf0d0
R10: fffff5200035be08 R11: 0000000000000000 R12: ffff88807dc51d00
R13: ffffc90001adefe0 R14: ffffc90001adf0c0 R15: dffffc0000000000
FS:  00007ff8f86fc800(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffd72f03008 CR3: 00000000241c6000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 arch_stack_walk+0x112/0x140 arch/x86/kernel/stacktrace.c:25
 stack_trace_save+0x11b/0x1e0 kernel/stacktrace.c:122
 save_stack+0xff/0x200 mm/page_owner.c:119
 __reset_page_owner+0x51/0x1a0 mm/page_owner.c:140
 reset_page_owner include/linux/page_owner.h:24 [inline]
 free_pages_prepare mm/page_alloc.c:1338 [inline]
 free_pcp_prepare+0xd1c/0xe00 mm/page_alloc.c:1389
 free_unref_page_prepare mm/page_alloc.c:3309 [inline]
 free_unref_page+0x7d/0x580 mm/page_alloc.c:3388
 free_slab mm/slub.c:2033 [inline]
 discard_slab mm/slub.c:2039 [inline]
 __unfreeze_partials+0x1ab/0x200 mm/slub.c:2527
 put_cpu_partial+0x116/0x180 mm/slub.c:2603
 do_slab_free mm/slub.c:3501 [inline]
 ___cache_free+0xe6/0x120 mm/slub.c:3520
 qlist_free_all mm/kasan/quarantine.c:165 [inline]
 kasan_quarantine_reduce+0x151/0x1c0 mm/kasan/quarantine.c:272
 __kasan_slab_alloc+0x2f/0xf0 mm/kasan/common.c:444
 kasan_slab_alloc include/linux/kasan.h:259 [inline]
 slab_post_alloc_hook mm/slab.h:519 [inline]
 slab_alloc_node mm/slub.c:3234 [inline]
 __kmalloc_node_track_caller+0x21d/0x400 mm/slub.c:4956
 kmalloc_reserve net/core/skbuff.c:354 [inline]
 __alloc_skb+0x127/0x5a0 net/core/skbuff.c:426
 alloc_skb include/linux/skbuff.h:1126 [inline]
 alloc_skb_with_frags+0xab/0x660 net/core/skbuff.c:6078
 sock_alloc_send_pskb+0x928/0xa60 net/core/sock.c:2575
 unix_dgram_sendmsg+0x816/0x2a50 net/unix/af_unix.c:1811
 sock_sendmsg_nosec net/socket.c:704 [inline]
 sock_sendmsg net/socket.c:724 [inline]
 __sys_sendto+0x42e/0x5b0 net/socket.c:2036
 __do_sys_sendto net/socket.c:2048 [inline]
 __se_sys_sendto net/socket.c:2044 [inline]
 __x64_sys_sendto+0xda/0xf0 net/socket.c:2044
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ff8f88980ac
Code: 89 02 48 c7 c0 ff ff ff ff eb b8 0f 1f 00 41 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 19 45 31 c9 45 31 c0 b8 2c 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 64 c3 0f 1f 00 55 48 83 ec 20 48 89 54 24 10
RSP: 002b:00007ffd65aae908 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007ff8f88980ac
RDX: 0000000000000076 RSI: 000055b9fa6fc600 RDI: 0000000000000003
RBP: 000055b9fa6f5910 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000004000 R11: 0000000000000246 R12: 0000000000000014
R13: 0000000000000001 R14: 00007ff8f8a1377d R15: 00007ffd65aaea18
 </TASK>
----------------
Code disassembly (best guess), 5 bytes skipped:
   0:	df 48 8d             	fisttps -0x73(%rax)
   3:	5f                   	pop    %rdi
   4:	48                   	rex.W
   5:	48 89 d8             	mov    %rbx,%rax
   8:	48 c1 e8 03          	shr    $0x3,%rax
   c:	48 89 44 24 38       	mov    %rax,0x38(%rsp)
  11:	42 80 3c 38 00       	cmpb   $0x0,(%rax,%r15,1)
  16:	74 08                	je     0x20
  18:	48 89 df             	mov    %rbx,%rdi
  1b:	e8 53 a9 95 00       	callq  0x95a973
  20:	48 89 5c 24 08       	mov    %rbx,0x8(%rsp)
* 25:	4d 8b 75 48          	mov    0x48(%r13),%r14 <-- trapping instruction
  29:	4d 8d 65 38          	lea    0x38(%r13),%r12
  2d:	4c 89 e3             	mov    %r12,%rbx
  30:	48 c1 eb 03          	shr    $0x3,%rbx
  34:	42 80 3c 3b 00       	cmpb   $0x0,(%rbx,%r15,1)
  39:	74 08                	je     0x43

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-smack-root 2021/12/15 12:28 upstream 5472f14a3742 f752fb53 .config log report info INFO: task hung in page_cache_ra_unbounded
ci-upstream-kasan-gce-smack-root 2021/11/25 16:53 upstream 5f53fa508db0 545ab074 .config log report info INFO: task hung in page_cache_ra_unbounded
* Struck through repros no longer work on HEAD.