Re: INFO: task hung in filemap_fault

From: Tetsuo Handa
Date: Mon Dec 18 2017 - 09:52:26 EST


On 2017/12/18 17:43, syzbot wrote:
> Hello,
>
> syzkaller hit the following crash on 6084b576dca2e898f5c101baef151f7bfdbb606d
> git://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/master
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached
> Raw console output is attached.
>
> Unfortunately, I don't have any reproducer for this bug yet.
>

This log has a lot of mmap() but also has Android's binder messages.

r9 = syz_open_dev$binder(&(0x7f0000000000)='/dev/binder#\x00', 0x0, 0x800)

[ 49.200735] binder: 9749:9755 IncRefs 0 refcount change on invalid ref 2 ret -22
[ 49.221514] binder: 9749:9755 Acquire 1 refcount change on invalid ref 4 ret -22
[ 49.233325] binder: 9749:9755 Acquire 1 refcount change on invalid ref 0 ret -22
[ 49.241979] binder: binder_mmap: 9749 205a3000-205a7000 bad vm_flags failed -1
[ 49.256949] binder: 9749:9755 unknown command 0
[ 49.262470] binder: 9749:9755 ioctl c0306201 20000fd0 returned -22
[ 49.293365] binder: 9749:9755 IncRefs 0 refcount change on invalid ref 2 ret -22
[ 49.301297] binder: binder_mmap: 9749 205a3000-205a7000 bad vm_flags failed -1
[ 49.314146] binder: 9749:9755 Acquire 1 refcount change on invalid ref 4 ret -22
[ 49.322732] binder: 9749:9755 Acquire 1 refcount change on invalid ref 0 ret -22
[ 49.332063] binder: 9749:9755 Release 1 refcount change on invalid ref 1 ret -22
[ 49.340796] binder: 9749:9755 Acquire 1 refcount change on invalid ref 2 ret -22
[ 49.349457] binder: 9749:9755 BC_DEAD_BINDER_DONE 0000000000000001 not found
[ 49.349462] binder: 9749:9755 BC_DEAD_BINDER_DONE 0000000000000000 not found

[ 246.752088] INFO: task syz-executor7:10280 blocked for more than 120 seconds.

Anything that hung after uptime > 46.75 can be reported at uptime = 246.75, can't it?

Is it possible to reproduce this problem by running the same program?

>
> INFO: task syz-executor7:10280 blocked for more than 120 seconds.
> ÂÂÂÂÂ Not tainted 4.15.0-rc3-next-20171214+ #67
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor7ÂÂ DÂÂÂ 0 10280ÂÂ 3310 0x00000004
> Call Trace:
> Âcontext_switch kernel/sched/core.c:2800 [inline]
> Â__schedule+0x30b/0xaf0 kernel/sched/core.c:3376
> Âschedule+0x2e/0x90 kernel/sched/core.c:3435
> Âio_schedule+0x11/0x40 kernel/sched/core.c:5043
> Âwait_on_page_bit_common mm/filemap.c:1099 [inline]
> Âwait_on_page_bit mm/filemap.c:1132 [inline]
> Âwait_on_page_locked include/linux/pagemap.h:530 [inline]
> Â__lock_page_or_retry+0x391/0x3e0 mm/filemap.c:1310
> Âlock_page_or_retry include/linux/pagemap.h:510 [inline]
> Âfilemap_fault+0x61c/0xa70 mm/filemap.c:2532
> Â__do_fault+0x23/0xa4 mm/memory.c:3206
> Âdo_read_fault mm/memory.c:3616 [inline]
> Âdo_fault mm/memory.c:3716 [inline]
> Âhandle_pte_fault mm/memory.c:3947 [inline]
> Â__handle_mm_fault+0x10b5/0x1930 mm/memory.c:4071
> Âhandle_mm_fault+0x215/0x450 mm/memory.c:4108
> Âfaultin_page mm/gup.c:502 [inline]
> Â__get_user_pages+0x1ff/0x980 mm/gup.c:699
> Âpopulate_vma_page_range+0xa1/0xb0 mm/gup.c:1200
> Â__mm_populate+0xcc/0x190 mm/gup.c:1250
> Âmm_populate include/linux/mm.h:2233 [inline]
> Âvm_mmap_pgoff+0x103/0x110 mm/util.c:338
> ÂSYSC_mmap_pgoff mm/mmap.c:1533 [inline]
> ÂSyS_mmap_pgoff+0x215/0x2c0 mm/mmap.c:1491
> ÂSYSC_mmap arch/x86/kernel/sys_x86_64.c:100 [inline]
> ÂSyS_mmap+0x16/0x20 arch/x86/kernel/sys_x86_64.c:91
> Âentry_SYSCALL_64_fastpath+0x1f/0x96
> RIP: 0033:0x452a09
> RSP: 002b:00007efce66dac58 EFLAGS: 00000212 ORIG_RAX: 0000000000000009
> RAX: ffffffffffffffda RBX: 000000000071bea0 RCX: 0000000000452a09
> RDX: 0000000000000003 RSI: 0000000000001000 RDI: 0000000020e5b000
> RBP: 0000000000000033 R08: 0000000000000016 R09: 0000000000000000
> R10: 0000000000002011 R11: 0000000000000212 R12: 00000000006ed568
> R13: 00000000ffffffff R14: 00007efce66db6d4 R15: 0000000000000000