单机多网卡互通——问题跟踪+工具分析

一、背景

想搭建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+1udp4_gro_receive+402inet_gro_receive+675dev_gro_receive+1574napi_gro_receive+96receive_buf+911virtnet_poll+331net_rx_action+309__softirqentry_text_start+188asm_call_sysvec_on_stack+15do_softirq_own_stack+55irq_exit_rcu+208common_interrupt+120asm_common_interrupt+30cpuidle_enter_state+214cpuidle_enter+41do_idle+452cpu_startup_entry+25start_secondary+276secondary_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路由的相关知识后续学习补充。