用 JMeter 压测 API:大部分工作其实是读懂错误
一个 JMeter 测试计划、三套配置、59 组结果。这些数字到底说明了什么:包括最后一轮 703 个错误里一个线程贡献了 209 个,以及压测找出的一个真实数据库 bug。
我们需要确认基于 Node.js 的后端 API 能不能扛住大量用户同时登录和拉取数据。我写了一套 JMeter 脚本,四天里跑了 59 组测试结果。其实写脚本没花多少时间,真正耗费精力的是搞清楚那些测试数据到底说明了什么。
一个测试计划,三套配置
测试流程模拟了用户打开应用后的常规操作,包括登录、查看个人资料和几条历史记录、打开二维码、查看消息,最后视情况更新一下个人资料。测试账号统一从 CSV 文件读取,每个环境对应一份账号文件。
我不想维护三套几乎一样的脚本,所以只做了一个测试计划。每次运行时需要调整的参数,都通过 JMeter 的 ${__P(name,default)} 从 profile 中读取。
# stress.properties
threads=150
rampUpSec=30
perApiRpm=115
loginRpm=115
durationSec=1800
enableWrites=true
| 线程数 | 持续时间 | 单接口每分钟请求数 | |
|---|---|---|---|
| Smoke | 100 | 3 分钟 | 115 |
| Load | 50 | 1 小时 | 23 |
| Stress | 150 | 30 分钟 | 115 |
每次执行都会把 HTML 报告、原始 .jtl 结果和日志输出到带时间戳的目录里。也多亏保存了这些产物,我现在才能回头把各个批次的数据放在一起比对。
写操作由 enableWrites 控制,可以用来跑纯读测试。不过目前三套 profile 默认都开着写操作,想要只读压测得手动调整。
控制每分钟请求量,而不是控制线程数
线程数只能决定当前活跃的用户量,不能决定发到后端的请求频次。如果某个接口响应很快,线程循环就会变快,发出的请求反而更多。为了让不同批次的测试具备可比性,我给每个接口都配了 Constant Throughput Timer 来限制每分钟的请求上限。
这也意味着压力测试报告里看到的每秒 17 个请求,只是我主动设定的负载量,并不代表服务器的极限吞吐。我没有做梯度加压去探测瓶颈,所以这套脚本测不出系统最大的承载上限。
脚本里的登录处理
接口不支持明文密码传输。客户端要先拿到 RSA 公钥,把密码加密之后再提交。因此每个线程在初始化阶段,都要在 Groovy 前置处理器里走一遍同样的加密流程。
import java.security.KeyFactory
import java.security.spec.MGF1ParameterSpec
import java.security.spec.X509EncodedKeySpec
import javax.crypto.Cipher
import javax.crypto.spec.OAEPParameterSpec
import javax.crypto.spec.PSource
def pem = vars.get('publicKeyPem')
.replaceAll('-----(BEGIN|END) PUBLIC KEY-----', '')
.replaceAll('\\s', '')
def key = KeyFactory.getInstance('RSA')
.generatePublic(new X509EncodedKeySpec(Base64.decoder.decode(pem)))
def cipher = Cipher.getInstance('RSA/ECB/OAEPWithSHA-256AndMGF1Padding')
def oaep = new OAEPParameterSpec('SHA-256', 'MGF1', new MGF1ParameterSpec('SHA-256'), PSource.PSpecified.DEFAULT)
cipher.init(Cipher.ENCRYPT_MODE, key, oaep)
def encrypted = cipher.doFinal(vars.get('password').getBytes('UTF-8'))
vars.put('encryptedPassword', Base64.encoder.encodeToString(encrypted))
这里必须显式指定 OAEPParameterSpec。服务端两处哈希用的都是 SHA-256,但 Java 对应算法名称的默认实现里,MGF1 用的却是 SHA-1,光看这个名称很容易弄错。
第一天大部分时间都在调试脚本,Base64 编解码、JSON 提取器、Groovy 语法、时间戳这些细节改来改去。这就是 smoke 测试的用处,在怀疑服务端出问题之前,先确保脚本本身的逻辑跑得通。
压测过程中的数据波动
下面是我挑出来的几组压力测试结果,保留了当时的报告,波动非常大。
| 运行批次 | 错误率 | p90 |
|---|---|---|
| 10 月 27 日 17:58 | 23.69% | 30.4 s |
| 10 月 27 日 23:00 | 0.76% | 2.3 s |
| 10 月 28 日 02:30 | 53.81% | 2.8 s |
| 10 月 28 日 02:48 | 50.86% | 2.2 s |
| 10 月 28 日 18:13 | 34.57% | 30.4 s |
| 10 月 29 日 01:03 | 9.56% | 12.0 s |
| 10 月 29 日 23:09 | 3.79% | 10.1 s |
| 10 月 29 日 23:56 | 2.23% | 2.3 s |
单看其中任何一行其实说明不了太多问题。不同批次之间脚本和配置都有改动,有些测试的运行时间比别的短得多,而且我当时没有记录每次压测对应的部署版本。不过有两个现象很明确。p90 达到 30 秒说明打到了超时上限,请求是被拖死的;而 50% 错误率对应 2.2 秒 p90 则是另一种情况,说明那些请求很快就失败了。
光看一个汇总的错误率,根本推导不出问题到底在谁身上。
拆解最后一轮压测的错误
为了排查原因,我在计划里加上了请求和响应日志,这样就能从汇总数字查到具体的失败请求。最后一轮压测总共发了 31,588 个请求,报错 703 个,错误率 2.23%。
| 错误类型 | 数量 |
|---|---|
| HTTP 500 | 387 |
| HTTP 401 | 282 |
| 连接错误与超时 | 34 |
401 大部分是脚本自己的问题。 有个线程在拉取公钥时超时了,手里没有拿到密钥。测试计划配置了遇到错误继续运行,这个线程就把字符串字面量 ${encryptedPassword} 当成密码发了过去,登录直接返回 401。登录失败后,它后续发出的所有业务请求也全都是 401。单单这一个线程就贡献了 703 个错误里的 209 个,包括 8 个下游接口各 23 次、登录 24 次,以及那次公钥请求本身。
500 报错指向了上游依赖。 业务里有部分数据需要通过代理转发给第三方系统。日志显示那个代理在压测期间挂了大约 100 秒,API 直接把第三方的异常透传出来,转成了 500。
剩下的 34 个错误不好归因。 连接超时和连接重置可能是网络波动、压测机本身瓶颈,也可能是服务端的问题。所以我只能说最后一轮绝大多数错误并不是 API 自己的问题,但没办法说所有错误都跟它无关。
当时分析时我还看错过一处。我在 JMeter 里看到了 97 个登录 401,而服务端日志里有 98 个,当时我以为是统计时间窗口不对齐。这次写博客翻看原始数据才发现,有 97 个记录在普通登录标签下,还有一个被记在了单独的初始登录标签下,只是标签统计上的差异。
压测真正找出的 bug
这轮测试最实在的收获来自更早的一批运行。上压力之后,API 触发了 Prisma 的 P2028 错误,事务无法在限定时间内启动或完成。同事排查后把一次查询移到了事务外部,并删掉了每次请求末尾都会调用的 $disconnect()。
从测试时间来看,后面的数据是在修完这个问题后跑出来的,不过因为当时没有记录部署版本号,严格来说我也没法证实每一轮测试都包含了这个修复。
| 错误率 | 平均耗时 | p90 | p95 | |
|---|---|---|---|---|
| Stress (150 线程, 30 分钟) | 2.23% | 1.5 s | 2.3 s | 2.7 s |
| Load (50 线程, 1 小时) | 0.22% | 1.3 s | 2.0 s | 2.2 s |
后续需要改进的地方
- 拿不到公钥的线程应该直接停止。 报错后继续运行让一次超时变成了 209 个假错误。虽然我复盘时记下了这一点,但手头的脚本里依然没有改掉。
- 每次测试都要记录对应的部署版本。 没有版本号,就很难把代码修复和具体的测试结果对应起来。
- 区分上游依赖报错和 API 自身的 500。
- 逐步加压摸清系统上限。 固定请求速率只能回答系统在当前压力下行不行,测不出它的最大容量。
- 把超时时间参数化。 连接超时和响应超时目前还是硬编码在测试计划里,没有放到 profile 中。