INFO: rcu detected stall in br_hello_timer

Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
upstream	INFO: rcu detected stall in br_hello_timer_expired net				4	1895d	1900d	13/28	fixed on 2019/10/09 10:54
netlink: 4 bytes leftover after parsing attributes in process `syz-executor.4'.
INFO: rcu_sched detected stalls on CPUs/tasks:
	1-...: (1 GPs behind) idle=356/140000000000002/0 softirq=307264/307265 fqs=51 
	(detected by 0, t=10502 jiffies, g=78161, c=78160, q=14)
Sending NMI from CPU 0 to CPUs 1:
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.354 msecs
NMI backtrace for cpu 1
CPU: 1 PID: 28572 Comm: syz-executor.0 Not tainted 4.14.169-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88819386a600 task.stack: ffff888193ff8000
RIP: 0010:hrtimer_forward+0x147/0x1f0 kernel/time/hrtimer.c:830
RSP: 0018:ffff8880aed06b68 EFLAGS: 00000006
RAX: ffff88819386a600 RBX: ffff8881f14575c8 RCX: 0000000000000017
RDX: 0000000000010100 RSI: 0000026e9b5cc2ac RDI: ffff8881f14575e8
RBP: ffff8880aed06bb0 R08: 0000026fdfbaefa5 R09: ffff88821fff7048
R10: ffff88821fff7050 R11: 0000000000000001 R12: 0000000000002710
R13: 0000026e9b5cd2bf R14: 0000026e9b5cabaf R15: 0000000000000001
FS:  00007f68aed87700(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b31b21000 CR3: 00000001f111a000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 hrtimer_forward_now include/linux/hrtimer.h:457 [inline]
 perf_swevent_hrtimer+0x2c3/0x350 kernel/events/core.c:8733
 __run_hrtimer kernel/time/hrtimer.c:1223 [inline]
 __hrtimer_run_queues+0x270/0xbc0 kernel/time/hrtimer.c:1287
 hrtimer_interrupt+0x1d8/0x5d0 kernel/time/hrtimer.c:1321
 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:kernel_text_address+0x0/0xf0 kernel/extable.c:121
RSP: 0018:ffff8880aed07080 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: dffffc0000000000 RBX: ffffffff85af91eb RCX: 1ffff11015da0e20
RDX: 1ffff11015da0e21 RSI: 1ffff11015da0e00 RDI: ffffffff85af91eb
RBP: ffff8880aed07090 R08: 0000000000000001 R09: ffff8880aed07118
R10: ffff8880aed070e8 R11: ffff8880aed070f8 R12: ffff8880aed07108
R13: 0000000000000000 R14: ffff88819386a600 R15: ffff8880aa800ac0
 unwind_get_return_address arch/x86/kernel/unwind_frame.c:18 [inline]
 unwind_get_return_address+0x61/0xa0 arch/x86/kernel/unwind_frame.c:13
 __save_stack_trace+0x7b/0xd0 arch/x86/kernel/stacktrace.c:45
 save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
 save_stack+0x45/0xd0 mm/kasan/kasan.c:447
 set_track mm/kasan/kasan.c:459 [inline]
 kasan_kmalloc mm/kasan/kasan.c:551 [inline]
 kasan_kmalloc+0xce/0xf0 mm/kasan/kasan.c:529
 kasan_slab_alloc+0xf/0x20 mm/kasan/kasan.c:489
 slab_post_alloc_hook mm/slab.h:442 [inline]
 slab_alloc_node mm/slab.c:3333 [inline]
 kmem_cache_alloc_node_trace+0x13c/0x770 mm/slab.c:3659
 __do_kmalloc_node mm/slab.c:3681 [inline]
 __kmalloc_node_track_caller+0x3d/0x80 mm/slab.c:3696
 __kmalloc_reserve.isra.0+0x40/0xe0 net/core/skbuff.c:137
 pskb_expand_head+0x116/0xc10 net/core/skbuff.c:1462
 __skb_cow include/linux/skbuff.h:2936 [inline]
 skb_cow_head include/linux/skbuff.h:2970 [inline]
 gre_tap_xmit+0x2f4/0x370 net/ipv4/ip_gre.c:772
 __netdev_start_xmit include/linux/netdevice.h:4039 [inline]
 netdev_start_xmit include/linux/netdevice.h:4048 [inline]
 xmit_one net/core/dev.c:3009 [inline]
 dev_hard_start_xmit+0x18c/0x8b0 net/core/dev.c:3025
 sch_direct_xmit+0x27a/0x550 net/sched/sch_generic.c:186
 __dev_xmit_skb net/core/dev.c:3218 [inline]
 __dev_queue_xmit+0x1b6e/0x25e0 net/core/dev.c:3493
 dev_queue_xmit+0x18/0x20 net/core/dev.c:3558
 macvlan_queue_xmit drivers/net/macvlan.c:538 [inline]
 macvlan_start_xmit+0x3da/0x7a7 drivers/net/macvlan.c:566
 __netdev_start_xmit include/linux/netdevice.h:4039 [inline]
 netdev_start_xmit include/linux/netdevice.h:4048 [inline]
 xmit_one net/core/dev.c:3009 [inline]
 dev_hard_start_xmit+0x18c/0x8b0 net/core/dev.c:3025
 __dev_queue_xmit+0x1d95/0x25e0 net/core/dev.c:3525
 dev_queue_xmit+0x18/0x20 net/core/dev.c:3558
 br_send_bpdu_finish net/bridge/br_stp_bpdu.c:36 [inline]
 NF_HOOK include/linux/netfilter.h:250 [inline]
 br_send_bpdu.isra.0.constprop.0+0x5d0/0xa70 net/bridge/br_stp_bpdu.c:63
 br_send_config_bpdu+0x64b/0x750 net/bridge/br_stp_bpdu.c:124
 br_transmit_config.part.0+0x448/0x640 net/bridge/br_stp.c:207
 br_transmit_config net/bridge/br_stp.c:368 [inline]
 br_config_bpdu_generation+0x194/0x1f0 net/bridge/br_stp.c:366
 br_hello_timer_expired+0x92/0x170 net/bridge/br_stp_timer.c:41
 call_timer_fn+0x161/0x670 kernel/time/timer.c:1279
 expire_timers kernel/time/timer.c:1318 [inline]
 __run_timers kernel/time/timer.c:1636 [inline]
 __run_timers kernel/time/timer.c:1604 [inline]
 run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649
 __do_softirq+0x244/0x9a0 kernel/softirq.c:288
 invoke_softirq kernel/softirq.c:368 [inline]
 irq_exit+0x160/0x1b0 kernel/softirq.c:409
 exiting_irq arch/x86/include/asm/apic.h:648 [inline]
 smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
 apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
 </IRQ>
RIP: 0010:insert_header+0x467/0xef0 fs/proc/proc_sysctl.c:231
RSP: 0018:ffff888193fff9e8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 1ffff110084330b0 RBX: ffff8881f1a6e600 RCX: ffffc90006829000
RDX: 1ffff1103e34dcba RSI: ffff88801e1619d0 RDI: ffff8881f1a6e630
RBP: ffff888193fffa60 R08: ffff8881f1a6e5d8 R09: ffffffff89566558
R10: ffff88819386ae80 R11: ffff88819386a600 R12: ffff8881f1a6e630
R13: dffffc0000000000 R14: ffff8881f1a6e5f0 R15: ffff8881f1a6e580
 __register_sysctl_table+0x5d3/0xe50 fs/proc/proc_sysctl.c:1339
 setup_userns_sysctls+0xbc/0x180 kernel/ucount.c:97
 create_user_ns+0x79c/0xcd0 kernel/user_namespace.c:138
 copy_creds+0x3e9/0x4f0 kernel/cred.c:353
 copy_process.part.0+0x868/0x6a70 kernel/fork.c:1644
 copy_process kernel/fork.c:1586 [inline]
 _do_fork+0x19e/0xce0 kernel/fork.c:2070
 SYSC_clone kernel/fork.c:2180 [inline]
 SyS_clone+0x37/0x50 kernel/fork.c:2174
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45b399
RSP: 002b:00007f68aed86c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000038
RAX: ffffffffffffffda RBX: 00007f68aed876d4 RCX: 000000000045b399
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000030020100
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000070 R14: 00000000004c1c24 R15: 000000000075bf2c
Code: 00 4c 3b 6d b8 7c 42 e8 f8 e3 0c 00 4d 39 ec 48 b8 ff ff ff ff ff ff ff 7f 4c 0f 4f e8 e8 e2 e3 0c 00 4c 89 6b 20 e8 d9 e3 0c 00 <4c> 89 f8 48 83 c4 20 5b 41 5c 41 5d 41 5e 41 5f 5d c3 49 bd ff 
rcu_sched kthread starved for 10398 jiffies! g78161 c78160 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=0
rcu_sched       R  running task    28976     9      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1746
 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
INFO: rcu_preempt detected stalls on CPUs/tasks:
	1-...: (1 GPs behind) idle=356/140000000000002/0 softirq=307264/307265 fqs=38 
	(detected by 0, t=10572 jiffies, g=115510, c=115509, q=254)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 28572 Comm: syz-executor.0 Not tainted 4.14.169-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88819386a600 task.stack: ffff888193ff8000
RIP: 0010:check_preemption_disabled+0x6/0x250 lib/smp_processor_id.c:13
RSP: 0018:ffff8880aed076c0 EFLAGS: 00000006
RAX: ffff88819386a600 RBX: 00000000000278c8 RCX: ffff88819386ae80
RDX: 0000000000010100 RSI: ffffffff87045280 RDI: ffffffff870452c0
RBP: ffff8880aed076c8 R08: 0000027019fbe0fa R09: ffff88821fff7048
R10: ffff88821fff7050 R11: 0000000000000001 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
FS:  00007f68aed87700(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b31b21000 CR3: 00000001f111a000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 debug_smp_processor_id+0x1c/0x20 lib/smp_processor_id.c:57
 irq_work_run+0x1a/0xb0 kernel/irq_work.c:171
 smp_irq_work_interrupt+0xa8/0x4e0 arch/x86/kernel/irq_work.c:21
 irq_work_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:823
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:779 [inline]
RIP: 0010:lock_release+0x44d/0x940 kernel/locking/lockdep.c:4016
RSP: 0018:ffff8880aed077e8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff09
RAX: 1ffffffff0fe2ce1 RBX: 1ffff11015da0f03 RCX: 1ffff1103270d5ce
RDX: dffffc0000000000 RSI: 0000000000000005 RDI: 0000000000000286
RBP: ffff8880aed07880 R08: ffff88819386a600 R09: 0000000000000004
R10: 0000000000000000 R11: ffff88819386a600 R12: ffff88819386a600
R13: ffffffff85b4a423 R14: 0000000000000003 R15: ffff8880aed07858
 __raw_read_unlock_bh include/linux/rwlock_api_smp.h:249 [inline]
 _raw_read_unlock_bh+0x1b/0x40 kernel/locking/spinlock.c:280
 ebt_do_table+0x1663/0x1ac0 net/bridge/netfilter/ebtables.c:300
 ebt_in_hook+0x65/0x80 net/bridge/netfilter/ebtable_filter.c:63
 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_send_bpdu.isra.0.constprop.0+0x6e3/0xa70 net/bridge/br_stp_bpdu.c:63
 br_send_config_bpdu+0x64b/0x750 net/bridge/br_stp_bpdu.c:124
 br_transmit_config.part.0+0x448/0x640 net/bridge/br_stp.c:207
 br_transmit_config net/bridge/br_stp.c:368 [inline]
 br_config_bpdu_generation+0x194/0x1f0 net/bridge/br_stp.c:366
 br_hello_timer_expired+0x92/0x170 net/bridge/br_stp_timer.c:41
 call_timer_fn+0x161/0x670 kernel/time/timer.c:1279
 expire_timers kernel/time/timer.c:1318 [inline]
 __run_timers kernel/time/timer.c:1636 [inline]
 __run_timers kernel/time/timer.c:1604 [inline]
 run_timer_softirq+0x5b7/0x1520 kernel/time/timer.c:1649
 __do_softirq+0x244/0x9a0 kernel/softirq.c:288
 invoke_softirq kernel/softirq.c:368 [inline]
 irq_exit+0x160/0x1b0 kernel/softirq.c:409
 exiting_irq arch/x86/include/asm/apic.h:648 [inline]
 smp_apic_timer_interrupt+0x146/0x5e0 arch/x86/kernel/apic/apic.c:1102
 apic_timer_interrupt+0x96/0xa0 arch/x86/entry/entry_64.S:792
 </IRQ>
RIP: 0010:insert_header+0x467/0xef0 fs/proc/proc_sysctl.c:231
RSP: 0018:ffff888193fff9e8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
RAX: 1ffff110084330b0 RBX: ffff8881f1a6e600 RCX: ffffc90006829000
RDX: 1ffff1103e34dcba RSI: ffff88801e1619d0 RDI: ffff8881f1a6e630
RBP: ffff888193fffa60 R08: ffff8881f1a6e5d8 R09: ffffffff89566558
R10: ffff88819386ae80 R11: ffff88819386a600 R12: ffff8881f1a6e630
R13: dffffc0000000000 R14: ffff8881f1a6e5f0 R15: ffff8881f1a6e580
 __register_sysctl_table+0x5d3/0xe50 fs/proc/proc_sysctl.c:1339
 setup_userns_sysctls+0xbc/0x180 kernel/ucount.c:97
 create_user_ns+0x79c/0xcd0 kernel/user_namespace.c:138
 copy_creds+0x3e9/0x4f0 kernel/cred.c:353
 copy_process.part.0+0x868/0x6a70 kernel/fork.c:1644
 copy_process kernel/fork.c:1586 [inline]
 _do_fork+0x19e/0xce0 kernel/fork.c:2070
 SYSC_clone kernel/fork.c:2180 [inline]
 SyS_clone+0x37/0x50 kernel/fork.c:2174
 do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x45b399
RSP: 002b:00007f68aed86c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000038
RAX: ffffffffffffffda RBX: 00007f68aed876d4 RCX: 000000000045b399
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000030020100
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000070 R14: 00000000004c1c24 R15: 000000000075bf2c
Code: 71 4a 79 fe e9 5b f2 ff ff e8 c7 49 79 fe e9 2f f2 ff ff e8 9d 4a 79 fe e9 5b f1 ff ff 90 90 90 90 90 90 90 90 55 48 89 e5 41 57 <41> 56 49 89 fe 41 55 49 89 f5 41 54 53 48 83 ec 08 e8 54 b9 4e 
rcu_preempt kthread starved for 10495 jiffies! g115510 c115509 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:2808 [inline]
 __schedule+0x7b8/0x1cd0 kernel/sched/core.c:3384
 schedule+0x92/0x1c0 kernel/sched/core.c:3428
 schedule_timeout+0x43e/0xe10 kernel/time/timer.c:1746
 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