题图:Photo by Snapwire from Pexels
wrk 是一个非常棒的 HTTP 压力测试工具,构建在 Redis、NGINX、Node.js 和 LuaJIT 这几个开源项目的基础之上,充分利用了他们在事件驱动、HTTP 解析、高性能和灵活性方面的优点,并且可以自己写 Lua 脚本来生成测试请求。
虽然 wrk 没有测试案例,并且作者大概一年现身一次来合并代码,但这些并不妨碍我们把 wrk 作为性能测试和 fuzz 测试的首选工具。如果你还在使用多线程的 ab,那么非常值得尝试下 wrk。
下面是 wrk 结果中的延时分布统计部分:
代码语言:javascript复制Latency Distribution
50% 1.20ms
75% 595.78ms
90% 899.11ms
99% 1.00s
这个示例是指,50% 的请求在 1.2ms 内完成,90% 的请求在 899 ms 内完成,99% 的请求在 1s 内完成。
我们在使用 wrk 压力测试自己产品的时候,发现 wrk 统计的延时结果中,大部分请求都是几毫秒内完成,但有一小部分请求的延时会超过 100 毫秒。 对于用 OpenResty 构建的系统,出现这么大的延时是不太科学的事情。
虽然这个问题最终解决方法非常简单,但具体的分析和定位有些曲折,花了好几天的时间。最终的解决方法并不重要,过程和思考问题的方式才是值得关注的。
遇到延迟问题,我们的第一反应是代码或者系统某个地方有阻塞。 由于系统比较复杂,所以我们祭出了火焰图。
没有现成的 systemtap 脚本来分析这类问题,所以花了点时间写脚本。但调整了几次 systemtap 脚本,都没有捕获到明显的延时,这个和 wrk 的结果明显不符。我们猜测这个脚本可能不够完善,可能遗漏了某些函数没有 hook 住。但同时也对 wrk 的结果是否正确产生了怀疑。
我们调转方向,先来定位到底是 wrk 统计错了,还是确实是 server 的问题。我们在 wrk 所在的服务器上,把压测期间的包都 dump 出来,按照耗时进行排序,惊奇的发现结果和 wrk 的延时统计大相径庭,没有发现超过 100 毫秒的请求。重复了几次以上测试,结果都一致。
这下目标就很明确了,只要把 wrk 关于延迟统计的代码捋顺就可以了。最担心的就是 wrk 内部统计时候有 bug,这就不好修复了,毕竟是一个没有任何测试案例的项目:(
我们仔细过了一遍 wrk 的统计逻辑,并在开始和结束的地方加了日志,发现关于延时的统计都是正确的,这也让我们松了一口气。但是在打印最终结果之前,有一段统计数据校正
的代码:
if (complete / cfg.connections > 0) {
int64_t interval = runtime_us / (complete / cfg.connections);
stats_correct(statistics.latency, interval);
}
按照这个 if 判断,只要有压测数据产生,就会进行校正。有兴趣的同学,可以去看看 stats_correct
函数的代码,只有 10 行,我看了几遍也没看懂。
再去查代码的提交记录,说不定有什么收获,但只有下面这一行,又没看懂:
remove calibration & improve CO correction
吐槽下,如果提交记录稍微详细一点儿,不用缩写,或者加个代码注释,就能省不少事儿。
问题查到这里,已经可以证实不是产品的问题,而且解决方法已经有了,就是注释掉上面这段校正的代码。但 wrk 作者特意加上肯定是有原因的,不明白这个原因始终是个隐患。自然的,要开一个 issue 来请教下作者,一年现身一次的 wg 在 15 天后给了答复,原来上面 commit info 里面的缩写 CO
是指 Coordinated Omission
,并且给了一篇专门讲这个问题的文章,感兴趣的同学可以用这个关键字自行搜索。
简单的说,Coordinated Omission
是指在做压力测试的时候,只统计发送和收到回复之间的时间是不够的,这个是指服务时间
,会遗漏掉很多潜在的问题,还需要把测试请求的等待时间也计算在内,才算是用户关心的响应时间
。
提出 CO 这个问题的 Gil Tene,还对 wrk 做了修改,专门解决 CO 的问题: https://github.com/giltene/wrk2,在这个项目的 README 里面也有一些对此的解释,有兴趣的可以看看,这里就不多提及了。
对于我们自己的产品来说,代码中肯定不会有任何阻塞,在做压力测试的时候,是会把 CPU 跑满。即使出现阻塞,也是有火焰图来采样分析的。所以 wrk 这里针对 Coordinated Omission 做的简单粗暴的校正,反而会产生误导。