INFO: task hung in blk_trace_ioctl

4 views
Skip to first unread message

syzbot

unread,
Sep 17, 2018, 5:23:04 PM9/17/18
to syzkaller-upst...@googlegroups.com
Hello,

syzbot found the following crash on:

HEAD commit: 090b75bcba62 Merge tag 'devicetree-fixes-for-4.19-2' of gi..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=10fd86c6400000
kernel config: https://syzkaller.appspot.com/x/.config?x=9c4a80625153107e
dashboard link: https://syzkaller.appspot.com/bug?extid=e2ed26ec4d1d80c8a2d9
compiler: gcc (GCC) 8.0.1 20180413 (experimental)
userspace arch: i386
CC: [ax...@kernel.dk linux...@vger.kernel.org
linux-...@vger.kernel.org mi...@redhat.com ros...@goodmis.org]

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+e2ed26...@syzkaller.appspotmail.com

INFO: task syz-executor1:8616 blocked for more than 140 seconds.
Not tainted 4.19.0-rc3+ #140
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor1 D25312 8616 5375 0x20020004
Call Trace:
context_switch kernel/sched/core.c:2825 [inline]
__schedule+0x86c/0x1ed0 kernel/sched/core.c:3473
schedule+0xfe/0x460 kernel/sched/core.c:3517
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3575
__mutex_lock_common kernel/locking/mutex.c:1003 [inline]
__mutex_lock+0xbfb/0x1710 kernel/locking/mutex.c:1073
mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1088
blk_trace_ioctl+0xeb/0x2f0 kernel/trace/blktrace.c:711
compat_blkdev_ioctl+0x99f/0x1b30 block/compat_ioctl.c:402
__do_compat_sys_ioctl fs/compat_ioctl.c:1419 [inline]
__se_compat_sys_ioctl fs/compat_ioctl.c:1365 [inline]
__ia32_compat_sys_ioctl+0x20e/0x630 fs/compat_ioctl.c:1365
do_syscall_32_irqs_on arch/x86/entry/common.c:326 [inline]
do_fast_syscall_32+0x34d/0xfb2 arch/x86/entry/common.c:397
entry_SYSENTER_compat+0x70/0x7f arch/x86/entry/entry_64_compat.S:139
RIP: 0023:0xf7f20ca9
Code: Bad RIP value.
RSP: 002b:00000000f5e770cc EFLAGS: 00000296 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00000000c0401273
RDX: 0000000020000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/984:
#0: 000000002daf40cf (rcu_read_lock){....}, at:
debug_show_all_locks+0xd0/0x424 kernel/locking/lockdep.c:4436
1 lock held by rsyslogd/5238:
#0: 00000000c26227b9 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200
fs/file.c:766
2 locks held by getty/5328:
#0: 00000000cdd88dd6 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 00000000d6542c8d (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5329:
#0: 00000000db035720 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000005d1fedd0 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5330:
#0: 000000005be091c0 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000001bc78629 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5331:
#0: 0000000009963e61 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000007faf05ac (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5332:
#0: 00000000bbc9f98c (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000004def5e06 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5333:
#0: 0000000069a4a808 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 000000000dc82a72 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/5334:
#0: 0000000099c41288 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:353
#1: 0000000053551e12 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
3 locks held by syz-executor1/8576:
1 lock held by syz-executor1/8616:
#0: 000000009db690bf (&q->blk_trace_mutex){+.+.}, at:
blk_trace_ioctl+0xeb/0x2f0 kernel/trace/blktrace.c:711

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

