syzbot


INFO: task hung in flush_old_commits

Status: upstream: reported C repro on 2023/03/21 14:16
Bug presence: origin:upstream
[Documentation on labels]
Reported-by: syzbot+bd77ba23a65c1739f0b4@syzkaller.appspotmail.com
First crash: 349d, last: 145d
Fix bisection: failed (error log, bisect log)
  
Bug presence (1)
Date Name Commit Repro Result
2023/10/11 upstream (ToT) 1c8b86a3799f C [report] INFO: task hung in flush_old_commits
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 INFO: task hung in flush_old_commits origin:upstream C 16 1d02h 335d 0/3 upstream: reported C repro on 2023/04/04 05:08
upstream INFO: task hung in flush_old_commits reiserfs C done 113 35d 286d 0/26 upstream: reported C repro on 2023/05/23 03:33
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2023/11/13 02:22 0m bisect fix linux-5.15.y error job log (0)
2023/10/11 03:42 1h12m bisect fix linux-5.15.y job log (0) log

Sample crash report:
INFO: task kworker/1:0:21 blocked for more than 143 seconds.
      Not tainted 5.15.124-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:0     state:D stack:25216 pid:   21 ppid:     2 flags:0x00004000
Workqueue: events_long flush_old_commits

Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5026 [inline]
 __schedule+0x12c4/0x4590 kernel/sched/core.c:6372
 schedule+0x11b/0x1f0 kernel/sched/core.c:6455
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6514
 __mutex_lock_common+0xe34/0x25a0 kernel/locking/mutex.c:669
 __mutex_lock kernel/locking/mutex.c:729 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:743
 reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
 reiserfs_sync_fs fs/reiserfs/super.c:76 [inline]
 flush_old_commits+0x1df/0x2e0 fs/reiserfs/super.c:111
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>

Showing all locks held in the system:
4 locks held by kworker/1:0/21:
 #0: 
ffff888011c65538
 (
(wq_completion)events_long
){+.+.}-{0:0}
, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: 
ffffc90000db7d20
 (
(work_completion)(&(&sbi->old_work)->work)
){+.+.}-{0:0}
, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: 
ffff8880788c40e0
 (
&type->s_umount_key
#42
){++++}-{3:3}
, at: flush_old_commits+0xc7/0x2e0 fs/reiserfs/super.c:97
 #3: 
ffff888147847090
 (
&sbi->lock
){+.+.}-{3:3}
, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
1 lock held by khungtaskd/27:
 #0: 
ffffffff8c91e920
 (
rcu_read_lock
){....}-{1:2}
, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/3275:
 #0: 
ffff88814ab98098
 (
&tty->ldisc_sem
){++++}-{0:0}
, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: 
ffffc90002bb32e8
 (
&ldata->atomic_read_lock
){+.+.}-{3:3}
, at: n_tty_read+0x6af/0x1db0 drivers/tty/n_tty.c:2158
7 locks held by syz-executor283/3522:

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.15.124-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/12/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 nmi_cpu_backtrace+0x46a/0x4a0 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x181/0x2a0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xe72/0xeb0 kernel/hung_task.c:295
 kthread+0x3f6/0x4f0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3522 Comm: syz-executor283 Not tainted 5.15.124-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/12/2023
