接口性能是后端服务最基础的质量指标之一。当用户反馈页面慢的时候,第一步往往就是要弄清楚:到底是哪个接口慢,慢在哪个环节。在Koa框架里,实现这个需求的标准做法就是编写一个统计响应时间的中间件,本文从原理到实现完整地走一遍这个过程。

理解Koa洋葱模型与中间件执行顺序
要写好一个计时中间件,必须先弄清楚Koa的洋葱模型。Koa的中间件是层层嵌套的,请求进来时依次穿过每一层中间件到达路由处理函数,响应返回时再按相反顺序穿出来。这意味着如果我们在中间件函数中,把计时逻辑写在调用next()之前和之后,就能分别拿到请求开始和响应结束这两个时间点,二者相减就是整个请求的处理耗时。
这个特性使得计时中间件的实现非常自然,不需要侵入任何业务代码。假设有日志中间件、计时中间件、路由中间件三层,只要把计时中间件注册在最外层或者合适的位置,它就能把内部所有环节的耗时全部统计进去,包括路由匹配、业务逻辑、数据库查询等等。当然要注意,如果把计时中间件放在某个中间件的内层,那么外层中间件消耗的时间就不会被统计到,所以一般建议把这类全局观测的中间件放在靠近最外层的位置。
另外需要注意的一点是,await next()之后并不意味着响应一定已经发送给客户端了,只是表示后续的中间件都执行完毕。绝大多数场景下这个时间点可以作为响应完成的近似值,因为Koa在这一步之后会立即进行实际的响应输出。如果需要更精确的发送时刻,可以监听response对象的finish事件,本文后面会提到这种做法。
手写一个基础版计时中间件
基础版的思路非常简单:进入中间件时记录起始时间,next()返回后计算差值。代码如下:
const Koa = require('koa');
const app = new Koa();
// 响应时间统计中间件
app.use(async (ctx, next) => {
const start = Date.now();
await next();
const cost = Date.now() - start;
// 把耗时写入响应头,方便前端在Network面板中直接查看
ctx.set('X-Response-Time', cost + 'ms');
console.log(`${ctx.method} ${ctx.url} - ${cost}ms`);
});
app.use(async (ctx) => {
// 模拟一个耗时300毫秒的业务处理
await new Promise(resolve => setTimeout(resolve, 300));
ctx.body = { code: 0, msg: 'ok' };
});
app.listen(3000, () => {
console.log('server is running at http://127.0.0.1:3000');
});运行后访问任意接口,控制台会输出类似GET /api/user - 302ms的日志,同时浏览器开发者工具的响应头里也能看到X-Response-Time这个字段。把耗时暴露在响应头里是一个非常实用的技巧,前端同学联调时不用问后端就能自己看到每个接口的耗时,排障效率会高很多。
关于计时的精度,Date.now()的精度是毫秒级,对于绝大多数接口监控来说足够了。如果需要亚毫秒精度,可以使用Node.js提供的process.hrtime.bigint(),它返回纳秒级的高精度时间,适合做更细致的性能剖析:
app.use(async (ctx, next) => {
const start = process.hrtime.bigint();
try {
await next();
} finally {
const cost = Number(process.hrtime.bigint() - start) / 1e6;
ctx.set('X-Response-Time', cost.toFixed(2) + 'ms');
}
});这里还做了一个小改进:用try和finally包裹next()的调用。这样做的好处是即使下游中间件或业务代码抛出了异常,耗时统计依然会执行,不会因为一次报错就丢失这条请求的耗时记录。配合Koa的全局错误处理,日志的完整性会好很多。
进阶:慢接口告警与访问日志持久化
单纯的console.log在生产环境是不够的,日志量一大既影响性能也不方便检索。更合理的做法是把访问日志结构化,并根据耗时阈值做分级处理。例如超过500毫秒的请求标记为慢请求,输出警告级别的日志,甚至上报到监控系统:
const SLOW_THRESHOLD = 500;
app.use(async (ctx, next) => {
const start = Date.now();
try {
await next();
} finally {
const cost = Date.now() - start;
ctx.set('X-Response-Time', cost + 'ms');
const log = {
time: new Date().toISOString(),
method: ctx.method,
url: ctx.url,
status: ctx.status,
cost: cost + 'ms',
ip: ctx.ip
};
if (cost > SLOW_THRESHOLD) {
// 慢请求输出警告,也可以在这里接入报警系统
console.warn('[SLOW]', JSON.stringify(log));
} else {
console.log(JSON.stringify(log));
}
}
});结构化日志的最大好处是方便后续接入日志采集系统。把JSON格式的日志写入文件或者发送到ELK这类平台之后,就可以按接口聚合统计平均耗时、P95耗时、P99耗时等指标,从而发现性能劣化的趋势。相比逐条翻日志,这种方式在排查线上问题时效率高出一个数量级。
如果项目规模逐渐变大,也可以考虑现成的中间件库,比如koa-response-time这类包,它们的核心实现原理与上文完全一致,只是额外做了一些边界处理。不过自己维护一份二三十行的计时中间件,灵活性更高,可以随时加入采样、按路由过滤、自定义上报等逻辑,很多团队最终都会选择自己维护。
更精确的统计:监听finish事件与指标上报
前面提到await next()执行完并不完全等于响应已发送。如果想精确测量响应真正写回客户端的耗时,可以监听Koa的response对象发出的finish事件:
app.use(async (ctx, next) => {
const start = Date.now();
await next();
const cost = Date.now() - start;
ctx.set('X-Response-Time', cost + 'ms');
console.log(`${ctx.method} ${ctx.url} - ${cost}ms`);
});
// 精确的发送完成时间,基于res的finish事件
app.use(async (ctx, next) => {
const start = Date.now();
ctx.res.on('finish', () => {
const total = Date.now() - start;
console.log('finish event, total:', total + 'ms');
});
await next();
});finish事件在响应流被完全写出到操作系统底层之后触发,包含了网络传输的一部分时间,用它统计出来的数字会更接近用户实际感受到的延迟。对于大响应体的下载类接口,这两种统计方式的差异会比较明显,大家可以根据业务需要选择统计口径。
更进一步的做法是把耗时数据定期聚合后上报到Prometheus这类监控系统。思路是在内存中维护一个按路由维度分组的直方图,每次请求结束时累加计数和耗时分布,然后通过定时任务或者metrics端点暴露给采集器。这样就能在Grafana面板上看到每个接口的实时耗时曲线和分位数,比翻日志直观得多。对于中小型项目,先做好响应头加结构化日志这两步,已经能覆盖日常百分之八九十的排障需求,等流量真正上来了再演进到完整的指标监控体系也不迟。