NMI backtrace for cpu 0
CPU: 0 PID: 984 Comm: khungtaskd Not tainted 4.19.0-rc3+ #140
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+0x1c4/0x2b4 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.3+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b3/0x1ed 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:144 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
watchdog+0xb3e/0x1050 kernel/hung_task.c:265
kthread+0x35a/0x420 kernel/kthread.c:246
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 8576 Comm: syz-executor1 Not tainted 4.19.0-rc3+ #140
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x50 kernel/kcov.c:146
Code: 14 dd 28 00 00 00 4d 39 d0 72 1b 49 83 c1 01 4a 89 7c 10 e0 4a 89 74
10 e8 4a 89 54 10 f0 4a 89 4c d8 20 4c 89 08 5d c3 66 90 <55> 48 89 e5 65
48 8b 04 25 40 ee 01 00 65 8b 15 8c 1d 83 7e 81 e2
RSP: 0018:ffff8801daf07d78 EFLAGS: 00000002
RAX: 0000000080010000 RBX: ffff8801daf1f140 RCX: ffffffff817088c5
RDX: 0000000000000726 RSI: 0000000000000000 RDI: 0000000000000007
RBP: ffff8801daf07da8 R08: ffff880192460240 R09: 0000000000000006
R10: fffffbfff14fba09 R11: 0000000000000001 R12: 0000000000000726
R13: 0000000000000000 R14: 0000000000000000 R15: 7fffffffffffffff
FS: 0000000000000000(0000) GS:ffff8801daf00000(0063) knlGS:00000000f5eb9b40
CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
CR2: 00000000f7f20c7f CR3: 00000001d2b20000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
tick_program_event+0xb7/0x130 kernel/time/tick-oneshot.c:48
hrtimer_interrupt+0x368/0x780 kernel/time/hrtimer.c:1531
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1029 [inline]
smp_apic_timer_interrupt+0x1a1/0x760 arch/x86/kernel/apic/apic.c:1054
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:864
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:788
[inline]
RIP: 0010:lock_acquire+0x268/0x520 kernel/locking/lockdep.c:3904
Code: 00 00 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 44 02 00 00 48 83 3d cf
38 f1 07 00 0f 84 c3 01 00 00 48 8b bd 20 ff ff ff 57 9d <0f> 1f 44 00 00
48 b8 00 00 00 00 00 fc ff df 48 01 c3 48 c7 03 00
RSP: 0018:ffff8801932b74a0 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: 1ffff10032656e99 RCX: 0000000000000000
RDX: 1ffffffff12a453d RSI: 0000000000000000 RDI: 0000000000000282
RBP: ffff8801932b7590 R08: ffff880192460b30 R09: 0000000000000002
R10: ffff880192460b10 R11: 075286450d921dd9 R12: ffff880192460240
R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000000
__fs_reclaim_acquire mm/page_alloc.c:3728 [inline]
fs_reclaim_acquire.part.97+0x24/0x30 mm/page_alloc.c:3739
fs_reclaim_acquire mm/page_alloc.c:3738 [inline]
prepare_alloc_pages mm/page_alloc.c:4321 [inline]
__alloc_pages_nodemask+0x43e/0xde0 mm/page_alloc.c:4364
alloc_pages_current+0x10c/0x210 mm/mempolicy.c:2093
alloc_pages include/linux/gfp.h:509 [inline]
relay_alloc_buf kernel/relay.c:136 [inline]
relay_create_buf kernel/relay.c:177 [inline]
relay_open_buf.part.10+0x2ab/0xb20 kernel/relay.c:450
relay_open_buf kernel/relay.c:447 [inline]
relay_open+0x5e9/0xac0 kernel/relay.c:597
do_blk_trace_setup+0x4fb/0xda0 kernel/trace/blktrace.c:532
compat_blk_trace_setup+0x3d3/0x710 kernel/trace/blktrace.c:623
blk_trace_ioctl+0x298/0x2f0 kernel/trace/blktrace.c:721
compat_blkdev_ioctl+0x99f/0x1b30 block/compat_ioctl.c:402
__do_compat_sys_ioctl fs/compat_ioctl.c:1419 [inline]
__se_compat_sys_ioctl fs/compat_ioctl.c:1365 [inline]
__ia32_compat_sys_ioctl+0x20e/0x630 fs/compat_ioctl.c:1365
do_syscall_32_irqs_on arch/x86/entry/common.c:326 [inline]
do_fast_syscall_32+0x34d/0xfb2 arch/x86/entry/common.c:397
entry_SYSENTER_compat+0x70/0x7f arch/x86/entry/entry_64_compat.S:139
RIP: 0023:0xf7f20ca9
Code: 85 d2 74 02 89 0a 5b 5d c3 8b 04 24 c3 8b 0c 24 c3 8b 1c 24 c3 90 90
90 90 90 90 90 90 90 90 90 90 51 52 55 89 e5 0f 34 cd 80 <5d> 5a 59 c3 90
90 90 90 eb 0d 90 90 90 90 90 90 90 90 90 90 90 90
RSP: 002b:00000000f5eb90cc EFLAGS: 00000296 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00000000c0401273
RDX: 0000000020000340 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with
syzbot.

syzbot

unread,
Jun 4, 2019, 4:29:04 AM6/4/19
to syzkaller-upst...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages