INFO: task hung in do_vfs_ioctl

8 views
Skip to first unread message

syzbot

unread,
Apr 14, 2018, 1:02:03 PM4/14/18
to syzkaller-upst...@googlegroups.com
Hello,

syzbot hit the following crash on upstream commit
1bad9ce155a7c010a9a5f3261ad12a6a8eccfb2c (Fri Apr 13 19:27:11 2018 +0000)
Merge tag 'sh-for-4.17' of git://git.libc.org/linux-sh
syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=3675876c83947fbafd05

Unfortunately, I don't have any reproducer for this crash yet.
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=5052849029382144
Kernel config:
https://syzkaller.appspot.com/x/.config?id=-5947642240294114534
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
CC: [k...@vger.kernel.org linux-...@vger.kernel.org pbon...@redhat.com
rkr...@redhat.com]

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+367587...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed. See footer for
details.
If you forward the report, please keep this part and the footer.

INFO: task kworker/1:1:24 blocked for more than 120 seconds.
Not tainted 4.16.0+ #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1 D
18120 24 2 0x80000000
kvm_vcpu_ioctl+0x27e/0x12e0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:2712
Workqueue: events cgwb_release_workfn
Call Trace:
context_switch kernel/sched/core.c:2848 [inline]
__schedule+0x801/0x1e30 kernel/sched/core.c:3490
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x1cf/0x16a0 fs/ioctl.c:684
ksys_ioctl+0xa9/0xd0 fs/ioctl.c:701
SYSC_ioctl fs/ioctl.c:708 [inline]
SyS_ioctl+0x24/0x30 fs/ioctl.c:706
schedule+0xef/0x430 kernel/sched/core.c:3549
do_syscall_64+0x29e/0x9d0 arch/x86/entry/common.c:287
bit_wait+0x18/0x90 kernel/sched/wait_bit.c:197
__wait_on_bit+0xb3/0x130 kernel/sched/wait_bit.c:48
out_of_line_wait_on_bit+0x204/0x3a0 kernel/sched/wait_bit.c:63
wait_on_bit include/linux/wait_bit.h:76 [inline]
wb_shutdown+0x370/0x470 mm/backing-dev.c:366
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x455319
cgwb_release_workfn+0x87/0x750 mm/backing-dev.c:509
RSP: 002b:00007f2576bbcc68 EFLAGS: 00000246
process_one_work+0xc1e/0x1b50 kernel/workqueue.c:2145
ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f2576bbd6d4 RCX: 0000000000455319
RDX: 0000000020000080 RSI: 000000004008ae89 RDI: 0000000000000015
RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000263 R14: 00000000006f69e8 R15: 0000000000000000
worker_thread+0x1cc/0x1440 kernel/workqueue.c:2279
kthread+0x345/0x410 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411

Showing all locks held in the system:
2 locks held by kworker/1:1/24:
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at:
__write_once_size include/linux/compiler.h:215 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:57 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000009fceaa74 ((wq_completion)"events"){+.+.}, at:
process_one_work+0xaef/0x1b50 kernel/workqueue.c:2116
#1: 00000000dd936bb3 ((work_completion)(&wb->release_work)){+.+.}, at:
process_one_work+0xb46/0x1b50 kernel/workqueue.c:2120
2 locks held by khungtaskd/888:
#0: 000000005d8a19e4 (rcu_read_lock){....}, at:
check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
#0: 000000005d8a19e4 (rcu_read_lock){....}, at: watchdog+0x1ff/0xf60
kernel/hung_task.c:249
#1: 00000000950e23d0 (tasklist_lock){.+.+}, at:
debug_show_all_locks+0xde/0x34a kernel/locking/lockdep.c:4470
2 locks held by getty/4447:
#0: 00000000d9904e91 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000c95351e1 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4448:
#0: 000000007488013f (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 000000007f06b0c1 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4449:
#0: 0000000009dabb77 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000932836af (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4450:
#0: 00000000ee8d47b6 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 0000000025a58b30 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4451:
#0: 00000000ae7d1553 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000f6957bf8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4452:
#0: 000000006a56f8cc (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 000000008ea8cf2a (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/17132:
#0: 00000000e46ed2f2 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 0000000088c9925b (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
1 lock held by syz-executor1/19153:
#0: 000000005e950c1e (&vcpu->mutex){+.+.}, at: kvm_vcpu_ioctl+0x1e2/0x12e0
arch/x86/kvm/../../../virt/kvm/kvm_main.c:2542
1 lock held by syz-executor3/19140:
#0: 00000000d20be082 (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
1 lock held by syz-executor4/19151:
#0: 00000000253129b5 (&vcpu->mutex){+.+.}, at: kvm_vcpu_ioctl+0x1e2/0x12e0
arch/x86/kvm/../../../virt/kvm/kvm_main.c:2542

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

