高精度监控指标收集：在Fastify钩子中实现请求耗时分布统计

可能你也遇到过这种情况：接口平均响应时间看着挺正常，一到晚上高峰期，总有几个请求慢得像乌龟。看监控面板上的平均值，一切岁月静好，但实际上有一小撮请求已经超时了。平均值这个东西，就像寓言里把头埋进沙子的鸵鸟，它把长尾问题藏得严严实实。今天我们就来聊聊，怎么用 Fastify 的钩子，自己动手做一个请求耗时分布统计，把那些被平均值掩盖的慢请求一个一个揪出来。

一、先聊聊为什么需要关心请求耗时分布

想象一个每天几百万次调用的接口。平均耗时是 200ms，听起来还不错。可如果其中有 1% 的请求要花 5 秒，这一部分请求对于使用者来说已经是“卡死”了。平均值不会告诉你这些，从平均值里你甚至看不出任何异常。而耗时分布，比如把耗时分成几个区间：10ms 以下、100ms 以下、500ms 以下、1 秒以上，然后分别统计每个区间的请求数，你就能一眼看到长尾到底有多长。进一步，你还可以计算 P50、P95、P99 这些分位数，用来判断大多数人的体验以及最差的那部分人的体验。分位数和分布桶思路类似，都是对“平均值失灵”的补救。

二、Fastify 钩子是怎么一回事

Fastify 之所以快，除了底层引擎之外，还因为它的生命周期非常清晰。在请求从进入到返回的整个过程中，Fastify 会触发一系列钩子，比如 onRequest、preHandler、onResponse 等等。这些钩子就像是流水线上的几个工位，每个工位都可以让你做一些额外动作，而不需要去改动业务代码。我们要做的“请求耗时统计”，其实就是在两个工位上各放一个小闹钟：一个在请求进来时打点，一个在响应出去时打点，两者一减，就是耗时。

2.1 我们选哪个钩子

Fastify 常用的钩子有 onRequest、preHandler、onResponse 等。对于统计耗时来说，最合适的是 onRequest 和 onResponse。onRequest 在请求被解析后、路由处理前执行；onResponse 在响应发送之后执行。这两个钩子一个在最前面，一个在最后面，刚好能覆盖一个请求的完整生命周期。注意，onResponse 的时机是响应已经发给客户端了，所以你不用担心自己加的逻辑会拖慢响应。

三、动手实现：在 Fastify 钩子中统计耗时分布

下面的示例统一使用 Node.js（JavaScript）技术栈。我们一步步来，先搭个基础服务，再往上加统计插件。

3.1 先搭一个最简单的 Fastify 服务

先初始化一个项目，并安装 Fastify。打开终端，输入：

npm init -y
npm install fastify

然后创建一个 app.js 文件，写一个最小服务：

// 引入 Fastify
const Fastify = require('fastify');

// 创建实例
const app = Fastify();

// 定义一个简单的路由
app.get('/hello', async () => {
  return { message: 'hello world' };
});

// 启动服务
app.listen({ port: 3000 }, (err) => {
  if (err) {
    console.error(err);
    process.exit(1);
  }
  console.log('服务已启动: http://localhost:3000');
});

运行 node app.js，访问 http://localhost:3000/hello，就能看到响应。这个基础服务里没有任何统计逻辑。

3.2 用钩子记录每一个请求的开始和结束

现在，我们在 onRequest 里记录开始时间，在 onResponse 里计算耗时。最简单的做法是直接注册两个钩子：

// 记录每个请求的开始时间
app.addHook('onRequest', (request, reply, done) => {
  // 给 request 挂一个自定义属性，用来存开始时间
  request.startTime = Date.now();
  done();
});

// 在响应完成后计算耗时
app.addHook('onResponse', (request, reply, done) => {
  // 计算耗时，单位是毫秒
  const duration = Date.now() - request.startTime;
  console.log(`请求路径: ${request.url}, 耗时: ${duration}ms`);
  done();
});

这样每次请求都会打一行日志。但这样只能看看单个请求，没法形成分布。下一步我们要把耗时存起来。

3.3 设计一个简单的耗时分布存储

我们用一个对象来当“分布桶”。把耗时分成几个区间，每个区间一个计数器。比如：

// 分布桶定义：每个桶的边界（毫秒）
const BUCKETS = [10, 50, 100, 250, 500, 1000];

// 统计数据的存储对象
const distribution = {
  // 先初始化所有桶的计数为 0
  buckets: {
    '10': 0,
    '50': 0,
    '100': 0,
    '250': 0,
    '500': 0,
    '1000': 0,
    'other': 0, // 超过 1000ms 的单独放这儿
  },
  totalCount: 0,  // 总请求数
  totalTime: 0,   // 总耗时，用来算平均值
};

