syzbot


INFO: task hung in xlog_grant_head_check

Status: upstream: reported C repro on 2020/02/10 12:53
Subsystems: xfs
[Documentation on labels]
Reported-by: syzbot+79bf1b7904386a38a51a@syzkaller.appspotmail.com
First crash: 1596d, last: 522d
Fix bisection the fix commit could be any of (bisect log):
  78d697fc93f9 Linux 4.14.172
  4139fb08c05f Linux 4.14.187
  
Similar bugs (6)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 INFO: task hung in xlog_grant_head_check origin:upstream C error 153 2h27m 449d 0/3 upstream: reported C repro on 2023/04/02 19:36
linux-4.19 INFO: task hung in xlog_grant_head_check (3) xfs C 88 476d 558d 0/1 upstream: reported C repro on 2022/12/14 09:42
upstream INFO: task hung in xlog_grant_head_check no-reminders xfs C done error 995 17h42m 2226d 0/27 upstream: reported C repro on 2018/05/21 17:55
linux-5.15 INFO: task hung in xlog_grant_head_check origin:upstream C error 93 4h22m 457d 0/3 upstream: reported C repro on 2023/03/25 07:23
linux-4.19 INFO: task hung in xlog_grant_head_check 1 1825d 1825d 0/1 auto-closed as invalid on 2019/10/25 08:51
linux-4.19 INFO: task hung in xlog_grant_head_check (2) 3 1466d 1514d 0/1 auto-closed as invalid on 2020/10/17 16:39
Last patch testing requests (2)
Created Duration User Patch Repo Result
2022/09/09 07:27 9m retest repro linux-4.14.y report log
2022/09/09 06:27 8m retest repro linux-4.14.y report log
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2020/07/03 08:59 33m bisect fix linux-4.14.y job log (2)
2020/06/03 07:31 31m bisect fix linux-4.14.y job log (0) log

Sample crash report:
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): Starting recovery (logdev: internal)
INFO: task syz-executor158:7970 blocked for more than 140 seconds.
      Not tainted 4.14.302-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor158 D27312  7970   7969 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 xlog_grant_head_wait+0x12f/0xc10 fs/xfs/xfs_log.c:274
 xlog_grant_head_check+0x357/0x3a0 fs/xfs/xfs_log.c:336
 xfs_log_reserve+0x2fb/0x9e0 fs/xfs/xfs_log.c:465
 xfs_trans_reserve+0x5bb/0x940 fs/xfs/xfs_trans.c:176
 xfs_trans_alloc+0x1fc/0x320 fs/xfs/xfs_trans.c:255
 xlog_finish_defer_ops fs/xfs/xfs_log_recover.c:4833 [inline]
 xlog_recover_process_intents+0x1d2/0x3f0 fs/xfs/xfs_log_recover.c:4938
 xlog_recover_finish+0x52/0x210 fs/xfs/xfs_log_recover.c:5840
 xfs_log_mount_finish+0xd9/0x2d0 fs/xfs/xfs_log.c:789
 xfs_mountfs+0xeef/0x1f40 fs/xfs/xfs_mount.c:952
 xfs_fs_fill_super+0xb7a/0x1380 fs/xfs/xfs_super.c:1688
 mount_bdev+0x2b3/0x360 fs/super.c:1134
 mount_fs+0x92/0x2a0 fs/super.c:1237
 vfs_kern_mount.part.0+0x5b/0x470 fs/namespace.c:1046
 vfs_kern_mount fs/namespace.c:1036 [inline]
 do_new_mount fs/namespace.c:2572 [inline]
 do_mount+0xe65/0x2a30 fs/namespace.c:2905
 SYSC_mount fs/namespace.c:3121 [inline]
 SyS_mount+0xa8/0x120 fs/namespace.c:3098
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7f32598b85ca
RSP: 002b:00007fff621632d8 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
RAX: ffffffffffffffda RBX: 00646975756f6e2c RCX: 00007f32598b85ca
RDX: 000000002000bb00 RSI: 0000000020000040 RDI: 00007fff621632e0
RBP: 00007fff621632e0 R08: 00007fff62163320 R09: 0000000000000002
R10: 0000000000000003 R11: 0000000000000206 R12: 0000000000000004
R13: 0000555556f022c0 R14: 00007fff62163320 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1533:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff8702b3a4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
2 locks held by syz-executor158/7970:
 #0:  (&type->s_umount_key#46/1){+.+.}, at: [<ffffffff81879256>] alloc_super fs/super.c:251 [inline]
 #0:  (&type->s_umount_key#46/1){+.+.}, at: [<ffffffff81879256>] sget_userns+0x556/0xc10 fs/super.c:516
 #1:  (sb_internal#2){.+.+}, at: [<ffffffff825f0729>] sb_start_intwrite include/linux/fs.h:1598 [inline]
 #1:  (sb_internal#2){.+.+}, at: [<ffffffff825f0729>] xfs_trans_alloc+0x259/0x320 fs/xfs/xfs_trans.c:242

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

