转载

一次连接超时问题排查的历程

我们有一个 java 应用，启动的时候要初始化连接池，在连接一堆 sharding 过的 DB 时，经常会有一部分连接超时失败的，集中在一两台后端机器上，但每次失败的后端服务器却又不固定，也并不是每次启动都能遇到。超时时间设为了 50ms，看起来有点短但是对局域网，和压力并不算大的 DB 来说，这个时间已经长得匪夷所思了。后来尝试调大成 100ms，还是有失败的。但是如果启动成功后，却没再记录到过连接超时的情况。

排查网络问题首先是抓包，本来打算看看是不是对端响应慢有啥重传的，结果发现了更神奇的事情：发起 TCP 连接的 SYN 包不够数！也就是说，有几个连接根本连 SYN 包都没发出去过。还发现有一两个连接收到了 DB 服务器的 SYN/ACK 后，居然发了 RST ！所有服务器有响应的 SYN/ACK，包括被 RST 的，延迟都不到 0.2ms，速度挺正常的。那些个丢了的 SYN 和被 RST 的是怎么回事呢？

然后再用 strace 套着启动试试。这回也顺带了解了 java 在 linux 上连接超时的实现方式。首先发起一个非阻塞的 connect，然后用 poll 来等待直到超时，如果超时，则把 socket shutdown 了。然而在 strace 的记录里，所有的 connect 系统调用一个不少，只是在 poll 的时候超时了。这倒是可以解释前面抓包里 RST 的原因。在服务端 SYN/ACK 返回的时候，客户端已经超时 shutdown 了 socket，这时候自然就会返回 RST。但是奇怪的是为啥 connect 了却没看到 SYN 包，从被 RST 的现象推断，是从 connect 到发出 SYN 有了延迟。有的延迟发出后，返回的时候超时，于是就被 RST，绝大部分一直延迟到超时都没发出，于是就再也没了。但是为啥从 connect 到发出 SYN 包会有那么大的延迟呢？

于是去看了一下内核 connect 的实现，connect 系统调用对 TCP 来说，就是一路从数据构造 TCP 包、IP 包、Ethernet 包进入网卡的 QDisc。对非阻塞的 connect 来说就到此为止，返回 EINPROGRESS。对阻塞 connect，还会继续等待三次握手完成。进入 QDisc 后就是网卡驱动通过 DMA Engine 来发包了。因为是非阻塞 connect，这一路构造包的过程中没想出可以阻塞的点，于是怀疑是不是在 QDisc 或者 DMA Engine 发生了什么事情，研究实验了很久而无所得。

再一次碰到问题时，又抓了次包。这回凑巧没过滤 ARP 包，于是在结果里看到了一些查询 DB 服务器 MAC 地址的 ARP 请求。突然想起来，如果本地 ARP 缓存没命中的话，ARP 请求也是一个可能会有延迟的点。这个过程是发生在从 IP 包到构造 Ethernet 包的过程中的。于是把所有 ARP 包过滤出来看，真的发现对连接失败的 IP，ARP 请求第一次没有响应，隔 1s 重试以后才成功。就是这 1s 足以让超时时间是 50ms 的连接失败好多回了。

至于为啥 ARP 请求会超时倒不是啥难题。网络上有广播限流，之前也碰到过 ARP、VRRP 包被干的情况。至于启动成功后，应用和后端 DB 一直会有数据来往，ARP 缓存也就不会再被清掉，这也就解释了为啥问题只会出现在启动的时候。搞清楚原因以后，就不担心运行当中会出故障了。至于启动失败，重试就行了，或者 ping 一把后端 IP，产生一次 ARP 缓存就能绕过。彻底解决问题反倒不是个很紧迫的事了。

中间费了这么大劲，最后发现的问题却如此操蛋没技术含量，感觉挺失望的。不过大部分时候总是这样。隔壁老王有句名言，每个匪夷所思的问题背后，都有一个啼笑皆非的原因。

原文 http://xiezhenye.com/2016/07/一次网络问题排查的历程.html

正文到此结束