LOAD TEST · RT · QUEUEING · LITTLE'S LAW · TOMCAT · HIKARICP · BACKLOG · GC · RETRY
多出来的响应时间,大多是在排队
压测时响应时间(RT)往上涨,大多数时候每个请求真正干活的时间没变,多出来的全是排队。并发往上加:线程、连接这些“窗口”早就满了,多来的人只能排着,RT ≈ 并发数 ÷ 吞吐上限,跟着并发线性涨。时间往后走:要么来得比走得快,队伍每秒都在变长;要么出口在变窄,表越来越大、堆越来越满、连接被漏掉。排查就是找出:哪一个队在变长,它为什么变长。
假设场景下单服务上线前压测。JMeter 从 10 个线程一级级加到 400 个:吞吐到 500 左右就不涨了,RT 却一级比一级高;最后一级保持半小时,RT 还在慢慢往上爬,服务器 CPU 才三成。领导问“接口是不是写得有问题,到底能扛多少”。这类问题工作里常碰到,面试也常问,所以本页按排查顺序讲,第⑥步末尾附面试题。标“实测”的数字都在本机跑过:Spring Boot 3.5.16、Tomcat 10.1.55、HikariCP 6.3.3、H2 内存库,2 核虚拟机。
①现象:两种“越来越长”
先把现象拆开。“随着并发增长”和“随着时间增长”是两件事,背后的原因不一样,排查的方向也不一样。
②常见误判:看起来都对,其实都没找到队
先看一张账单:把压测机看到的 RT 拆开,看时间花在哪了。
http.server.requests 从线程接手请求才开始计时,最后那一段它看不到。干活的时间(这里是 SQL 的 20 ms)通常不变,变的是排队。
所以别先问“代码哪里慢”,先问“请求在哪个队里等、那个队为什么越来越长”。
- 为什么像
- RT 确实高,代码是最容易想到的地方。
- 证据说
- 在方法里打点:SQL 一直 20 ms,方法本身没变慢。变的是等待,优化代码最多省下那 20 ms。
- 为什么像
- CPU 是最先看、最常看的指标。
- 证据说
- 满的是连接池:10 个连接全借出去,190 个线程停在
getConnection()。CPU 只是众多窗口里的一个,线程、连接、锁、下游都能先满。
- 为什么像
- 调大以后,这一站的队确实变短了。
- 证据说
- 队伍会挪到下一站。连接给到 50,数据库就要同时跑 50 条 SQL,锁和 CPU 更挤,每条更慢。只有最窄的那一站变宽,上限才会涨,而且要它下游接得住。
- 为什么像
- 泄漏确实会让服务越跑越慢。
- 证据说
- 来得比走得快、表越来越大、连接被漏掉,看起来都一样。三种修法完全不同:限流、加索引、修代码。先用“停压后低压重测”分开它们。
- 为什么像
- 压测工具就是干这个的。
- 证据说
- 压测机自己也会排队:GUI 模式、结果监听器、它自己的 GC、客户端连接池。另一头,闭环压测会把卡顿藏起来。先确认数可信,再分析服务。
- 为什么像
- 服务端说自己 300 ms,客户端说 3 秒,中间只剩网络。
- 证据说
- 差的那段在 Tomcat 的任务队列里。服务端的计时从线程接手才开始,在队里等的时间它不算。看
tomcat.threads.busy是不是顶在最大值。
③排查路线:四个问题,找到正在变长的那个队
按顺序问。每个问题都有能拿到手的证据,不靠猜。
看压测机自己的 CPU、GC、报错;对比压测机的 RT 和服务端入口(Nginx 的 $request_time、网关)的 RT。
把每一级的吞吐和 RT 放在一起看,就是 ① 左边那张图。
把并发降到饱和点以下,比如原来的十分之一,看 RT 回不回到基线。
满了的那一站,去哪看 “满了”指窗口全忙,而且有人在等
| 站 | 满了的样子 | 看什么指标 | 拿证据的命令 |
|---|---|---|---|
| 压测机 | CPU 高、自己在 GC、实际并发达不到设定值 | 压测机的 CPU、内存、报错数 | top、jstat -gcutil <JMeter 的 pid> 1000 |
| Tomcat 线程 | 忙线程顶在 threads.max(默认 200),连接数远大于 200 | tomcat.threads.busy、tomcat.connections.current | 要先开 server.tomcat.mbeanregistry.enabled=true |
| 业务线程池 | 队列长度一直涨,活跃线程顶满 | executor.queued、executor.active | Micrometer 的 ExecutorServiceMetrics;Spring Boot 会给容器里的 ThreadPoolTaskExecutor 自动绑定 |
| 连接池 | pending 一直大于 0,借连接要等很久 | hikaricp.connections.pending、.active、.acquire、.timeout | jstack 里大量线程停在 ConcurrentBag.borrow |
| 锁 | 很多线程 BLOCKED,等同一把锁 | 线程状态分布 | jstack 里的 waiting to lock <0x…>;Arthas thread -b |
| CPU | 可运行的线程比核多,长期排队 | CPU 使用率、运行队列 | vmstat 1 的 r 列长期大于核数;top -H;async-profiler |
| GC | 老年代每次回收后还在涨,Full GC 越来越密 | jvm.gc.pause、老年代占用 | jstat -gcutil <pid> 1000、-Xlog:gc* |
| 数据库 | 同一条 SQL 越来越慢,活跃会话多 | 慢查询数、行锁等待 | 慢查询日志、EXPLAIN、SHOW PROCESSLIST |
| 下游 HTTP | 线程停在 socket 读,客户端连接池要等 | HTTP 客户端连接池的指标 | jstack 里的 socketRead;链路追踪 |
本页的例子里,满的是 HikariCP 的 10 个连接:每次占 20 ms,上限 10 ÷ 0.02 s = 500 次/秒。下面就拿它讲透“为什么会排、排在哪、怎么越排越长”。
④背后的机制:一串窗口,一个浴缸
只用三样东西就能推出 ① 里的两种现象:窗口有几个(c),每次占多久(S),请求来得多快。
先知道这些 都是一两句话的前置知识
Tomcat 怎么收请求
Acceptor 接连接,Poller 等数据到了,交给工作线程(最多 threads.max=200)。线程都忙时,请求在线程池的任务队列里等;连接最多 8192 个,再多就在内核的 accept 队列等(100)。
HikariCP 借连接
最多 maximum-pool-size=10 个连接。全借出去时,getConnection() 阻塞等别人还,最多等 connection-timeout=30 秒,等不到就抛异常。
一个请求要过好几道窗口
并发轴:窗口满了以后,多来的人只能排队
第二个式子就是利特尔法则 L = X × R 倒过来:闭环里系统中的请求数固定是 N。所以每多 1 个并发,RT 多 1 ÷ 500 秒 = 2 ms,线性涨,不会自己停。
动手:一级级加并发,看队排在哪
“理论”按上面的式子算,“实测”来自 ⑤ 实验 1。实测吞吐略低于 500,是因为每次借还连接、走一遍 Spring MVC 还要多花零点几毫秒。
时间轴:浴缸里的水,为什么一直涨
比喻对不上的地方:真实系统是好几个浴缸串起来,最窄的那个先满,水会倒灌到前一个(上面那张窗口图里,连接满了,线程就停着等,线程用完,请求就在 Tomcat 的任务队列里等)。闭环压测也不是开着的水龙头,而是固定 N 滴水在转圈,水位最多到 N。
⑤ 实验 2 实测:每秒发 600 个,实际出 490 个,30 秒后在途 3993 个,P50 6.4 秒,和 (600 − 490) × 30 ÷ 490 ≈ 6.7 秒对得上。没有上限,直到连接数满、超时或 OOM。
(b) X(t) = c(t) ÷ S(t) 在变小:闭环里 R = N ÷ X(t) 跟着涨;开环里一旦 X(t) 掉到 λ 以下,就变成 (a)S 变长:表里行数变多而 SQL 走全表扫描、堆越来越满导致 GC 越来越频繁、缓存命中率掉下来。c 变少:连接借了没还、线程卡在一个没设超时的下游上。
一条推论闭环压测(JMeter 线程组)里,系统中的请求最多就是线程数 N,(a) 不会发生。所以线程数不变、RT 随时间涨,一定是 (b):出口在变窄,去找在累积的东西。
为什么是“越来越”:两个会自己加速的环
为什么这样设计:默认让请求排队,而不是满了就拒
Tomcat 的任务队列默认几乎无限长,HikariCP 借不到连接默认等 30 秒。这是有意的选择:它们不知道你的延迟预算,对大多数应用来说,偶尔多等一会儿比直接报错好。下面是同一台机器、同样每秒 600 个请求时,两种设计的实测对比。
大队列,慢慢等默认
threads.max-queue-capacity = 2147483647 · max-connections = 8192 · connection-timeout = 30s- 短时间的尖峰能接住,一个请求都不丢
- 持续超载时队伍没有上限:30 秒后 P50 6.4 秒,还在涨
- 0 个错误,可用户早走了,服务端在给没人要的请求干活
- 等到真报错,已经是连接数满了或者 OOM
按延迟预算限长,满了马上拒本页推荐
--server.tomcat.threads.max-queue-capacity=300- 留在队里的 P50 稳在约 0.7 秒,不再随时间涨
- 约 22% 的请求 1~8 ms 就失败,客户端能马上换实例或降级
- 服务端只做还有人在等的活
- 短时尖峰也会拒掉一部分;P99 仍有 2.6~4 秒,剩下的队在连接池里(⑥ 第三圈)
决定胜负的约束:队列只能吸收短时间的波动,前提是平均进水小于出水。进水长期大于出水时,队再长也只是把失败往后推,推到用户已经走了。所以队长要按延迟预算来定:上限 ≈ 吞吐 × 能容忍的排队时间,比如 500/s × 1 s = 500。
最少的公式和配置 这几个值怎么定、版本差异,放到第⑥步
# 并发轴:闭环,N 个用户,每人思考 Z 秒
吞吐上限 X = c ÷ S # 10 ÷ 0.02 s = 500/s
响应时间 R = N ÷ X − Z # 200 ÷ 500 − 0 = 0.4 s
拐点 N* = X × (S + Z) # Z=1 s 时 500 × 1.02 ≈ 510 个线程
# 时间轴:开环,λ > X
积压(t) = (λ − X) × t # 每秒多 100,30 秒积 3000
等待(t) ≈ 积压(t) ÷ X # 3000 ÷ 500 = 6 s
server.tomcat:
threads.max: 200 # 窗口:工作线程
max-connections: 8192 # 最多这么多连接在 Tomcat 里
accept-count: 100 # 再多,在内核里排
threads.max-queue-capacity: 2147483647
spring.datasource.hikari:
maximum-pool-size: 10 # 窗口:连接
connection-timeout: 30000 # 借不到最多等 30 秒
排队实验台:先猜,再跑 10 个窗口起步,每次占 20 ms,模拟 2 分钟
模型:c 个窗口,先来先服务,每次占用在 10~30 ms 之间均匀分布(平均 20 ms),按毫秒推进。“表变大”每完成 2.5 万个请求,S 多 20 ms;“连接泄漏”每 10 秒少一个窗口;“堆泄漏”在完成 3 万个请求后老年代满,之后 95% 的时间在 Full GC。数字是示意,形状和 ⑤ 的实测一致。
⑤复现一次:在自己机器上把队排出来
一个 Spring Boot 小服务加一个 70 行的压测机。连接池 10 个连接,每条 SQL 固定占 20 ms(用 H2 的自定义函数模拟),所以上限算得出来:500 次/秒。四个实验分别对应 ④ 的并发轴、时间轴 (a)、时间轴 (b) 两种累积。
环境服务端 JDK 17 以上、Spring Boot 3.5.16(Tomcat 10.1.55、HikariCP 6.3.3、H2 2.3.232)。压测机用了虚拟线程,要 JDK 21。下面的实测都在一台 2 核 11 GB 的云主机上,压测机和服务跑在同一台机器上,绝对数字只代表这台机器。
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>3.5.16</version>
</parent>
<!-- groupId=demo, artifactId=rtdemo, version=1.0 -->
<dependencies>
<dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-web</artifactId></dependency>
<dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-jdbc</artifactId></dependency>
<dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-actuator</artifactId></dependency>
<dependency><groupId>com.h2database</groupId><artifactId>h2</artifactId><scope>runtime</scope></dependency>
</dependencies>
<!-- build 里加 spring-boot-maven-plugin,打成可执行 jar -->
# application.properties
server.port=8090
spring.datasource.url=jdbc:h2:mem:demo
# 下面两项就是默认值,写出来是为了看清楚
spring.datasource.hikari.maximum-pool-size=10
server.tomcat.threads.max=200
# Tomcat 的线程指标默认不出,要打开这个
server.tomcat.mbeanregistry.enabled=true
management.endpoints.web.exposure.include=health,metrics
# Actuator 单独一个端口:业务端口排满了,指标照样能查(⑥ 坑 1)
management.server.port=8091
-- schema.sql(H2 内存库启动时自动执行)
CREATE ALIAS IF NOT EXISTS SLEEP_MS FOR 'demo.DemoApp.sleepMs';
CREATE TABLE IF NOT EXISTS orders (id BIGINT AUTO_INCREMENT PRIMARY KEY, user_id BIGINT, amount INT);
package demo;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.jdbc.core.ConnectionCallback;
import org.springframework.jdbc.core.JdbcTemplate;
import org.springframework.web.bind.annotation.*;
@SpringBootApplication
@RestController
public class DemoApp {
private final JdbcTemplate jdbc;
private final Timer sql; // 只量“拿到连接以后”SQL 自己花的时间
DemoApp(JdbcTemplate jdbc, MeterRegistry registry) {
this.jdbc = jdbc;
this.sql = registry.timer("demo.sql");
}
public static void main(String[] args) { SpringApplication.run(DemoApp.class, args); }
/** 实验 1、2:每个请求占一个数据库连接 20 ms,模拟一条 20 ms 的 SQL */
@GetMapping("/work")
public String work() {
jdbc.execute((ConnectionCallback<Object>) con -> { // 进到这里时,已经从连接池拿到连接了
long t0 = System.nanoTime();
con.createStatement().execute("CALL SLEEP_MS(20)");
sql.record(System.nanoTime() - t0, java.util.concurrent.TimeUnit.NANOSECONDS);
return null;
});
return "ok";
}
/** 实验 3:下单 = 插一行,再数一数这个用户有几单(user_id 上没有索引) */
@PostMapping("/order")
public Long order(@RequestParam long uid) {
jdbc.update("INSERT INTO orders(user_id, amount) VALUES (?, 1)", uid);
long t0 = System.nanoTime();
Long n = jdbc.queryForObject("SELECT COUNT(*) FROM orders WHERE user_id = ?", Long.class, uid);
sql.record(System.nanoTime() - t0, java.util.concurrent.TimeUnit.NANOSECONDS);
return n;
}
/** 实验 3 收尾:给 user_id 补上索引(演示用,真实项目在数据库客户端里执行) */
@PostMapping("/admin/add-index")
public String addIndex() {
jdbc.execute("CREATE INDEX IF NOT EXISTS idx_orders_user ON orders(user_id)");
return "index added";
}
/** 选做:和 /work 一样占连接 20 ms,但每次往一个“只放不删”的本地缓存里塞 8 KB */
static final java.util.Map<Long, byte[]> CACHE = new java.util.concurrent.ConcurrentHashMap<>();
static final java.util.concurrent.atomic.AtomicLong SEQ = new java.util.concurrent.atomic.AtomicLong();
@GetMapping("/leaky")
public String leaky() {
CACHE.put(SEQ.incrementAndGet(), new byte[8 * 1024]);
return work();
}
/** 给 H2 用的自定义函数:SLEEP_MS(20) 就是“这条 SQL 要跑 20 ms” */
public static void sleepMs(int ms) throws InterruptedException { Thread.sleep(ms); }
}
import java.net.URI;
import java.net.http.*;
import java.util.*;
import java.util.concurrent.*;
import java.util.concurrent.atomic.*;
/**
* 最小压测机。两种发法:
* java Load.java closed 50 30 http://localhost:8090/work 50 个用户,各自“等回来再发下一个”
* java Load.java open 600 30 http://localhost:8090/work 每秒 600 个,到点就发,不管上一个回没回来
* 每秒打一行:这一秒完成了几个、它们的 P50 / P99、此刻还有几个没回来。
*/
public class Load {
static final ConcurrentLinkedQueue<Long> done = new ConcurrentLinkedQueue<>();
static final AtomicInteger inflight = new AtomicInteger(), errors = new AtomicInteger();
public static void main(String[] a) throws Exception {
String mode = a[0];
int n = Integer.parseInt(a[1]), secs = Integer.parseInt(a[2]);
URI uri = URI.create(a[3]);
boolean post = a.length > 4 && a[4].equals("POST");
HttpClient http = HttpClient.newBuilder().version(HttpClient.Version.HTTP_1_1).build();
long start = System.nanoTime(), end = start + secs * 1_000_000_000L;
if (mode.equals("closed")) {
for (int i = 0; i < n; i++)
Thread.ofVirtual().start(() -> {
while (System.nanoTime() < end) call(http, uri, post, System.nanoTime());
});
} else {
Thread.ofPlatform().start(() -> {
for (long k = 0; ; k++) {
long due = start + k * 1_000_000_000L / n; // 第 k 个请求“应该”在这一刻发出
if (due > end) break;
while (System.nanoTime() < due) Thread.onSpinWait();
Thread.ofVirtual().start(() -> call(http, uri, post, due)); // 从计划时刻开始计时
}
});
}
System.out.println(" 秒 完成/s P50(ms) P99(ms) 在途 错误");
for (int s = 1; s <= secs; s++) {
Thread.sleep(Math.max(0, (start + s * 1_000_000_000L - System.nanoTime()) / 1_000_000));
List<Long> l = new ArrayList<>();
for (Long x; (x = done.poll()) != null; ) l.add(x);
Collections.sort(l);
System.out.printf("%4d %8d %9d %9d %6d %6d%n", s, l.size(), pct(l, 50), pct(l, 99), inflight.get(), errors.getAndSet(0));
}
System.exit(0);
}
static void call(HttpClient http, URI uri, boolean post, long t0) {
inflight.incrementAndGet();
try {
URI u = post ? URI.create(uri + "?uid=" + ThreadLocalRandom.current().nextInt(1000)) : uri;
HttpRequest.Builder b = HttpRequest.newBuilder(u);
HttpResponse<String> r = http.send(post ? b.POST(HttpRequest.BodyPublishers.noBody()).build() : b.build(),
HttpResponse.BodyHandlers.ofString());
if (r.statusCode() != 200) errors.incrementAndGet();
} catch (Exception e) {
errors.incrementAndGet();
} finally {
inflight.decrementAndGet();
done.add((System.nanoTime() - t0) / 1_000_000);
}
}
static long pct(List<Long> l, int p) {
return l.isEmpty() ? 0 : l.get(Math.min(l.size() - 1, (int) Math.ceil(l.size() * p / 100.0) - 1));
}
}
mvn -q package -DskipTests
java -jar target/rtdemo-1.0.jar # 业务在 8090,Actuator 在 8091
javac -d classes Load.java # 压测机,另开一个终端
java -cp classes Load closed 20 5 http://localhost:8090/work # 先预热 5 秒
开环的计时从“计划发出的那一刻”算,而不是从真正发出算。压测机自己卡了一下时,这段时间也算进 RT,不会被漏掉(⑥ 坑 2 的 coordinated omission)。
加并发:吞吐到顶,队排在哪
实测for N in 5 10 20 50 100 200 400; do
java -cp classes Load closed $N 10 http://localhost:8090/work | tail -5
done
# 压测进行中,另一个终端看三样东西
curl -s localhost:8091/actuator/metrics/hikaricp.connections.pending
curl -s localhost:8091/actuator/metrics/tomcat.threads.busy
jstack <pid> | grep -c 'ConcurrentBag.borrow'
| 并发 N | 吞吐/s | P50 ms | P99 ms | 等连接的线程 | Tomcat 忙线程 | 平均等连接 ms | SQL 自己 ms | 服务端记录 ms |
|---|---|---|---|---|---|---|---|---|
| 5 | 230 | 21 | 25 | 0 | 6 | 0.0 | 20.3 | 20.6 |
| 10 | 468 | 21 | 25 | 0 | 11 | 0.0 | 20.3 | 20.5 |
| 20 | 495 | 40 | 60 | 10 | 21 | 19.1 | 20.2 | 39.5 |
| 50 | 495 | 100 | 182 | 39 | 51 | 79.1 | 20.1 | 99.4 |
| 100 | 494 | 201 | 387 | 89 | 101 | 178.1 | 20.2 | 198.4 |
| 200 | 495 | 403 | 867 | 189 | 200 | 368.4 | 20.2 | 388.6 |
| 400 | 496 | 810 | 1505 | 189 | 200 | 366.7 | 20.2 | 386.7 |
每级跑 10 秒,取最后 5 秒的平均。“等连接的线程”是 hikaricp.connections.pending,“平均等连接”来自 hikaricp.connections.acquire,“SQL 自己”是代码里的 demo.sql,“服务端记录”是 http.server.requests,后三个都是这一级的平均值。这一轮 Actuator 还和业务共用 8090 端口,查指标的那个请求自己也占一个线程,所以忙线程比 N 多 1。
$ jstack <pid> # N=400 时:200 个 http-nio-8090-exec 线程,190 个停在这里 "http-nio-8090-exec-1" #30 daemon prio=5 ... waiting on condition java.lang.Thread.State: TIMED_WAITING (parking) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:338) at com.zaxxer.hikari.util.ConcurrentBag.borrow(ConcurrentBag.java:162) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:160) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:127) at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:160) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:342) 另外 10 个停在 demo.DemoApp.sleepMs:正在“跑 SQL”。
读法:吞吐 20 并发就到顶,SQL 一直 20 ms,RT 的增长全是等连接;到 400 并发,线程也用完了,客户端 810 ms 里有约 420 ms 在 Tomcat 的任务队列里,服务端的 386.7 ms 看不到它。
开环:每秒 400 个和每秒 600 个
实测java -cp classes Load open 400 30 http://localhost:8090/work
java -cp classes Load open 600 30 http://localhost:8090/work
$ curl -s localhost:8091/actuator/metrics/… # 每秒 600 个时,每 5 秒看一次 第 5 秒 tomcat.threads.busy=200 hikaricp.connections.pending=190 tomcat.connections.current=893 第 15 秒 tomcat.threads.busy=200 hikaricp.connections.pending=190 tomcat.connections.current=2291 第 30 秒 tomcat.threads.busy=200 hikaricp.connections.pending=190 tomcat.connections.current=3724
读法:线程和等连接的人数都顶住不动了,只有连接数在涨。涨出来的请求全在 Tomcat 的任务队列里,所以盯住 tomcat.connections.current 才看得到水位。
压力不变,表越压越大
实测java -cp classes Load closed 20 200 http://localhost:8090/order POST
# 跑到第 170 秒左右,另一个终端:
curl -X POST localhost:8090/admin/add-index
user_id 数一数,而 user_id 上没有索引,每次都要扫全表。表从 0 长到约 7.4 万行,每次处理时间 S 跟着变长,20 个用户一直没变,RT 却慢慢涨了三倍多。补上索引以后,P50 立刻掉到 4 ms。读法:这是 ④ 的 (b),出口在变窄。闭环里在途固定是 20,所以不可能是积压。压测本身在往库里写数据,压得越久表越大;测试环境的表本来又小,上线后会更慢。
选做:堆泄漏,前面一直正常
实测java -Xmx256m -jar target/rtdemo-1.0.jar
java -cp classes Load closed 10 120 http://localhost:8090/leaky
jstat -gcutil <pid> 10000 # 每 10 秒一行
秒 完成/s P50(ms) │ O(老年代%) FGC(次) FGCT(秒) 10 450 21 │ 67.07 0 0.000 30 483 20 │ 79.87 0 0.000 40 480 20 │ 81.62 0 0.000 50 480 20 │ 91.37 0 0.000 60 474 20 │ 96.98 1 0.072 65 230 21 │ ← 开始变慢 70 0 - │ 99.91 95 5.554 80 0 - │ 99.90 259 15.371 ← 10 秒里 164 次 Full GC,停了 9.8 秒 之后日志里出现 java.lang.OutOfMemoryError: Java heap space
读法:RT 前 60 秒一直是 20 ms,看 RT 根本发现不了;能提前报警的是老年代一路往上爬(O 是占当前老年代容量的百分比,G1 扩容时会往回跳一下,所以要看趋势)。一满,Full GC 连成片,吞吐直接掉到 0。所以“随时间越来越慢”的堆泄漏,常常不是慢慢变慢,而是平稳一阵后突然掉下去。
⑥根治和预防
按三圈来:先是不知道就会出事的坑,再是团队里该怎么配、怎么压,最后是排队论和源码里的深处。每个坑旁边的小标签指回 ④ 里推出它的那条原理。
注意事项:十个坑
- 现象
- 监控上
http.server.requests平均 387 ms,压测机 P50 810 ms;过载时连 Actuator 都查不动。 - 根源
- 服务端计时从工作线程接手才开始,在 Tomcat 任务队列里等的时间不算。Actuator 和业务共用端口时,查指标的请求也排在同一个队里:实测每秒 600 个时,同端口的指标请求 5 秒都没回来。
- 做法
- 以压测机或网关的 RT 为准;看
tomcat.threads.busy是否顶在最大值、tomcat.connections.current是否远大于线程数;management.server.port单独开一个端口。
- 现象
- JMeter 线程组压到上限,RT 平在 400 ms;上线后真实流量一超过上限,RT 涨到几秒。
- 根源
- 闭环里系统中的请求最多 N 个,系统一慢,压测机也跟着少发,卡顿只落在少数请求上,这叫 coordinated omission。真实用户不会因为你慢就少来。
- 做法
- 模拟互联网流量用开环:JMeter 5.5 起的 Open Model Thread Group、k6 的
constant-arrival-rate、Gatling 的开环注入、wrk2;RT 从计划发出的时刻算。
- 现象
- 开始变慢以后没有任何报错,RT 一路涨,内存一路涨。
- 根源
- Tomcat 的
threads.max-queue-capacity默认Integer.MAX_VALUE(实际被 8192 个连接挡住);Executors.newFixedThreadPool的LinkedBlockingQueue也是无界;Spring Boot 默认的applicationTaskExecutor队列无界,max-size根本用不上。 - 做法
- 自己的线程池一律有界队列加拒绝策略(@Async 与线程池);入口按延迟预算限队长(规范 3)。
- 现象
- 压测机满屏超时,服务端的连接池、CPU 却一直满负荷。
- 根源
- 服务端不知道客户端已经走了,队里的请求照样处理;先来先服务的队一旦比超时还长,每个请求轮到时都已经过期。实测每秒 600 个、客户端 1 秒超时、跑 30 秒:发出的 18000 个请求服务端全都执行了,其中 4175 个是压测机停下以后才轮到的;客户端只收到 1099 个成功。
- 做法
- 有界队列让请求早点失败;把截止时间往下传,排队已经超时的直接丢;下游的超时比上游短。
- 现象
- 一次 GC 或下游抖动之后,系统再也回不到正常,重启才好。
- 根源
- 抖动时积下的请求都超时,每个再重试 2 次,进水最多变 3 倍,永远追不上。实验台剧情 5:每秒 400 个、上限 500,卡 3 秒以后再也恢复不了;同样的抖动不重试,约 15 秒就恢复。
- 做法
- 只重试幂等请求,最多 1~2 次,指数退避加随机抖动;设重试预算(规范 5);配断路器。
- 现象
- 同一个场景,第二轮比第一轮慢,跑久了越来越慢。
- 根源
- 写接口在往表里插数据,表一大,缺索引的查询、深分页、
count(*)都跟着变慢;热数据超出 InnoDB buffer pool 以后还要读盘。实测表到 7.4 万行,P50 从 22 涨到 73 ms,补索引后 4 ms。 - 做法
- 每轮压测前恢复数据量,或直接用和生产一样大的数据;压测时开慢查询日志,对可疑 SQL 看
EXPLAIN。
- 现象
- 跑几分钟到几小时都正常,然后 RT 突增、吞吐掉到 0,最后 OOM。
- 根源
- 本地缓存不设上限、静态
Map只放不删、ThreadLocal不清,老年代只涨不降;满了以后 Full GC 一个接一个,实测 10 秒里停了 9.8 秒。 - 做法
- 本地缓存用 Caffeine 设
maximumSize和过期(缓存那页);压测时用jstat看老年代的趋势;加-XX:+HeapDumpOnOutOfMemoryError。
- 现象
- 越跑能用的连接越少,pending 越来越高,最后都卡在
getConnection()等满 30 秒。 - 根源
- 手写 JDBC 没 close,c 在变少;
@Transactional方法里调 HTTP、发消息,连接被占着等外部,S 在变长。两样都让 c ÷ S 变小。 - 做法
- 开
leakDetectionThreshold(比如 2000 ms),超时没还会打出借连接时的堆栈;外部调用挪到事务外(连接池与事务性能)。
- 现象
- 服务端很闲,报告上的 RT 却越跑越长,或者设定的并发怎么也打不满。
- 根源
- JMeter GUI 模式加“查看结果树”会把每个结果留在内存里,压测机的堆越来越满、GC 越来越多;压测机 CPU 打满;客户端连接池太小,比如 Apache HttpClient 4.x 默认每个目标地址只有 2 个连接。
- 做法
- 用
jmeter -n -t plan.jmx -l result.jtl命令行跑,关掉监听器;同时监控压测机;一台不够就分布式压。
- 现象
- 压了十几分钟后吞吐突然掉一截;或者 CPU 不高,P99 却一阵一阵地高。
- 根源
- 这条推不出来,是运行环境的规则:突发性能实例的 CPU 积分用完,会被降到基线性能;容器设了 CPU limit,一个调度周期(默认 100 ms)的配额用完,就被暂停到下一个周期。
- 做法
- 压测用和生产同规格、非突发的实例;看 cgroup
cpu.stat里的nr_throttled;JVM 的 GC 线程、线程池按 limit 来算。
使用规范:团队里该怎么配、怎么压
线程数 ≈ 目标吞吐 × 每个请求占线程的时间;连接数 ≈ 目标吞吐 × 每次占连接的时间。再确认数据库扛得住这么多条 SQL 同时跑。
拍脑袋调大,把队伍推给下游。
比如网关 3 s,服务处理 2 s,下游调用 1 s。HikariCP 的 connection-timeout 设到 1~3 秒(最小 250 ms);HTTP 客户端一定设连接和读超时,HttpURLConnection 默认是 0,表示一直等。
请求在某一站一直等,用户早走了它还占着位置。
上限 ≈ 吞吐 × 能容忍的排队时间。Tomcat 用 server.tomcat.threads.max-queue-capacity,自己的线程池用 ArrayBlockingQueue 加拒绝策略。
超载变成没有上限的延迟(坑 3、坑 4)。
Sentinel、Resilience4j 的 RateLimiter 和 Bulkhead。限同时在处理的请求数,比限每秒请求数更贴近排队的本质。
一个慢接口吃光所有线程,别的接口一起慢。
只重试幂等请求,最多 1~2 次,指数退避加随机抖动;全部重试加起来不超过正常请求量的一成,超了就不再重试。
重试风暴(坑 5)。
先预热;阶梯加压,每级等指标稳了再加;上线前跑几个小时的稳定性压测;每轮前恢复数据量;互联网接口用开环。
拿到一个好看但不真的数(坑 2、坑 6)。
压测机 RT、服务端 RT、在途数、每个池子的 busy 和 pending、方法自己的耗时 S、老年代占用的趋势。
只看到 RT 涨,不知道哪个队在涨。
server.tomcat.mbeanregistry.enabled=true,不开就没有 tomcat.threads.*;management.server.port 单独端口;HikariCP 的指标 Spring Boot 会自动绑定。
出事时才发现没有数(坑 1)。
优化和深处
P99 为什么涨得比 P50 快
排队论里的 Kingman 近似:等待 ≈ S × ρ/(1−ρ) × (Ca² + Cs²)/2,ρ 是利用率,Ca、Cs 是到达间隔和处理时间的波动程度。来得越不均匀、处理时间越参差,同样利用率下等得越久;一次 GC 停顿、一条慢 SQL,让后面所有人一起多等。
实测里 P99 大约是 P50 的 2 倍,还有一个原因:HikariCP 借连接不是严格先来先得。还连接时,刚进来的线程会先扫 ConcurrentBag 的共享列表,可能抢在排队的线程前面拿走。实测把 connection-timeout 改成 1 秒、每秒 600 个:平均只等 338 ms,却有 1808 次等过 1 秒而超时。
一个大池子,还是几个小池子
同样的利用率,窗口越多排队越短(M/M/c 模型,Erlang C 公式),所以几个接口共享一个大池子更省。可共享也意味着一个慢接口能拖垮所有接口。常见折中:关键接口单独一个小池子(舱壁隔离),其余共享。
亚稳态故障
名字来自 2021 年 HotOS 的论文 Metastable Failures in Distributed Systems:触发因素(一次抖动)已经消失,系统却被自己的反馈环(重试、缓存冷启动)困在过载里。出路是打断环:直接拒掉一部分(减载)、重试预算、断路器、排队超时就丢。实验台剧情 5 就是一个。
过载时队伍该怎么排
先来先服务在过载时最糟:每个人都等到超时。Facebook 在 Fail at Scale(ACM Queue,2015)里写过他们的做法:队伍一直清不空时,排队超过很短时间的请求直接丢掉(借鉴网络里的 CoDel);拥塞时改成后进先出,让刚来的、还有人在等的请求先被处理。
自适应并发限制
Netflix 开源的 concurrency-limits 借鉴 TCP 拥塞控制:RT 开始上涨,就把允许的并发往下调;RT 回落再慢慢放开。相当于在线上自动找 ④ 里的拐点 N*,不用手算。
虚拟线程:队伍挪了个地方
JDK 21 加 Spring Boot 3.2 起的 spring.threads.virtual.enabled=true:Tomcat 线程不再是窗口,可连接池还是 10 个。实测 400 并发:hikaricp.connections.pending 变成 389,不再被 200 个线程挡住;http.server.requests 平均 837 ms,和压测机对上了;tomcat.threads.busy 变成 −1,没法用了。没有 200 个线程兜底,在途请求能涨到几千个,更要显式限流。JDK 21~23 在 synchronized 里阻塞会占住底层的载体线程,JDK 24 的 JEP 491 解决了。
版本差异
- 2.2 起 Tomcat 的 MBean 注册默认关,
tomcat.threads.*指标要开server.tomcat.mbeanregistry.enabled - 2.3 起线程数配置叫
server.tomcat.threads.max,之前是server.tomcat.max-threads http.server.requests由WebMvcMetricsFilter记录,也是过滤器里开始计时,同样看不到 Tomcat 队列
http.server.requests改由 Observation(ServerHttpObservationFilter)记录,计时起点不变- 3.2 起支持虚拟线程
spring.threads.virtual.enabled - 较新的 3.x 有
server.tomcat.threads.max-queue-capacity,本机 3.5.16 验证过,默认Integer.MAX_VALUE
- JDK 8 默认 Parallel GC,Full GC 停顿长;JDK 9 起默认 G1
- JDK 21 有虚拟线程;JDK 24 起
synchronized不再钉住载体线程 - JMeter 5.5 起有 Open Model Thread Group;k6 用
constant-arrival-rate;wrk2 是 wrk 的固定速率版
面试官会怎么问
压测时吞吐不涨了、RT 随并发线性涨,说明什么?怎么估一台能扛多少?
说明已经饱和,多出来的并发都在排队,RT = 并发 ÷ 吞吐上限。上限由最窄那一站决定:窗口数 ÷ 每次占用时间,比如 10 个连接 × 20 ms = 500/s。容量规划只用到上限的 70%~80%,因为利用率越接近 100%,排队越陡。
为什么把线程池调大,RT 反而更差了?
如果最窄的是连接池或数据库,线程多了只是让更多线程停着等连接,队伍原地不动;如果连带着把连接池也调大,数据库要同时跑更多 SQL,锁竞争和 CPU 切换让每条 SQL 变慢,S 变长,上限反而变小。
什么是 coordinated omission?
闭环压测机要等上一个请求回来才发下一个。系统卡住时压测机也停下了,这段时间里本该发出的请求没发,卡顿只落在少数几个请求上,P99 被严重低估。解法:用开环按固定速率发,RT 从计划发出的时刻算(wrk2、k6 constant-arrival-rate、本页 ⑤ 的 Load.java 都是这样)。
线上一次 GC 之后 RT 一直下不来,重启才好,可能是什么?
先怀疑亚稳态:卡顿期间积压的请求超时、被重试,进水变多,加上无界的先来先服务队列让服务端一直在处理过期请求,系统困在过载里。治理:有界队列和减载、重试预算和退避、超时层层递减、排队超时就丢。也要排除真正的累积,比如堆泄漏,用“低压重测”和 jstat 区分。
下一圈
- 排队论再深一步:M/M/c、Erlang C 和 Kingman 公式,自己算池子大小
- 读 HikariCP 的 ConcurrentBag:无锁借还连接,以及它为什么不严格公平
- Tomcat NIO 源码:Acceptor、Poller、TaskQueue 怎么在线程满之前优先建线程
- 自适应限流:Sentinel 和 concurrency-limits 的算法
- GC 日志分析:G1、ZGC 怎么影响尾延迟
- 全链路压测:流量染色、影子库、挡板
- 容器里的 Java:CPU limit、调度节流和 JVM 的容器感知
- 尾延迟的工程手段:对冲请求(hedged request)、超时预算往下传
↺回到第⑤步,再做一遍
每个练习都在 ⑤ 的 rtdemo 和 Load.java 上做,用一条第⑥步的内容。
练习 1 · 给 Tomcat 的队伍设上限
用 --server.tomcat.threads.max-queue-capacity=300 启动,重跑实验 2 的每秒 600 个。本机实测:P50 稳在约 0.7 秒,约 22% 的请求 1~8 ms 就失败,服务端日志里是 RejectedExecutionException: Queue capacity is full,压测机看到的是连接被关掉。
练习 2 · 让客户端超时,数一数白做了多少
在 Load.java 的 HttpRequest.newBuilder(u) 后面加 .timeout(java.time.Duration.ofSeconds(1)),每秒 600 个跑 30 秒,对比压测机的成功数和 /actuator/metrics/demo.sql 的 COUNT。本机实测:成功 1099 个,服务端执行了约 18000 次。
练习 3 · 换成虚拟线程,队伍去哪了
用 --spring.threads.virtual.enabled=true 启动,重跑实验 1 的 400 并发。跑之前先写下你对 hikaricp.connections.pending 和服务端 http.server.requests 平均值的预测,答案在下面第 6 题。
自测
1. 用一句话说出本页的精华。
RT = 干活 + 排队,干活的时间通常不变,变的是排队;排查就是找到正在变长的那个队,再问它为什么变长。
2. 为什么“把池子调大”常常没用?
只有最窄的那一站变宽,上限才会涨。调大的不是最窄那站,队伍原地不动;调大的是最窄那站,队伍挪到下游,下游的 S 可能跟着变长。
3. 服务端 P99 300 ms,压测机 P99 3 秒,差的去哪了?
多半在 Tomcat 的任务队列里:线程都忙时,请求连线程都拿不到,而 http.server.requests 从线程接手才开始计时。看 tomcat.threads.busy 是否顶在最大值。
从 ④ “一个请求要过好几道窗口”推出。
4. 预测:连接池从 10 调到 20,数据库扛得住、每条 SQL 还是 20 ms,200 并发时 P50 大约多少?
上限变成 20 ÷ 0.02 s = 1000/s,R = 200 ÷ 1000 = 200 ms,减半。在实验台里把窗口数切到 20、闭环 200 个用户就能验证。前提是数据库真扛得住,不然 S 会变长,抵掉一部分。
从 ④ 并发轴的两个式子推出。
5. 预测:开环每秒 550 个,上限 500,一直跑 10 分钟,会怎样?
每秒多积约 50 个。理论上 10 分钟积 3 万个、要等约 60 秒;实际上积到 8192 个连接时(约 2 分 44 秒,这时要等约 16 秒)Tomcat 就不再接新连接,再来的先排进内核的 accept 队列(100 个),再多就连不上,压测机开始报连接超时。
从 ④ 时间轴 (a) 和默认配置推出。
6. 预测:开虚拟线程以后重跑 400 并发,hikaricp.connections.pending 和服务端 http.server.requests 平均值会变成多少?
pending 约 390,因为不再有 200 个线程挡在前面,除了正在用连接的 10 个,其余都停在等连接;服务端记录的 RT 约等于客户端,因为请求不用在 Tomcat 队列里等线程了。本机实测 pending 389,服务端平均 837 ms,压测机 P50 815 ms。
从 ④ 一串窗口推出:拿掉一站,队伍就倒灌到前面那一站。
7. 预测:JMeter 20 个线程(闭环),RT 从 22 ms 慢慢涨到 73 ms。这会是“来得比走得快”吗?
不会。闭环里系统中的请求固定是 20 个,积压不起来。一定是出口在变窄:S 变长(表变大、GC)或 c 变少(连接泄漏)。⑤ 实验 3 就是这个情况。
从 ④ 时间轴的推论推出。