NMI backtrace for cpu 0
CPU: 0 PID: 1533 Comm: khungtaskd Not tainted 4.14.302-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Call Trace:
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x1b2/0x281 lib/dump_stack.c:58
 nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x13a/0x180 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
 watchdog+0x5b9/0xb40 kernel/hung_task.c:274
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:406
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 4620 Comm: systemd-journal Not tainted 4.14.302-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
task: ffff8880a1b38040 task.stack: ffff8880a1b40000
RIP: 0010:__lock_acquire+0x1d0/0x3f20 kernel/locking/lockdep.c:3369
RSP: 0018:ffff8880a1b47728 EFLAGS: 00000046
RAX: dffffc0000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 1ffffffff180e304 RSI: 0000000000000000 RDI: ffffffff8c071820
RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000001
R10: 0000000000000001 R11: ffff8880a1b38040 R12: ffffffff8c071820
R13: 0000000000000000 R14: 0000000000000001 R15: ffffffff8becfdc0
FS:  00007f77ead318c0(0000) GS:ffff8880ba500000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f77e8104000 CR3: 00000000a183f000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x8c/0xc0 kernel/locking/spinlock.c:160
 __debug_check_no_obj_freed lib/debugobjects.c:738 [inline]
 debug_check_no_obj_freed+0x135/0x680 lib/debugobjects.c:776
 free_pages_prepare mm/page_alloc.c:1064 [inline]
 __free_pages_ok+0x215/0xed0 mm/page_alloc.c:1262
 slab_destroy mm/slab.c:1723 [inline]
 slabs_destroy+0x90/0xd0 mm/slab.c:1739
 cache_flusharray mm/slab.c:3483 [inline]
 ___cache_free+0x213/0x2c0 mm/slab.c:3525
 qlink_free mm/kasan/quarantine.c:147 [inline]
 qlist_free_all+0x79/0x140 mm/kasan/quarantine.c:166
 quarantine_reduce+0x185/0x200 mm/kasan/quarantine.c:259
 kasan_kmalloc+0xa2/0x160 mm/kasan/kasan.c:536
 slab_post_alloc_hook mm/slab.h:442 [inline]
 slab_alloc mm/slab.c:3390 [inline]
 kmem_cache_alloc+0x111/0x3c0 mm/slab.c:3550
 prepare_creds+0x39/0x490 kernel/cred.c:255
 SYSC_faccessat fs/open.c:365 [inline]
 SyS_faccessat+0x7b/0x680 fs/open.c:353
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x5e/0xd3
RIP: 0033:0x7f77e9fec9c7
RSP: 002b:00007ffd8aaf5f28 EFLAGS: 00000246 ORIG_RAX: 0000000000000015
RAX: ffffffffffffffda RBX: 00007ffd8aaf8e40 RCX: 00007f77e9fec9c7
RDX: 00007f77eaa5da00 RSI: 0000000000000000 RDI: 00005620675209a3
RBP: 00007ffd8aaf5f60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000069 R11: 0000000000000246 R12: 0000000000000000
R13: 0000000000000000 R14: 00007ffd8aaf8e40 R15: 00007ffd8aaf6450
Code: 00 48 81 c4 80 01 00 00 44 89 e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 48 b8 00 00 00 00 00 fc ff df 4c 89 e2 48 c1 ea 03 80 3c 02 00 <0f> 85 67 2a 00 00 49 81 3c 24 e0 b7 2f 8b 0f 84 5f ff ff ff 83 

Crashes (10):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/01/01 13:04 linux-4.14.y c4215ee4771b ab32d508 .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-4-14 INFO: task hung in xlog_grant_head_check
2022/12/30 10:13 linux-4.14.y c4215ee4771b 44712fbc .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-4-14 INFO: task hung in xlog_grant_head_check
2020/03/10 01:05 linux-4.14.y 78d697fc93f9 35f53e45 .config console log report syz C ci2-linux-4-14
2020/02/10 14:36 linux-4.14.y e0f8b8a65a47 35f5e45e .config console log report syz C ci2-linux-4-14
2023/01/19 16:17 linux-4.14.y 97205fccccdc 66fca3ae .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-4-14 INFO: task hung in xlog_grant_head_check
2020/07/12 22:44 linux-4.14.y b850307b279c 9ebcc5b1 .config console log report ci2-linux-4-14
2020/05/04 06:56 linux-4.14.y 773e2b1cd56a 58ae5e18 .config console log report ci2-linux-4-14
2020/04/23 12:38 linux-4.14.y c10b57a567e4 2e44d63e .config console log report ci2-linux-4-14
2020/04/07 20:43 linux-4.14.y 4520f06b03ae db9bcd4b .config console log report ci2-linux-4-14
2020/02/10 12:52 linux-4.14.y e0f8b8a65a47 35f5e45e .config console log report ci2-linux-4-14
* Struck through repros no longer work on HEAD.