syzbot


INFO: rcu detected stall in sys_mkdir (6)

Status: closed as invalid on 2022/02/08 09:50
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 308d, last: 300d
similar bugs (5):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in sys_mkdir (3) 1 1053d 1053d 0/24 closed as invalid on 2020/01/08 05:33
upstream INFO: rcu detected stall in sys_mkdir 2 1221d 1223d 0/24 auto-closed as invalid on 2019/10/25 14:21
upstream INFO: rcu detected stall in sys_mkdir (2) 5 1088d 1089d 0/24 closed as invalid on 2019/12/04 14:04
upstream INFO: rcu detected stall in sys_mkdir (4) 2 1053d 1053d 0/24 closed as invalid on 2020/01/09 08:13
upstream INFO: rcu detected stall in sys_mkdir (5) 1 435d 435d 0/24 auto-closed as invalid on 2021/12/15 23:48

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	0-...!: (0 ticks this GP) idle=217/1/0x4000000000000000 softirq=34653/34653 fqs=4 
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P10560/1:b..l
	(detected by 1, t=10502 jiffies, g=50169, q=190)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 10561 Comm: syz-executor.4 Not tainted 5.17.0-rc1-syzkaller-00436-g24f4db1f3a27 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:match_held_lock+0xc/0xc0 kernel/locking/lockdep.c:5086
