syzbot


INFO: rcu detected stall in br_handle_frame
Status: fixed on 2019/12/07 19:24
Reported-by: syzbot+04f79b221ef00491c0c7@syzkaller.appspotmail.com
Fix commit: cc243e2427ce sch_hhf: ensure quantum and hhf_non_hh_weight are non-zero
First crash: 991d, last: 979d

Fix bisection: fixed by (bisect log) :
commit cc243e2427cef2a5dd7367cb0e0b846503350ffe
Author: Cong Wang <xiyou.wangcong@gmail.com>
Date: Sun Sep 8 20:40:51 2019 +0000

  sch_hhf: ensure quantum and hhf_non_hh_weight are non-zero

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 601d 601d 0/1 auto-closed as invalid on 2021/01/28 07:46
upstream INFO: rcu detected stall in br_handle_frame C done 341 982d 987d 14/22 fixed on 2019/10/09 10:54
upstream INFO: rcu detected stall in br_handle_frame (2) C done 2 886d 882d 16/22 fixed on 2020/02/18 14:31
upstream INFO: rcu detected stall in br_handle_frame (3) 1 311d 311d 0/22 auto-closed as invalid on 2021/10/15 13:41
linux-4.14 INFO: rcu detected stall in br_handle_frame (2) C done 1 887d 887d 1/1 fixed on 2020/01/19 15:05
linux-4.19 INFO: rcu detected stall in br_handle_frame (2) C error 28 50d 587d 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 979d 991d 1/1 fixed on 2019/12/07 19:18
upstream INFO: rcu detected stall in br_handle_frame (4) 1 150d 150d 0/22 closed as invalid on 2022/02/08 10:10

Sample crash report:
IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready
IPv6: ADDRCONF(NETDEV_UP): vxcan1: link is not ready
8021q: adding VLAN 0 to HW filter on device batadv0
INFO: rcu_preempt self-detected stall on CPU
	1-...: (1 GPs behind) idle=4ca/140000000000001/0 softirq=10255/10259 fqs=24 
	 (t=10500 jiffies g=1056 c=1055 q=14)
rcu_preempt kthread starved for 10452 jiffies! g1056 c1055 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_preempt     R  running task    29776     8      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1744
 rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
NMI backtrace for cpu 1
CPU: 1 PID: 18 Comm: kworker/1:0 Not tainted 4.14.142 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: ipv6_addrconf addrconf_dad_work
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:17 [inline]
 dump_stack+0x138/0x197 lib/dump_stack.c:53
 nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x141/0x189 lib/nmi_backtrace.c:62
 arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
 trigger_single_cpu_backtrace include/linux/nmi.h:158 [inline]
 rcu_dump_cpu_stacks+0x186/0x1d2 kernel/rcu/tree.c:1396
 print_cpu_stall kernel/rcu/tree.c:1542 [inline]
 check_cpu_stall kernel/rcu/tree.c:1610 [inline]
 __rcu_pending kernel/rcu/tree.c:3390 [inline]
 rcu_pending kernel/rcu/tree.c:3452 [inline]
 rcu_check_callbacks.cold+0x43d/0xd0a kernel/rcu/tree.c:2792
 update_process_times+0x31/0x70 kernel/time/timer.c:1588
 tick_sched_handle+0x85/0x160 kernel/time/tick-sched.c:161
 tick_sched_timer+0x43/0x130 kernel/time/tick-sched.c:1219
 __run_hrtimer kernel/time/hrtimer.c:1220 [inline]
 __hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1284
 hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1318
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1075 [inline]
 smp_apic_timer_interrupt+0x11c/0x5e0 arch/x86/kernel/apic/apic.c:1100
 apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
