记一次有惊无险的丢包调试经历

某个项目把服务器从 CentOS 操作系统从 5 升级到了 7(3.10.0-693),一切都很顺利,直到我在服务器上闲逛的时候,无意间发现了一个「大问题」:网卡 eth0 在 RX 上存在丢包(dropped)现象,丢得还很有规律,每一两秒丢一个包!

watch -d -n1 'ifconfig'

watch -d -n1 ‘ifconfig’

一开始怀疑是不是网卡的 ring buffer 太小了,通过「ethtool」确认:

shell> ethtool -g eth0
Ring parameters for eth0:
Pre-set maximums:
RX:		256
RX Mini:	0
RX Jumbo:	0
TX:		256
Current hardware settings:
RX:		256
RX Mini:	0
RX Jumbo:	0
TX:		256

看上去确实不大,可惜 Current hardware settings 已经达到 Pre-set maximums 最大值,没法加大了。为了确认网卡是否真的存在丢包,继续通过「ethtool」确认:

shell> ethtool -S eth0
no stats available

shell> ethtool -i eth0
driver: virtio_net
version: 1.0.0
firmware-version:
expansion-rom-version:
bus-info: 0000:00:04.0
supports-statistics: no
supports-test: no
supports-eeprom-access: no
supports-register-dump: no
supports-priv-flags: no

看上去是 kvm 的 virtio_net 不支持 statistics,好在还有别的方法:

shell> find /sys -name eth0
/sys/devices/pci0000:00/0000:00:04.0/virtio1/net/eth0
/sys/class/net/eth0

shell> cd /sys/devices/pci0000:00/0000:00:04.0/virtio1/net/eth0
shell> cd statistics
shell> grep . * | grep rx
rx_bytes:633037730314
rx_compressed:0
rx_crc_errors:0
rx_dropped:206975
rx_errors:0
rx_fifo_errors:0
rx_frame_errors:0
rx_length_errors:0
rx_missed_errors:0
rx_nohandler:0
rx_over_errors:0
rx_packets:4717658080

虽然 rx_dropped 不为零,但是 rx_errors 等却都为零,这说明 ring buffer 并没有出现溢出的情况,否则 rx_fifo_errors 之类的错误不可能为零,由此可以推断:网卡已经把数据完整交给了操作系统,其本身并没有丢包,真正丢包的是操作系统。

如何判断操作系统在哪里丢包的呢?是时候表演真正的技术了,dropwatch 出场:

shell> dropwatch -l kas
Initalizing kallsyms db

dropwatch> start
Enabling monitoring...
Kernel monitoring activated.
Issue Ctrl-C to stop monitoring
6 drops at ip_rcv+cf (0xffffffff815ca47f)
11 drops at ipv6_rcv+3ad (0xffffffff81643d7d)
75 drops at tcp_v4_rcv+87 (0xffffffff815f0197)
426 drops at sk_stream_kill_queues+50 (0xffffffff8157a740)
235 drops at tcp_rcv_state_process+1b0 (0xffffffff815e4fb0)
137 drops at tcp_v4_rcv+87 (0xffffffff815f0197)
11 drops at ipv6_rcv+3ad (0xffffffff81643d7d)
1 drops at __netif_receive_skb_core+3d2 (0xffffffff81586d82)

shell> grep -w -A 10 __netif_receive_skb_core /proc/kallsyms
ffffffff815869b0 t __netif_receive_skb_core
ffffffff81587170 t __netif_receive_skb
ffffffff815871d0 t netif_receive_skb_internal
ffffffff81587290 T netif_receive_skb
ffffffff81587300 t napi_gro_complete
ffffffff81587400 T napi_gro_flush
ffffffff81587490 T napi_complete_done
ffffffff81587550 T napi_complete
ffffffff81587570 T sk_busy_loop
ffffffff81587830 t net_rx_action
ffffffff81587bb0 t dev_gro_receive

关于 dropwatch 的原理,它是通过监控 kfree_skb 的调用来监控操作系统可能的丢包行为,有的丢包可能是正常行为,有的丢包可能是异常行为。如此说来,我们遇到的丢包会是上面哪个函数引起的呢?是正常的还是异常的呢?运气不好的话,可能得一个一个挨个分析,好在我们运气不错,记得文章开头我们提到过,在我们的问题中,每一两秒丢一个包,于是自然而然的将目光锁定在 __netif_receive_skb_core 之上(丢包地址 0xffffffff81586d82 介于 ffffffff815869b0 和 ffffffff81587170 之间)。

查询一下 Linux 源代码中 __netif_receive_skb_core 函数的定义来确认一下丢包原因:

static int __netif_receive_skb_core(struct sk_buff *skb, bool pfmemalloc)
{
    ...

    if (pfmemalloc && !skb_pfmemalloc_protocol(skb))
        goto drop;

    ...

drop:
    atomic_long_inc(&skb->dev->rx_dropped);
    kfree_skb(skb);
    /* Jamal, now you will not able to escape explaining
     * me how you were going to use this. :-)
     */
    ret = NET_RX_DROP;

    ...
}

static bool skb_pfmemalloc_protocol(struct sk_buff *skb)
{
    switch (skb->protocol) {
    case __constant_htons(ETH_P_ARP):
    case __constant_htons(ETH_P_IP):
    case __constant_htons(ETH_P_IPV6):
    case __constant_htons(ETH_P_8021Q):
    case __constant_htons(ETH_P_8021AD):
        return true;
    default:
        return false;
    }
}

当 pfmemalloc 为真,且 skb_pfmemalloc_protocol 中判断不支持包协议的时候,就会丢包。此外,代码里能看到调用了 kfree_skb,侧面验证了 dropwatch 的工作原理。

如何判断我们问题中丢的包协议是什么呢,是时候表演真正的技术了, systemtap 出场:

#! /usr/bin/env stap

probe kernel.function("__netif_receive_skb_core").label("drop") {
    printf("0x%04X\n", ntohs($skb->protocol))
}

// output

0x0004

顺便说一句,有了 systemtap,几乎可以为所欲为,比如替换前面提到的 dropwatch。

从前面我们对 Linux 源代码的分析,skb_pfmemalloc_protocol 中支持的包 protocol 如下:

#define ETH_P_ARP	0x0806	/* Address Resolution packet	*/
#define ETH_P_IP	0x0800	/* Internet Protocol packet	*/
#define ETH_P_IPV6	0x86DD	/* IPv6 over bluebook		*/
#define ETH_P_8021Q	0x8100  /* 802.1Q VLAN Extended Header  */
#define ETH_P_8021AD	0x88A8  /* 802.1ad Service VLAN		*/

而 systemtap 脚本检测到的包 protocol 为 0x0004,也就是路由器发出的 802.3 包:

#define	ETHERTYPE_8023	0x0004	/* IEEE 802.3 packet */

因为是系统不支持的包,所以被丢掉了。

其实只要了解了问题的缘由,使用 tcpdump 也能抓出被系统丢掉的包,只要:打印出包的 ether type,然后过滤掉操作系统支持其协议的包,剩下的就是丢掉的包:

shell> tcpdump -i eth0 -e | grep -v -E 'ARP|IP|802.1Q|802.1AD'
802.3,
length 105: LLC,
dsap STP (0x42) Individual,
ssap STP (0x42) Command,
ctrl 0x03: STP 802.1s,
Rapid STP,
CIST Flags [Learn, Forward, Agreement],
length 102

需要说明得是,CentOS 新旧版本在处理此类问题的行为有所不同:面对不支持协议的包,虽然 CentOS 新旧版本都会丢掉它,但是旧版不会更新丢包计数器(rx_dropped),新版却会更新丢包计数器(rx_dropped),细节就不展开了,有兴趣的自行查阅。

记一次有惊无险的丢包调试经历》上有5个想法

  1. 这个文章很炫技!厉害!

    不过在生产库上执行 stap 会不会把系统搞down?

  2. 我排查过一个ListenDrops的问题。结果是三次握手期间服务端回了SYN/ACK之后,客户端主机不可达,收到了ICMP类型的报文,Linux收到该报文后对ListenDrops的计数器加一。这个是通过搜索与这个计数器有关的代码确认的。同样有惊无险。

  3. 请问博主熟悉tc么?在用tc filter进行限速时怎么查看丢掉的字节数,如下:
    $ tc qdisc add dev eth0 ingress
    $ tc filter add dev eth0 parent ffff: protocol ip prio 1 u32 match ip dst 0.0.0.0/0 police rate 3000Mbit burst 6M peakrate 200000 mtu 64k drop flowid ffff:
    $ tc -s filter ls dev eth0 parent ffff:
    filter protocol ip pref 1 u32
    filter protocol ip pref 1 u32 fh 800: ht divisor 1
    filter protocol ip pref 1 u32 fh 800::800 order 2048 key ht 800 bkt 0 flowid ffff: (rule hit 29738 success 29738)
    match 00000000/00000000 at 16 (success 29738 )
    police 0x67 rate 3Gbit burst 6Mb mtu 64Kb peakrate 1600Kbit action drop overhead 0b
    ref 1 bind 1

    Sent 2668647 bytes 29738 pkts (dropped 0, overlimits 0)

    dropped和overlimits代表的丢掉的packets,丢掉的bytes有什么方法可以看呢?

发表评论

电子邮件地址不会被公开。 必填项已用*标注