Code: bc ff 48 c7 c7 80 60 ac 89 e8 2e 2d bc ff e8 df e3 cb ff 31 c0 5d c3 0f 1f 80 00 00 00 00 53 48 89 fb 48 83 ec 08 48 39 77 10 <74> 6a 66 f7 47 22 f0 ff 74 5a 48 8b 46 08 48 89 f7 48 85 c0 74 42
RSP: 0018:ffffc90000007cf8 EFLAGS: 00000083
RAX: 000000000000000f RBX: ffff88803cd527d8 RCX: 0000000000000001
RDX: 0000000000000000 RSI: ffffffff8bb83b60 RDI: ffff88803cd527d8
RBP: ffffffff8bb83b60 R08: 0000000000000000 R09: ffffffff8d94c617
R10: fffffbfff1b298c2 R11: 0000000000000000 R12: ffff88803cd51d00
R13: ffff88803cd52760 R14: 00000000ffffffff R15: ffff88803cd527d8
FS:  00007fe80ad3f700(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fe80ad1e718 CR3: 000000007aa6b000 CR4: 0000000000350ef0
Call Trace:
 <IRQ>
 __lock_is_held kernel/locking/lockdep.c:5380 [inline]
 lock_is_held_type+0xa7/0x140 kernel/locking/lockdep.c:5682
 lock_is_held include/linux/lockdep.h:283 [inline]
 rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
 trace_lock_release include/trace/events/lock.h:58 [inline]
 lock_release+0x522/0x720 kernel/locking/lockdep.c:5650
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:149 [inline]
 _raw_spin_unlock_irqrestore+0x16/0x70 kernel/locking/spinlock.c:194
 __run_hrtimer kernel/time/hrtimer.c:1681 [inline]
 __hrtimer_run_queues+0x51a/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:preempt_count arch/x86/include/asm/preempt.h:27 [inline]
RIP: 0010:check_kcov_mode kernel/kcov.c:166 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x60 kernel/kcov.c:200
Code: 48 89 ef 5d e9 91 ac 46 00 5d be 03 00 00 00 e9 a6 10 66 02 66 0f 1f 44 00 00 48 8b be b0 01 00 00 e8 b4 ff ff ff 31 c0 c3 90 <65> 8b 05 69 00 8a 7e 89 c1 48 8b 34 24 81 e1 00 01 00 00 65 48 8b
RSP: 0018:ffffc90002b8f8c0 EFLAGS: 00000202
RAX: 0000000000000000 RBX: 0000000000000020 RCX: ffff88803cd51d00
RDX: 0000000000000000 RSI: ffff88803cd51d00 RDI: 0000000000000003
RBP: ffff8880718e2a80 R08: 0000000000000000 R09: 0000000000000020
R10: ffffffff82136cca R11: 0000000000000000 R12: ffff88805bedca00
R13: 0000000000000001 R14: 000000000000000f R15: dffffc0000000000
 ext4_fill_raw_inode+0x16df/0x1e90 fs/ext4/inode.c:4350
 ext4_do_update_inode fs/ext4/inode.c:5083 [inline]
 ext4_mark_iloc_dirty+0x587/0x1cf0 fs/ext4/inode.c:5677
 __ext4_mark_inode_dirty+0x220/0x8d0 fs/ext4/inode.c:5873
 __ext4_new_inode+0x237f/0x56f0 fs/ext4/ialloc.c:1343
 ext4_mkdir+0x33a/0xb20 fs/ext4/namei.c:2929
 vfs_mkdir+0x1c3/0x3b0 fs/namei.c:3933
 do_mkdirat+0x285/0x300 fs/namei.c:3959
 __do_sys_mkdir fs/namei.c:3979 [inline]
 __se_sys_mkdir fs/namei.c:3977 [inline]
 __x64_sys_mkdir+0xf2/0x140 fs/namei.c:3977
 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:0x7fe80c3c9167
Code: 73 01 c3 48 c7 c1 b8 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 53 00 00 00 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:00007fe80ad3ef88 EFLAGS: 00000213 ORIG_RAX: 0000000000000053
RAX: ffffffffffffffda RBX: 0000000020000180 RCX: 00007fe80c3c9167
RDX: 0000000000000004 RSI: 00000000000001ff RDI: 0000000020000100
RBP: 00007fe80ad3f020 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000213 R12: 0000000020000000
R13: 0000000020000100 R14: 00007fe80ad3efe0 R15: 0000000020000200
 </TASK>
task:sed             state:R  running task     stack:28152 pid:10560 ppid: 10535 flags:0x00000000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 preempt_schedule_irq+0x4e/0x90 kernel/sched/core.c:6710
 irqentry_exit+0x31/0x80 kernel/entry/common.c:425
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:lock_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5687
Code: 00 00 b8 ff ff ff ff 65 0f c1 05 1c 5f b4 76 83 f8 01 75 29 9c 58 f6 c4 02 75 3d 48 f7 04 24 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89 e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb b9 0f 0b 48
RSP: 0000:ffffc9000298fc90 EFLAGS: 00000296
RAX: 0000000000000046 RBX: 0000000000000002 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffffff8bbc6008 R08: 0000000000000000 R09: 0000000000000001
R10: ffffffff814e2982 R11: 0000000000000000 R12: ffff8880195f9d00
R13: 0000000000000000 R14: 00000000ffffffff R15: ffff8880195fa788
 lock_is_held include/linux/lockdep.h:283 [inline]
 task_css include/linux/cgroup.h:494 [inline]
 blk_cgroup_congested include/linux/blk-cgroup.h:281 [inline]
 __cgroup_throttle_swaprate+0x3cc/0x680 mm/swapfile.c:3740
 cgroup_throttle_swaprate include/linux/swap.h:735 [inline]
 do_anonymous_page mm/memory.c:3785 [inline]
 handle_pte_fault mm/memory.c:4568 [inline]
 __handle_mm_fault+0x2d8f/0x5110 mm/memory.c:4705
 handle_mm_fault+0x1c8/0x790 mm/memory.c:4803
 do_user_addr_fault+0x489/0x11c0 arch/x86/mm/fault.c:1397
 handle_page_fault arch/x86/mm/fault.c:1484 [inline]
 exc_page_fault+0x9e/0x180 arch/x86/mm/fault.c:1540
 asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:568
RIP: 0033:0x7fadaeb86f1f
RSP: 002b:00007ffc16031dc0 EFLAGS: 00010206
RAX: 0000000000016ff1 RBX: 0000000000000004 RCX: 00007fadb0244010
RDX: 0000000000000021 RSI: 0000000000000000 RDI: 0000000000000004
RBP: 0000000000000020 R08: 0000000000000003 R09: 00007fadaecb9a60
R10: 00007fadb0243fa8 R11: 0000000000000020 R12: 00007fadaecb9a00
R13: 0000000000000002 R14: ffffffffffffffb8 R15: 00007fadb0243ff0
 </TASK>
rcu: rcu_preempt kthread starved for 10494 jiffies! g50169 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->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:R  running task     stack:28736 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_timeout+0x14a/0x2a0 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x186/0x810 kernel/rcu/tree.c:1963
 rcu_gp_kthread+0x1de/0x320 kernel/rcu/tree.c:2136
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 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: 3736 Comm: kworker/u4:6 Not tainted 5.17.0-rc1-syzkaller-00436-g24f4db1f3a27 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound toggle_allocation_gate
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:458
 print_other_cpu_stall kernel/rcu/tree_stall.h:563 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:706 [inline]
 rcu_pending kernel/rcu/tree.c:3919 [inline]
 rcu_sched_clock_irq+0x1f7c/0x2150 kernel/rcu/tree.c:2617
 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+0x447/0xc90 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 fb 7d 0b 00 f3 90 <41> 0f b6 04 24 40 38 c5 7c 08 84 c0 0f 85 95 06 00 00 8b 43 08 31
RSP: 0018:ffffc9000415fa08 EFLAGS: 00000293
RAX: 0000000000000000 RBX: ffff8880b9c41fa0 RCX: 0000000000000000
RDX: ffff88801da93a00 RSI: ffffffff816cf155 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000001
R10: ffffffff816cf17b R11: 0000000000000000 R12: ffffed10173883f5
R13: 0000000000000000 R14: ffff8880b9c41fa8 R15: 0000000000000001
 on_each_cpu_cond_mask+0x56/0xa0 kernel/smp.c:1135
 on_each_cpu include/linux/smp.h:71 [inline]
 text_poke_sync arch/x86/kernel/alternative.c:1112 [inline]
 text_poke_bp_batch+0x1b1/0x510 arch/x86/kernel/alternative.c:1300
 text_poke_flush arch/x86/kernel/alternative.c:1470 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1467 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1477
 arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
 jump_label_update+0x1da/0x400 kernel/jump_label.c:830
 static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
 static_key_enable+0x16/0x20 kernel/jump_label.c:190
 toggle_allocation_gate mm/kfence/core.c:734 [inline]
 toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:726
 process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
 worker_thread+0x657/0x1110 kernel/workqueue.c:2454
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	bc ff 48 c7 c7       	mov    $0xc7c748ff,%esp
   5:	80 60 ac 89          	andb   $0x89,-0x54(%rax)
   9:	e8 2e 2d bc ff       	callq  0xffbc2d3c
   e:	e8 df e3 cb ff       	callq  0xffcbe3f2
  13:	31 c0                	xor    %eax,%eax
  15:	5d                   	pop    %rbp
  16:	c3                   	retq
  17:	0f 1f 80 00 00 00 00 	nopl   0x0(%rax)
  1e:	53                   	push   %rbx
  1f:	48 89 fb             	mov    %rdi,%rbx
  22:	48 83 ec 08          	sub    $0x8,%rsp
  26:	48 39 77 10          	cmp    %rsi,0x10(%rdi)
* 2a:	74 6a                	je     0x96 <-- trapping instruction
  2c:	66 f7 47 22 f0 ff    	testw  $0xfff0,0x22(%rdi)
  32:	74 5a                	je     0x8e
  34:	48 8b 46 08          	mov    0x8(%rsi),%rax
  38:	48 89 f7             	mov    %rsi,%rdi
  3b:	48 85 c0             	test   %rax,%rax
  3e:	74 42                	je     0x82

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-root 2022/01/30 16:42 upstream 24f4db1f3a27 495e00c5 .config log report info INFO: rcu detected stall in sys_mkdir
ci-upstream-kasan-gce-smack-root 2022/01/21 19:38 upstream 9b57f4589857 214351e1 .config log report info INFO: rcu detected stall in sys_mkdir
* Struck through repros no longer work on HEAD.