一次有趣的 Docker 网络问题排查

一次有趣的 Docker 网络问题排查

一次有趣的 Docker 网络问题排查

前段时间公司的安卓打包服务出现问题，现象是在上传 360 服务器进行加固的时候，非常大概率会卡在上传阶段，长时间重试最后失败。我对这个情况进行了一些排查分析，解决了这个问题，写了这篇长文复盘了排查的经历，会涉及到下面这些内容。

• Docker 桥接模式网络模型
• Netfilter 与 NAT 原理
• Systemtap 在内核探针中的用法

打包服务的部署结构这样的：安卓打包环境被打包为一个 docker 镜像，部署在某台物理机上，这镜像会完成代码编译打包、加固、签名、生成渠道包的功能，如下图所示：

问题就出在上传 APK 这一步，传到一部分就卡住，360 的 sdk 提示超时等异常，如下图所示。

通过在宿主机和容器内分别抓包，我们发现了这样一些现象。

宿主机的抓包如下，序号为 881 的包是一个延迟的 ACK，它的 ACK 值为 530104，比这个 ACK 号更大的序列号在 875 的那个包已经确认过了（序列号为 532704，随后宿主机发送了一个 RST 包给远程的 360 加固服务器。

再后面就是不停重试发送数据，上传卡住也就对应这个不断重试发送数据的阶段，如下图所示

在容器侧抓包，并没有出现这个 RST，其它的包一样，如下图所示

因为容器侧没有感知到连接的异常，容器内的服务就一直在不停的重试上传，经过多次重试以后依然是失败的。

初步的排查分析

一开始的疑虑是，是不是因为收到了延迟到达的 ACK，所以回复 RST呢？

这不应该，在 TCP 协议规范中，收到延迟到达的 ACK，忽略即可，不必回复 ACK，那到底为什么会发 RST 包呢？

那是不是这个包本来就不合法呢？经过仔细分析这个包的信息，没有发现什么异常。从已有的 TCP 原理知识，已经没法推断这个现象了。

黔驴技穷，没有什么思路，这个时候就该用上 systemtap，来看看 rst 包到底是哪里发出来。

通过查看内核的代码，发送 rst 包的函数主要是下面这两个

tcp_v4_send_reset@net/ipv4/tcp_ipv4.c

static void tcp_v4_send_reset(struct sock *sk, struct sk_buff *skb) {
}

tcp_send_active_reset@net/ipv4/tcp_output.c

void tcp_send_active_reset(struct sock *sk, gfp_t priority) {
}

接下来 systemtap 注入这两个函数即可。

probe kernel.function("tcp_send_active_reset@net/ipv4/tcp_output.c").call {
    printf ("\n%-25s %s<-%s\n", ctime(gettimeofday_s()) ,execname(), ppfunc());
    if ($sk) {
        src_addr = tcp_src_addr($sk);
        src_port = tcp_src_port($sk);
        dst_addr = tcp_dst_addr($sk);
        dst_port = tcp_dst_port($sk);
        if (src_port == 443 || dst_port == 443) {
          printf (">>>>>>>>>[%s->%s] %s<-%s %d\n", str_addr(src_addr, src_port), str_addr(dst_addr, dst_port), execname(), ppfunc(), dst_port);
          print_backtrace();
        }
    }
}

probe kernel.function("tcp_v4_send_reset@net/ipv4/tcp_ipv4.c").call {
    printf ("\n%-25s %s<-%s\n", ctime(gettimeofday_s()) ,execname(), ppfunc());
    if ($sk) {
        src_addr = tcp_src_addr($sk);
        src_port = tcp_src_port($sk);
        dst_addr = tcp_dst_addr($sk);
        dst_port = tcp_dst_port($sk);
        if (src_port == 443 || dst_port == 443) {
          printf (">>>>>>>>>[%s->%s] %s<-%s %d\n", str_addr(src_addr, src_port), str_addr(dst_addr, dst_port), execname(), ppfunc(), dst_port);
          print_backtrace();
        }
    } else if ($skb) {
        header = __get_skb_tcphdr($skb);
        src_port = __tcp_skb_sport(header)
        dst_port = __tcp_skb_dport(header)
        if (src_port == 443 || dst_port == 443) {
            try {
                iphdr = __get_skb_iphdr($skb)
                src_addr_str = format_ipaddr(__ip_skb_saddr(iphdr), @const("AF_INET"))
                dst_addr_str = format_ipaddr(__ip_skb_daddr(iphdr), @const("AF_INET"))

                tcphdr = __get_skb_tcphdr($skb)
                urg = __tcp_skb_urg(tcphdr)
                ack = __tcp_skb_ack(tcphdr)
                psh = __tcp_skb_psh(tcphdr)
                rst = __tcp_skb_rst(tcphdr)
                syn = __tcp_skb_syn(tcphdr)
                fin = __tcp_skb_fin(tcphdr)

                printf ("skb [%s:%d->%s:%d] ack:%d, psh:%d, rst:%d, syn:%d fin:%d %s<-%s %d\n",
                        src_addr_str, src_port, dst_addr_str, dst_port, ack, psh, rst, syn, fin, execname(), ppfunc(), dst_port);
                print_backtrace();
            } 
            catch { }
	}
    } else {
          printf ("tcp_v4_send_reset else\n");
          print_backtrace();
    }
}

