INFO: task hung in xlog_grant_head_check

18 views

Skip to first unread message

syzbot

unread,

Feb 10, 2020, 7:53:14 AM2/10/20

to syzkaller...@googlegroups.com

Hello,

syzbot found the following crash on:

HEAD commit: e0f8b8a6 Linux 4.14.170
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=12f7f25ee00000
kernel config: https://syzkaller.appspot.com/x/.config?x=633dd9db249084f5
dashboard link: https://syzkaller.appspot.com/bug?extid=79bf1b7904386a38a51a
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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+79bf1b...@syzkaller.appspotmail.com

NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
NOHZ: local_softirq_pending 08
INFO: task syz-executor.3:11956 blocked for more than 140 seconds.
Not tainted 4.14.170-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3 D27376 11956 7356 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
schedule+0x92/0x1c0 kernel/sched/core.c:3428
xlog_grant_head_wait+0x135/0xc10 fs/xfs/xfs_log.c:274
xlog_grant_head_check+0x374/0x3c0 fs/xfs/xfs_log.c:336
xfs_log_reserve+0x305/0xa20 fs/xfs/xfs_log.c:465
xfs_log_unmount_write fs/xfs/xfs_log.c:857 [inline]
xfs_log_quiesce+0x30e/0xa10 fs/xfs/xfs_log.c:983
xfs_log_unmount+0x22/0xb0 fs/xfs/xfs_log.c:997
xfs_log_mount_cancel+0x47/0x60 fs/xfs/xfs_log.c:800
xfs_mountfs+0x12ad/0x2170 fs/xfs/xfs_mount.c:1031
xfs_fs_fill_super+0xb94/0x1380 fs/xfs/xfs_super.c:1688
mount_bdev+0x2be/0x370 fs/super.c:1134
xfs_fs_mount+0x35/0x40 fs/xfs/xfs_super.c:1762
mount_fs+0x97/0x2a1 fs/super.c:1237
vfs_kern_mount.part.0+0x5e/0x3d0 fs/namespace.c:1046
vfs_kern_mount fs/namespace.c:1036 [inline]
do_new_mount fs/namespace.c:2549 [inline]
do_mount+0x417/0x27d0 fs/namespace.c:2879
SYSC_mount fs/namespace.c:3095 [inline]
SyS_mount+0xab/0x120 fs/namespace.c:3072
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45ddea
RSP: 002b:00007fd92d5f8a68 EFLAGS: 00000202 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007fd92d5f96d4 RCX: 000000000045ddea
RDX: 00007fd92d5f8ae0 RSI: 0000000020000140 RDI: 00007fd92d5f8b00
RBP: 000000000075bf20 R08: 00007fd92d5f8b40 R09: 00007fd92d5f8ae0
R10: 0000000000000000 R11: 0000000000000202 R12: 00000000ffffffff
R13: 0000000000000bb5 R14: 00000000004cc92a R15: 000000000075bf2c

Showing all locks held in the system:
1 lock held by khungtaskd/1058:
#0: (tasklist_lock){.+.+}, at: [<ffffffff81488cf8>] debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4544
1 lock held by rsyslogd/7187:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffff8196347b>] __fdget_pos+0xab/0xd0 fs/file.c:769
2 locks held by getty/7309:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7310:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7311:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7312:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7313:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7314:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
2 locks held by getty/7315:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156
1 lock held by syz-executor.3/11956:
#0: (&type->s_umount_key#64/1){+.+.}, at: [<ffffffff818ffe51>] alloc_super fs/super.c:251 [inline]
#0: (&type->s_umount_key#64/1){+.+.}, at: [<ffffffff818ffe51>] sget_userns+0x551/0xc30 fs/super.c:516

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

NMI backtrace for cpu 0
CPU: 0 PID: 1058 Comm: khungtaskd Not tainted 4.14.170-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x142/0x197 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x141/0x189 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:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5e7/0xb90 kernel/hung_task.c:274
kthread+0x319/0x430 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at pc 0xffffffff866933be

---
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#status for how to communicate with syzbot.

syzbot

unread,

Feb 10, 2020, 9:37:13 AM2/10/20

to syzkaller...@googlegroups.com

syzbot has found a reproducer for the following crash on:

HEAD commit: e0f8b8a6 Linux 4.14.170
git tree: linux-4.14.y

console output: https://syzkaller.appspot.com/x/log.txt?x=1757cca1e00000

kernel config: https://syzkaller.appspot.com/x/.config?x=633dd9db249084f5
dashboard link: https://syzkaller.appspot.com/bug?extid=79bf1b7904386a38a51a
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=10445431e00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=15d826b5e00000

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

XFS (loop0): Log size out of supported range.
XFS (loop0): Continuing onwards, but if log hangs are experienced then please report this message in the bug report.
XFS (loop0): totally zeroed log
XFS (loop0): failed to read root inode
INFO: task syz-executor745:7504 blocked for more than 140 seconds.

Not tainted 4.14.170-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

syz-executor745 D27376 7504 7502 0x00000000

Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
schedule+0x92/0x1c0 kernel/sched/core.c:3428
xlog_grant_head_wait+0x135/0xc10 fs/xfs/xfs_log.c:274
xlog_grant_head_check+0x374/0x3c0 fs/xfs/xfs_log.c:336
xfs_log_reserve+0x305/0xa20 fs/xfs/xfs_log.c:465
xfs_log_unmount_write fs/xfs/xfs_log.c:857 [inline]
xfs_log_quiesce+0x30e/0xa10 fs/xfs/xfs_log.c:983
xfs_log_unmount+0x22/0xb0 fs/xfs/xfs_log.c:997
xfs_log_mount_cancel+0x47/0x60 fs/xfs/xfs_log.c:800
xfs_mountfs+0x12ad/0x2170 fs/xfs/xfs_mount.c:1031
xfs_fs_fill_super+0xb94/0x1380 fs/xfs/xfs_super.c:1688
mount_bdev+0x2be/0x370 fs/super.c:1134
xfs_fs_mount+0x35/0x40 fs/xfs/xfs_super.c:1762
mount_fs+0x97/0x2a1 fs/super.c:1237
vfs_kern_mount.part.0+0x5e/0x3d0 fs/namespace.c:1046
vfs_kern_mount fs/namespace.c:1036 [inline]
do_new_mount fs/namespace.c:2549 [inline]
do_mount+0x417/0x27d0 fs/namespace.c:2879
SYSC_mount fs/namespace.c:3095 [inline]
SyS_mount+0xab/0x120 fs/namespace.c:3072
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7

RIP: 0033:0x44721a
RSP: 002b:00007ffc7fe044b8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007ffc7fe04690 RCX: 000000000044721a
RDX: 00007ffc7fe04500 RSI: 0000000020000140 RDI: 00007ffc7fe04520
RBP: 0000000000000000 R08: 00007ffc7fe04560 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000402500
R13: 0000000000402590 R14: 0000000000000000 R15: 0000000000000000

Showing all locks held in the system:

1 lock held by khungtaskd/1035:

#0: (tasklist_lock){.+.+}, at: [<ffffffff81488cf8>] debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4544

2 locks held by getty/7482:

#0: (&tty->ldisc_sem){++++}, at: [<ffffffff866928d3>] ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:376
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff834c38d6>] n_tty_read+0x1e6/0x17d0 drivers/tty/n_tty.c:2156

2 locks held by getty/7483:

2 locks held by getty/7484:

2 locks held by getty/7485:

2 locks held by getty/7486:

2 locks held by getty/7487:

2 locks held by getty/7488:

1 lock held by syz-executor745/7504:
#0: (&type->s_umount_key#51/1){+.+.}, at: [<ffffffff818ffe51>] alloc_super fs/super.c:251 [inline]
#0: (&type->s_umount_key#51/1){+.+.}, at: [<ffffffff818ffe51>] sget_userns+0x551/0xc30 fs/super.c:516

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

NMI backtrace for cpu 0

CPU: 0 PID: 1035 Comm: khungtaskd Not tainted 4.14.170-syzkaller #0

Reply all

Reply to author

Forward

0 new messages