net rx drop

0.1. 问题来源

接OP问题报告，监控到部分机器的net rx drop统计值异常，触发报警，
需排查具体原因，并确认是否影响业务。

0.2. 问题分析

0.2.1. 复现问题

跟OP同学确认,通过采集/proc/net/dev下的rx drop。
登录到出问题的机器上, 确认内核该统计值确实异常。

  • 异常报文个数不多，大约1s一个左右。
  • 不是所有机器都有异常，有部分机器drop统计为0.

0.2.2. 相关内核代码

当一个数据报文经过对端设备（交换机或者网卡）传输到本机物理网卡时候，需要经过
网卡-- 网卡驱动-- 网络协议栈
这几个模块的处理。我们看到的drop统计值在增加，是在网络协议栈的入口处理部分产生异常导致。

0.2.2.1. 内核网络协议栈（伪）入口代码：

注：本文里使用内核3.10.0-514.16.1代码

net/core/dev.c

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
3709 static int __netif_receive_skb_core(struct sk_buff *skb, bool pfmemalloc)
3710 {
....
3753
3754         list_for_each_entry_rcu(ptype, &ptype_all, list) {
3755                 if (!ptype->dev || ptype->dev == skb->dev) {
3756                         if (pt_prev)
3757                                 ret = deliver_skb(skb, pt_prev, orig_dev);
3758                         pt_prev = ptype;
3759                 }
3760         }
3761
....
3814
3815         /* deliver only exact match when indicated */
3816         null_or_dev = deliver_exact ? skb->dev : NULL;
3817
3818         type = skb->protocol;
3819         list_for_each_entry_rcu(ptype,
3820                         &ptype_base[ntohs(type) & PTYPE_HASH_MASK], list) {
3821                 if (ptype->type == type &&
3822                     (ptype->dev == null_or_dev || ptype->dev == skb->dev ||
3823                      ptype->dev == orig_dev)) {
3824                         if (pt_prev)
3825                                 ret = deliver_skb(skb, pt_prev, orig_dev);
3826                         pt_prev = ptype;
3827                 }
3828         }
3829
3830         if (pt_prev) {
3831                 if (unlikely(skb_orphan_frags(skb, GFP_ATOMIC)))
3832                         goto drop;
3833                 else
3834                         ret = pt_prev->func(skb, skb->dev, pt_prev, orig_dev);
3835         } else {
3836 drop:
3837                 if (!deliver_exact)
3838                         atomic_long_inc(&skb->dev->rx_dropped);
3839                 else
3840                         atomic_long_inc(&skb->dev->rx_nohandler);
3841                 kfree_skb(skb);
3842                 /* Jamal, now you will not able to escape explaining
3843                  * me how you were going to use this. :-)
3844                  */
3845                 ret = NET_RX_DROP;
3846         }
3847
3848 out:
3849         return ret;
3850 }

有同学可能质疑rx_dropped的统计值不止这一处在修改（增加), 内核里确实不止这一处在增加drop。
这里使用perf调试命令，可以确认3838行的增加跟总统计值匹配，而不是其他地方导致增加。
具体perf命令的使用见下一节。

0.2.3. IPv6报文定位

在使用perf命令查看统计值增长点的时候，我们搂草打兔子，捎带把skb的protocol给打印出来了。
截止到目前可以认为protocol的值就是我们收的网络报文的ethernet头里的protocol字段。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
[root@testtest ~]# perf probe -a "__netif_receive_skb_core:129 skb->protocol"
Added new events:
  probe:__netif_receive_skb_core (on __netif_receive_skb_core:129 with protocol=skb->protocol)
  probe:__netif_receive_skb_core_1 (on __netif_receive_skb_core:129 with protocol=skb->protocol)

You can now use it in all perf tools, such as:

	perf record -e probe:__netif_receive_skb_core_1 -aR sleep 1

[root@testtest ~]# perf record -e probe:__netif_receive_skb_core_1 -aR sleep 5
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.209 MB perf.data (5 samples) ]
[root@testtest ~]#
[root@testtest ~]#
[root@testtest ~]# perf script
         swapper     0 [003] 596928.567038: probe:__netif_receive_skb_core_1: (ffffffff8152afb6) protocol=dd86
         swapper     0 [011] 596929.277293: probe:__netif_receive_skb_core_1: (ffffffff8152afb6) protocol=400
         swapper     0 [001] 596929.431077: probe:__netif_receive_skb_core_1: (ffffffff8152afb6) protocol=dd86
         swapper     0 [008] 596930.073356: probe:__netif_receive_skb_core_1: (ffffffff8152afb6) protocol=dd86
         swapper     0 [011] 596931.278891: probe:__netif_receive_skb_core_1: (ffffffff8152afb6) protocol=400