RIP: 0010:arch_static_branch arch/x86/include/asm/jump_label.h:27 [inline]
RIP: 0010:static_key_false include/linux/jump_label.h:212 [inline]
RIP: 0010:native_write_msr arch/x86/include/asm/msr.h:156 [inline]
RIP: 0010:wrmsr arch/x86/include/asm/msr.h:263 [inline]
RIP: 0010:native_apic_msr_write+0x35/0x50 arch/x86/include/asm/apic.h:207
Code: 74 2a 83 ff 30 74 25 eb 10 81 ff d0 00 00 00 74 1b 81 ff e0 00 00 00 74 13 c1 ef 04 81 c7 00 08 00 00 89 f9 89 f0 31 d2 0f 30 <66> 90 c3 89 f6 31 d2 e9 1f 71 f1 02 66 2e 0f 1f 84 00 00 00 00 00
RSP: 0018:ffffc90000dd0e60 EFLAGS: 00000046
RAX: 000000000008a774 RBX: ffffffff8c34e998 RCX: 0000000000000838
RDX: 0000000000000000 RSI: 000000000008a774 RDI: 0000000000000838
RBP: 000000000008a774 R08: ffffffff81722e1d R09: fffffbfff1bc7f3e
R10: 0000000000000000 R11: dffffc0000000001 R12: ffff8880b9b27240
R13: dffffc0000000000 R14: 000000000008a774 R15: dffffc0000000000
FS:  00005555566a7380(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005556435e0600 CR3: 0000000023beb000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <IRQ>
 apic_write arch/x86/include/asm/apic.h:394 [inline]
 lapic_next_event+0x5b/0x70 arch/x86/kernel/apic/apic.c:468
 clockevents_program_event+0x1c5/0x310 kernel/time/clockevents.c:334
 hrtimer_interrupt+0x546/0x980 kernel/time/hrtimer.c:1824
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1085 [inline]
 __sysvec_apic_timer_interrupt+0x139/0x470 arch/x86/kernel/apic/apic.c:1102
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1096
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:console_trylock_spinning+0x36b/0x3f0 kernel/printk/printk.c:1909
Code: 0f 84 75 ff ff ff e8 24 f4 19 00 fb 31 db eb 41 e8 1a f4 19 00 e8 a5 0a b6 08 4d 85 ed 74 cd e8 0b f4 19 00 fb bb 01 00 00 00 <48> c7 c7 e0 b1 7f 8c 31 f6 ba 01 00 00 00 31 c9 41 b8 01 00 00 00
RSP: 0018:ffffc900011deb60 EFLAGS: 00000293
RAX: ffffffff81660df5 RBX: 0000000000000001 RCX: ffff888078fcd940
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffc900011dec30 R08: ffffffff81660dae R09: fffffbfff1f7ac3a
R10: 0000000000000000 R11: dffffc0000000001 R12: 1ffff9200023bd6c
R13: 0000000000000200 R14: 0000000000000046 R15: dffffc0000000000
 vprintk_emit+0xa1/0x150 kernel/printk/printk.c:2267
 _printk+0xd1/0x111 kernel/printk/printk.c:2289
 __reiserfs_warning+0x14f/0x1a0 fs/reiserfs/prints.c:290
 reiserfs_read_bitmap_block+0x209/0x670 fs/reiserfs/bitmap.c:1434
 scan_bitmap_block+0x1a7/0x1060 fs/reiserfs/bitmap.c:164
 scan_bitmap fs/reiserfs/bitmap.c:402 [inline]
 allocate_without_wrapping_disk fs/reiserfs/bitmap.c:1161 [inline]
 blocknrs_and_prealloc_arrays_from_search_start fs/reiserfs/bitmap.c:1274 [inline]
 reiserfs_allocate_blocknrs+0x2cf5/0x5070 fs/reiserfs/bitmap.c:1375
 reiserfs_get_block+0x32b4/0x5390 fs/reiserfs/inode.c:764
 __block_write_begin_int+0x60b/0x1650 fs/buffer.c:2012
 reiserfs_write_begin+0x346/0x810 fs/reiserfs/inode.c:2790
 generic_perform_write+0x2bf/0x5b0 mm/filemap.c:3776
 __generic_file_write_iter+0x243/0x4f0 mm/filemap.c:3903
 generic_file_write_iter+0xa7/0x1b0 mm/filemap.c:3935
 call_write_iter include/linux/fs.h:2103 [inline]
 new_sync_write fs/read_write.c:507 [inline]
 vfs_write+0xacf/0xe50 fs/read_write.c:594
 ksys_write+0x1a2/0x2c0 fs/read_write.c:647
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7feceba95f99
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 f1 17 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fff22637058 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007fecebadf095 RCX: 00007feceba95f99
RDX: 000000000208e24b RSI: 0000000020000280 RDI: 0000000000000005
RBP: 00007fecebb0b5f0 R08: 0000000020000000 R09: 00005555566a84c0
R10: 0000000000000000 R11: 0000000000000246 R12: 00007fff22637080
R13: 00007fff226372a8 R14: 431bde82d7b634db R15: 00007fecebadf01d
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 2.416 msecs

Crashes (16):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/08/06 17:56 linux-5.15.y 38d4ca22a528 4ffcc9ef .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan INFO: task hung in flush_old_commits
2023/05/19 09:35 linux-5.15.y 9d6bde853685 3bb7af1d .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/06/18 18:16 linux-5.15.y 471e639e59d1 f3921d4d .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan INFO: task hung in flush_old_commits
2023/06/17 06:16 linux-5.15.y 471e639e59d1 f3921d4d .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan INFO: task hung in flush_old_commits
2023/08/21 14:13 linux-5.15.y f6f7927ac664 d216d8a0 .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/06/21 14:53 linux-5.15.y 471e639e59d1 79782afc .config console log report syz C [disk image] [vmlinux] [kernel image] [mounted in repro] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/06/27 05:10 linux-5.15.y f67653019430 4cd5bb25 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in flush_old_commits
2023/05/05 15:49 linux-5.15.y 8a7f2a5c5aa1 de870ca5 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in flush_old_commits
2023/06/19 22:22 linux-5.15.y 471e639e59d1 d521bc56 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/06/03 02:39 linux-5.15.y 0ab06468cbd1 a4ae4f42 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/04/13 09:58 linux-5.15.y d86dfc4d95cd 82d5e53e .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/04/12 00:51 linux-5.15.y d86dfc4d95cd 49faf98d .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/04/09 16:14 linux-5.15.y d86dfc4d95cd 71147e29 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/04/06 19:32 linux-5.15.y d86dfc4d95cd 08707520 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/03/29 01:23 linux-5.15.y 115472395b0a fc067f05 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
2023/03/21 14:16 linux-5.15.y 8020ae3c051d 7939252e .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in flush_old_commits
* Struck through repros no longer work on HEAD.