syzbot


INFO: rcu detected stall in br_handle_frame (3)

Status: auto-closed as invalid on 2021/10/15 13:41
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 503d, last: 503d
similar bugs (8):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.14 INFO: rcu detected stall in br_handle_frame (3) 1 794d 794d 0/1 auto-closed as invalid on 2021/01/28 07:46
upstream INFO: rcu detected stall in br_handle_frame C done 341 1174d 1179d 14/24 fixed on 2019/10/09 10:54
upstream INFO: rcu detected stall in br_handle_frame (2) C done 2 1078d 1074d 16/24 fixed on 2020/02/18 14:31
linux-4.14 INFO: rcu detected stall in br_handle_frame (2) C done 1 1079d 1079d 1/1 fixed on 2020/01/19 15:05
linux-4.14 INFO: rcu detected stall in br_handle_frame C done 15 1171d 1183d 1/1 fixed on 2019/12/07 19:24
linux-4.19 INFO: rcu detected stall in br_handle_frame (2) C error 30 15d 779d 0/1 upstream: reported C repro on 2020/10/14 18:56
linux-4.19 INFO: rcu detected stall in br_handle_frame C done 41 1171d 1183d 1/1 fixed on 2019/12/07 19:18
upstream INFO: rcu detected stall in br_handle_frame (4) 1 342d 342d 0/24 closed as invalid on 2022/02/08 10:10

Sample crash report:
bridge0: received packet on veth1_to_bridge with own address as source address (addr:aa:aa:aa:aa:aa:0c, vlan:0)
bridge0: received packet on veth1_to_bridge with own address as source address (addr:76:4a:46:7d:84:b2, vlan:0)
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	0-...0: (2 ticks this GP) idle=16e/1/0x4000000000000000 softirq=333224/333224 fqs=2968 
	(detected by 1, t=10502 jiffies, g=523825, q=1939)

============================================
WARNING: possible recursive locking detected
5.14.0-rc1-syzkaller #0 Not tainted
--------------------------------------------
ksoftirqd/1/19 is trying to acquire lock:
ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: rcu_dump_cpu_stacks+0xd0/0x3f0 kernel/rcu/tree_stall.h:337

but task is already holding lock:
ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: print_other_cpu_stall kernel/rcu/tree_stall.h:543 [inline]
ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: check_cpu_stall kernel/rcu/tree_stall.h:709 [inline]
ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: rcu_pending kernel/rcu/tree.c:3922 [inline]
ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: rcu_sched_clock_irq+0xc9a/0x20c0 kernel/rcu/tree.c:2641

other info that might help us debug this:
 Possible unsafe locking scenario:

       CPU0
       ----
  lock(rcu_node_0);
  lock(rcu_node_0);

 *** DEADLOCK ***

 May be due to missing lock nesting notation

2 locks held by ksoftirqd/1/19:
 #0: ffffffff8b97b900 (rcu_read_lock){....}-{1:2}, at: __skb_unlink include/linux/skbuff.h:2094 [inline]
 #0: ffffffff8b97b900 (rcu_read_lock){....}-{1:2}, at: __skb_dequeue include/linux/skbuff.h:2109 [inline]
 #0: ffffffff8b97b900 (rcu_read_lock){....}-{1:2}, at: process_backlog+0x250/0x6c0 net/core/dev.c:6481
 #1: ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: print_other_cpu_stall kernel/rcu/tree_stall.h:543 [inline]
 #1: ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: check_cpu_stall kernel/rcu/tree_stall.h:709 [inline]
 #1: ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: rcu_pending kernel/rcu/tree.c:3922 [inline]
 #1: ffffffff8b984758 (rcu_node_0){-.-.}-{2:2}, at: rcu_sched_clock_irq+0xc9a/0x20c0 kernel/rcu/tree.c:2641

stack backtrace:
CPU: 1 PID: 19 Comm: ksoftirqd/1 Not tainted 5.14.0-rc1-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:105
 print_deadlock_bug kernel/locking/lockdep.c:2944 [inline]
 check_deadlock kernel/locking/lockdep.c:2987 [inline]
 validate_chain kernel/locking/lockdep.c:3776 [inline]
 __lock_acquire.cold+0x149/0x3ab kernel/locking/lockdep.c:5015
 lock_acquire kernel/locking/lockdep.c:5625 [inline]
 lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5590
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:159
 rcu_dump_cpu_stacks+0xd0/0x3f0 kernel/rcu/tree_stall.h:337
 print_other_cpu_stall kernel/rcu/tree_stall.h:561 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:709 [inline]
 rcu_pending kernel/rcu/tree.c:3922 [inline]
 rcu_sched_clock_irq+0x1cc6/0x20c0 kernel/rcu/tree.c:2641
 update_process_times+0x16d/0x200 kernel/time/timer.c:1782
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:226
 tick_sched_timer+0x1b0/0x2d0 kernel/time/tick-sched.c:1421
 __run_hrtimer kernel/time/hrtimer.c:1537 [inline]
 __hrtimer_run_queues+0x1c0/0xe50 kernel/time/hrtimer.c:1601
 hrtimer_interrupt+0x330/0xa00 kernel/time/hrtimer.c:1663
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1089 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1106
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1100
 </IRQ>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:preempt_count_sub+0x5f/0x150 kernel/sched/core.c:5182
