syzbot


INFO: rcu detected stall in console_trylock_spinning

Status: auto-closed as invalid on 2021/12/01 13:04
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 456d, last: 456d

Sample crash report:
rcu: INFO: rcu_preempt self-detected stall on CPU
rcu: 	1-...!: (1 GPs behind) idle=83f/1/0x4000000000000000 softirq=75863/75864 fqs=0 
	(t=17963 jiffies g=98533 q=2385)
rcu: rcu_preempt kthread starved for 17963 jiffies! g98533 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
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:26288 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 context_switch kernel/sched/core.c:4940 [inline]
 __schedule+0xbfd/0x11d0 kernel/sched/core.c:6287
 schedule+0x14b/0x210 kernel/sched/core.c:6366
 schedule_timeout+0x1aa/0x2f0 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x1fd/0x770 kernel/rcu/tree.c:1957
 rcu_gp_kthread+0xa5/0x340 kernel/rcu/tree.c:2130
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
rcu: Stack dump where RCU GP kthread last ran:
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 10393 Comm: kworker/0:9 Not tainted 5.14.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: rcu_gp wait_rcu_exp_gp
RIP: 0010:orc_ip arch/x86/kernel/unwind_orc.c:30 [inline]
RIP: 0010:__orc_find arch/x86/kernel/unwind_orc.c:52 [inline]
RIP: 0010:orc_find arch/x86/kernel/unwind_orc.c:173 [inline]
RIP: 0010:unwind_next_frame+0x501/0x1fa0 arch/x86/kernel/unwind_orc.c:443
Code: 89 c1 48 c1 f9 02 48 c1 e8 3f 48 01 c8 48 83 e0 fe 49 8d 1c 47 48 89 d8 48 c1 e8 03 48 b9 00 00 00 00 00 fc ff df 0f b6 04 08 <84> c0 75 27 48 63 03 48 01 d8 48 8d 4b 04 4c 39 e0 4c 0f 46 f9 48
RSP: 0018:ffffc900000072e0 EFLAGS: 00000a03
RAX: 0000000000000000 RBX: ffffffff8de9477c RCX: dffffc0000000000
RDX: ffffffff8e518f6a RSI: ffffffff814dd51f RDI: 0000000000000001
RBP: ffffffff8de94778 R08: 0000000000000009 R09: ffffc90000007470
R10: fffff52000000e80 R11: 0000000000000000 R12: ffffffff814dd51e
R13: ffffffff8de94784 R14: ffffffff8de94778 R15: ffffffff8de94778
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c019034000 CR3: 000000002877c000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 arch_stack_walk+0xb2/0xe0 arch/x86/kernel/stacktrace.c:25
 stack_trace_save+0x104/0x1e0 kernel/stacktrace.c:121
 kasan_save_stack mm/kasan/common.c:38 [inline]
 kasan_set_track+0x3d/0x70 mm/kasan/common.c:46
 kasan_set_free_info+0x1f/0x40 mm/kasan/generic.c:360
 ____kasan_slab_free+0x10d/0x150 mm/kasan/common.c:366
 kasan_slab_free include/linux/kasan.h:230 [inline]
 slab_free_hook mm/slub.c:1628 [inline]
 slab_free_freelist_hook+0x1e8/0x2a0 mm/slub.c:1653
 slab_free mm/slub.c:3213 [inline]
 kfree+0xcf/0x2e0 mm/slub.c:4267
 skb_free_head net/core/skbuff.c:654 [inline]
 skb_release_data+0x3c3/0x4f0 net/core/skbuff.c:676
 skb_release_all net/core/skbuff.c:741 [inline]
 __kfree_skb+0x56/0x1d0 net/core/skbuff.c:755
 ip6_mc_input+0x8d0/0xd40 net/ipv6/ip6_input.c:569
 __netif_receive_skb_one_core net/core/dev.c:5436 [inline]
 __netif_receive_skb+0x1d1/0x500 net/core/dev.c:5550
 process_backlog+0x4d8/0x940 net/core/dev.c:6427
 __napi_poll+0xba/0x4f0 net/core/dev.c:6982
 napi_poll net/core/dev.c:7049 [inline]
 net_rx_action+0x62c/0xf30 net/core/dev.c:7136
 __do_softirq+0x372/0x783 kernel/softirq.c:558
 __irq_exit_rcu+0xcf/0x150 kernel/softirq.c:636
 irq_exit_rcu+0x5/0x20 kernel/softirq.c:648
 sysvec_apic_timer_interrupt+0x91/0xb0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:console_trylock_spinning+0x31b/0x3a0 kernel/printk/printk.c:1885