[root@testtest ~]#

看到protocol=dd86，drop增加的触发原因就找到了（一个）。

因为我们公司是把内核的IPv6功能禁止的，网络协议栈收到IPv6报文的时候是不做任何处理并丢弃的。

1
2
[root@testtest ~]# cat /proc/cmdline
BOOT_IMAGE=/vmlinuz-3.10.0-327.36.3.el7.x86_64 root=UUID=7918e921-db4e-4652-9938-a38607100a96 ro crashkernel=128M selinux=0 ipv6.disable=1

为了进一步验证分析结果，上一个tcpdump的结果

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
[root@testtest ~]# tcpdump -i eth0 ip6 -c 10
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 65535 bytes
14:15:40.663327 IP6 fe80::6e0b:84ff:fe81:b4d3.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:15:45.334814 IP6 fe80::6e0b:84ff:fed6:c323.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:15:45.403538 IP6 fe80::6e0b:84ff:febd:aef8.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:15:52.542434 IP6 fe80::6e0b:84ff:fe81:b935.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:00.186710 IP6 fe80::6e0b:84ff:febd:b27c.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:06.397437 IP6 fe80::6e0b:84ff:fe81:ba03.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:07.834059 IP6 fe80::6e0b:84ff:febd:b602.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:22.138601 IP6 fe80::6e92:bfff:fe2e:616f.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:31.827770 IP6 fe80::6e0b:84ff:fed6:c053.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
14:16:31.882039 IP6 fe80::6e0b:84ff:febd:b798.dhcpv6-client > ff02::1:2.dhcpv6-server: dhcp6 solicit
10 packets captured
10 packets received by filter
0 packets dropped by kernel
[root@testtest ~]#

注：

  1. 这里的截屏是写文章时候去线上测试机抓取的，部分机器上的IPv6问题被修复过一部分。
    所以，我们看到的IPv6报文个数比当初分析问题的时候，相对要偏少。

IPv6报文的来源：服务器同学定位是浪潮服务器的网卡主动发出的。

0.2.4. STP报文定位

0.2.4.1. 异常报文统计有出入

在使用perf工具定位IPv6报文后，人肉查看，发现IPv6的个数大约占drop统计值的60%左右，
也就是说，还有其他类型的报文导致drop统计值在增加。
在硬件厂商修复网卡问题后，观察到大幅降低了drop的增长速度，但没有彻底消除drop的异常统计增长。

正如perf结果显示还有部分protocol=400的报文，这是些啥报文？

我们搜集到了如下一些信息：

  • tcpdump全量抓包，也没有看到400的报文。
  • 查询RFC相关定义，可以发现他们是802.2 LLC
  • 在内核代码里，被网桥的llc模块处理的。
0.2.4.1.1. 内核代码

net/llc/llc_core.c

1
2
3
4
5
6
110 #define ETH_P_802_2     0x0004          /* 802.2 frames                 */

135 static struct packet_type llc_packet_type __read_mostly = {
136         .type = cpu_to_be16(ETH_P_802_2),
137         .func = llc_rcv,
138 };

做一个试验：
手动加载llc模块，加载后drop统计值不再增张了。
这个实验侧面验证了，有部分网桥相关的报文被传递到内核网络协议栈了。

0.2.4.1.2. 802.2 LLC

LLC对应了一大家族的链路协议类型，我们需要定位具体是哪一种类型的报文引起的。
这就需要把protocol=400的报文被统计异常的时候，把它当时对应的ethernet头信息打印出来。
针对这样的需求，下一节的centos7上的核弹（热补丁）派上用场了。

注：
LLC对应一大坨的链路层协议，网卡驱动（以ixgbe为例）会借助eth_type_trans函数，
把这些ethernet 协议汇总为802.2 LLC，并存放在skb->protocol里的。

drivers/net/ethernet/intel/ixgbe/ixgbe_main.c

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
1665 static void ixgbe_process_skb_fields(struct ixgbe_ring *rx_ring,
1666                                      union ixgbe_adv_rx_desc *rx_desc,
1667                                      struct sk_buff *skb)
1668 {
1669         struct net_device *dev = rx_ring->netdev;
1670         u32 flags = rx_ring->q_vector->adapter->flags;
1671
1672         ixgbe_update_rsc_stats(rx_ring, skb);
1673
1674         ixgbe_rx_hash(rx_ring, rx_desc, skb);
1675
1676         ixgbe_rx_checksum(rx_ring, rx_desc, skb);
1677
1678         if (unlikely(flags & IXGBE_FLAG_RX_HWTSTAMP_ENABLED))
1679                 ixgbe_ptp_rx_hwtstamp(rx_ring, rx_desc, skb);
1680
1681         if ((dev->features & NETIF_F_HW_VLAN_CTAG_RX) &&
1682             ixgbe_test_staterr(rx_desc, IXGBE_RXD_STAT_VP)) {
1683                 u16 vid = le16_to_cpu(rx_desc->wb.upper.vlan);
1684                 __vlan_hwaccel_put_tag(skb, htons(ETH_P_8021Q), vid);
1685         }
1686
1687         skb_record_rx_queue(skb, rx_ring->queue_index);
1688
1689         skb->protocol = eth_type_trans(skb, dev);
1690 }

