syzbot


INFO: rcu detected stall in sys_rmdir

Status: closed as invalid on 2022/02/08 09:50
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 360d, last: 324d

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	0-...!: (1 GPs behind) idle=077/1/0x4000000000000000 softirq=49351/49353 fqs=0 
	(detected by 1, t=10502 jiffies, g=66153, q=86)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 2265 Comm: syz-executor.5 Not tainted 5.16.0-rc8-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:memory_is_poisoned_n mm/kasan/generic.c:135 [inline]
RIP: 0010:memory_is_poisoned mm/kasan/generic.c:159 [inline]
RIP: 0010:check_region_inline mm/kasan/generic.c:180 [inline]
RIP: 0010:kasan_check_range+0x122/0x180 mm/kasan/generic.c:189
Code: 4c 89 d8 4c 39 da 74 0e 80 3a 00 74 ef 49 8d 04 2c 48 85 d2 75 0b 48 89 da 48 29 c2 e9 55 ff ff ff 49 39 d2 75 17 49 0f be 02 <41> 83 e1 07 49 39 c1 7d 0a 5b b8 01 00 00 00 5d 41 5c c3 44 89 c2
RSP: 0018:ffffc90000007d88 EFLAGS: 00000046
RAX: 0000000000000004 RBX: fffff52000000fbb RCX: ffffffff815c4e40
RDX: fffff52000000fba RSI: 0000000000000004 RDI: ffffc90000007dd0
RBP: fffff52000000fba R08: 0000000000000001 R09: ffffc90000007dd3
R10: fffff52000000fba R11: 0000000000000001 R12: ffff8880b9c2a408
R13: ffff8880b9c2a410 R14: ffff8880b9c2a400 R15: 0000000000000001
FS:  00005555566ff400(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000555556708848 CR3: 000000008ac85000 CR4: 00000000003526f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 instrument_atomic_read_write include/linux/instrumented.h:101 [inline]
 atomic_try_cmpxchg_acquire include/linux/atomic/atomic-instrumented.h:512 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:82 [inline]
 do_raw_spin_lock+0x120/0x2b0 kernel/locking/spinlock_debug.c:115
 __run_hrtimer kernel/time/hrtimer.c:1689 [inline]
 __hrtimer_run_queues+0x243/0xe50 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:on_stack arch/x86/include/asm/stacktrace.h:56 [inline]
RIP: 0010:stack_access_ok arch/x86/kernel/unwind_orc.c:342 [inline]
RIP: 0010:deref_stack_reg+0x5c/0x150 arch/x86/kernel/unwind_orc.c:352
Code: 00 00 41 8b 04 24 85 c0 74 62 49 8d 7c 24 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 c3 00 00 00 <49> 8d 7c 24 10 4d 8b 6c 24 08 48 b8 00 00 00 00 00 fc ff df 48 89
RSP: 0018:ffffc900039c7270 EFLAGS: 00000246
RAX: dffffc0000000000 RBX: ffffc900039c7410 RCX: ffffffff8e0b2019
RDX: 1ffff92000738e7a RSI: ffffc900039c7458 RDI: ffffc900039c73d0
RBP: ffffc900039c7458 R08: ffffffff8e0b2014 R09: 0000000000000001
R10: fffff52000738e84 R11: 000000000008808a R12: ffffc900039c73c8
R13: ffffc900039c73fd R14: ffffc900039c73c8 R15: ffffffff8e0b2018
 unwind_next_frame+0xcdc/0x1ce0 arch/x86/kernel/unwind_orc.c:534
 __unwind_start+0x51b/0x800 arch/x86/kernel/unwind_orc.c:712
 unwind_start arch/x86/include/asm/unwind.h:64 [inline]
 arch_stack_walk+0x5c/0xe0 arch/x86/kernel/stacktrace.c:24
 stack_trace_save+0x8c/0xc0 kernel/stacktrace.c:122
 kasan_save_stack+0x1e/0x50 mm/kasan/common.c:38
 kasan_set_track mm/kasan/common.c:46 [inline]
 set_alloc_info mm/kasan/common.c:434 [inline]
 __kasan_slab_alloc+0x85/0xb0 mm/kasan/common.c:467
 kasan_slab_alloc include/linux/kasan.h:259 [inline]
 slab_post_alloc_hook mm/slab.h:519 [inline]
 slab_alloc mm/slab.c:3323 [inline]
 kmem_cache_alloc+0x265/0x560 mm/slab.c:3507
 ext4_free_blocks+0x9a5/0x1de0 fs/ext4/mballoc.c:6033
 ext4_remove_blocks fs/ext4/extents.c:2541 [inline]
 ext4_ext_rm_leaf fs/ext4/extents.c:2707 [inline]
 ext4_ext_remove_space+0x1f84/0x4520 fs/ext4/extents.c:2955
 ext4_ext_truncate+0x205/0x260 fs/ext4/extents.c:4417
 ext4_truncate+0xecc/0x1440 fs/ext4/inode.c:4201
 ext4_evict_inode+0xa71/0x1950 fs/ext4/inode.c:287
 evict+0x2ed/0x6b0 fs/inode.c:590
 iput_final fs/inode.c:1670 [inline]
 iput.part.0+0x562/0x820 fs/inode.c:1696
 iput+0x58/0x70 fs/inode.c:1686
 dentry_unlink_inode+0x2b1/0x460 fs/dcache.c:376
 d_delete fs/dcache.c:2505 [inline]
 d_delete+0x16b/0x1c0 fs/dcache.c:2494
 vfs_rmdir.part.0+0x3ae/0x4b0 fs/namei.c:3982
 vfs_rmdir fs/namei.c:3954 [inline]
 do_rmdir+0x3a6/0x430 fs/namei.c:4030
 __do_sys_rmdir fs/namei.c:4049 [inline]
 __se_sys_rmdir fs/namei.c:4047 [inline]
 __x64_sys_rmdir+0xc6/0x110 fs/namei.c:4047
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f1ba6d2b807
Code: 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 54 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fffadf94a68 EFLAGS: 00000207 ORIG_RAX: 0000000000000054
RAX: ffffffffffffffda RBX: 0000000000000065 RCX: 00007f1ba6d2b807
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00007fffadf95bf0
RBP: 00007fffadf94b30 R08: 0000000000000000 R09: 00007fffadf94900
R10: 00005555567008e3 R11: 0000000000000207 R12: 00007f1ba6d85172
R13: 00007fffadf95bf0 R14: 0000555556700810 R15: 00007fffadf95c30
 </TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 10501 jiffies! g66153 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=1 timer-softirq=34808
rcu: rcu_preempt kthread starved for 10502 jiffies! g66153 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=1
rcu: 	Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt     state:I stack:28632 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4900 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 schedule_timeout+0x14a/0x2a0 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x186/0x810 kernel/rcu/tree.c:1955
 rcu_gp_kthread+0x1de/0x320 kernel/rcu/tree.c:2128
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 1
CPU: 1 PID: 3706 Comm: syz-executor.0 Not tainted 5.16.0-rc8-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_check_gp_kthread_starvation.cold+0x1fb/0x200 kernel/rcu/tree_stall.h:481
 print_other_cpu_stall kernel/rcu/tree_stall.h:586 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:729 [inline]
 rcu_pending kernel/rcu/tree.c:3878 [inline]
 rcu_sched_clock_irq+0x1f7c/0x2150 kernel/rcu/tree.c:2597
 update_process_times+0x16d/0x200 kernel/time/timer.c:1785
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:226
 tick_sched_timer+0x1b0/0x2d0 kernel/time/tick-sched.c:1428
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x1c0/0xe50 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:csd_lock_wait kernel/smp.c:440 [inline]
RIP: 0010:smp_call_function_many_cond+0x452/0xc20 kernel/smp.c:969
Code: 0b 00 85 ed 74 4d 48 b8 00 00 00 00 00 fc ff df 4d 89 f4 4c 89 f5 49 c1 ec 03 83 e5 07 49 01 c4 83 c5 03 e8 70 7e 0b 00 f3 90 <41> 0f b6 04 24 40 38 c5 7c 08 84 c0 0f 85 33 06 00 00 8b 43 08 31
RSP: 0018:ffffc90003b27c20 EFLAGS: 00000246
RAX: 0000000000040000 RBX: ffffe8ffffc0b640 RCX: ffffc90002d19000
RDX: 0000000000040000 RSI: ffffffff816b4fa0 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffff816b4fc6 R11: 0000000000000000 R12: fffff91ffff816c9
R13: 0000000000000000 R14: ffffe8ffffc0b648 R15: 0000000000000001
 clock_was_set+0x599/0x790 kernel/time/hrtimer.c:974
 do_settimeofday64 kernel/time/timekeeping.c:1326 [inline]
 do_settimeofday64+0x3b9/0x5b0 kernel/time/timekeeping.c:1293
 do_sys_settimeofday64 kernel/time/time.c:195 [inline]
 do_sys_settimeofday64+0x1de/0x260 kernel/time/time.c:169
 __do_sys_clock_settime kernel/time/posix-timers.c:1079 [inline]
 __se_sys_clock_settime kernel/time/posix-timers.c:1067 [inline]
 __x64_sys_clock_settime+0x1a1/0x280 kernel/time/posix-timers.c:1067
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f3aa5c22e99
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f3aa4598168 EFLAGS: 00000246 ORIG_RAX: 00000000000000e3
RAX: ffffffffffffffda RBX: 00007f3aa5d35f60 RCX: 00007f3aa5c22e99
RDX: 0000000000000000 RSI: 00000000200002c0 RDI: 0000000000000000
RBP: 00007f3aa5c7cff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe912b697f R14: 00007f3aa4598300 R15: 0000000000022000
 </TASK>
----------------
Code disassembly (best guess):
   0:	4c 89 d8             	mov    %r11,%rax
   3:	4c 39 da             	cmp    %r11,%rdx
   6:	74 0e                	je     0x16
   8:	80 3a 00             	cmpb   $0x0,(%rdx)
   b:	74 ef                	je     0xfffffffc
   d:	49 8d 04 2c          	lea    (%r12,%rbp,1),%rax
  11:	48 85 d2             	test   %rdx,%rdx
  14:	75 0b                	jne    0x21
  16:	48 89 da             	mov    %rbx,%rdx
  19:	48 29 c2             	sub    %rax,%rdx
  1c:	e9 55 ff ff ff       	jmpq   0xffffff76
  21:	49 39 d2             	cmp    %rdx,%r10
  24:	75 17                	jne    0x3d
  26:	49 0f be 02          	movsbq (%r10),%rax
* 2a:	41 83 e1 07          	and    $0x7,%r9d <-- trapping instruction
  2e:	49 39 c1             	cmp    %rax,%r9
  31:	7d 0a                	jge    0x3d
  33:	5b                   	pop    %rbx
  34:	b8 01 00 00 00       	mov    $0x1,%eax
  39:	5d                   	pop    %rbp
  3a:	41 5c                	pop    %r12
  3c:	c3                   	retq
  3d:	44 89 c2             	mov    %r8d,%edx

Crashes (3):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-selinux-root 2022/01/09 02:27 upstream 21f35d2ca83e 2ca0d385 .config log report info INFO: rcu detected stall in sys_rmdir
ci-upstream-kasan-gce-root 2022/01/05 23:11 upstream 49ef78e59b07 6acc789a .config log report info INFO: rcu detected stall in sys_rmdir
ci-upstream-kasan-gce-root 2021/12/03 12:54 upstream 5f58da2befa5 c7c20675 .config log report info INFO: rcu detected stall in sys_rmdir
* Struck through repros no longer work on HEAD.