syzbot


INFO: rcu detected stall in vfs_iter_write

Status: closed as invalid on 2022/02/08 10:00
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 339d, last: 339d

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	1-...!: (10501 ticks this GP) idle=9fb/1/0x4000000000000000 softirq=13964/13964 fqs=0 
	(t=10502 jiffies g=18617 q=494)
rcu: rcu_preempt kthread timer wakeup didn't happen for 10502 jiffies! g18617 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=1 timer-softirq=6597
rcu: rcu_preempt kthread starved for 10505 jiffies! g18617 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:26576 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xb72/0x1460 kernel/sched/core.c:6253
 schedule+0x12b/0x1f0 kernel/sched/core.c:6326
 schedule_timeout+0x1b9/0x300 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x1fd/0x770 kernel/rcu/tree.c:1955
 rcu_gp_kthread+0xa5/0x350 kernel/rcu/tree.c:2128
 kthread+0x468/0x490 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 1
CPU: 1 PID: 5690 Comm: syz-executor.1 Not tainted 5.16.0-rc6-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+0x1dc/0x2d8 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_check_gp_kthread_starvation+0x1ff/0x270 kernel/rcu/tree_stall.h:481
 print_cpu_stall kernel/rcu/tree_stall.h:625 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:711 [inline]
 rcu_pending kernel/rcu/tree.c:3878 [inline]
 rcu_sched_clock_irq+0x1e2e/0x2bc0 kernel/rcu/tree.c:2597
 update_process_times+0x197/0x200 kernel/time/timer.c:1785
 tick_sched_handle kernel/time/tick-sched.c:226 [inline]
 tick_sched_timer+0x27d/0x420 kernel/time/tick-sched.c:1428
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x4cb/0xa60 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x3b3/0x1040 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0xf9/0x270 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20
RIP: 0010:vfs_iter_write+0x0/0xa0 fs/read_write.c:889
Code: 89 e7 e8 c3 97 f4 ff e9 11 fe ff ff 44 89 e9 80 e1 07 80 c1 03 38 c1 0f 8c 40 fe ff ff 4c 89 ef e8 b5 97 f4 ff e9 33 fe ff ff <55> 41 57 41 56 41 55 41 54 53 41 89 ce 49 89 d7 49 89 f4 48 89 fb
RSP: 0018:ffffc90004adf818 EFLAGS: 00000246
RAX: 1fc590c5e9241d00 RBX: ffffc90004adf938 RCX: 0000000000000000
RDX: ffffc90004adf938 RSI: ffffc90004adf980 RDI: ffff88807c76f400
RBP: ffffc90004adfa30 R08: dffffc0000000000 R09: fffff5200095bf31
R10: fffff5200095bf31 R11: 0000000000000000 R12: dffffc0000000000
R13: ffff88807e44a578 R14: ffffc90004adf980 R15: dffffc0000000000
 iter_file_splice_write+0x7eb/0xfa0 fs/splice.c:689
 do_splice_from fs/splice.c:767 [inline]
 direct_splice_actor+0xe6/0x1c0 fs/splice.c:936
 splice_direct_to_actor+0x529/0xd00 fs/splice.c:891
 do_splice_direct+0x291/0x3e0 fs/splice.c:979
 do_sendfile+0x6fe/0x1040 fs/read_write.c:1245
 __do_sys_sendfile64 fs/read_write.c:1310 [inline]
 __se_sys_sendfile64+0x171/0x1d0 fs/read_write.c:1296
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f6ce24dce99
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:00007f6ce0e52168 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007f6ce25eff60 RCX: 00007f6ce24dce99
RDX: 0000000000000000 RSI: 000000000000000b RDI: 0000000000000005
RBP: 00007f6ce2536ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 00008400fffffffa R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff1f03dbef R14: 00007f6ce0e52300 R15: 0000000000022000
 </TASK>