NMI backtrace for cpu 1
CPU: 1 PID: 888 Comm: khungtaskd Not tainted 4.16.0+ #1
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+0x1b9/0x294 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.4+0x19/0xce lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
check_hung_task kernel/hung_task.c:132 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:190 [inline]
watchdog+0xc10/0xf60 kernel/hung_task.c:249
kthread+0x345/0x410 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 19177 Comm: syz-executor2 Not tainted 4.16.0+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
RIP: 0010:unwind_next_frame.part.7+0x73/0x9c0
arch/x86/kernel/unwind_frame.c:282
RSP: 0018:ffff8801896f6bb8 EFLAGS: 00000096
RAX: ffffed00312ded7c RBX: ffff8801896f6cd0 RCX: 000000000000000a
RDX: dffffc0000000000 RSI: ffffffff81446881 RDI: ffff8801896f6cd0
RBP: ffff8801896f6ca8 R08: ffff8801896f6d08 R09: ffff8801ab6f4340
R10: ffffed00312deda4 R11: ffff8801896f6d27 R12: 1ffff100312ded7c
R13: 0000000000000000 R14: ffff8801ab6f4340 R15: ffff8801896f6d20
FS: 00007f2eb93e7700(0000) GS:ffff8801db000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000000217c000 CR3: 0000000192d42000 CR4: 00000000001426f0
DR0: 0000000020000000 DR1: 0000000020000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
unwind_next_frame+0x3e/0x50 arch/x86/kernel/unwind_frame.c:287
__save_stack_trace+0x6e/0xd0 arch/x86/kernel/stacktrace.c:44
save_stack_trace+0x1a/0x20 arch/x86/kernel/stacktrace.c:60
save_stack+0x43/0xd0 mm/kasan/kasan.c:448
set_track mm/kasan/kasan.c:460 [inline]
__kasan_slab_free+0x11a/0x170 mm/kasan/kasan.c:521
kasan_slab_free+0xe/0x10 mm/kasan/kasan.c:528
__cache_free mm/slab.c:3498 [inline]
kmem_cache_free+0x86/0x2d0 mm/slab.c:3756
ptlock_free+0x38/0x42 mm/memory.c:4721
pte_lock_deinit include/linux/mm.h:1819 [inline]
pgtable_page_dtor include/linux/mm.h:1851 [inline]
___pte_free_tlb+0x52/0xc0 arch/x86/mm/pgtable.c:58
__pte_free_tlb arch/x86/include/asm/pgalloc.h:73 [inline]
free_pte_range mm/memory.c:446 [inline]
free_pmd_range mm/memory.c:464 [inline]
free_pud_range mm/memory.c:498 [inline]
free_p4d_range mm/memory.c:532 [inline]
free_pgd_range+0xc1d/0xf30 mm/memory.c:612
free_pgtables+0x2c3/0x380 mm/memory.c:644
exit_mmap+0x2ca/0x570 mm/mmap.c:3057
__mmput kernel/fork.c:962 [inline]
mmput+0x251/0x610 kernel/fork.c:983
exit_mm kernel/exit.c:544 [inline]
do_exit+0xe98/0x2730 kernel/exit.c:852
do_group_exit+0x16f/0x430 kernel/exit.c:968
get_signal+0x886/0x1960 kernel/signal.c:2469
do_signal+0x98/0x2040 arch/x86/kernel/signal.c:810
exit_to_usermode_loop+0x28a/0x310 arch/x86/entry/common.c:162
prepare_exit_to_usermode arch/x86/entry/common.c:196 [inline]
syscall_return_slowpath+0x516/0x5c0 arch/x86/entry/common.c:265
ret_from_fork+0x15/0x50 arch/x86/entry/entry_64.S:404
RIP: 0033:0x457ca9
RSP: 002b:00007f2eb93e6db0 EFLAGS: 00000202 ORIG_RAX: 0000000000000038
RAX: 0000000000000000 RBX: 00007f2eb93e7700 RCX: 0000000000457ca9
RDX: 00007f2eb93e79d0 RSI: 00007f2eb93e6db0 RDI: 00000000003d0f00
RBP: 0000000000a3e8a0 R08: 00007f2eb93e7700 R09: 00007f2eb93e7700
R10: 00007f2eb93e79d0 R11: 0000000000000202 R12: 0000000000000000
R13: 0000000000a3e81f R14: 00007f2eb93e79c0 R15: 0000000000000001
Code: ff 17 c0 77 88 48 c7 85 48 ff ff ff b0 54 34 81 c7 00 f1 f1 f1 f1 c7
40 04 00 f2 f2 f2 c7 40 08 f2 f2 f2 f2 c7 40 0c 00 f2 f2 f2 <c7> 40 10 f3
f3 f3 f3 4c 89 f8 48 c1 e8 03 80 3c 10 00 0f 85 75
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.025
msecs


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@googlegroups.com.

syzbot will keep track of this bug report.
If you forgot to add the Reported-by tag, once the fix for this bug is
merged
into any tree, please reply to this email with:
#syz fix: exact-commit-title
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug
report.
Note: all commands must start from beginning of the line in the email body.
To upstream this report, please reply with:
#syz upstream
Reply all
Reply to author
Forward
0 new messages