Code: 08 4d 85 ed 74 91 e8 f4 36 1a 00 fb 31 db eb 41 e8 ea 36 1a 00 e8 15 ff 7b 08 4d 85 ed 74 d1 e8 db 36 1a 00 fb bb 01 00 00 00 <48> c7 c7 80 7e 7f 8c 31 f6 ba 01 00 00 00 31 c9 41 b8 01 00 00 00
RSP: 0018:ffffc900181178e0 EFLAGS: 00000293
RAX: ffffffff8166a5a5 RBX: 0000000000000001 RCX: ffff888030d91c80
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffc900181179b0 R08: ffffffff8166a562 R09: fffffbfff1bb700e
R10: fffffbfff1bb700e R11: 0000000000000000 R12: 1ffff92003022f1c
R13: 0000000000000200 R14: 0000000000000082 R15: dffffc0000000000
 vprintk_emit+0xa1/0x140 kernel/printk/printk.c:2243
 _printk+0xc0/0x108 kernel/printk/printk.c:2265
 synchronize_rcu_expedited_wait kernel/rcu/tree_exp.h:525 [inline]
 rcu_exp_wait_wake kernel/rcu/tree_exp.h:584 [inline]
 rcu_exp_sel_wait_wake+0x88b/0x1a00 kernel/rcu/tree_exp.h:618
 process_one_work+0x853/0x1140 kernel/workqueue.c:2297
 worker_thread+0xac1/0x1320 kernel/workqueue.c:2444
 kthread+0x453/0x480 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
NMI backtrace for cpu 1
CPU: 1 PID: 5663 Comm: syz-executor.4 Not tainted 5.14.0-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+0x1ae/0x29f lib/dump_stack.c:105
 nmi_cpu_backtrace+0x405/0x430 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x191/0x2f0 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:3880 [inline]
 rcu_sched_clock_irq+0x1dc2/0x2b40 kernel/rcu/tree.c:2599
 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:1421
 __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>
 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+0xaa5/0xd60 kernel/smp.c:969
Code: df 75 12 e8 ad 9d 0b 00 eb 50 66 66 2e 0f 1f 84 00 00 00 00 00 f3 90 42 0f b6 04 3b 84 c0 75 11 41 f7 45 00 01 00 00 00 74 2b <e8> 86 9d 0b 00 eb e4 44 89 e9 80 e1 07 80 c1 03 38 c1 7c e2 4c 89
RSP: 0018:ffffc9000235fb00 EFLAGS: 00000202
RAX: 0000000000000000 RBX: 1ffff11017387055 RCX: 0000000000040000
RDX: ffffc90014c75000 RSI: 00000000000072a7 RDI: 00000000000072a8
RBP: ffffc9000235fc30 R08: ffffffff81753ebe R09: ffffffff842c1850
R10: 0000000000000009 R11: ffff88808de20000 R12: 0000000000000000
R13: ffff8880b9c382a8 R14: 1ffff110173a64a0 R15: dffffc0000000000
 clock_was_set+0x83e/0x910 kernel/time/hrtimer.c:974
 do_settimeofday64+0x80e/0x950 kernel/time/timekeeping.c:1327
 __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+0x1f4/0x230 kernel/time/posix-timers.c:1067
 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+0x44/0xae
RIP: 0033:0x4665f9
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:00007fa6a20df188 EFLAGS: 00000246 ORIG_RAX: 00000000000000e3
RAX: ffffffffffffffda RBX: 000000000056bf80 RCX: 00000000004665f9
RDX: 0000000000000000 RSI: 0000000020000100 RDI: 0000000000000000
RBP: 00000000004bfcc4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf80
R13: 00007ffe2d7308af R14: 00007fa6a20df300 R15: 0000000000022000
----------------
Code disassembly (best guess):
   0:	89 c1                	mov    %eax,%ecx
   2:	48 c1 f9 02          	sar    $0x2,%rcx
   6:	48 c1 e8 3f          	shr    $0x3f,%rax
   a:	48 01 c8             	add    %rcx,%rax
   d:	48 83 e0 fe          	and    $0xfffffffffffffffe,%rax
  11:	49 8d 1c 47          	lea    (%r15,%rax,2),%rbx
  15:	48 89 d8             	mov    %rbx,%rax
  18:	48 c1 e8 03          	shr    $0x3,%rax
  1c:	48 b9 00 00 00 00 00 	movabs $0xdffffc0000000000,%rcx
  23:	fc ff df
  26:	0f b6 04 08          	movzbl (%rax,%rcx,1),%eax
* 2a:	84 c0                	test   %al,%al <-- trapping instruction
  2c:	75 27                	jne    0x55
  2e:	48 63 03             	movslq (%rbx),%rax
  31:	48 01 d8             	add    %rbx,%rax
  34:	48 8d 4b 04          	lea    0x4(%rbx),%rcx
  38:	4c 39 e0             	cmp    %r12,%rax
  3b:	4c 0f 46 f9          	cmovbe %rcx,%r15
  3f:	48                   	rex.W

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-smack-root 2021/09/02 12:55 upstream 4ac6d90867a4 15cea0a3 .config log report info INFO: rcu detected stall in console_trylock_spinning
* Struck through repros no longer work on HEAD.