net/ethernet/eth.c

1
2
3
4
5
6
7
8
9
10
11
12
188 __be16 eth_type_trans(struct sk_buff *skb, struct net_device *dev)
189 {
...
230         if (likely(eth_proto_is_802_3(eth->h_proto)))
231                 return eth->h_proto;
...
242         /*
243          *      Real 802.2 LLC
244          */
245         return htons(ETH_P_802_2);
246 }
247 EXPORT_SYMBOL(eth_type_trans);

0.2.4.2. centos7上的核弹 内核热升级工具

centos7（3.10内核）开始，内核组已经部署了一个叫centos-kpatch-modules的rpm包，
它可以做到业务不感知的情况下，加载调试模块，调试完就可卸载。

刚好出问题的机器内核版本是3.10.0-514.16.1.el7.x86_64，
于是编写了一个调试模块(后续会集成到centos-kpatch-modules)，其功能是：
当drop掉异常报文的时候，把报文的内容（ethernet头）打印出来。

通过kpatch命令加载调试模块，就能把被drop的报文头信息打印出来，

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
[root@testtest xfile]# uname -a
Linux testtest 3.10.0-327.36.3.el7.x86_64 #1 SMP Mon Oct 24 16:09:20 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
[root@testtest xfile]# rpm -q centos-kpatch-modules
centos-kpatch-modules-1.6-1.x86_64
[root@testtest xfile]# kpatch  load /root/martin/xfile/net_rx_drop/327/kpatch-dev.ko
loading patch module: /root/martin/xfile/net_rx_drop/327/kpatch-dev.ko
[root@testtest xfile]# dmesg
[606774.224447] kpatch: loaded patch module 'kpatch_dev'
[606775.135343] __netif_receive_skb_core: skb len:105 protocol:0004
[606775.135348] skb_mac_head:ffff88003625c440 skb data:ffff88003625c44e, mac hdr offset:14
[606775.135350] mac hdr dest:01:80:c2:00:00:00 <=== 50:da:00:ef:54:0a proto: 0069
[606775.337246] __netif_receive_skb_core: skb len:96 protocol:86dd
[606775.337252] skb_mac_head:ffff880850046c40 skb data:ffff880850046c4e, mac hdr offset:14
[606775.337255] mac hdr dest:33:33:00:01:00:02 <=== 6c:0b:84:81:ba:03 proto: 86dd
[root@testtest xfile]#

通过日志我们看到被drop的报文ethernet头里protocol字段是0069, 其转化后存在skb里的protocol字段是0004。

tcpdump命令也显示有报文进入(此处说法不严谨，后续会被打脸)。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
[root@localhost ~]# tcpdump -i em1 not ip -c 8
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on em1, link-type EN10MB (Ethernet), capture size 65535 bytes
04:55:07.868905 IP6 fe80::303b:6dff:fe6a:20c4 > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28
04:55:08.183959 STP 802.1d, Config, Flags [none], bridge-id 812c.38:1c:1a:7a:c1:80.8036, length 42
04:55:08.738143 STP 802.1s, Rapid STP, CIST Flags [Learn, Forward, Agreement], length 102
04:55:08.790157 IP6 fe80::5c11:3ff:fe55:9037 > ff02::2: ICMP6, router solicitation, length 8
04:55:08.914911 IP6 :: > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28
04:55:09.033921 IP6 :: > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28
04:55:09.185917 IP6 :: > ff02::1:ffab:f174: ICMP6, neighbor solicitation, who has fe80::18cc:d5ff:feab:f174, length 24
04:55:09.773337 IP6 fe80::e818:a4ff:fe30:c522 > ff02::2: ICMP6, router solicitation, length 8
8 packets captured
14 packets received by filter
0 packets dropped by kernel
[root@localhost ~]#

至此，我们锁定STP报文是drop统计增加的另一个来源。

综合多台机器测试结果，被丢弃的报文有三类

  • IPv6
  • STP
  • LLDP

至此问题上半部分析清楚。

IRQ
#IRQ
net rx drop
https://martinbj2008.github.io/2020/03/15/2020-03-15-net-rx-drop/
Author
Martinbj2008
Posted on
March 15, 2020
Licensed under