服务A的请求可以在服务B的日志中找到,但是服务B的响应时间超过了服务A的等待超时3秒。在服务日志B 中找不到服务A 的请求。
3. 问题分析
此类超时请求集中在短时间内(一般在2 分钟内),然后恢复正常。因此,现场很难发现问题并分析原因。我们只能搭建一个测试环境,服务A继续请求服务B,在B服务主机上通过DD命令写入大量数据导致主机IOWAIT高,同时TCPDUMP用于捕获两端的数据包进行分析。部分服务超时日志:
服务A:获取http://xxxid=593930: net/http: 请求已取消(等待标头时超出Client.Timeout) 服务B: 'GET xxxid=593930 HTTP/1.1' 200 64 '-' 'Go-http-client/1.1' '-' ' -' 165000(单位微秒)服务A发起请求,3秒没有收到服务B的响应,断开连接。服务B的日志显示处理时间为0.165S,远低于3S。服务A侧面看服务B的响应时间是网络传输时间、TCP队列排队时间和服务B应用处理时间的总和。由于这是内网测试,网络传输时间可以忽略不计。主要排查方向应该是TCP队列排队时间。
4. 抓包数据分析
场景1:服务A 和服务B 都打印了连接日志。服务A端数据包分析:09:51:43.966553000 服务A发起的GET请求的数据包如下:
图1:服务A发起GET请求
09:51:46.966653000 服务A发起GET请求3秒后(即服务A设置的等待超时时间),由于没有收到服务B的响应,服务A发起FIN主动断开与服务B的连接。
图2:服务A等待超时后主动断开连接
09:51:59.958195000 服务A发起http请求16秒后收到服务B的http响应消息。由于服务A主动关闭了连接,所以直接回复RST。
图3: B16 维修后的响应
服务B端数据包分析:09:51:44.062095000 服务B收到服务A发送的http请求包。
图4:服务B 接收来自服务A 的请求
09:51:59.936169000 服务B响应服务A,服务B从接收http请求消息到响应http请求的总时间约为15秒,但服务B打印的日志响应时间约为0.165秒。
图5:使用B15S 后的响应
图6:服务B 日志显示响应时间为0.165 秒
场景2:服务A有连接日志,但服务B没有连接日志。服务A端数据包分析:09:51:43.973791000 服务A向服务B发送HTTP请求包,然后收到服务B重传的第二次握手的syn+ack包,超过3秒没有收到服务B的HTTP响应秒,它会中断打开连接。
图7:服务B重传syn+ack
服务B端数据包分析:服务B重传了第二次握手的syn+ack包,收到了服务A的http请求,服务B忽略了,没有响应。服务A等待超时后断开连接。
图8: 服务B忽略服务A请求
5. 根因分析
TCP的三次握手过程中,内核会维护两个队列:
半连接队列,即SYN队列全连接队列,即ACCEPT队列图9:TCP队列
TCP三次握手过程中,第一次握手时服务器收到客户端发来的syn后,内核会将连接存放到半连接队列中,并向客户端回复syn+ack(第二次握手)。第三次握手时,服务器收到客户端的ack后,如果此时全连接队列未满,内核会将该连接从半连接队列中移除,加入到accept队列中,等待应用进程调用accept函数来断开连接。如果全连接队列已满,内核的行为取决于内核参数tcp_abort_on_overflow:
tcp_abort_on_overflow=0,服务器将丢弃客户端的ack。 tcp_abort_on_overflow=1,服务器将向客户端发送重置数据包。默认值为0。场景1的抓包数据显示该连接已进入满连接队列,但服务B日志中显示的连接时间晚了15S以上,说明该连接在队列中等待了15S在应用程序处理之前。场景2的抓包数据显示全连接队列已经溢出。内核根据tcp_abort_on_overflow 值为0 丢弃了服务A 的ack,超过了服务A 的超时等待时间。结论:当服务B 主机IO 达到瓶颈时,系统CPU 时间主要消耗在等待上IO响应和处理软中断。服务B应用获得的CPU时间有限,无法及时调用accept函数取出并处理连接,导致整个TCP队列溢出或者队列等待时间过长,超过服务超时时间一个。
6. 如何观察和调整tcp全队列
图10: TCP满队列观察方法
当连接处于监听状态时:
Recv-Q:当前全连接队列的大小。 Send-Q:当前全连接最大队列长度。当Recv-Q Send-Q表明整个队列已经溢出时,可以通过执行netstat -s | 观察溢出情况。 grep 'overflowed' 命令可以查看累计溢出次数。如果需要观察一段时间内整个队列的溢出情况,建议使用监控系统来采集数据,比如prometheus。
图11: TCP队列溢出监控
本文采摘于网络,不代表本站立场,转载联系作者并注明出处:https://www.iotsj.com//kuaixun/5371.html
用户评论
tcp全队列溢出真是让人头疼
有13位网友表示赞同!
这也太难调试了!记录下这个過程希望能帮到遇到同类问题的同行
有17位网友表示赞同!
排查网络问题总是挺费时的,关键是怎么找到突破口啊!
有18位网友表示赞同!
感觉当时好痛苦,还好最终解决了问题
有10位网友表示赞同!
数据包丢失真的影响体验呀, tcp流量监控很重要
有12位网友表示赞同!
原来全队列溢出也有这种原因啊,涨姿势了!
有13位网友表示赞同!
TCP/IP协议真是太复杂了!
有9位网友表示赞同!
遇到过类似情况的,可以参考这篇文章
有18位网友表示赞同!
排查网优真难,这个过程记录得相当仔细了
有6位网友表示赞同!
全队列溢出的原因分析确实很有深度
有5位网友表示赞同!
调试工具也是关键啊!
有16位网友表示赞同!
感觉自己像个网络侦探一样!
有20位网友表示赞同!
TCP流量过大容易导致这个情况出现啊
有15位网友表示赞同!
分享经验太棒了,希望更多人能从这篇博文中学到东西!
有6位网友表示赞同!
排查过程真是一番苦旅!
有10位网友表示赞同!
全队列溢出会导致通信延迟和数据丢失,简直是噩梦
有12位网友表示赞同!
以后遇到类似问题可以参考这篇文章来解决!
有15位网友表示赞同!
学习笔记:TCP的全队列是如何实现的?
有19位网友表示赞同!