懵了!简单的HTTP调用,时延竟如此大?
以下文章来源于涤生的博客 ,作者涤生YQ
最近项目测试遇到个奇怪的现象,在测试环境通过 Apache HTTP Client 调用后端的 HTTP 服务,平均耗时居然接近 39.2ms。
图片来自 Pexels
可能乍一看觉得这不是很正常吗,有什么好奇怪的?其实不然,我再来说下一些基本信息。
该后端的 HTTP 服务并没有什么业务逻辑,只是将一段字符串转成大写然后返回,字符串长度也仅只有 100 字符,另外网络 Ping 延时只有 1.9ms左右。
调用时延
由于工作原因,调用耗时的问题,对我来说,已经见怪不怪了,经常会帮业务解决内部 RPC 框架调用超时的相关问题,但是 HTTP 调用耗时是第一次遇到。
不过,排查问题的套路是一样的。主要方法论无外乎由外而内、自上而下等排查方法。我们先来看看外围的一些指标,看能否发现蛛丝马迹。
外围指标
系统指标
主要看外围的一些系统指标(注意:调用与被调用的机器都要看)。例如负载、CPU。只需一个 Top 命令就能一览无余。
因此,确认了下 CPU 和负载都很空闲。由于当时没有截图,这里就不放图了。
进程指标
Java 程序进程指标主要看 GC、线程堆栈情况(注意:调用与被调用的机器都要看)。
Young GC 都非常少,而且耗时也在 10ms 以内,因此没有长时间的 STW。
因为平均调用时间 39.2ms,比较大,如果耗时是代码导致,线程堆栈应该能发现点啥。
看了之后一无所获,服务的相关线程堆栈主要表现是线程池的线程在等任务,这就意味着线程并不忙。
是不是感觉黔驴技穷了,接下来该怎么办呢?
本地复现
如果本地(本地是 MAC 系统)能复现,对排查问题也是极好的。
因此在本地使用 Apache HTTP Client 写了个简单 Test 程序,直接调用后端的 HTTP 服务,发现平均耗时在 55ms 左右。
咦,怎么跟测试环境 39.2ms 的结果有点区别。主要是本地与测试环境的后端的 HTTP 服务机器跨地区了,Ping 时延在 26ms 左右,所以延时增大了。
不过本地确实也是存在问题的,因为 Ping 时延是 26ms,后端 HTTP 服务逻辑简单,几乎不耗时,因此本地调用平均耗时应该在 26ms 左右,为什么是 55ms?
是不是越来越迷惑,一头雾水,不知如何下手?期间怀疑过 Apache HTTP Client 是不是有什么地方使用的不对。
因此使用 JDK 自带的 HttpURLConnection 写了简单的程序,做了测试,结果一样。
诊断
定位
其实从外围的系统指标、进程指标,以及本地复现来看,大致能够断定不是程序上的原因。那 TCP 协议层面呢?
有网络编程经验的同学一定知道 TCP 什么参数会引起这个现象。对,你猜的没错,就是 TCP_NODELAY。
那调用方和被调用方哪边的程序没有设置呢?调用方使用的是 Apache Http Client ,tcpNoDelay 默认设置的就是 True。
HttpServer server = HttpServer.create(new InetSocketAddress(config.getPort()), BACKLOGS);
居然没看到直接设置 tcpNoDelay 接口,翻了下源码。哦,原来在这里。
static {
AccessController.doPrivileged(new PrivilegedAction<Void>() {
public Void run() {
ServerConfig.idleInterval = Long.getLong("sun.net.httpserver.idleInterval", 30L) * 1000L;
ServerConfig.clockTick = Integer.getInteger("sun.net.httpserver.clockTick", 10000);
ServerConfig.maxIdleConnections = Integer.getInteger("sun.net.httpserver.maxIdleConnections", 200);
ServerConfig.drainAmount = Long.getLong("sun.net.httpserver.drainAmount", 65536L);
ServerConfig.maxReqHeaders = Integer.getInteger("sun.net.httpserver.maxReqHeaders", 200);
ServerConfig.maxReqTime = Long.getLong("sun.net.httpserver.maxReqTime", -1L);
ServerConfig.maxRspTime = Long.getLong("sun.net.httpserver.maxRspTime", -1L);
ServerConfig.timerMillis = Long.getLong("sun.net.httpserver.timerMillis", 1000L);
ServerConfig.debug = Boolean.getBoolean("sun.net.httpserver.debug");
ServerConfig.noDelay = Boolean.getBoolean("sun.net.httpserver.nodelay");
return null;
}
});
}
验证
在后端 HTTP 服务,加上启动"-Dsun.net.httpserver.nodelay=true"参数再试试。
优化后调用时延
问题是解决了,但是到这里如果你就此止步,那就太便宜了这个案例了,简直暴殄天物。
因为还有一堆疑惑等着你呢:
为什么加了 TCP_NODELAY ,时延就从 39.2ms 降低到 2.8ms?
为什么本地测试的平均时延是 55ms,而不是 Ping 的时延 26ms?
TCP 协议究竟是怎么发送数据包的?
解惑
①TCP_NODELAY 何许人也?
②Nagle 算法是什么鬼?
Nagle 算法的内容比较简单,以下是伪代码:
if there is new data to send
if the window size >= MSS and available data is >= MSS
send complete MSS segment now
else
if there is unconfirmed data still in the pipe
enqueue data in the buffer until an acknowledge is received
else
send data immediately
end if
end if
end if
如果发送内容大于等于 1 个 MSS,立即发送。
如果之前没有包未被 ACK,立即发送。
如果之前有包未被 ACK,缓存发送内容。
如果收到 ACK,立即发送缓存的内容。(MSS 为 TCP 数据包每次能够传输的最大数据分段)
③Delayed ACK 又是什么玩意?
当有响应数据要发送时,ACK 会随响应数据立即发送给对方。
如果没有响应数据,ACK 将会延迟发送,以等待看是否有响应数据可以一起发送。在 Linux 系统中,默认这个延迟时间是 40ms。
如果在等待发送 ACK 期间,对方的第二个数据包又到达了,这时要立即发送 ACK。
但是如果对方的三个数据包相继到达,第三个数据段到达时是否立即发送 ACK,则取决于以上两条。
④Nagle 与 Delayed ACK 一起会发生什么化学反应?
⑤抓个包玩玩吧
我们来抓个包验证下吧,在后端 HTTP 服务上执行以下脚本,就可以轻松完成抓包过程。
sudo tcpdump -i eth0 tcp and host 10.48.159.165 -s 0 -w traffic.pcap
如下图,这是使用 Wireshark 分析包内容的展示,红框内是一个完整的 POST 请求处理过程。
如下图,红框内是一个完整的 POST 请求处理过程,看 8 序号和 9 序号之间相差 25ms 左右,再减去网络延时约是 Ping 延时的一半 13ms。
因此 Delayed Ack 约 12ms 左右(由于本地是 MAC 系统与 Linux 有些差异)。
1. Linux 使用的是 /proc/sys/net/ipv4/tcp_delack_min 这个系统配置来控制 Delayed ACK 的时间,Linux 默认是 40ms;
2. MAC 是通过 net.inet.tcp.delayed_ack 系统配置来控制 Delayed ACK 的。
delayed_ack=0 responds after every packet (OFF)
delayed_ack=1 always employs delayed ack, 6 packets can get 1 ack
delayed_ack=2 immediate ack after 2nd packet, 2 packets per ack (Compatibility Mode)
delayed_ack=3 should auto detect when to employ delayed ack, 4packets per ack. (DEFAULT)
设置为 0 表示禁止延迟 ACK,设置为 1 表示总是延迟 ACK,设置为 2 表示每两个数据包回复一个 ACK,设置为 3 表示系统自动探测回复 ACK 的时机。
⑥为什么 TCP_NODELAY 能够解决问题?
总结
作者:涤生YQ
编辑:陶家龙、孙淑娟
出处:转载自微信公众号涤生的博客(ID:disheng_yq)
精彩文章推荐: