用 JMeter 压测 API:大部分工作其实是读懂错误

一个 JMeter 测试计划、三套配置、59 组结果。这些数字到底说明了什么:包括最后一轮 703 个错误里一个线程贡献了 209 个,以及压测找出的一个真实数据库 bug。

文章目录
  1. 一个测试计划,三套配置
  2. 控制每分钟请求量,而不是控制线程数
  3. 脚本里的登录处理
  4. 压测过程中的数据波动
  5. 拆解最后一轮压测的错误
  6. 压测真正找出的 bug
  7. 后续需要改进的地方

我们需要确认基于 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
线程数持续时间单接口每分钟请求数
Smoke1003 分钟115
Load501 小时23
Stress15030 分钟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:5823.69%30.4 s
10 月 27 日 23:000.76%2.3 s
10 月 28 日 02:3053.81%2.8 s
10 月 28 日 02:4850.86%2.2 s
10 月 28 日 18:1334.57%30.4 s
10 月 29 日 01:039.56%12.0 s
10 月 29 日 23:093.79%10.1 s
10 月 29 日 23:562.23%2.3 s

单看其中任何一行其实说明不了太多问题。不同批次之间脚本和配置都有改动,有些测试的运行时间比别的短得多,而且我当时没有记录每次压测对应的部署版本。不过有两个现象很明确。p90 达到 30 秒说明打到了超时上限,请求是被拖死的;而 50% 错误率对应 2.2 秒 p90 则是另一种情况,说明那些请求很快就失败了。

光看一个汇总的错误率,根本推导不出问题到底在谁身上。

拆解最后一轮压测的错误

为了排查原因,我在计划里加上了请求和响应日志,这样就能从汇总数字查到具体的失败请求。最后一轮压测总共发了 31,588 个请求,报错 703 个,错误率 2.23%。

错误类型数量
HTTP 500387
HTTP 401282
连接错误与超时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()。

从测试时间来看,后面的数据是在修完这个问题后跑出来的,不过因为当时没有记录部署版本号,严格来说我也没法证实每一轮测试都包含了这个修复。

错误率平均耗时p90p95
Stress (150 线程, 30 分钟)2.23%1.5 s2.3 s2.7 s
Load (50 线程, 1 小时)0.22%1.3 s2.0 s2.2 s

后续需要改进的地方

  • 拿不到公钥的线程应该直接停止。 报错后继续运行让一次超时变成了 209 个假错误。虽然我复盘时记下了这一点,但手头的脚本里依然没有改掉。
  • 每次测试都要记录对应的部署版本。 没有版本号,就很难把代码修复和具体的测试结果对应起来。
  • 区分上游依赖报错和 API 自身的 500。
  • 逐步加压摸清系统上限。 固定请求速率只能回答系统在当前压力下行不行,测不出它的最大容量。
  • 把超时时间参数化。 连接超时和响应超时目前还是硬编码在测试计划里,没有放到 profile 中。