bisecting fixing commit since f35111a946548e3b34a55abbad3e9bacce6cb10f
building syzkaller on 35f53e457420e79fa28e3260cdbbf9f37b9f97e4
testing commit f35111a946548e3b34a55abbad3e9bacce6cb10f with gcc (GCC) 8.1.0
kernel signature: b8dd5bb9f66f7b1dbb24724f99ec11e95a78dfbe5a1d97bb93506eea5673aa8f
all runs: crashed: INFO: task hung in xlog_grant_head_check
testing current HEAD c0cc271173b2e1c2d8d0ceaef14e4dfa79eefc0d
testing commit c0cc271173b2e1c2d8d0ceaef14e4dfa79eefc0d with gcc (GCC) 8.1.0
kernel signature: ef556a9ccda04be08030b3166cde0e9e4b831f3d4540400aecd7b429dd1b036d
all runs: crashed: INFO: task hung in xlog_grant_head_check
revisions tested: 2, total time: 24m46.336164422s (build: 12m16.507016087s, test: 11m56.805447192s)
the crash still happens on HEAD
commit msg: Merge tag 'modules-for-v5.7' of git://git.kernel.org/pub/scm/linux/kernel/git/jeyu/linux
crash: INFO: task hung in xlog_grant_head_check
INFO: task syz-executor.1:8580 blocked for more than 143 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D26848 8580 7318 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007f63f48a6a68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007f63f48a76d4 RCX: 000000000045eefa
RDX: 00007f63f48a6ae0 RSI: 0000000020000000 RDI: 00007f63f48a6b00
RBP: 000000000076bf20 R08: 00007f63f48a6b40 R09: 00007f63f48a6ae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
INFO: task syz-executor.0:8590 blocked for more than 143 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.0 D26848 8590 7316 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007fd05715da68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007fd05715e6d4 RCX: 000000000045eefa
RDX: 00007fd05715dae0 RSI: 0000000020000000 RDI: 00007fd05715db00
RBP: 000000000076bf20 R08: 00007fd05715db40 R09: 00007fd05715dae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
INFO: task syz-executor.2:8606 blocked for more than 144 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2 D26848 8606 7314 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007f7284fe0a68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007f7284fe16d4 RCX: 000000000045eefa
RDX: 00007f7284fe0ae0 RSI: 0000000020000000 RDI: 00007f7284fe0b00
RBP: 000000000076bf20 R08: 00007f7284fe0b40 R09: 00007f7284fe0ae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
INFO: task syz-executor.4:8626 blocked for more than 144 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D26848 8626 7322 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007ff84b12aa68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007ff84b12b6d4 RCX: 000000000045eefa
RDX: 00007ff84b12aae0 RSI: 0000000020000000 RDI: 00007ff84b12ab00
RBP: 000000000076bf20 R08: 00007ff84b12ab40 R09: 00007ff84b12aae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
INFO: task syz-executor.3:8641 blocked for more than 144 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3 D26848 8641 7313 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007f2ceccf4a68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007f2ceccf56d4 RCX: 000000000045eefa
RDX: 00007f2ceccf4ae0 RSI: 0000000020000000 RDI: 00007f2ceccf4b00
RBP: 000000000076bf20 R08: 00007f2ceccf4b40 R09: 00007f2ceccf4ae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
INFO: task syz-executor.5:8645 blocked for more than 145 seconds.
Not tainted 5.6.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5 D26848 8645 7321 0x00004004
Call Trace:
schedule+0xc4/0x2b0 kernel/sched/core.c:4168
xlog_grant_head_wait+0x2e8/0xa30 fs/xfs/xfs_log.c:272
xlog_grant_head_check+0x250/0x350 fs/xfs/xfs_log.c:334
xfs_log_reserve+0x2e5/0x950 fs/xfs/xfs_log.c:459
xfs_log_write_unmount_record+0x17f/0x5f0 fs/xfs/xfs_log.c:904
xfs_log_unmount+0xe/0xa0 fs/xfs/xfs_log.c:1036
xfs_mountfs+0x102d/0x19a0 fs/xfs/xfs_mount.c:1022
xfs_fc_fill_super+0x6fd/0xf70 fs/xfs/xfs_super.c:1495
get_tree_bdev+0x3d7/0x640 fs/super.c:1342
vfs_get_tree+0x7e/0x2c0 fs/super.c:1547
do_new_mount fs/namespace.c:2816 [inline]
do_mount+0x10c5/0x17b0 fs/namespace.c:3141
__do_sys_mount fs/namespace.c:3350 [inline]
__se_sys_mount fs/namespace.c:3327 [inline]
__x64_sys_mount+0x15d/0x1b0 fs/namespace.c:3327
do_syscall_64+0xc6/0x620 arch/x86/entry/common.c:295
entry_SYSCALL_64_after_hwframe+0x49/0xb3
RIP: 0033:0x45eefa
Code: Bad RIP value.
RSP: 002b:00007ffa721baa68 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00007ffa721bb6d4 RCX: 000000000045eefa
RDX: 00007ffa721baae0 RSI: 0000000020000000 RDI: 00007ffa721bab00
RBP: 000000000076bf20 R08: 00007ffa721bab40 R09: 00007ffa721baae0
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000be9 R14: 00000000004cdd27 R15: 000000000076bf2c
Showing all locks held in the system:
2 locks held by kworker/u4:0/7:
#0: ffff8880ae837998 (&rq->lock){-.-.}-{2:2}, at: newidle_balance+0xa6f/0xe80 kernel/sched/fair.c:10516
#1: ffffffff88db4f80 (rcu_read_lock){....}-{1:2}, at: __update_idle_core+0x45/0x400 kernel/sched/fair.c:5978
1 lock held by khungtaskd/1138:
#0: ffffffff88db4f80 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x52/0x28d kernel/locking/lockdep.c:5743
1 lock held by in:imklog/6755:
#0: ffff8880993e48b0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x9c/0xb0 fs/file.c:826
1 lock held by syz-executor.1/8580:
#0: ffff8880881ce0e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
1 lock held by syz-executor.0/8590:
#0: ffff8880900d40e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
1 lock held by syz-executor.2/8606:
#0: ffff8880a7fc40e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
1 lock held by syz-executor.4/8626:
#0: ffff88808ea5c0e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
1 lock held by syz-executor.3/8641:
#0: ffff8880881640e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
1 lock held by syz-executor.5/8645:
#0: ffff888086b920e0 (&type->s_umount_key#62/1){+.+.}-{3:3}, at: alloc_super+0x19d/0x9b0 fs/super.c:229
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 1138 Comm: khungtaskd Not tainted 5.6.0-syzkaller #0
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+0x128/0x182 lib/dump_stack.c:118
nmi_cpu_backtrace.cold.7+0x4b/0x83 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x183/0x1ac lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:205 [inline]
watchdog+0x629/0xc70 kernel/hung_task.c:289
kthread+0x340/0x410 kernel/kthread.c:268
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.6.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:wg_expired_send_persistent_keepalive+0x0/0x60 drivers/net/wireguard/timers.c:140
Code: ff ff 48 8d bb f8 04 00 00 e8 4c 8a ff ff 48 8d bb 20 04 00 00 e8 b0 8e ff ff 48 89 df 5b e9 87 f4 ff ff 0f 1f 80 00 00 00 00 <48> b8 00 00 00 00 00 fc ff df 55 48 8d af 48 f6 ff ff 53 48 89 fb
RSP: 0018:ffffc90000007d30 EFLAGS: 00000202
RAX: ffffffff844469b0 RBX: ffff888087f489b8 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: ffffffff88db4ec0 RDI: ffff888087f489b8
RBP: ffffc90000007e00 R08: ffffed1015d07104 R09: ffffed1015d07104
R10: ffff8880ae83881b R11: ffffed1015d07103 R12: ffffc90000007d78
R13: 1ffff92000000fab R14: 0000000000000000 R15: ffffffff844469b0
FS: 0000000000000000(0000) GS:ffff8880ae800000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ff892833000 CR3: 00000000a7894000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
call_timer_fn+0x16f/0x580 kernel/time/timer.c:1405
expire_timers kernel/time/timer.c:1450 [inline]
__run_timers kernel/time/timer.c:1774 [inline]
run_timer_softirq+0xc8c/0x1170 kernel/time/timer.c:1787
__do_softirq+0x26e/0xa0c kernel/softirq.c:292
invoke_softirq kernel/softirq.c:373 [inline]
irq_exit+0x191/0x1d0 kernel/softirq.c:413
exiting_irq arch/x86/include/asm/apic.h:546 [inline]
smp_apic_timer_interrupt+0x1a1/0x5f0 arch/x86/kernel/apic/apic.c:1140
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61
Code: e9 57 ff ff ff 48 89 df e8 6f c7 75 fa e9 e6 fe ff ff 48 89 df e8 62 c7 75 fa eb 9c e9 07 00 00 00 0f 00 2d 84 33 61 00 fb f4 90 e9 07 00 00 00 0f 00 2d 74 33 61 00 f4 c3 cc cc 41 56 41 55
RSP: 0018:ffffffff88c07d90 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: dffffc0000000000 RCX: 0000000000000000
RDX: 1ffffffff11a8807 RSI: 0000000000000006 RDI: ffffffff88d44038
RBP: fffffbfff11a8805 R08: fffffbfff1190c81 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffffffff89bd3b80 R15: 0000000000000000
arch_safe_halt arch/x86/include/asm/paravirt.h:144 [inline]
default_idle+0x4c/0x340 arch/x86/kernel/process.c:697
cpuidle_idle_call kernel/sched/idle.c:154 [inline]
do_idle+0x470/0x680 kernel/sched/idle.c:269
cpu_startup_entry+0x14/0x20 kernel/sched/idle.c:361
start_kernel+0x6c1/0x6ff init/main.c:1004
secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:242