Code: d2 0e 85 c9 75 1b 65 8b 05 0e 9a b2 7e 89 c2 81 e2 ff ff ff 7f 39 da 7c 13 81 fb fe 00 00 00 76 63 f7 db 65 01 1d f1 99 b2 7e <5b> c3 e8 2a 1b 84 02 85 c0 74 f5 48 c7 c0 e8 77 6c 8d 48 ba 00 00
RSP: 0018:ffffc90000d97028 EFLAGS: 00000217
RAX: 0000000000000101 RBX: 00000000ffffffff RCX: 0000000000000000
RDX: 0000000000000101 RSI: ffffc90000d97cd8 RDI: 0000000000000001
RBP: ffffc90000d97d08 R08: ffffffff8e5ab07e R09: 0000000000000001
R10: fffff520001b2e2d R11: 0000000000086088 R12: ffffc90000d90000
R13: ffffc90000d97145 R14: ffffc90000d97110 R15: ffffc90000d97144
 unwind_next_frame+0xec8/0x1ce0 arch/x86/kernel/unwind_orc.c:611
 arch_stack_walk+0x7d/0xe0 arch/x86/kernel/stacktrace.c:25
 stack_trace_save+0x8c/0xc0 kernel/stacktrace.c:121
 kasan_save_stack+0x1b/0x40 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+0x84/0xa0 mm/kasan/common.c:467
 kasan_slab_alloc include/linux/kasan.h:253 [inline]
 slab_post_alloc_hook mm/slab.h:512 [inline]
 slab_alloc_node mm/slub.c:2981 [inline]
 slab_alloc mm/slub.c:2989 [inline]
 kmem_cache_alloc+0x216/0x3a0 mm/slub.c:2994
 skb_clone+0x170/0x3c0 net/core/skbuff.c:1505
 deliver_clone net/bridge/br_forward.c:118 [inline]
 br_flood+0x34c/0x450 net/bridge/br_forward.c:231
 br_handle_frame_finish+0xeaa/0x17a0 net/bridge/br_input.c:163
 br_nf_hook_thresh+0x2a5/0x360 net/bridge/br_netfilter_hooks.c:1025
 br_nf_pre_routing_finish_ipv6+0x684/0xd90 net/bridge/br_netfilter_ipv6.c:206
 NF_HOOK include/linux/netfilter.h:307 [inline]
 br_nf_pre_routing_ipv6+0x42c/0x7b0 net/bridge/br_netfilter_ipv6.c:236
 br_nf_pre_routing+0x1477/0x1ec0 net/bridge/br_netfilter_hooks.c:505
 nf_hook_entry_hookfn include/linux/netfilter.h:142 [inline]
 nf_hook_bridge_pre net/bridge/br_input.c:225 [inline]
 br_handle_frame+0x8fa/0x1180 net/bridge/br_input.c:368
 __netif_receive_skb_core+0x9da/0x3640 net/core/dev.c:5402
 __netif_receive_skb_one_core+0xae/0x180 net/core/dev.c:5506
 __netif_receive_skb+0x24/0x1b0 net/core/dev.c:5622
 process_backlog+0x2a5/0x6c0 net/core/dev.c:6483
 __napi_poll+0xaf/0x440 net/core/dev.c:7038
 napi_poll net/core/dev.c:7105 [inline]
 net_rx_action+0x801/0xb40 net/core/dev.c:7192
 __do_softirq+0x29b/0x9c2 kernel/softirq.c:558
 run_ksoftirqd kernel/softirq.c:920 [inline]
 run_ksoftirqd+0x2d/0x60 kernel/softirq.c:912
 smpboot_thread_fn+0x645/0x9c0 kernel/smpboot.c:164
 kthread+0x3e5/0x4d0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-net-kasan-gce 2021/07/17 13:37 net-next ab0441b4a920 f115ae98 .config log report info INFO: rcu detected stall in br_handle_frame
* Struck through repros no longer work on HEAD.