NMI backtrace for cpu 1
CPU: 1 PID: 5690 Comm: syz-executor.1 Not tainted 5.16.0-rc6-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+0x1dc/0x2d8 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x45f/0x490 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x16a/0x280 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_dump_cpu_stacks+0x22d/0x390 kernel/rcu/tree_stall.h:343
 print_cpu_stall kernel/rcu/tree_stall.h:627 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:711 [inline]
 rcu_pending kernel/rcu/tree.c:3878 [inline]
 rcu_sched_clock_irq+0x1e33/0x2bc0 kernel/rcu/tree.c:2597
 update_process_times+0x197/0x200 kernel/time/timer.c:1785
 tick_sched_handle kernel/time/tick-sched.c:226 [inline]
 tick_sched_timer+0x27d/0x420 kernel/time/tick-sched.c:1428
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x4cb/0xa60 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x3b3/0x1040 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0xf9/0x270 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20
RIP: 0010:vfs_iter_write+0x0/0xa0 fs/read_write.c:889
Code: 89 e7 e8 c3 97 f4 ff e9 11 fe ff ff 44 89 e9 80 e1 07 80 c1 03 38 c1 0f 8c 40 fe ff ff 4c 89 ef e8 b5 97 f4 ff e9 33 fe ff ff <55> 41 57 41 56 41 55 41 54 53 41 89 ce 49 89 d7 49 89 f4 48 89 fb
RSP: 0018:ffffc90004adf818 EFLAGS: 00000246
RAX: 1fc590c5e9241d00 RBX: ffffc90004adf938 RCX: 0000000000000000
RDX: ffffc90004adf938 RSI: ffffc90004adf980 RDI: ffff88807c76f400
RBP: ffffc90004adfa30 R08: dffffc0000000000 R09: fffff5200095bf31
R10: fffff5200095bf31 R11: 0000000000000000 R12: dffffc0000000000
R13: ffff88807e44a578 R14: ffffc90004adf980 R15: dffffc0000000000
 iter_file_splice_write+0x7eb/0xfa0 fs/splice.c:689
 do_splice_from fs/splice.c:767 [inline]
 direct_splice_actor+0xe6/0x1c0 fs/splice.c:936
 splice_direct_to_actor+0x529/0xd00 fs/splice.c:891
 do_splice_direct+0x291/0x3e0 fs/splice.c:979
 do_sendfile+0x6fe/0x1040 fs/read_write.c:1245
 __do_sys_sendfile64 fs/read_write.c:1310 [inline]
 __se_sys_sendfile64+0x171/0x1d0 fs/read_write.c:1296
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x44/0xd0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f6ce24dce99
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:00007f6ce0e52168 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00007f6ce25eff60 RCX: 00007f6ce24dce99
RDX: 0000000000000000 RSI: 000000000000000b RDI: 0000000000000005
RBP: 00007f6ce2536ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 00008400fffffffa R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff1f03dbef R14: 00007f6ce0e52300 R15: 0000000000022000
 </TASK>
sched: RT throttling activated
----------------
Code disassembly (best guess):
   0:	89 e7                	mov    %esp,%edi
   2:	e8 c3 97 f4 ff       	callq  0xfff497ca
   7:	e9 11 fe ff ff       	jmpq   0xfffffe1d
   c:	44 89 e9             	mov    %r13d,%ecx
   f:	80 e1 07             	and    $0x7,%cl
  12:	80 c1 03             	add    $0x3,%cl
  15:	38 c1                	cmp    %al,%cl
  17:	0f 8c 40 fe ff ff    	jl     0xfffffe5d
  1d:	4c 89 ef             	mov    %r13,%rdi
  20:	e8 b5 97 f4 ff       	callq  0xfff497da
  25:	e9 33 fe ff ff       	jmpq   0xfffffe5d
* 2a:	55                   	push   %rbp <-- trapping instruction
  2b:	41 57                	push   %r15
  2d:	41 56                	push   %r14
  2f:	41 55                	push   %r13
  31:	41 54                	push   %r12
  33:	53                   	push   %rbx
  34:	41 89 ce             	mov    %ecx,%r14d
  37:	49 89 d7             	mov    %rdx,%r15
  3a:	49 89 f4             	mov    %rsi,%r12
  3d:	48 89 fb             	mov    %rdi,%rbx

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-smack-root 2021/12/23 21:57 upstream 76657eaef4a7 6caa12e4 .config log report info INFO: rcu detected stall in vfs_iter_write
* Struck through repros no longer work on HEAD.