基于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.