INFO: rcu detected stall in ipv6_rcv

7 views
Skip to first unread message

syzbot

unread,
Nov 22, 2020, 2:41:15 PM11/22/20
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 76bda503 Linux 4.19.159
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1709fd6d500000
kernel config: https://syzkaller.appspot.com/x/.config?x=9312892b010d9dd0
dashboard link: https://syzkaller.appspot.com/bug?extid=1fe510cef04db175073d
compiler: gcc (GCC) 10.1.0-syz 20200507

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+1fe510...@syzkaller.appspotmail.com

bridge0: received packet on veth0_to_bridge with own address as source address (addr:aa:a8:ad:5b:8e:82, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on veth0_to_bridge with own address as source address (addr:aa:a8:ad:5b:8e:82, vlan:0)
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: (detected by 1, t=10502 jiffies, g=9109, q=4609)
rcu: All QSes seen, last rcu_preempt kthread activity 10485 (4294972934-4294962449), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.3 R running task 26944 10174 8121 0x8000000c
Call Trace:
<IRQ>
sched_show_task.cold+0x332/0x396 kernel/sched/core.c:5341
print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
check_cpu_stall kernel/rcu/tree.c:1557 [inline]
__rcu_pending kernel/rcu/tree.c:3293 [inline]
rcu_pending kernel/rcu/tree.c:3336 [inline]
rcu_check_callbacks.cold+0xb37/0xe19 kernel/rcu/tree.c:2682
update_process_times+0x2a/0x70 kernel/time/timer.c:1650
tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:168
tick_sched_timer+0xfc/0x290 kernel/time/tick-sched.c:1278
__run_hrtimer kernel/time/hrtimer.c:1401 [inline]
__hrtimer_run_queues+0x3f6/0xe60 kernel/time/hrtimer.c:1463
hrtimer_interrupt+0x32a/0x930 kernel/time/hrtimer.c:1521
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1067 [inline]
smp_apic_timer_interrupt+0x10c/0x550 arch/x86/kernel/apic/apic.c:1092
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
RIP: 0010:find_match.part.0+0x34b/0x1530 net/ipv6/route.c:700
Code: 89 45 a8 e8 47 e3 3e fa 48 8b 45 a8 48 85 c0 0f 89 9a fe ff ff 4c 8b 65 b8 e8 a1 e1 3e fa 48 8d 65 d0 4c 89 e0 5b 41 5a 41 5c <41> 5d 41 5e 41 5f 5d c3 c6 45 a8 01 45 31 ed e9 bd fe ff ff e8 7c
RSP: 0018:ffff8880ba106cc8 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: ffff888097b3a480 RCX: ffffffff8725ed2e
RDX: 0000000000000100 RSI: ffffffff8725ee5f RDI: 0000000000000005
RBP: ffff8880ba106ce0 R08: 0000000000000000 R09: 00000000fffffffd
R10: 0000000000000005 R11: 0000000000000000 R12: 0000000000000000
R13: 00000000fffffffd R14: ffff888097b3a4d4 R15: 0000000000000000
find_match net/ipv6/route.c:670 [inline]
find_rr_leaf net/ipv6/route.c:719 [inline]
rt6_select net/ipv6/route.c:769 [inline]
fib6_table_lookup+0x4c2/0xf40 net/ipv6/route.c:1876
ip6_pol_route+0x180/0x1270 net/ipv6/route.c:1909
fib6_rule_lookup+0x10b/0x4e0 net/ipv6/fib6_rules.c:118
ip6_route_input_lookup net/ipv6/route.c:1990 [inline]
ip6_route_input+0x709/0xa40 net/ipv6/route.c:2125
ip6_rcv_finish_core.constprop.0.isra.0+0xd7/0x550 net/ipv6/ip6_input.c:63
ip6_rcv_finish+0x176/0x2f0 net/ipv6/ip6_input.c:74
ip_sabotage_in net/bridge/br_netfilter_hooks.c:844 [inline]
ip_sabotage_in+0x17d/0x1d0 net/bridge/br_netfilter_hooks.c:838
nf_hook_entry_hookfn include/linux/netfilter.h:119 [inline]
nf_hook_slow+0xc5/0x1e0 net/netfilter/core.c:511
nf_hook include/linux/netfilter.h:244 [inline]
NF_HOOK include/linux/netfilter.h:287 [inline]
ipv6_rcv+0x26a/0x3f0 net/ipv6/ip6_input.c:283
__netif_receive_skb_one_core+0x114/0x180 net/core/dev.c:4954
__netif_receive_skb+0x27/0x1c0 net/core/dev.c:5066
netif_receive_skb_internal+0xf0/0x3f0 net/core/dev.c:5156
NF_HOOK include/linux/netfilter.h:289 [inline]
br_pass_frame_up+0x309/0x6c0 net/bridge/br_input.c:69
br_handle_frame_finish+0x6f2/0x1410 net/bridge/br_input.c:173
br_nf_hook_thresh+0x2a3/0x330 net/bridge/br_netfilter_hooks.c:1011
br_nf_pre_routing_finish_ipv6+0x6e3/0xd40 net/bridge/br_netfilter_ipv6.c:210
NF_HOOK include/linux/netfilter.h:289 [inline]
br_nf_pre_routing_ipv6+0x3f4/0x854 net/bridge/br_netfilter_ipv6.c:240
br_nf_pre_routing+0xf05/0x14fe net/bridge/br_netfilter_hooks.c:494
nf_hook_entry_hookfn include/linux/netfilter.h:119 [inline]
nf_hook_slow+0xc5/0x1e0 net/netfilter/core.c:511
nf_hook include/linux/netfilter.h:244 [inline]
NF_HOOK include/linux/netfilter.h:287 [inline]
br_handle_frame+0xa60/0x13ae net/bridge/br_input.c:306
__netif_receive_skb_core+0x929/0x3270 net/core/dev.c:4876
__netif_receive_skb_one_core+0xae/0x180 net/core/dev.c:4952
__netif_receive_skb+0x27/0x1c0 net/core/dev.c:5066
process_backlog+0x241/0x700 net/core/dev.c:5848
napi_poll net/core/dev.c:6272 [inline]
net_rx_action+0x4ac/0xfb0 net/core/dev.c:6338
__do_softirq+0x26c/0x9a0 kernel/softirq.c:292
invoke_softirq kernel/softirq.c:372 [inline]
irq_exit+0x215/0x260 kernel/softirq.c:412
exiting_irq arch/x86/include/asm/apic.h:544 [inline]
smp_apic_timer_interrupt+0x136/0x550 arch/x86/kernel/apic/apic.c:1094
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
</IRQ>
RIP: 0010:lock_page_memcg+0x6b/0x220 mm/memcontrol.c:1913
Code: 3d bc 68 6e 09 00 0f 84 e0 00 00 00 0f 1f 44 00 00 4c 8d 7b 38 48 b8 00 00 00 00 00 fc ff df 4c 89 fa 48 c1 ea 03 80 3c 02 00 <0f> 85 78 01 00 00 4c 8b 63 38 4d 89 fd 49 be 00 00 00 00 00 fc ff
RSP: 0018:ffff8880580676b8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: ffffea0002450c80 RCX: ffffffff81538403
RDX: 1ffffd400048a197 RSI: 0000000000000004 RDI: ffff8880ba122a90
RBP: ffffea0002450c80 R08: 0000000000000000 R09: ffffed1017424552
R10: ffff8880ba122a93 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: ffffea0002450c80 R15: ffffea0002450cb8
page_remove_file_rmap+0x36/0xa30 mm/rmap.c:1215
page_remove_rmap+0xe5/0x120 mm/rmap.c:1300
zap_pte_range mm/memory.c:1350 [inline]
zap_pmd_range mm/memory.c:1452 [inline]
zap_pud_range mm/memory.c:1481 [inline]
zap_p4d_range mm/memory.c:1502 [inline]
unmap_page_range+0x12f6/0x2a70 mm/memory.c:1523
unmap_single_vma+0x198/0x300 mm/memory.c:1568
unmap_vmas+0xa9/0x180 mm/memory.c:1598
exit_mmap+0x2b9/0x530 mm/mmap.c:3093
__mmput kernel/fork.c:1015 [inline]
mmput+0x14e/0x4a0 kernel/fork.c:1036
exit_mm kernel/exit.c:549 [inline]
do_exit+0xaf0/0x2be0 kernel/exit.c:877
do_group_exit+0x125/0x310 kernel/exit.c:993
get_signal+0x3f2/0x1f70 kernel/signal.c:2589
do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45deb9
Code: f9 00 48 8d 15 08 4f 6c 01 48 89 14 24 e8 cf ce fa ff 0f b6 44 24 2f 3c 00 0f 85 10 01 00 00 e8 7d 7e fd ff 48 8d 05 a2 c1 55 <00> 48 89 04 24 48 c7 44 24 08 11 00 00 00 e8 a4 87 fd ff 8b 44 24
RSP: 002b:00007fbefead5c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: 0000000000000004 RBX: 0000000000023540 RCX: 000000000045deb9
RDX: 0000000000060000 RSI: 0000000020000040 RDI: ffffffffffffff9c
RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007fffb43e1c9f R14: 00007fbefead69c0 R15: 000000000118bf2c
rcu: rcu_preempt kthread starved for 10485 jiffies! g9109 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt R running task 29760 10 2 0x80000000
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_timeout+0x4cf/0xfe0 kernel/time/timer.c:1818
rcu_gp_kthread+0xdad/0x21c0 kernel/rcu/tree.c:2202
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
INFO: task syz-executor.1:10191 blocked for more than 140 seconds.
Not tainted 4.19.159-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D29288 10191 8117 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
genl_lock net/netlink/genetlink.c:33 [inline]
genl_rcv_msg+0x12f/0x160 net/netlink/genetlink.c:625
netlink_rcv_skb+0x160/0x440 net/netlink/af_netlink.c:2455
genl_rcv+0x24/0x40 net/netlink/genetlink.c:638
netlink_unicast_kernel net/netlink/af_netlink.c:1318 [inline]
netlink_unicast+0x4d5/0x690 net/netlink/af_netlink.c:1344
netlink_sendmsg+0x6bb/0xc40 net/netlink/af_netlink.c:1909
sock_sendmsg_nosec net/socket.c:622 [inline]
sock_sendmsg+0xc3/0x120 net/socket.c:632
__sys_sendto+0x21a/0x320 net/socket.c:1787
__do_sys_sendto net/socket.c:1799 [inline]
__se_sys_sendto net/socket.c:1795 [inline]
__x64_sys_sendto+0xdd/0x1b0 net/socket.c:1795
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x417937
Code: Bad RIP value.
RSP: 002b:00007f5f534c9b40 EFLAGS: 00000293 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 00007f5f534c9bf0 RCX: 0000000000417937
RDX: 0000000000000020 RSI: 00007f5f534c9c40 RDI: 0000000000000007
RBP: 0000000000000000 R08: 00007f5f534c9b50 R09: 000000000000000c
R10: 0000000000000000 R11: 0000000000000293 R12: 00007f5f534c9bb4
R13: 0000000000000010 R14: 00007f5f534c9c40 R15: 0000000000000007
INFO: task syz-executor.0:10172 blocked for more than 140 seconds.
Not tainted 4.19.159-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.0 D27904 10172 8115 0x80000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
net_ratelimit: 18919 callbacks suppressed
bridge0: received packet on veth0_to_bridge with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on bridge_slave_0 with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on veth0_to_bridge with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on bridge_slave_0 with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on veth0_to_bridge with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
ip6_tnl_exit_batch_net+0x82/0x660 net/ipv6/ip6_tunnel.c:2275
ops_exit_list+0xf9/0x150 net/core/net_namespace.c:156
setup_net+0x3d1/0x720 net/core/net_namespace.c:332
copy_net_ns+0x1f7/0x335 net/core/net_namespace.c:438
create_new_namespaces+0x3f6/0x7b0 kernel/nsproxy.c:107
unshare_nsproxy_namespaces+0xbd/0x1f0 kernel/nsproxy.c:206
ksys_unshare+0x36c/0x9a0 kernel/fork.c:2551
__do_sys_unshare kernel/fork.c:2619 [inline]
__se_sys_unshare kernel/fork.c:2617 [inline]
__x64_sys_unshare+0x2d/0x40 kernel/fork.c:2617
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45deb9
Code: Bad RIP value.
RSP: 002b:00007f4f18597c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000110
RAX: ffffffffffffffda RBX: 0000000000038240 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000060000000
RBP: 000000000118bf50 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007ffd0db19ebf R14: 00007f4f185989c0 R15: 000000000118bf2c
INFO: task syz-executor.2:10183 blocked for more than 140 seconds.
Not tainted 4.19.159-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2 D29040 10183 8119 0x80000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
gtp_net_exit+0x1ba/0x37d drivers/net/gtp.c:1361
ops_exit_list+0xa5/0x150 net/core/net_namespace.c:153
setup_net+0x3d1/0x720 net/core/net_namespace.c:332
copy_net_ns+0x1f7/0x335 net/core/net_namespace.c:438
create_new_namespaces+0x3f6/0x7b0 kernel/nsproxy.c:107
unshare_nsproxy_namespaces+0xbd/0x1f0 kernel/nsproxy.c:206
ksys_unshare+0x36c/0x9a0 kernel/fork.c:2551
__do_sys_unshare kernel/fork.c:2619 [inline]
__se_sys_unshare kernel/fork.c:2617 [inline]
__x64_sys_unshare+0x2d/0x40 kernel/fork.c:2617
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45deb9
Code: Bad RIP value.
RSP: 002b:00007fe33cf84c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000110
RAX: ffffffffffffffda RBX: 0000000000038240 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000040000000
RBP: 000000000118bf50 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007fffbe08e47f R14: 00007fe33cf859c0 R15: 000000000118bf2c

Showing all locks held in the system:
3 locks held by kworker/u4:0/7:
4 locks held by kworker/u4:1/23:
3 locks held by kworker/u4:2/33:
3 locks held by kworker/u4:3/175:
3 locks held by kworker/u4:4/664:
1 lock held by khungtaskd/1567:
#0: 000000005dc2302b (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
2 locks held by bat_events/4602:
1 lock held by systemd-journal/4685:
1 lock held by in:imklog/7775:
2 locks held by kworker/1:4/9278:
4 locks held by kworker/u4:5/9421:
3 locks held by kworker/u4:6/9537:
2 locks held by kworker/u4:7/9540:
3 locks held by syz-executor.5/10177:
2 locks held by syz-executor.1/10191:
net_ratelimit: 14493 callbacks suppressed
bridge0: received packet on veth0_to_bridge with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
bridge0: received packet on bridge_slave_0 with own address as source address (addr:aa:aa:aa:aa:aa:1b, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on bridge_slave_0 with own address as source address (addr:aa:aa:aa:aa:aa:1b, vlan:0)
bridge0: received packet on bridge_slave_0 with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
bridge0: received packet on veth0_to_bridge with own address as source address (addr:aa:a8:ad:5b:8e:82, vlan:0)
ICMPv6: NA: 24:02:48:ff:05:00 advertised our address fe80::2602:48ff:feff:500 on bridge0!
bridge0: received packet on bridge_slave_0 with own address as source address (addr:aa:aa:aa:aa:aa:1b, vlan:0)
bridge0: received packet on veth0_to_bridge with own address as source address (addr:24:02:48:ff:05:00, vlan:0)
bridge0: received packet on veth0_to_bridge with own address as source address (addr:aa:a8:ad:5b:8e:82, vlan:0)


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

syzbot

unread,
Mar 22, 2021, 3:41:11 PM3/22/21
to syzkaller...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages