企业官网建设流程全解析

上周五下午三点多，我这边负责的活动系统突然连发告警：霸王餐接口/activity/hungry/dinner/apply的P99耗时从平时的80ms一路飙到2秒以上，超时率直接冲到6%，前端同事开始在群里喊“用户反馈页面一直转圈，活动入口快崩了”。这个接口就是用户报名霸王餐活动的核心入口，业务上要处理用户资格校验、订单绑定、返现计划生成，一挂就是整个活动全挂。

本地模拟测了几轮，接口一切正常，毫无复现迹象。但线上就是慢，还伴随着频繁的GC告警。这种“本地没事、线上出事”的场景，最忌讳乱猜乱试。我当时的判断是：要么线程池被打满，要么数据库连接池耗尽，要么有锁竞争，要么GC停顿严重。但光靠猜没用，得看线上JVM里到底发生了什么。

这种时候直接上Arthas，用它的dashboard、thread、trace、watch和profiler几个核心命令，把线上运行现场完整接出来，从整体到局部一层层往下拆。这篇文章就是我这次排查和优化全过程的一个复盘，包括当时的判断思路、每一条命令执行的输出怎么看、问题根因怎么定位、最后怎么通过分批查询把接口耗时降下来的，以及Arthas在生产环境使用时的几个避坑点。适合正在做Java后端、尤其是618或大促前经常被线上性能问题折磨的朋友参考。

1. 霸王餐接口的线上告警与初步判断

1.1 接口出了什么症状，先别急着猜

先说霸王餐接口本身。这个接口做的事情很直接：用户在前端点“参加霸王餐”，后端需要校验当前用户是否符合活动资格、检查该用户是否已经参加过、锁定用户本次关联的订单、生成一条返现计划记录，然后返回参与结果。

业务逻辑不算复杂，但它依赖的外部资源比较多：Redis里有活动配置和用户资格缓存，MySQL里有订单表和返现计划表，偶尔还会调一下会员系统的接口同步用户等级。

告警是在下午三点左右开始的。监控面板上的数据非常难看：

• P99耗时从正常的约80ms暴涨到2.1s
• 超时率从接近0升到6%
• 错误日志里开始出现RejectedExecutionException，提示“活动太火爆请稍后再试”
• 老年代GC频率从几分钟一次变成几十秒一次，单次Full GC耗时在300ms到800ms之间徘徊
• 活跃连接数从50涨到接近连接池上限

这几个症状摆在一起，很容易让人误判成“流量太大，服务扛不住”。但问题是，当天的实际QPS只有正常水平的40%，远没到触顶的程度。流量不大却出现线程池拒绝、GC频繁，这通常是某个环节出现了慢调用，把线程和内存双双拖垮了，而不是简单的容量问题。

所以我当时先做了一件事：控制住自己乱猜的冲动，停止在网上搜索“Java 线上 CPU 高怎么办”之类的通用答案，直接登录跳板机，准备用Arthas去现场看JVM内部到底发生了什么。

1.2 为什么选Arthas而不是jstack和jstat

服务器上其实也装了JDK自带的工具，比如jstack、jstat、jmap。这些工具能用，但在这种紧急排查场景下有几个问题。

jstack可以打印线程快照，但它是“拍一张照片”，只能看到某个瞬间的线程状态。线上问题往往需要连续观察多个时间点，才能判断线程是偶发阻塞还是一直阻塞。jstat可以看到GC情况，但它输出的是累加数据，看不出某个接口调用触发了哪次GC。jmap更是要谨慎，在线上下载堆转储文件有时候会触发Full GC，对正在抖动中的服务来说是火上浇油。

Arthas的优势在于它是“交互式现场勘探工具”，全部命令在进程内执行，不需要重启服务，不需要停机，不强制触发GC，而且可以持续观察一段时间的运行状态。它做的事情就是护着线上进程，让你像本地调试一样去查看：

所以我的选择很明确：Arthas定位问题，JDK原生工具做辅助验证。

2. Arthas接入与第一轮现场观察

2.1 几秒钟把Arthas挂到运行中的服务上

Arthas的接入过程很快，前提是你已经能ssh到服务器上，并且知道服务的运行用户是谁。我当时用的是3.7.x版本的arthas-boot，流程是这样的：

# 在服务器上启动arthas-boot，它会列出当前机器上所有Java进程 java -jar arthas-boot.jar # 选择目标进程，输入序号后回车，比如选择活动服务进程 [INFO] arthas-boot version: 3.7.2 [INFO] Found existing java process, please choose one and input the index: * [1] 12345 com.example.activity.ActivityApplication [2] 23456 com.example.pay.PayApplication

选择进程后，Arthas会attach到目标JVM上，输出一个交互式控制台的欢迎信息。这里有一个很重要的判断：attach动作本身不会影响业务线程，Arthas是在目标JVM里开了一个独立的诊断线程，占用资源很小，放心做。

值得注意的是，如果服务运行在容器里，记得先docker exec进入容器再执行。如果用的是K8s环境，则需要先找到Pod再进入对应容器。另外，Arthas连接后建议第一时间用options命令确认是否开启了详细日志输出，避免后面操作时有大量无关日志刷屏。

2.2 dashboard: 一眼看清线程、GC和内存的整体状态

挂上Arthas后，我执行的第一条命令就是dashboard。这条命令相当于一个实时仪表盘，会定期刷新整个JVM的概览，包括线程总数、各个线程池活跃线程数、内存各区使用量、GC次数和耗时。

当时的输出大致是下面这样：

ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED 29 busi-pool-1-thread-5 main 5 RUNNABLE 23 0:58 false 30 busi-pool-1-thread-7 main 5 RUNNABLE 21 1:20 false 31 busi-pool-1-thread-12 main 5 RUNNABLE 18 1:35 false 32 busi-pool-1-thread-3 main 5 WAITING 0 0:00 false Memory used total max usage heap 4.2G 4.5G 4.5G 91% g1_old_gen 3.1G 3.5G 3.5G 88% survivor_space 120M 128M 128M 93% GC Time: Young GC 128 times, Cost 3.2s; Full GC 32 times, Cost 21s

只看这一屏我就有了几个清晰的判断：

• 线程池busi-pool-1的大部分线程都处于RUNNABLE状态且CPU占用高，说明业务线程并没有闲着，而是在持续执行某种耗时操作。线程不是等锁，也不是单纯的池子被占满，而是真的在CPU上干活。
• 堆内存已经用到91%，老年代88%，Survivor区93%，GC时间累计21秒。这说明内存压力非常大，对象分配速度远超回收速度。
• Full GC有32次，平均每次耗时600ms以上，这个停顿对接口延迟的影响已经不可忽略。

到这里，初步判断范围缩小了：不是简单的线程数不够，而是业务执行过程中存在某些耗CPU或者耗内存的调用，导致线程池繁忙、内存被大量对象撑爆。接下来需要找到具体是哪个方法在消耗资源。

3. 用Arthas定位卡顿线程与调用链路

3.1 thread -n: 找出最热的忙碌线程

dashboard只给了概览，接下来我要找到具体是哪些业务代码在消耗CPU。这时候用thread -n 3查看CPU占用率最高的3个线程，并打印它们的线程栈，会非常直观。

$ thread -n 3 "SIMPLE-DUBBO-REFS-210" Id=129 RUNNABLE at com.example.activity.service.impl.HungryDinnerServiceImpl.queryEligibleOrders(HungryDinnerServiceImpl.java:187) at com.example.activity.service.impl.HungryDinnerServiceImpl.applyForDinner(HungryDinnerServiceImpl.java:92) at com.example.activity.controller.HungryDinnerController.apply(HungryDinnerController.java:34) at org.apache.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) ...

这里看到关键信息的价值一下子就体现出来了。queryEligibleOrders方法被标了出来，它是被applyForDinner调用的。也就是说，霸王餐接口在报名流程中，需要查询用户的“符合返现资格的历史订单”，这一步是当前CPU消耗最严重的地方。

线程栈里还显示了SIMPLE-DUBBO-REFS-210这样一个线程名，说明这个调用是发生在一个Dubbo业务线程里。如果当时线程栈里出现多个不同线程都卡在同一个方法上，基本就能确定瓶颈在哪一段代码了。

3.2 trace: 追踪方法的耗时分布，找到“罪魁祸首”

找到可疑方法后，下一步就是看这个方法内部到底哪一行代码慢。用trace可以输出方法内部每个子调用的耗时分布，精确到行：

# 这里把包名和方法名列清楚，-n 3表示只跟踪前3次完整调用 trace com.example.activity.service.impl.HungryDinnerServiceImpl queryEligibleOrders -n 3

输出结果如下：

`---[queryEligibleOrders] com.example.activity.service.impl.HungryDinnerServiceImpl@61aecaa `---[31.5%] [65ms] com.example.activity.mapper.OrderMapper#selectBatchIds `---[90.1%] [58ms] JdbcTemplate execute `---[0.3%] [0.2ms] DynamicContext `---[66.1%] [137ms] com.example.activity.service.impl.HungryDinnerServiceImpl::filterExpiredOrders `---[1.8%] [3.7ms] com.example.activity.service.impl.HungryDinnerServiceImpl::collectReturnPlan

一眼就能看到，OrderMapper.selectBatchIds花了65ms，filterExpiredOrders花了137ms。前者看起来是一个批量主键查询，65ms对于单次查询来说已经不正常，但更可疑的是后者——一个纯内存过滤方法竟然要137ms。

说明filterExpiredOrders内部的处理代价非常大，大概率是因为传入的数据量太大了。

3.3 watch: 看方法的入参和出参，还原现场

要验证“数据量太大”这个猜测，就得看看queryEligibleOrders和filterExpiredOrders的入参到底是什么。用watch命令直接观察：

# 观察queryEligibleOrders的入参，打印所有参数并限制只输出前2个结果 watch com.example.activity.service.impl.HungryDinnerServiceImpl queryEligibleOrders "{params, returnObj}" -x 2 -n 2

输出结果里我看到queryEligibleOrders接收到的订单ID集合居然有3000多个元素。单个用户的历史订单怎么可能有三千个？这里面一定有一个业务Bug：原本应该只查“当前活动周期内、状态为待返现”的订单，结果代码把用户的所有历史订单ID全部捞出来了。

再看filterExpiredOrders的返回结果，它遍历那3000多个ID，挨个去查Redis里的活动批次信息，等于在循环里做了3000次Redis网络请求。这正好解释了为什么一个内存方法会需要137ms——它不是简单的内存计算，而是循环里的网络IO。

到这里，整个问题的链路已经基本清晰：

1. 业务代码里查询订单的筛选条件因为状态枚举判断错误，导致把用户的所有历史订单都查了出来
2. 一个订单ID集合膨胀到3000多个元素
3. 后续没有分批处理，直接用全量集合去查询数据库，产生超大IN条件的慢SQL
4. 同时还在循环中大量访问Redis，进一步放大网络开销
5. 请求耗时暴涨，线程被长期占用，线程池活跃线程打满
6. 大量请求堆积触发拒绝策略，前端看到“活动太火爆”
7. 对象膨胀导致内存占用过高，GC频繁，全链路雪上加霜

4. 慢SQL批量查询的根因与修复

4.1 慢SQL到底慢在哪个环节

找到了查询数据量异常之后，接下来要验证数据库侧的情况。我在Arthas里用trace继续观察了selectBatchIds的调用，发现它拼接出来的SQL里IN条件包含了3000多个ID。一条SQL写了3000多个ID，MySQL在解析、优化、执行这条SQL时，代价都很大。

具体来说：

• SQL语句本身就非常长，网络传输耗费更多时间，数据库的语法解析成本也更高
• 优化器面对3000多个参数的IN条件，很难准确估计基数，可能放弃最优索引而选择全表扫描
• 即使走了主键索引，一次加载这么多行记录返回给应用层，也会造成严重的网络和内存开销
• 数据库连接被这类慢SQL长期占用，连接池被耗尽，其他正常请求拿不到连接

这些因素叠加，直接导致selectBatchIds从正常的10ms以下变成65ms以上，再加上后续3000次Redis访问的耗时，整个接口自然就慢到不可接受了。

4.2 修复方案：分批查询加内存聚合

修复的思路不复杂，核心是三条：

1. 修正状态枚举判断的Bug，只捞取当前活动周期内待返现的订单记录
2. 就算偶尔出现订单数量较多的情况，也要分批查询，例如每批100个ID
3. 后续的过滤和状态检查，尽量减少Redis交互，尽量合并成批量查询

具体到代码层面，原来的逻辑大致是这样：

// 错误示例：直接查询所有订单ID，并且一次IN条件全量传入 List<Long> orderIds = orderMapper.selectAllOrderIdsByUserId(userId); List<Order> orders = orderMapper.selectBatchIds(orderIds); for (Order order : orders) { String status = orderStatusService.getRealTimeStatus(order.getOrderNo()); if (!returnPlanSupported(status)) { continue; } eligibleOrders.add(order); }

修复后的写法应该是这样：

List<Long> orderIds = orderMapper.selectEligibleOrderIds(userId, activityId, LocalDateTime.now().minusDays(30)); for (List<Long> batchIds : Lists.partition(orderIds, 100)) { List<Order> batchOrders = orderMapper.selectBatchIds(batchIds); for (Order order : batchOrders) { eligibleOrders.add(order); } }

与此同时，Redis状态查询也改成了批量管道模式，通过pipeline一次获取多个订单的状态，把原来的N次网络请求压缩为一次。

修复之后重新上线，用trace再看queryEligibleOrders：