一运行就发现，出问题时，进入的是 tcp_v4_send_reset 这个函数，调用堆栈是

Tue Jun 15 11:23:04 2021  swapper/6<-tcp_v4_send_reset
skb [36.110.213.207:443->10.21.17.99:39700] ack:1, psh:0, rst:0, syn:0 fin:0 swapper/6<-tcp_v4_send_reset 39700
 0xffffffff99e5bc50 : tcp_v4_send_reset+0x0/0x460 [kernel]
 0xffffffff99e5d756 : tcp_v4_rcv+0x596/0x9c0 [kernel]
 0xffffffff99e3685d : ip_local_deliver_finish+0xbd/0x200 [kernel]
 0xffffffff99e36b49 : ip_local_deliver+0x59/0xd0 [kernel]
 0xffffffff99e364c0 : ip_rcv_finish+0x90/0x370 [kernel]
 0xffffffff99e36e79 : ip_rcv+0x2b9/0x410 [kernel]
 0xffffffff99df0b79 : __netif_receive_skb_core+0x729/0xa20 [kernel]
 0xffffffff99df0e88 : __netif_receive_skb+0x18/0x60 [kernel]
 0xffffffff99df0f10 : netif_receive_skb_internal+0x40/0xc0 [kernel]
...

可以看到是在收到 ACK 包以后，调用 tcp_v4_rcv 来处理时发送的 RST，那到底是哪一行呢？

这就需要用到一个很厉害的工具 faddr2line ，把堆栈中的信息还原为源码对应的行数。

wget https://raw.githubusercontent.com/torvalds/linux/master/scripts/faddr2line

bash faddr2line /usr/lib/debug/lib/modules/`uname -r`/vmlinux tcp_v4_rcv+0x536/0x9c0
 
tcp_v4_rcv+0x596/0x9c0:
tcp_v4_rcv in net/ipv4/tcp_ipv4.c:1740

可以看到是在 tcp_ipv4.c 的 1740 行调用了 tcp_v4_send_reset 函数，

int tcp_v4_rcv(struct sk_buff *skb)
{
	struct sock *sk;

	sk = __inet_lookup_skb(&tcp_hashinfo, skb, th->source, th->dest);
	if (!sk)
		goto no_tcp_socket;

...

no_tcp_socket:
	if (!xfrm4_policy_check(NULL, XFRM_POLICY_IN, skb))
		goto discard_it;

	if (skb->len < (th->doff << 2) || tcp_checksum_complete(skb)) {
csum_error:
		TCP_INC_STATS_BH(net, TCP_MIB_CSUMERRORS);
bad_packet:
		TCP_INC_STATS_BH(net, TCP_MIB_INERRS);
	} else {
		tcp_v4_send_reset(NULL, skb);  // 1739 行
	}
}

唯一可能调用到的逻辑就是找不到这个包对应的套接字信息，sk 为 NULL，然后走到 no_tcp_socket 标签处，然后走到 else 的流程，才有可能。

这怎么可能呢？连接好好的存在，怎么可能收到一个延迟到达的 ack 包处理的时候找不到这个连接套接字了呢？接下来我们来看 __inet_lookup_skb 函数的底层实现，最终走到了 __inet_lookup_established 这个函数。

struct sock *__inet_lookup_established(struct net *net,
				  struct inet_hashinfo *hashinfo,
				  const __be32 saddr, const __be16 sport,
				  const __be32 daddr, const u16 hnum,
				  const int dif)

刨去现有的现象，有一个很类似的 RST 的场景是，往一个没有监听某端口的服务发送包。这个包没有对应的连接，内核就会回复 RST，告知发送端无法处理这个包。

到这里，排查陷入了僵局。为什么明明连接还在，内核协议栈就是找不到呢？

Docker 桥接模式网络包流通方式

Docker 进程启动时，会在主机上创建一个名为 docker0 的虚拟网桥，这个主机上的 docker 容器会连接到这个虚拟网桥上。

容器启动后，Docker 会生成一对 veth 接口（veth pair），本质相当于软件实现的以太网连接，docker 通过 veth 把容器内的 eth0 连接到 docker0 网桥。外部的连接可以通过 IP 伪装（IP masquerading）的方式提供，IP 伪装是网络地址转换（NAT）的一种方式，以 IP 转发（IP forwarding）和 iptables 规则建立。

深入 Netfilter 与 NAT

Netfilter 是一个 Linux 内核框架，它在内核协议栈中设置了若干hook 点，以此对数据包进行拦截、过滤或其他处理。从简单的防火墙，到对网络通信数据的详细分析，到复杂的、依赖于状态的分组过滤器，它都可以实现。

Docker 利用了它的 NAT（network address translation，网络地址转换）特性，根据某些规则来转换源地址和目标地址。iptables 正是一个用户态用于管理这些 Netfilter 的工具。

对于这个场景中的部署结构，它的原理如下图所示。

经过查看 netfilter 的代码，发现它会把 out of window 的包标记为 INVALID 状态，源码见 net/netfilter/nf_conntrack_proto_tcp.c:

/* Returns verdict for packet, or -1 for invalid. */
static int tcp_packet(struct nf_conn *ct,
		      const struct sk_buff *skb,
		      unsigned int dataoff,
		      enum ip_conntrack_info ctinfo,
		      u_int8_t pf,
		      unsigned int hooknum,
		      unsigned int *timeouts) {
    
    // ...	
    	      
    if (!tcp_in_window(ct, &ct->proto.tcp, dir, index,
			   skb, dataoff, th, pf)) {
		spin_unlock_bh(&ct->lock);
		return -NF_ACCEPT;
	}
}

口说无凭，上面只是理论分析，你怎么就能说是一个 ACK 导致的 invalid 包呢？

我们可以通过 iptables 的规则，把 invalid 的包打印出来。

iptables -A INPUT -m conntrack --ctstate INVALID -m limit --limit 1/sec   -j LOG --log-prefix "invalid: " --log-level 7

添加上面的规则以后，再次运行加固上传的脚本，同时开始抓包，现象重现。

然后在 dmesg 中查看对应的日志。

以第一行为例，它的 LEN=40，也就是 20 IP 头 + 20 字节 TCP 头，ACK 位被置位，表示这是一个没有任何内容的 ACK 包，对应于上图中 RST 包的前一个 ACK 包。这个包的详情如下图，window 等于 187 也是对的上的。

如果是 INVALID 状态的包，netfilter 不会对其做 IP 和端口的 NAT 转换，这样协议栈再去根据 ip + 端口去找这个包的连接时，就会找不到，这个时候就会回复一个 RST，过程如下图所示。

这也印证了我们前面 __inet_lookup_skb 为 null，然后发送 RST 的代码逻辑。

知道了原因，修改起来就很简单了，有两个改法。第一个改法有点粗暴，使用 iptables 把 invalid 包 drop 掉，不让它产生 RST。

iptables -A INPUT -m conntrack --ctstate INVALID -j DROP

这样修改以后，问题瞬间解决了，经过几十次的测试，一次都没有出现过上传超时和失败的情况。

这样修改有一个小问题，可能会误伤 FIN 包和一些其它真正 invalid 的包。有一个更加优雅的改法是修改 把内核选项 net.netfilter.nf_conntrack_tcp_be_liberal 设置为 1：

sysctl -w "net.netfilter.nf_conntrack_tcp_be_liberal=1"
net.netfilter.nf_conntrack_tcp_be_liberal = 1

把这个参数值设置为 1 以后，对于窗口外的包，将不会被标记为 INVALID，源码见 net/netfilter/nf_conntrack_proto_tcp.c:

static bool tcp_in_window(const struct nf_conn *ct,
			  struct ip_ct_tcp *state,
			  enum ip_conntrack_dir dir,
			  unsigned int index,
			  const struct sk_buff *skb,
			  unsigned int dataoff,
			  const struct tcphdr *tcph,
			  u_int8_t pf) {
		...
		
		res = false;
		if (sender->flags & IP_CT_TCP_FLAG_BE_LIBERAL ||
		    tn->tcp_be_liberal)
			res = true;
		...
    return res;
}

最后来一个如丝般顺滑的上传截图结束本篇文章。

多看代码，怀疑一些不可能的现象。以上可能说的都是错误，看看方法就好。