平均响应时间正常，并不代表用户没有变慢。本文从 p95、p99 长尾延迟入手，结合 Spring Boot 指标、慢请求日志、线程池与数据库连接池，建立一条适合生产环境的 Java 服务故障定位路径。
问题背景：平均值为什么会掩盖故障
生产环境里有一种很容易被忽略的故障：接口平均耗时只有几十毫秒，错误率也没有明显变化，但一部分用户已经频繁遇到超时，或者页面偶尔卡住几秒。
这类问题通常不是“所有请求都变慢”，而是少量请求变得非常慢。假设 1000 个请求中有 990 个在 50 毫秒内完成，另外 10 个请求耗时 5 秒，平均耗时约为 99.5 毫秒。这个数字看起来并不严重，但那 1% 的用户已经明显感知到了问题。
因此，生产环境不能只看平均耗时。至少要同时关注：
- p50：中位数，代表典型请求的体验；
- p95：95% 请求低于该耗时，用来观察较普遍的慢请求；
- p99：99% 请求低于该耗时，更容易发现长尾；
- 最大耗时：适合辅助排查，但容易受到极端单次请求影响。
长尾延迟本身不是根因，它只是一个结果。根因可能来自数据库慢查询、连接池等待、锁竞争、下游调用超时、线程池排队、Full GC，甚至某一类特殊参数触发了低效代码路径。排查的关键，是把“接口变慢”拆成可观测的等待阶段。
先建立一套不会误导自己的指标
以 Spring Boot 应用为例，可以使用 Micrometer 记录请求耗时。下面的过滤器展示了一个接近完整的实现：它会记录请求总耗时，并对超过阈值的请求输出慢请求日志。
package example.web;
import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import java.io.IOException;
import java.util.concurrent.TimeUnit;
@Component
public class RequestMetricsFilter extends OncePerRequestFilter {
private static final long SLOW_REQUEST_MILLIS = 1000L;
private final Timer requestTimer;
private final Counter errorCounter;
public RequestMetricsFilter(MeterRegistry registry) {
this.requestTimer = Timer.builder("app.http.server.requests")
.description("HTTP request latency")
.publishPercentiles(0.5, 0.95, 0.99)
.register(registry);
this.errorCounter = Counter.builder("app.http.server.errors")
.description("HTTP responses with status >= 500")
.register(registry);
}
@Override
protected void doFilterInternal(
HttpServletRequest request,
HttpServletResponse response,
FilterChain filterChain) throws ServletException, IOException {
long startNanos = System.nanoTime();
try {
filterChain.doFilter(request, response);
} finally {
long elapsedNanos = System.nanoTime() - startNanos;
requestTimer.record(elapsedNanos, TimeUnit.NANOSECONDS);
if (response.getStatus() >= 500) {
errorCounter.increment();
}
long elapsedMillis = TimeUnit.NANOSECONDS.toMillis(elapsedNanos);
if (elapsedMillis >= SLOW_REQUEST_MILLIS) {
System.err.printf(
"slow request method=%s uri=%s status=%d costMs=%d%n",
request.getMethod(),
request.getRequestURI(),
response.getStatus(),
elapsedMillis
);
}
}
}
}项目需要引入与自身 Spring Boot 版本匹配的 Actuator 和 Micrometer 依赖。Timer 负责记录耗时，百分位数的计算和展示由 Micrometer 的实现及监控系统共同完成。示例中的慢请求日志只是基础方案，正式环境应使用项目统一的日志框架，而不是直接使用 System.err。
这里有一个重要细节：不要直接把完整 URL、用户输入参数或订单号作为指标标签。比如把 /order/100001、/order/100002 分别作为 uri 标签，会造成高基数，最终让监控系统本身变慢甚至失控。应尽量使用路由模板，例如 /order/{id}，或者使用 Spring Boot Actuator 默认提供的规范化 URI 标签。
慢请求日志应该记录什么
一条慢请求日志的目标不是“证明它很慢”，而是帮助我们缩小范围。至少应包含：
- 请求方法、规范化后的接口路径；
- HTTP 状态码；
- 总耗时和各阶段耗时；
- 请求是否发生异常；
- 业务上可以安全记录的关键参数摘要；
- trace 标识或请求标识；
- 应用实例、机房、版本号。
不建议记录完整请求体、密码、身份证号、支付信息等敏感内容。也不要把所有请求都打印成 INFO 日志，否则正常流量一上来，日志量会掩盖真正的异常。更合理的方式是：所有请求进入指标系统，只有超过阈值的请求进入慢日志；异常请求无论是否超过阈值，都记录必要上下文。
如果想进一步拆分耗时，可以在业务服务中显式记录阶段：
long start = System.nanoTime();
Order order = orderRepository.findById(orderId)
.orElseThrow(() -> new IllegalArgumentException("order not found"));
long afterDb = System.nanoTime();
InventoryResult result = inventoryClient.query(order.getSku());
long afterRemote = System.nanoTime();
orderAssembler.fill(order, result);
long afterAssemble = System.nanoTime();
log.info("order detail cost, orderId={}, dbMs={}, remoteMs={}, assembleMs={}, totalMs={}",
orderId,
millis(start, afterDb),
millis(afterDb, afterRemote),
millis(afterRemote, afterAssemble),
millis(start, afterAssemble));实际项目中，更建议将这些阶段分别记录为 Timer，而不是长期依赖字符串日志做统计。日志适合查看单个请求，指标适合观察一段时间内的趋势。
一条可执行的排查路径
第一步：确认是全局问题还是单接口问题
先按接口、状态码、实例和版本号查看 p95、p99 的变化。如果所有接口同时变慢，优先检查节点资源、网络、数据库和公共依赖；如果只有一个接口异常，再进入该接口的业务链路。
同时对比请求量。如果流量增长伴随 p99 上升，可能是容量或排队问题；如果流量没有变化却突然变慢，更像是慢查询、锁等待、下游异常或代码发布引入的问题。
第二步：观察应用实例的资源和排队
不要只看 CPU 百分比。还要观察：
- CPU 是否被少数线程持续占用；
- 堆内存、Old Gen 和 GC 暂停时间是否同步变化；
- Tomcat、Jetty 或 Undertow 工作线程是否接近上限；
- 数据库连接池 active、idle、pending 是否异常；
- 下游 HTTP 客户端连接池是否有等待；
- 文件描述符、网络连接数是否接近限制。
如果 CPU 不高但请求变慢，等待型问题的可能性反而更高。线程可能阻塞在数据库连接、锁、网络响应或队列上。
第三步：在问题发生时抓线程状态
生产环境排查应尽量使用低侵入方式，并且先确认目标 Java 进程。常见命令如下：
jps -lv
jcmd <pid> Thread.print -l > /tmp/thread-1.txt
sleep 10
jcmd <pid> Thread.print -l > /tmp/thread-2.txt连续抓取两次比只看一次更有价值。对比线程状态时重点关注：
- 大量线程是否处于
WAITING或TIMED_WAITING； - 是否集中等待同一个锁；
- 是否大量线程卡在 JDBC 获取连接；
- 是否大量线程停在 HTTP 客户端读取响应；
- 是否存在少数
RUNNABLE线程持续占用 CPU。
线程 dump 不能直接告诉你“数据库慢了”或“某个服务故障了”，但它能告诉你请求时间消耗在计算、锁等待还是外部等待上。随后要结合数据库连接池指标、慢查询日志和下游监控继续验证，而不是只凭线程栈下结论。
第四步：核对发布、配置和依赖变化
长尾问题经常与一次看似无关的变更有关，例如：
- 新增了一个未建立索引的查询条件；
- 将下游超时时间从 500 毫秒改成了 5 秒；
- 连接池大小没有随流量调整；
- 某个日志级别被临时改成 DEBUG；
- 新版本引入了同步远程调用；
- 某个缓存失效后，大量请求同时回源。
排查时应把 p99 上升时间点与发布记录、配置变更、数据库执行计划和依赖方告警放在同一条时间线上。单独查看应用日志，往往只能看到结果，无法看到因果关系。
常见误区
只设置平均耗时告警
平均值对少量慢请求不敏感。告警应至少包含 p95 或 p99，并配合请求量阈值，避免低流量时几个异常样本造成误报。
慢请求阈值全服务统一
查询接口、写入接口和文件导出接口的合理耗时不同。阈值可以先统一建立基线，再按接口类型调整。阈值不是越低越好，过多慢日志会增加磁盘和采集压力。
一发现慢就盲目扩大线程池
如果线程都在等待数据库连接，扩大 Web 线程池只会让更多请求进入等待；如果下游已经过载，增加并发还可能造成级联故障。先确认瓶颈所在，再决定限流、降级、调连接池还是优化查询。
只看应用节点，不看依赖方
一次接口请求可能经过缓存、数据库、消息系统和多个 HTTP 服务。应用自身 CPU 正常，不代表依赖正常。监控面板应能按请求入口和下游调用阶段关联查看。
实践建议
- 为核心接口建立 p50、p95、p99 和请求量基线，不要等故障发生后才开始采集。
- 慢请求日志与错误日志分开设计，控制采样和敏感信息，保证故障时日志仍然可写。
- 指标标签使用低基数维度，如路由、状态码、实例和版本，避免把业务 ID 放进去。
- 数据库连接池、HTTP 连接池、线程池都要监控“使用量”和“等待量”，只看池大小没有意义。
- 为发布、配置、扩缩容和依赖方异常保留可查询的时间线。
- 预先演练线程 dump、日志检索和回滚流程，避免故障时临时摸索命令。
- 对关键接口设置超时、隔离和降级边界，让单个慢依赖不会无限占用整个应用的处理能力。
总结
接口平均耗时正常，并不等于服务健康。长尾延迟通常藏在少量请求、某个实例或某个等待阶段里。有效的排查方法不是盯着一张 CPU 面板，而是先用 p95、p99 发现问题，再通过慢请求日志、线程状态、连接池指标和依赖方监控逐层缩小范围。
真正成熟的生产监控，不只是故障发生时提供一堆数据，而是让人能够回答三个问题：哪些请求变慢了，时间具体耗在哪里，最近发生了什么变化。只要这条证据链完整，很多看似偶发的“接口卡顿”，就能从猜测变成可以验证和修复的问题。