`---[queryEligibleOrders] com.example.activity.service.impl.HungryDinnerServiceImpl@61aecaa `---[32.5%] [2.3ms] com.example.activity.mapper.OrderMapper#selectBatchIds `---[10.2%] [0.8ms] com.example.activity.service.impl.HungryDinnerServiceImpl::filterExpiredOrders `---[1.5%] [0.1ms] com.example.activity.service.impl.HungryDinnerServiceImpl::collectReturnPlan

同一个方法的总耗时从约300ms直接降到5ms以内，接口P99也从2.1s降回150ms左右，GC频率恢复正常，线程池活跃线程数回到正常水平。

5. 火焰图量化性能分析与优化后验证

5.1 用Arthas生成线上火焰图，不做经验主义优化

修复完成之后，我并没有直接宣布“问题解决”，而是用Arthas的profiler生成了一次火焰图，目的是拿到更客观的性能瓶颈分布，验证是否还有新的热点存在。

Arthas的profiler命令在3.7.x版本中提供了火焰图能力，使用方式比较简单：

# 启动CPU性能采样 profiler start # 等待一段时间，比如压测或者让线上自然流量跑30秒 # 停止采样并生成火焰图结果 profiler stop

profiler stop之后会在服务器上生成一个HTML格式的火焰图文件，可以用浏览器打开。也可以指定输出格式和文件路径：

profiler start --format html --file /tmp/arthas-cpu-flame.html

我当时让服务自然运行了60秒，采样的结果是：OrderMapper.selectBatchIds的CPU占比从修复前的30%以上降到了约2%，filterExpiredOrders的占比从40%降到了1.5%以下。火焰图上所有大平顶都消失了，只剩下一些比较均匀的短栈和正常业务逻辑调用。

这一步做得很有价值。因为性能优化最怕的是修了一个问题、又冒出另一个问题，或者把A问题的耗时转移到了B问题上。火焰图能把整个进程的CPU热点扫描一遍，确认没有其他隐藏瓶颈。

5.2 优化后的接口表现与线上复验

上线后第三天，我又回到监控面板上看数据，接口的各项指标已经完全恢复：

• P99稳定在200ms以内，平均耗时约80ms
• 超时率降到0.1%以下
• 线程池活跃线程数峰值从25降到8
• 老年代内存占用从91%降到正常水位，Full GC次数几乎清零
• 用户在端上的反馈是“丝滑了”，没有再出现转圈或报错的投诉

这个结果说不上是激进优化，只是把Bug修对了，把数据访问方式改合理了，性能自然就回来了。

6. 常见问题与Arthas实用避坑

6.1 Arthas使用中的典型坑

第一次使用Arthas的人，很容易在几个细节上踩坑，我结合这次经历整理了一份速查表：

另外，Arthas虽然很好用，但生产环境使用一定要有节制。不要长时间开着watch和trace，用完就要stop。如果是大促期间，建议在低峰期再执行诊断命令。

日常排查中，我自己最常用的Arthas命令就这几个：dashboard、thread -n、thread -b、trace、watch、jad、profiler。其中thread -b是查死锁和等待锁的关键命令，jad则用来确认线上运行的代码是不是最新版本，尤其排查“代码改了但没生效”这类问题时极有作用。

6.2 排查过程的几个宝贵经验

最后分享几个我个人的体会。

第一，线上问题排查最忌讳一上来就改代码。一定要先还原现场，再分析链路，最后才动手修复。有些朋友看到GC频繁就以为要调堆大小，看到超时以为要扩容机器，其实全都是舍本逐末。

第二，Arthas的trace结果一定要和业务判断结合起来看。trace输出的是“耗时分布”，不是“问题结论”。比如我这次trace发现filterExpiredOrders耗时137ms，如果不继续往下看入参，可能就会在内存过滤逻辑里找半天，实际上真正的原因在循环里的Redis调用。

第三，修好一个Bug后，一定要用profiler或者重新trace验证一遍，不能只凭监控上的P99数据就认为万事大吉。监控指标是宏观的，火焰图是微观的，两者结合起来才能确认根因已经彻底消除。

霸王餐接口这次线上故障，从接警到定位再到修复收尾，整体耗时大概三个小时。其中真正花在Arthas操作上的时间不到半小时，大部分时间都在看业务代码和确认数据量异常的原因。工具本身学起来不难，难的是拿到现场数据之后，能不能结合业务逻辑判断出哪一步是异常的。Arthas给我的感觉是，它把线上JVM变成了一间透明的房子，你能看见线程在等什么、内存被什么占着、方法在哪里慢，剩下的就是靠业务嗅觉去定位了。