// 根据耗时（毫秒）找到它属于哪个桶，并累加计数
function recordDuration(duration) {
  let bucketName = 'other';
  for (const b of BUCKETS) {
    if (duration < b) {
      bucketName = String(b);
      break;
    }
  }
  // 累加对应桶的计数
  distribution.buckets[bucketName] += 1;
  // 总请求数加一
  distribution.totalCount += 1;
  // 累计总耗时
  distribution.totalTime += duration;
}

这里用了一个数组表示桶的边界。比如耗时 30ms，会落在 '50' 这个桶里，因为它大于 10 且小于 50。耗时 1200ms，会落在 'other' 桶里。这样，统计完一批请求后，你就能看出来有多少请求是慢的。

3.4 整合成一个小插件

我们把这些逻辑封装成一个 Fastify 插件。Fastify 支持用函数封装插件，然后在主服务里注册。这样做的好处是，以后任何一个项目都能直接复用。

创建一个 metrics.js 文件：

// 这个函数就是插件的入口
function metricsPlugin(app, options, done) {
  // 分布桶边界
  const BUCKETS = [10, 50, 100, 250, 500, 1000];

  // 统计存储
  const distribution = {
    buckets: {},
    totalCount: 0,
    totalTime: 0,
  };

  // 初始化每个桶为 0
  for (const b of BUCKETS) {
    distribution.buckets[String(b)] = 0;
  }
  // 大于最大桶的单独一个桶
  distribution.buckets.other = 0;

  // 记录耗时的内部函数
  function recordDuration(duration) {
    let bucketName = 'other';
    for (const b of BUCKETS) {
      if (duration < b) {
        bucketName = String(b);
        break;
      }
    }
    distribution.buckets[bucketName] += 1;
    distribution.totalCount += 1;
    distribution.totalTime += duration;
  }

  // onRequest 钩子：开始计时
  app.addHook('onRequest', (request, reply, done) => {
    // 使用高精度时间，避免 Date.now() 的毫秒精度不够
    request.startTime = process.hrtime.bigint();
    done();
  });

  // onResponse 钩子：计算耗时并记录
  app.addHook('onResponse', (request, reply, done) => {
    // 当前时间减去开始时间，得到纳秒；再除以 1e6 转成毫秒
    const duration = Number(process.hrtime.bigint() - request.startTime) / 1e6;
    // 入桶
    recordDuration(duration);
    done();
  });

  // 提供一个获取统计快照的方法
  app.decorate('getMetrics', () => {
    // 返回一个拷贝，防止外面直接修改
    const snapshot = JSON.parse(JSON.stringify(distribution));
    snapshot.averageMs = snapshot.totalCount === 0 ? 0 : snapshot.totalTime / snapshot.totalCount;
    return snapshot;
  });

  done();
}

module.exports = metricsPlugin;

这个插件在注册后，会给 Fastify 实例添加一个 getMetrics() 方法，用于获取当前的统计快照。在这个实现里，我们用到了 process.hrtime.bigint()，它能提供纳秒级的精度，比 Date.now() 准得多。注意，Fastify 要求插件必须传 done 回调，并且在完成初始化后调用它。

3.5 在服务里注册插件，并提供一个查看统计结果的接口

修改 app.js，导入插件并注册，然后加一个 /metrics 路由来展示统计数据：

const Fastify = require('fastify');
const metricsPlugin = require('./metrics');

const app = Fastify();

// 注册我们自己写的插件
app.register(metricsPlugin);

// 一个业务接口
app.get('/hello', async () => {
  return { message: 'hello world' };
});

// 返回统计快照的接口
app.get('/metrics', async () => {
  // 调用插件提供的 getMetrics 方法
  return app.getMetrics();
});

app.listen({ port: 3000 }, (err) => {
  if (err) {
    console.error(err);
    process.exit(1);
  }
  console.log('服务已启动: http://localhost:3000');
});

注意，app.getMetrics() 是我们在插件里通过 decorate 挂上去的，所以能这样直接用。

3.6 完整测试一把

为了看到效果，我们再加一个故意慢一点的接口，模拟耗时的波动：

// 模拟耗时操作：根据参数等待不同时间
app.get('/slow', async (request) => {
  const waitTime = Number(request.query.ms) || 200;
  // 使用 Promise 和 setTimeout 模拟异步等待
  await new Promise((resolve) => setTimeout(resolve, waitTime));
  return { waited: waitTime };
});

然后我们通过命令行工具请求多次，先请求慢接口，再看统计结果。在终端里输入：

# 请求 2 次慢接口，分别是 80ms、300ms
curl "http://localhost:3000/slow?ms=80"
curl "http://localhost:3000/slow?ms=300"

# 再请求 2 次正常接口
curl "http://localhost:3000/hello"
curl "http://localhost:3000/hello"

# 查看统计结果
curl "http://localhost:3000/metrics"

你会看到类似这样的输出（实际数值可能略有偏差）：

{
  "buckets": {
    "10": 2,
    "50": 0,
    "100": 1,
    "250": 0,
    "500": 1,
    "1000": 0,
    "other": 0
  },
  "totalCount": 4,
  "totalTime": 390.086,
  "averageMs": 97.5215
}

这里有两个请求落在了 '10' 桶里，分别是两个 hello 接口。一个 80ms 的慢接口落在了 '100' 桶，一个 300ms 的慢接口落在了 '500' 桶。你就能直观地看到耗时都集中在哪些区间。

3.7 也可以做一个定时打印任务

如果不想暴露接口，也可以每隔一段时间把统计结果打印到日志里。这样在开发环境或者内部测试时很方便。代码示例：

// 每隔 60 秒打印一次统计快照
setInterval(() => {
  console.log(`当前统计: ${JSON.stringify(app.getMetrics())}`);
}, 60 * 1000);

这个可以放在服务启动之后。

四、这个技术主要用在哪里

第一，生产环境监控。你不用再担心平均值不好看，直接把统计结果暴露给 Prometheus 或者自己做一个内部 dashboard，就可以看到真实的长尾分布。

第二，发布效果对比。新版本上线后，对比同样一段时间的耗时分布，看看慢请求比例有没有上升。比如原来 p99 是 1 秒，新版本后变成 2 秒，说明有性能回退。

第三，容量规划。如果发现耗时分布里，超过1秒的请求比例在逐渐升高，说明系统可能接近瓶颈，该扩容了。

第四，调用链问题的初始定位。当某个接口的耗时分布出现明显异常时，你可以根据统计结果快速判断是整体变慢了，还是只有极端请求变慢了，再决定是否深入排查。

五、这种方案的优点和缺点

5.1 优点

• 代码侵入性小。业务路由里不用写任何计时逻辑，改动只集中在插件里。
• 精度高。用 process.hrtime.bigint() 能拿到纳秒级时间，毫秒耗时误差基本可以忽略。
• 性能开销低。每次请求只是做几次加法和一个对象字段的累加，对接口本身影响微乎其微。
• 易于扩展。你想统计路由维度、状态码维度、用户维度，都可以在钩子里继续加信息，然后拆分桶。

5.2 缺点

• 单机内存统计，服务重启后就清零。如果需要长期保存，得定时把快照刷出去，比如写入到数据库或对接监控系统。
• 多实例部署时，每个实例只有自己的一部分数据，需要汇总才能看到全局分布。
• 如果流量特别大，每请求一次对象累加也可能产生内存热点。不过通常不会达到这个量级。
• 没有现成的分位数值。我们目前用的是桶分布，如果你想直接得到 P95、P99，需要额外维护一个有序耗时列表或使用近似算法，比如 HdrHistogram。

六、实际落地要注意哪些坑

• 千万别用 Date.now() 来计时。它的精度只有毫秒，而且受系统时钟调整影响，可能跳变。使用 process.hrtime.bigint() 是更专业的选择。
• 在 onResponse 钩子里不要做太重的同步操作。如果统计逻辑太复杂，比如写文件、发网络请求，最好异步化，或者使用独立的队列。
• 注意内存泄漏。如果使用 Map 按请求 id 存时间，记得在 onResponse 里删掉。我们这里直接用 request 属性，请求生命周期结束就自动释放了，没有泄漏问题。
• 采样策略。对于超高并发系统，全量统计也会有一点开销，可以只统计百分之一的请求。加一个随机数判断就行。
• 桶的边界要合理。如果你服务的正常耗时在 200ms 左右，那么桶可以放得更密一些，比如 50、100、150、200、250、300、500、1000；如果服务很快，桶的粒度可以更细。分布桶的意义在于观察形态，粒度要符合你要分析的区间。
• 多实例部署时，要记得每个实例的 app.getMetrics() 只反映当前进程。把它暴露出来之后，需要一个收集器去聚合所有实例的数据。

七、文章总结

用 Fastify 钩子做耗时分布统计，是一个非常轻量又实用的方案。它不需要引入额外的大型框架，也不需要修改业务代码，只需要在插件里维护几个计数器，就能把请求耗时的真实形态记录下来。通过分布桶，你可能会惊讶地发现，原来有那么多请求慢得不像话，而平均值之前一直瞒着你。这个统计插件还可以继续扩展，比如加路由维度、状态码维度，或者对接外部监控系统。希望这篇文章能给你一个思路，下次再遇到“平均耗时正常但个别请求超时”的问题时，自己动手就能解决。