RIP: 0010:hhf_dequeue+0xa6/0xa60 net/sched/sch_hhf.c:433
RSP: 0018:ffff8880aef06dc0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 0000000000000000 RBX: ffff8880916d41f8 RCX: 0000000000000000
RDX: 0000000000000100 RSI: ffff8880916d4290 RDI: ffff8880916d4208
RBP: ffff8880aef06e10 R08: 0000000000000000 R09: ffff8880a9d5eef0
R10: ffff8880a9d5eed0 R11: ffff8880a9d5e4c0 R12: dffffc0000000000
R13: ffff8880916d4000 R14: ffff8880916d4290 R15: ffff8880916d4280
 dequeue_skb net/sched/sch_generic.c:148 [inline]
 qdisc_restart net/sched/sch_generic.c:241 [inline]
 __qdisc_run+0x2b8/0xe00 net/sched/sch_generic.c:257
 __dev_xmit_skb net/core/dev.c:3235 [inline]
 __dev_queue_xmit+0x1571/0x25e0 net/core/dev.c:3493
 dev_queue_xmit+0x18/0x20 net/core/dev.c:3558
 br_dev_queue_push_xmit+0x367/0x530 net/bridge/br_forward.c:55
 br_nf_dev_queue_xmit+0x307/0x1440 net/bridge/br_netfilter_hooks.c:776
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 br_nf_post_routing+0xb80/0xf00 net/bridge/br_netfilter_hooks.c:822
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 br_forward_finish+0x1b7/0x320 net/bridge/br_forward.c:67
 br_nf_hook_thresh+0x25b/0x2e0 net/bridge/br_netfilter_hooks.c:1005
 br_nf_forward_finish+0x264/0x640 net/bridge/br_netfilter_hooks.c:550
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 br_nf_forward_ip net/bridge/br_netfilter_hooks.c:617 [inline]
 br_nf_forward_ip+0x5fc/0x11d0 net/bridge/br_netfilter_hooks.c:561
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 __br_forward+0x312/0x9c0 net/bridge/br_forward.c:111
 deliver_clone+0x61/0xc0 net/bridge/br_forward.c:127
 br_flood+0x43c/0x530 net/bridge/br_forward.c:222
 br_handle_frame_finish+0xaf0/0x1830 net/bridge/br_input.c:210
 br_nf_hook_thresh+0x25b/0x2e0 net/bridge/br_netfilter_hooks.c:1005
 br_nf_pre_routing_finish_ipv6+0x621/0xc50 net/bridge/br_netfilter_ipv6.c:210
 NF_HOOK include/linux/netfilter.h:250 [inline]
 br_nf_pre_routing_ipv6+0x417/0x790 net/bridge/br_netfilter_ipv6.c:240
 br_nf_pre_routing+0xdce/0x12c7 net/bridge/br_netfilter_hooks.c:491
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 br_handle_frame+0x80c/0x1110 net/bridge/br_input.c:348
 __netif_receive_skb_core+0x789/0x2ca0 net/core/dev.c:4431
 __netif_receive_skb+0x2c/0x1b0 net/core/dev.c:4515
 process_backlog+0x21f/0x730 net/core/dev.c:5197
 napi_poll net/core/dev.c:5598 [inline]
 net_rx_action+0x490/0xf80 net/core/dev.c:5664
 __do_softirq+0x244/0x9a0 kernel/softirq.c:288
 do_softirq_own_stack+0x2a/0x40 arch/x86/entry/entry_64.S:1015
 </IRQ>
 do_softirq.part.0+0x10e/0x160 kernel/softirq.c:332
 do_softirq kernel/softirq.c:324 [inline]
 __local_bh_enable_ip+0x154/0x1a0 kernel/softirq.c:185
 local_bh_enable include/linux/bottom_half.h:32 [inline]
 rcu_read_unlock_bh include/linux/rcupdate.h:725 [inline]
 ip6_finish_output2+0x9f3/0x21b0 net/ipv6/ip6_output.c:121
 ip6_finish_output+0x4f4/0xb50 net/ipv6/ip6_output.c:154
 NF_HOOK_COND include/linux/netfilter.h:239 [inline]
 ip6_output+0x20f/0x6d0 net/ipv6/ip6_output.c:171
 dst_output include/net/dst.h:462 [inline]
 NF_HOOK include/linux/netfilter.h:250 [inline]
 ndisc_send_skb+0xb56/0x11e0 net/ipv6/ndisc.c:483
 ndisc_send_ns+0x360/0x7e0 net/ipv6/ndisc.c:625
 addrconf_dad_work+0xa40/0xff0 net/ipv6/addrconf.c:3996
 process_one_work+0x863/0x1600 kernel/workqueue.c:2114
 worker_thread+0x5d9/0x1050 kernel/workqueue.c:2248
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: rcu_sched detected stalls on CPUs/tasks:
	1-...: (1 GPs behind) idle=4ca/140000000000000/0 softirq=10252/10259 fqs=24 
	(detected by 0, t=10578 jiffies, g=755, c=754, q=1)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 18 Comm: kworker/1:0 Not tainted 4.14.142 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: ipv6_addrconf addrconf_dad_work
task: ffff8880a9d5e4c0 task.stack: ffff8880a9d68000
RIP: 0010:__sanitizer_cov_trace_pc+0x9/0x60 kernel/kcov.c:65
RSP: 0018:ffff8880aef06db8 EFLAGS: 00000246
RAX: ffff8880a9d5e4c0 RBX: ffff8880916d41f8 RCX: 0000000000000000
RDX: 0000000000000007 RSI: ffff8880916d4290 RDI: ffff8880916d42ac
RBP: ffff8880aef06e10 R08: 0000000000000000 R09: ffff8880a9d5eef0
R10: ffff8880a9d5eed0 R11: ffff8880a9d5e4c0 R12: dffffc0000000000
R13: ffff8880916d4000 R14: 0000000000000002 R15: ffff8880916d4280
FS:  0000000000000000(0000) GS:ffff8880aef00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000004c7308 CR3: 000000000766a000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 dequeue_skb net/sched/sch_generic.c:148 [inline]
 qdisc_restart net/sched/sch_generic.c:241 [inline]
 __qdisc_run+0x2b8/0xe00 net/sched/sch_generic.c:257
 __dev_xmit_skb net/core/dev.c:3235 [inline]
 __dev_queue_xmit+0x1571/0x25e0 net/core/dev.c:3493
 dev_queue_xmit+0x18/0x20 net/core/dev.c:3558
 br_dev_queue_push_xmit+0x367/0x530 net/bridge/br_forward.c:55
 br_nf_dev_queue_xmit+0x307/0x1440 net/bridge/br_netfilter_hooks.c:776
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 br_nf_post_routing+0xb80/0xf00 net/bridge/br_netfilter_hooks.c:822
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 br_forward_finish+0x1b7/0x320 net/bridge/br_forward.c:67
 br_nf_hook_thresh+0x25b/0x2e0 net/bridge/br_netfilter_hooks.c:1005
 br_nf_forward_finish+0x264/0x640 net/bridge/br_netfilter_hooks.c:550
 NF_HOOK include/linux/netfilter.h:250 [inline]
 NF_HOOK include/linux/netfilter.h:244 [inline]
 br_nf_forward_ip net/bridge/br_netfilter_hooks.c:617 [inline]
 br_nf_forward_ip+0x5fc/0x11d0 net/bridge/br_netfilter_hooks.c:561
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 __br_forward+0x312/0x9c0 net/bridge/br_forward.c:111
 deliver_clone+0x61/0xc0 net/bridge/br_forward.c:127
 br_flood+0x43c/0x530 net/bridge/br_forward.c:222
 br_handle_frame_finish+0xaf0/0x1830 net/bridge/br_input.c:210
 br_nf_hook_thresh+0x25b/0x2e0 net/bridge/br_netfilter_hooks.c:1005
 br_nf_pre_routing_finish_ipv6+0x621/0xc50 net/bridge/br_netfilter_ipv6.c:210
 NF_HOOK include/linux/netfilter.h:250 [inline]
 br_nf_pre_routing_ipv6+0x417/0x790 net/bridge/br_netfilter_ipv6.c:240
 br_nf_pre_routing+0xdce/0x12c7 net/bridge/br_netfilter_hooks.c:491
 nf_hook_entry_hookfn include/linux/netfilter.h:108 [inline]
 nf_hook_slow+0xaf/0x1b0 net/netfilter/core.c:467
 nf_hook include/linux/netfilter.h:205 [inline]
 NF_HOOK include/linux/netfilter.h:248 [inline]
 br_handle_frame+0x80c/0x1110 net/bridge/br_input.c:348
 __netif_receive_skb_core+0x789/0x2ca0 net/core/dev.c:4431
 __netif_receive_skb+0x2c/0x1b0 net/core/dev.c:4515
 process_backlog+0x21f/0x730 net/core/dev.c:5197
 napi_poll net/core/dev.c:5598 [inline]
 net_rx_action+0x490/0xf80 net/core/dev.c:5664
 __do_softirq+0x244/0x9a0 kernel/softirq.c:288
 do_softirq_own_stack+0x2a/0x40 arch/x86/entry/entry_64.S:1015
 </IRQ>
 do_softirq.part.0+0x10e/0x160 kernel/softirq.c:332
 do_softirq kernel/softirq.c:324 [inline]
 __local_bh_enable_ip+0x154/0x1a0 kernel/softirq.c:185
 local_bh_enable include/linux/bottom_half.h:32 [inline]
 rcu_read_unlock_bh include/linux/rcupdate.h:725 [inline]
 ip6_finish_output2+0x9f3/0x21b0 net/ipv6/ip6_output.c:121
 ip6_finish_output+0x4f4/0xb50 net/ipv6/ip6_output.c:154
 NF_HOOK_COND include/linux/netfilter.h:239 [inline]
 ip6_output+0x20f/0x6d0 net/ipv6/ip6_output.c:171
 dst_output include/net/dst.h:462 [inline]
 NF_HOOK include/linux/netfilter.h:250 [inline]
 ndisc_send_skb+0xb56/0x11e0 net/ipv6/ndisc.c:483
 ndisc_send_ns+0x360/0x7e0 net/ipv6/ndisc.c:625
 addrconf_dad_work+0xa40/0xff0 net/ipv6/addrconf.c:3996
 process_one_work+0x863/0x1600 kernel/workqueue.c:2114
 worker_thread+0x5d9/0x1050 kernel/workqueue.c:2248
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: 4c 89 35 eb 3f be 07 41 be f4 ff ff ff e8 13 3c ee ff 48 c7 05 d5 3f be 07 00 00 00 00 e9 2f ec ff ff 65 48 8b 04 25 40 ee 01 00 <48> 85 c0 74 1a 65 8b 15 4b fb a4 7e 81 e2 00 01 1f 00 75 0b 8b 
rcu_sched kthread starved for 10531 jiffies! g755 c754 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched       R  running task    29824     9      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2807 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
 schedule+0x92/0x1c0 kernel/sched/core.c:3427
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1744
 rcu_gp_kthread+0xbf4/0x1ec0 kernel/rcu/tree.c:2255
 kthread+0x319/0x430 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Crashes (15):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2019/09/08 13:20 linux-4.14.y 414510bc00a5 a60cb4cd .config log report syz C
