syzbot


INFO: rcu detected stall in trace_hardirqs_off_caller

Status: auto-closed as invalid on 2020/06/22 09:06
Subsystems: ext4
[Documentation on labels]
First crash: 1968d, last: 1968d

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P30749
	(detected by 0, t=10503 jiffies, g=40233, q=65)
syz-executor.0  R  running task    26736 30749  10464 0x00004000
Call Trace:
 context_switch kernel/sched/core.c:3380 [inline]
 __schedule+0x934/0x1f90 kernel/sched/core.c:4080
 __sched_text_start+0x8/0x8
 mark_held_locks+0x9f/0xe0 kernel/locking/lockdep.c:3359
 preempt_schedule_irq+0xb0/0x150 kernel/sched/core.c:4337
 retint_kernel+0x1b/0x2b
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:759 [inline]
RIP: 0010:lock_acquire+0x209/0x420 kernel/locking/lockdep.c:4487
Code: 94 08 00 00 00 00 00 00 48 c1 e8 03 80 3c 10 00 0f 85 de 01 00 00 48 83 3d a3 0f 1b 08 00 0f 84 5a 01 00 00 48 8b 3c 24 57 9d <0f> 1f 44 00 00 48 83 c4 18 5b 5d 41 5c 41 5d 41 5e 41 5f c3 65 8b
RSP: 0018:ffffc90004d8f4e8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff12e7698 RBX: ffff88807c286440 RCX: ffffffff815859ab
RDX: dffffc0000000000 RSI: 1ffff920009b1e86 RDI: 0000000000000286
RBP: ffffffff897accc0 R08: 0000000000000000 R09: fffffbfff180e575
R10: fffffbfff180e574 R11: ffffffff8c072ba7 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000002 R15: 0000000000000000
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:110 [inline]
 hlock_class kernel/locking/lockdep.c:163 [inline]
 __lock_acquire+0x80b/0x3ca0 kernel/locking/lockdep.c:3951
 rcu_lock_acquire include/linux/rcupdate.h:208 [inline]
 rcu_read_lock include/linux/rcupdate.h:601 [inline]
 ext4_get_group_desc+0x11c/0x4f0 fs/ext4/balloc.c:284
 ext4_get_group_desc+0xe5/0x4f0 fs/ext4/balloc.c:283
 recently_deleted fs/ext4/ialloc.c:679 [inline]
 find_inode_bit.isra.0+0x196/0x540 fs/ext4/ialloc.c:723
 __ext4_new_inode+0x1854/0x57e0 fs/ext4/ialloc.c:915
 ext4_free_inode+0x17e0/0x17e0 fs/ext4/ext4.h:3126
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:3388 [inline]
 lockdep_hardirqs_on+0x417/0x5d0 kernel/locking/lockdep.c:3433
 trace_hardirqs_on_thunk+0x1a/0x1c arch/x86/entry/thunk_64.S:41
 set_irq_regs arch/x86/include/asm/irq_regs.h:27 [inline]
 smp_apic_timer_interrupt+0x1b6/0x600 arch/x86/kernel/apic/apic.c:1148
 retint_kernel+0x2b/0x2b
 ext4_create+0x327/0x4a0 fs/ext4/namei.c:2614
 ext4_mknod+0x4a0/0x4a0 fs/ext4/ext4.h:1878
 ext4_mknod+0x4a0/0x4a0 fs/ext4/ext4.h:1878
 lookup_open+0x120d/0x1970 fs/namei.c:3309
 trailing_symlink+0x930/0x930 fs/namei.c:999
 __down_timeout+0x2d0/0x2d0
 get_lock_parent_ip include/linux/ftrace.h:796 [inline]
 preempt_latency_start kernel/sched/core.c:3764 [inline]
 preempt_latency_start kernel/sched/core.c:3761 [inline]
 preempt_count_add+0x74/0x140 kernel/sched/core.c:3789
 __mnt_want_write+0x1da/0x2c0 fs/namespace.c:338
 do_last fs/namei.c:3401 [inline]
 path_openat+0xe8f/0x32b0 fs/namei.c:3607
 __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
 _raw_spin_unlock_irq+0x1f/0x80 kernel/locking/spinlock.c:199
 path_mountpoint.isra.0+0x370/0x370 fs/namei.c:2387
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:110 [inline]
 hlock_class kernel/locking/lockdep.c:163 [inline]
 mark_lock+0xbc/0x1220 kernel/locking/lockdep.c:3642
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:110 [inline]
 hlock_class kernel/locking/lockdep.c:163 [inline]
 lookup_chain_cache_add kernel/locking/lockdep.c:2879 [inline]
 validate_chain kernel/locking/lockdep.c:2935 [inline]
 __lock_acquire+0x14bd/0x3ca0 kernel/locking/lockdep.c:3954
 do_filp_open+0x192/0x260 fs/namei.c:3637
 may_open_dev+0xf0/0xf0 fs/namei.c:3017
 __raw_spin_unlock include/linux/spinlock_api_smp.h:152 [inline]
 _raw_spin_unlock+0x24/0x40 kernel/locking/spinlock.c:183
 spin_unlock include/linux/spinlock.h:378 [inline]
 __alloc_fd+0x46d/0x600 fs/file.c:534
 do_sys_openat2+0x54c/0x740 fs/open.c:1146
 file_open_root+0x3d0/0x3d0 fs/open.c:1127
 _copy_to_user+0x107/0x150 lib/usercopy.c:31
 put_timespec64+0xcb/0x120 kernel/time/time.c:812
 ns_to_kernel_old_timeval+0x100/0x100 kernel/time/time.c:521
 do_sys_open+0xc3/0x140 fs/open.c:1162
 filp_open+0x70/0x70 fs/open.c:1115
 __ia32_sys_clock_settime+0x260/0x260 kernel/time/posix-timers.c:1409
 trace_hardirqs_off_caller+0x55/0x230 kernel/trace/trace_preemptirq.c:73
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45c849
Code: ad b6 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 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 0f 83 7b b6 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f98d4e5cc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000055
RAX: ffffffffffffffda RBX: 00007f98d4e5d6d4 RCX: 000000000045c849
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000280
RBP: 000000000076c040 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000098 R14: 00000000004c32ec R15: 000000000076c04c
rcu: rcu_preempt kthread starved for 10539 jiffies! g40233 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    29384    10      2 0x80004000
Call Trace:
 context_switch kernel/sched/core.c:3380 [inline]
 __schedule+0x934/0x1f90 kernel/sched/core.c:4080
 __sched_text_start+0x8/0x8
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:117 [inline]
 _raw_spin_lock_irqsave+0x94/0xbf kernel/locking/spinlock.c:159
 check_preemption_disabled lib/smp_processor_id.c:52 [inline]
 debug_smp_processor_id+0x2f/0x185 lib/smp_processor_id.c:57
 schedule+0xd0/0x2a0 kernel/sched/core.c:4154
 schedule_timeout+0x474/0xba0 kernel/time/timer.c:1895
 lock_acquire+0x197/0x420 kernel/locking/lockdep.c:4484
 usleep_range+0x160/0x160 kernel/time/timer.c:2090
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
 _raw_spin_unlock_irqrestore+0x62/0xe0 kernel/locking/spinlock.c:191
 __next_timer_interrupt+0x190/0x190 kernel/time/timer.c:1511
 swake_up_one+0x60/0x60 include/linux/compiler.h:199
 rcu_gp_fqs_loop kernel/rcu/tree.c:1658 [inline]
 rcu_gp_kthread+0x9d9/0x17d0 kernel/rcu/tree.c:1818
 lock_acquire+0x197/0x420 kernel/locking/lockdep.c:4484
 rcu_note_context_switch+0x18f0/0x18f0 include/linux/list.h:70
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:160 [inline]
 _raw_spin_unlock_irqrestore+0x62/0xe0 kernel/locking/spinlock.c:191
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:3388 [inline]
 lockdep_hardirqs_on+0x417/0x5d0 kernel/locking/lockdep.c:3433
 __kthread_parkme+0x10a/0x1c0 kernel/kthread.c:205
 rcu_note_context_switch+0x18f0/0x18f0 include/linux/list.h:70
 kthread+0x357/0x430 kernel/kthread.c:255
 kthread_mod_delayed_work+0x1a0/0x1a0 kernel/kthread.c:1077
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/03/24 09:04 upstream 979e52ca0469 33e14df3 .config console log report ci-upstream-kasan-gce-selinux-root
* Struck through repros no longer work on HEAD.