一、背景
想搭建soft ROCE(RXE)与实体ROCE设备互联的测试环境,为了节省机器以及使用方便,预想在配备ROCE卡的主机上,用另一个网卡绑定soft ROCE,然后互通。
[ETH1 + ROCE] <--------------------> [ETH2 + RXE]
二、问题跟踪
ROCE向RXE发送send only,两端都没有收到cqe。
1、tcpdump抓取ETH2网卡,抓获了ROCE v2的send only报文,没有ack报文。
也就是说数据包已经成功环回,外部链路正常;RXE的接受处理路径出现异常,导致没有响应。
2、使用funcgraph抓取,RXE注册的隧道接收处理函数
perf-tools funcgraph rxe_udp_encap_recv
没有捕获到,这跟预想的不一样,这说明:
数据包在进入RXE的处理之前,已经被丢掉了。需要看数据包的底层接收路径。
3、然后开启了将近一天的四处碰壁阶段。
由于过往对网络的内核处理路径了解很少,理了一下rxe_udp_encap_recv的调用路径,推测应该是通过udp_unicast_rcv_skb接口调用的,其余还有mcast/broadcast两个接口,但我们这个数据包不应该是多播和广播。
然后trace了一下udp_unicast_rcv_skb接口,还是没有捕获到!
这段代码是这个样子的:
int __udp4_lib_rcv(struct sk_buff *skb, struct udp_table *udptable,
int proto)
{
/* .............*/
sk = __udp4_lib_lookup_skb(skb, uh->source, uh->dest, udptable);
if (sk)
return udp_unicast_rcv_skb(sk, skb, uh);
/* .............*/
}
4、本着就近原则,trace了一下udp4_lib_lookup接口,发现可以trace 到!!!那问题不就出在这里了么???
所以接下来用bpftrace跟踪了下udp4_lib_lookup的返回值,确实是0,没有拿到socket,所以报文被丢了!
5、为什么拿不到socket
用bpftrace跟踪了upd4_lib_lookup中的入参,源目端口,源目地址,数值都是正确的!那为啥拿不到socket?RXE里监听这个端口的socket创建有问题???
试图梳理一下socket的创建、查找,短时间不好搞定,未果。
6、udp_rcv没有执行
这时候想要么funcgraph抓一下udp报文的处理入口,udp_rcv,看一下他的执行路径,在哪个环节跟正常的报文不一样?也可能前置出错,引发的问题。
结果发现,udp_rcv没有捕获到!!!离了个大谱!!
7、bpftrace跟踪udp_lib_lookup的调用栈
那谁调用了udp_lib_lookup呢?把它的调用栈打印出来看一下。
咦,是在udp_gro_receive接口中调用的。
#!/usr/bin/env bpftrace
#include <linux/netdevice.h>
#include <linux/udp.h>
#include <linux/skbuff.h>
#include <linux/netdev_features.h>
kprobe:__udp4_lib_lookup {
printf("saddr=0x%x,sport=0x%x,daddr=0x%x,dport=0x%x\n",arg1, arg2, arg3, arg4);
@[kstack]=count();
}
kretprobe:udp4_lib_lookup2 {
printf("sock=0x%x\n",retval);
if(retval != 0) {
printf("encap_recv = 0x%x, gro_receive= 0x%x, gro_enabled=%d\n", ((struct udp_sock *)retval)->encap_rcv, ((struct udp_sock *)retval)->gro_receive, ((struct udp_sock *)retval)->gro_enabled);
}
}
看到是udp4_gro_receive接口调用了udp4_lib_lookup,然后没有查询到socket。
[root@localhost leiyanjie]# bpftrace udp.bt
Attaching 3 probes...
saddr=0x3231a8c0,sport=0x8,daddr=0x7e33a8c0,dport=0xb712
sock=0x0
sock=0xa7ef9b00
encap_recv = 0xc071a520, gro_receive= 0x0, gro_enabled=0
skb->dev=0xffff9280187d7000, skb->dev->features = 0x10000134829, GRO_FEATURE_BIT=57
^C
@[
__udp4_lib_lookup+1
udp4_gro_receive+402
inet_gro_receive+675
dev_gro_receive+1574
napi_gro_receive+96
receive_buf+911
virtnet_poll+331
net_rx_action+309
__softirqentry_text_start+188
asm_call_sysvec_on_stack+15
do_softirq_own_stack+55
irq_exit_rcu+208
common_interrupt+120
asm_common_interrupt+30
cpuidle_enter_state+214
cpuidle_enter+41
do_idle+452
cpu_startup_entry+25
start_secondary+276
secondary_startup_64_no_verify+176
]: 1
8、跟踪udp4_gro_receive的执行路径
发现,怎么这个接口接口这么简单就退出了呀,是不是没有接收完,把报文丢掉了?!!
# ad perf-tools funcgraph udp4_gro_receive
Tracing "udp4_gro_receive"... Ctrl-C to end.
1) | udp4_gro_receive() {
1) 0.197 us | irq_enter_rcu();
1) | __sysvec_irq_work() {
1) | __wake_up() {
1) | __wake_up_common_lock() {
1) 0.644 us | _raw_spin_lock_irqsave();
1) | __wake_up_common() {
1) | autoremove_wake_function() {
1) | default_wake_function() {
1) | try_to_wake_up() {
1) 0.801 us | _raw_spin_lock_irqsave();
1) | select_task_rq_fair() {
1) 0.365 us | available_idle_cpu();
1) 0.364 us | cpus_share_cache();
1) 1.268 us | update_cfs_rq_h_load();
1) | select_idle_sibling() {
1) 0.374 us | available_idle_cpu();
1) 0.560 us | }
1) 0.086 us | rcu_read_unlock_strict();
1) 3.776 us | }
1) | ttwu_queue_wakelist() {
1) | __smp_call_single_queue() {
1) 0.569 us | send_call_function_single_ipi();
1) 1.396 us | }
1) 1.776 us | }
1) 0.097 us | _raw_spin_unlock_irqrestore();
1) 7.576 us | }
1) 8.340 us | }
1) 8.544 us | }
1) 9.832 us | }
1) 0.094 us | _raw_spin_unlock_irqrestore();
1) + 11.127 us | }
1) + 11.301 us | }
1) + 12.007 us | }
1) | irq_exit_rcu() {
1) 0.087 us | idle_cpu();
1) | tick_nohz_irq_exit() {
1) 0.102 us | ktime_get();
1) 0.287 us | }
1) 0.647 us | }
1) | __udp4_lib_lookup() {
1) 0.700 us | udp4_lib_lookup2();
1) | udp4_lib_lookup2() {
1) 0.227 us | compute_score();
1) 0.252 us | compute_score();
1) 1.306 us | }
1) 2.482 us | }
1) 0.243 us | udp_gro_receive();
1) 0.086 us | rcu_read_unlock_strict();
1) + 20.713 us | }
^C
Ending tracing...
然后掉进了一个大坑,查看udp_gro_receive的代码如下:
if (!sk || !udp_sk(sk)->gro_receive) {
if (skb->dev->features & NETIF_F_GRO_FRAGLIST)
NAPI_GRO_CB(skb)->is_flist = sk ? !udp_sk(sk)->gro_enabled : 1;
if ((!sk && (skb->dev->features & NETIF_F_GRO_UDP_FWD)) ||
(sk && udp_sk(sk)->gro_enabled) || NAPI_GRO_CB(skb)->is_flist)
return call_gro_receive(udp_gro_receive_segment, head, skb);
/* no GRO, be sure flush the current packet */
goto out;
}
那么udp_gro_receive_segment应该是要被执行的,可实际没有执行。为什么?
因为我们的网卡使能了GRO,而RXE只提供了encap_rcv接口,实际也需要注册自己的gro_receive么?!
tnl_cfg.encap_type = 1;
tnl_cfg.encap_rcv = rxe_udp_encap_recv;
/* Setup UDP tunnel */
setup_udp_tunnel_sock(net, sock, &tnl_cfg);
void setup_udp_tunnel_sock(struct net *net, struct socket *sock,
struct udp_tunnel_sock_cfg *cfg)
{
struct sock *sk = sock->sk;
/* Disable multicast loopback */
inet_sk(sk)->mc_loop = 0;
/* Enable CHECKSUM_UNNECESSARY to CHECKSUM_COMPLETE conversion */
inet_inc_convert_csum(sk);
rcu_assign_sk_user_data(sk, cfg->sk_user_data);
udp_sk(sk)->encap_type = cfg->encap_type;
udp_sk(sk)->encap_rcv = cfg->encap_rcv;
udp_sk(sk)->encap_err_rcv = cfg->encap_err_rcv;
udp_sk(sk)->encap_err_lookup = cfg->encap_err_lookup;
udp_sk(sk)->encap_destroy = cfg->encap_destroy;
udp_sk(sk)->gro_receive = cfg->gro_receive;
udp_sk(sk)->gro_complete = cfg->gro_complete;
udp_tunnel_encap_enable(sock);
}
RXE是标准内核驱动随着内核版本更新升级的,理论上不应该不支持开启了GRO的网卡?
9、bpfrrace跟踪这段代码的参数
因为不熟悉,所以全都靠猜:是不是我们的网卡置位NETIF_F_GRO_FRAGLIST这个标识,就可以执行后续的call_gro_receive?
# bpftrace udp.bt
Attaching 3 probes...
saddr=0x3231a8c0,sport=0x8,daddr=0x7e33a8c0,dport=0xb712
sock=0x0
sock=0xa7ef9b00
encap_recv = 0xc071a520, gro_receive= 0x0, gro_enabled=0
skb->dev=0xffff9280187d7000, skb->dev->features = 0x10000134829, GRO_FEATURE_BIT=57
10、增加GRO_FRAGLIST属性
man ethtool
ethtool -k eth2 查询网卡属性
ethtool -K eth2 **** on/off 设置网卡属性
# ethtool -k eth2 | grep gro
rx-gro-hw: off [fixed]
rx-gro-list: off
# thtool -K eth2 rx-gro-list on
然后bpftrace发现,这个标识确实在netdev->features开启成功了,但并还是没有进入后续的segment收包流程。
再次进入死胡同。
三、问题跟踪2
网络搜索了一下udp_gro_receive的相关流程,也不能够帮助在短时间内建立非常清晰的理解。
比较幸运的是,udp的报文并不多,所以我们在udp_gro_receive接口中轻易的抓到了报文,而且从sk_buff结构中拿到了netdev的地址。
1、bpftrace根据参数过滤eth2的ip_rcv接口
所以,尝试抓取ip_rcv接口,数据有没有进入ip_rcv接口呢?
eth0的IP报文是很多的,咋筛选出eth2的报文呢?既然我们拿到了netdev的地址,就可以根据netdev精确过滤出eth2的报文。
kprobe:ip_rcv {
if(arg1 == 0xffff9ab4a371a000) {
printf("get eth2 packet\n");
@[kstack]=count();
}
}
捕获到了get eth2 packet!
这说明之前推测的GRO丢包是错误的,其实报文已经送到了IP层,没有进入UDP层。是在IP层丢掉的。
saddr=0x3231a8c0,sport=0x8,daddr=0x8734a8c0,dport=0xb712
sock=0x0
sock=0x1680bf00
encap_recv = 0xc055d520, gro_receive= 0x0, gro_enabled=0
skb->dev=0xffff9ab4a371a000, skb->dev->features = 0x200010000134829, GRO_FEATURE_BIT=57
get eth2 packet
本来用funcgraph跟踪一下ip_rcv接口会更直观,看报文丢弃在了哪个环节,但因为funcgraph无法传入参数过滤,eth0的IP报文也比较多,就没有采用这种方式。
2、ip_rcv_finish接口返回失败
ip_rcv接口比较简单,很容易就跟踪到是ip_rcv_finish接口返回失败,导致报文没有进一步上送。
kretprobe:ip_rcv_finish {
printf("ret=0x%x\n",retval);
}
3、tracepoint跟踪kfree_skb_reason
分析了ip_rcv_finish_core接口,看到有多个位置可能导致异常返回,异常返回都会调用kfree_skb_reason这个接口传递释放sk_buff,而且会把错误码(drop_reason)传入。
kfree_skb_reason在我安装的5.10内核版本上实际测试,没有查询到bpftrace入口。
但是在我5.15的内核代码中,是有trace点的,可以把reason打印出来。
void kfree_skb_reason(struct sk_buff *skb, enum skb_drop_reason reason)
{
if (!skb_unref(skb))
return;
trace_kfree_skb(skb, __builtin_return_address(0), reason);
__kfree_skb(skb);
}
所以开始研究使用tracepoint。/sys/kernel/debug/tracing/available_events中记录了所有的可trace事件。可以看到
/sys/kernel/debug/tracing # cat available_events | grep kfree_skb
skb:kfree_skb
那么如何使能这个事件?进入events/skb/kfree_skb目录,有如下接口文件:
/sys/kernel/debug/tracing/events/skb/kfree_skb # ls
enable filter format id trigger
enable输入1,就可以使能trace,不需要其他开关。
filter是可以输入过滤条件的,比如过滤eth2的报文?这个需要后面学习一下。
format是显示trace日志格式的。
实际的trace日志,还可以显示pid、cpu和时间,挺好的。结果如下:
因为我的机器上的内核版本是5.10,所以看不到reason,这是个让人伤心的故事。从某个patch来看,确实是后面的版本合入的kfree_skb_reason。原来正常的skb释放也是走这个路径,所以trace kfree_skb有特别多的日志,无法区分。
4、tracepoint跟踪kfree_skb_reason和consume_skb
在高版本内核中,正常的skb释放走consume_skb路径,drop的skb释放走kfree_skb_reason路径,就可以区分出来了。
5、bpftrace打桩跟踪执行路径
既然看不出来drop reason,那其实直接用bpftrace在ip_recv_finish_core的各个接口中打桩是可以看到执行路径的。
因为我们也不是大流量的环境,网络报文的密度比较小。所以抓到udp报文后,紧跟着的打印可以认为是同一条报文的处理路径中的。
最终确认是在ip_route_input_slow接口,路由失败引发丢包的。
kprobe:ip_rcv {
if(arg1 == 0xffff9ab4a371a000) {
printf("get eth2 packet\n");
@[kstack]=count();
}
}
kprobe:ip_rcv_finish {
if(((struct sk_buff *)arg2)->dev == 0xffff9ab4a371a000) {
printf("get eth2 packet\n");
@[kstack]=count();
}
}
kretprobe:ip_route_use_hint {
printf("ip_route_use_hind, ret=0x%x\n", retval);
}
kretprobe:udp_v4_early_demux {
printf("udp_v4_early_demux, ret=0x%x\n", retval);
}
kretprobe:ip_route_input_noref {
printf("ip_route_input_noref, ret=%d\n", retval);
}
kretprobe:ip_rcv_finish {
printf("ret=0x%x\n",retval);
}
kretprobe:ip_route_input_slow {
printf("ip_route_input_slow, ret=%d\n", retval);
}
6、为什么会路由失败??
我简单尝试了一下,用eth1 ping eth2,发现也是无法ping通的。这台机器上的3个网卡都无法互相ping通。
所以此时意识到,同一台机器上的两个网卡之间是不是就是不能通信的?
然后开始资料查询,重点针对一台机器上的多个网卡。
有几篇文章都作了说明,但原理又都不清楚,只是说linux对此的支持不友好。
反而是最终在自己疯狂的尝试中,误打误撞解决了问题。
sysctl -w /proc/sys/net/ipv4/conf/all/accep_local=1
sysctl -w /proc/sys/net/ipv4/conf/all/rp_filter=2
IP路由的相关知识后续学习补充。