开发中的网络问题逻辑推理分析

基于TCP/IP的逻辑推理，大部分软件从业人员都不是很懂，导致很多问题都被误认为诡异问题。有些人是惧怕TCP/IP网络书籍中的复杂知识内容，有的是被wireshark[1]显示的深红色内容所干扰。

经典案例1：

例如有一个DBA遇到了性能问题，进行了抓包分析，但被wireshark中的内容所干扰，以为是TCP重传问题。

Figure 1. Packet capture screenshot provided by DBA suspecting retransmission problems.

既然怀疑是重传，应该去了解重传的本质是什么。重传的本质是超时重传，如果要确定是否是重传所导致，那么显然是要给出时间相关信息的，但上面截图并没有给出。

让开发人员重新截图后，看到了时间信息，具体见下图：

Figure 2. Packet capture screenshot with time information added.

在网络分析时，可以利用时间信息进行逻辑推理。如果重复的两个数据包时间差是微秒级别，那么要么是超时重传，要么是重复抓包。假设TCP超时在微秒级别，TCP设计时至少要满足一个Round-trip time（RTT）才能重传，而上面截图是常规LAN环境下的抓包，RTT一般为100微秒级别，重传时间差和RTT相差了100倍，所以上图中的重传并不是超时重传，而是重复抓包。

经典案例2：

再以一个经典案例来讲述逻辑推理在网络问题分析中的重要性：

有一天，业务开发和DBA运维跑过来，说凌晨调用MyQL数据库中间件[1]的定时脚本出问题了，MySQL数据库中间件没有响应回来。当听到这个问题以后，我查看了MySQL数据库中间件的错误日志，结果没有发现任何有价值的线索。于是我问开发能不能把问题重现一下，因为只要能够重现，问题就容易解决。开发回去试验了多次，问题没有重现，不过开发有了新的发现：执行相同的SQL语句，白天SQL的响应时间跟凌晨的响应时间不一样。开发认为SQL响应很慢的时候，MySQL数据库中间件会阻塞住会话，不返回结果给客户端。于是请DBA运维修改脚本中的SQL去模拟SQL响应慢的场景，结果MySQL数据库中间件返回了结果，没有出现凌晨的死等现象。

一时找不到根本原因，而开发发现了MySQL数据库中间件有功能方面的问题。因此，开发和DBA运维更加坚信是MySQL数据库中间件迟迟没有返回响应。事实上，这些问题与MySQL数据库中间件响应并不相关。

从第一天的情况来看，问题确实出现了，每一个相关的人都想找到问题原因，会做各种猜测，但并没有找到真正的原因。

第二天，开发反馈半夜的脚本问题又出现了，但白天还是无法重现。DBA运维反馈说白天试验偶尔会出现，第一次执行会出现，但不幸的是这个结论被后续测试所否定，问题再也没有在白天重现过。开发着急的抱怨线上很快就要使用脚本，我只能建议开发白天使用脚本，避免凌晨出现的问题。因为所有怀疑都聚焦在MySQL数据库中间件上面，很难从其他角度去分析问题。

作为MySQL数据库中间件的开发人员，这么诡异的问题不能轻易放过，否则会影响MySQL数据库中间件的后续使用，而且领导也要求问题必须尽快解决。最终决定用低成本抓包分析的方案，即在凌晨脚本执行的时候，在服务器端进行抓包，分析当时发生了什么：要么MySQL数据库中间件一直没有发送响应，要么MySQL数据库中间件返回了响应，客户端脚本没有收到。只要确认MySQL数据库中间件发送了响应，就不是MySQL数据库中间件开发人员的问题。

第三天，开发反馈凌晨问题没有再次出现，抓包分析也确认问题没出现。经过深入思考，如果是MySQL数据库中间件的问题，应该不会如此这么诡异：在凌晨多次出现，在白天却很难出现。只能继续等问题再出现，根据抓包进行分析。

第四天，问题还是没有出现。

第五天，问题终于出现，有希望了。

抓包文件很多，首先让开发给出问题出现的时间点，在大量的抓包信息里面找出出现问题的SQL语句，最终找到的结果如下：

Figure 3. Key packet information captured for problem resolution.

从上面的抓包文件（从服务器抓取）来看，发送SQL时间为凌晨3点，MySQL数据库中间件服务过了630秒（03:10:30.899249-03:00:00.353157）返回SQL响应信息给客户端，这说明MySQL数据库中间件是返回SQL响应的，但过了仅仅238微秒（03:10:30.899487-03:10:30.899249），服务器的TCP层就接收到了reset数据包，这么快就返回，reset数据包非常可疑。需要注意的是，这reset数据包，不能直接认为是客户端发的。首先要确认reset数据包是谁发的，要么是客户端发的，要么是中途设备发的。

因为抓包只在服务器端进行，客户端数据包情况并不了解。尝试通过分析服务器端的抓包文件，进行逻辑推理找出问题根源。假设客户端发送了reset，那意味着客户端TCP层已经不存在这个连接的TCP状态了，TCP状态从有到无，会通知客户端应用连接异常，客户端脚本在收到这个通知后，会立即报错，但现实是客户端仍然在等待响应回来，因此假设不成立，客户端没有发送reset。客户端连接还活着，但服务器这边的相应连接已经被reset干掉了。

reset到底是谁发的呢？最大怀疑对象是亚马逊的云环境。DBA运维根据这个抓包分析结果询问亚马逊客服，得到如下信息：

Figure 4. Final response from Amazon customer service.

客服给出的答复与分析结果一致，是亚马逊的elb（类似LVS负载均衡器）强制干扰了TCP会话。图中的回复指出，如果响应超过了350秒阈值（抓包显示为630秒），亚马逊的elb设备就会发送reset给响应的一方（本案例里是发送给服务器）。开发部署的客户端脚本，被忽视了，并没有接收到reset，认为服务器连接仍然还活着。官方对此类问题的建议是，利用TCP keepalive机制来规避这方面的问题。

得到官方答复以后，问题算是彻底解决。

从这个具体案例来看，线上问题有时候是非常复杂的，需要有关键信息的获取，这里是抓包信息，捕获到当时发生的情况。利用逻辑推理，分析出根源，这里采用了归谬法来辅助判断。

参考资料

[1] https://www.wireshark.org/

[2] MySQL proxy based: https://github.com/session-replay-tools/cetus.

[3] Bin Wang (2024). The Art of Problem-Solving in Software Engineering:How to Make MySQL Better.