ci2-linux-4-14 2019/09/08 07:38 linux-4.14.y 414510bc00a5 a60cb4cd .config log report syz C
ci2-linux-4-14 2019/09/07 13:59 linux-4.14.y 414510bc00a5 a60cb4cd .config log report syz C
ci2-linux-4-14 2019/09/18 16:44 linux-4.14.y 968722f5371a 46c0be24 .config log report
ci2-linux-4-14 2019/09/16 21:34 linux-4.14.y 968722f5371a 51ca0454 .config log report
ci2-linux-4-14 2019/09/16 20:48 linux-4.14.y 968722f5371a 51ca0454 .config log report
ci2-linux-4-14 2019/09/16 17:04 linux-4.14.y 968722f5371a 55c50e70 .config log report
ci2-linux-4-14 2019/09/16 07:08 linux-4.14.y 968722f5371a 32d59357 .config log report
ci2-linux-4-14 2019/09/14 11:32 linux-4.14.y e2cd24b62938 32d59357 .config log report
ci2-linux-4-14 2019/09/13 16:04 linux-4.14.y e2cd24b62938 32d59357 .config log report
ci2-linux-4-14 2019/09/11 21:00 linux-4.14.y e2cd24b62938 f4e53c10 .config log report
ci2-linux-4-14 2019/09/10 10:49 linux-4.14.y e2cd24b62938 a60cb4cd .config log report
ci2-linux-4-14 2019/09/09 04:57 linux-4.14.y 414510bc00a5 a60cb4cd .config log report
ci2-linux-4-14 2019/09/07 03:14 linux-4.14.y 414510bc00a5 a60cb4cd .config log report
ci2-linux-4-14 2019/09/07 03:05 linux-4.14.y 414510bc00a5 a60cb4cd .config log report