本来没打算这么快写第三篇。前两篇发完后陆陆续续有读者问同一个问题“你说的优化点我都知道可真拿到自己那条慢接口上还是不知道从哪下手。”这个问题背后的本质是优化这事最怕的不是没有方案而是找不到真正的瓶颈。这次我记录一个真实的导出接口优化过程从接口P99 1.2秒压到110毫秒中间没动架构、没换数据库、没用玄学参数纯粹是把JVM、代码层和数据库侧的问题逐个排掉最后做了一轮扎实的回归验证。这篇更适合那些每天维护老服务、被线上接口性能折腾、想知道“从哪开始排查”的Java后端同学。顺便说一句这个系列写到第三篇我最大的变化就是不再急着动代码了先让证据说话。1. 从一次导出接口变慢开始问题表象与排查链路1.1 表象不在CPU请求都堵在什么地方了这次出问题的接口是业务侧非常常见的数据导出根据筛选条件把最多两万多行数据导出成Excel。之前数据量只有几千行时接口稳定在120ms左右所以也没有人特意优化。直到业务侧把查询范围放开到两万行以上P99从几百毫秒一路飙到1.2秒部分请求直接超过3秒再往上走就开始超时报错。当时的直觉是“数据量变大SQL变慢了”。可一查监控数据库慢查询日志里确实有两条SQL耗时超过了1.8秒但CPU和内存占用都不到预警线这反而是最让人头疼的情况。没有明显单点意味着问题大概率是多个因素叠加在一起。我习惯把这种状态叫作“接口假性卡顿”你看着CPU不高线程池却可能已经塞满看着内存不高GC却可能频繁得可怕。先把症状记录下来导出接口的P99持续走高但平均响应时间只有300ms左右说明有大量请求在长尾里。服务端CPU使用率只有20%~30%没有打满。GC日志里Minor GC次数从每天几十次涨到每分钟几十次Young区回收后内存并没有明显回落。数据库端只有部分查询慢但通过索引命中的分析发现有不少慢SQL其实走了全表扫描。这四条摆在一起基本可以排除“CPU算力不够”和“数据库负载真的很高”这两个方向更可能的原因是JVM频繁GC导致STW业务线程被阻塞部分线程在等待数据库连接或锁整体吞吐下降接口长尾被拉大。这一步没法直接靠看代码判断必须动手拿数据。1.2 Arthas jstat把三个嫌疑点同时列出来排查环境是JDK 8我一般不会一上来就开VisualVM或者连线到生产环境做堆转储太重了。首选还是Arthas和JDK自带的jstat几行命令就能把线程状态、GC频次、方法耗时拉出来。第一步先在测试环境复现然后执行arthas-boot启动Arthas用dashboard看一下全局状态。重点不是看CPU而是看线程数和等待状态分布$ arthas-boot $ dashboarddashboard的统计里线程总数、WAITING和TIMED_WAITING数量会直接暴露问题。当时看到的情况是业务线程池里有大量线程处于WAITING状态而且om.sun.management相关线程也频繁活动说明JVM内部在做GC和内存管理。随后用jstat看一眼GC实时情况$ jstat -gcutil pid 1000 10输出里的FGCFull GC次数、FGCTFull GC耗时、YGCYoung GC次数会每分钟刷新。当时Young GC频率高得异常而且每次回收之后Eden使用率依然快速回升这通常是对象分配过快导致的不是简单“堆不够大”。接着用Arthas的trace命令去定位热点方法$ trace com.example.export.ExportServiceImpl exportData #cost 50只关心耗时超过50ms的方法调用很快发现耗时集中在三块ExcelBuilder.build里的字符串拼接与集合写入占整体耗时的40%左右数据库查询的ResultSet遍历和DTO转换占30%synchronized同步块锁住的输出流写入占20%。这个分布很有意思慢SQL只占了三分之一另外三分之二是代码层和锁竞争。如果当时只盯着慢查询优化最后顶多把P99从1.2秒压到800ms不会有质变。这也是我为什么反复强调排查阶段不要猜要让工具告诉你答案。1.3 先建立“瓶颈清单”再动手避免越改越乱很多人拿到慢接口的第一反应是“先加缓存”或者“把锁删掉”但我建议先列一张瓶颈清单把所有可疑项和对应验证方式写下来哪怕有些项到最后没用上也比盲目改强得多。当时我列出的候选瓶颈大概是这样的候选瓶颈验证方式最终判定JVM堆内存分配不合理Young区回收频繁jstat观察YGC/FGC、Survivor使用率确认代码循环内字符串拼接产生垃圾对象Arthas的trace、生成堆快照分析对象大小确认ArrayList批量写入反复扩容阅读代码 对象分配统计确认共享输出流锁竞争严重线程栈采样观察线程WAITING状态确认SQL索引失效或扫描行数过大explain分析SQL执行计划确认连接池大小与线程池不匹配观察数据库连接池活跃数、等待线程数确认这张清单最后基本全用上了。它还有个额外作用防止优化过程中“顺手改掉不该改的东西”。因为优化链路一旦拉长人的记忆会不可靠最后靠清单回归逐项恢复或保留修改能省很多返工。2. JVM参数不是越大越好G1调参与内存比例权衡2.1 堆内存失衡放大了STW停顿当时服务的JVM参数是典型的“裸奔状态”java -jar -Xms4g -Xmx4g export-service.jar没有设置年轻代比例也没有指定垃圾收集器所以JDK8默认用的是Parallel Scavenge Parallel Old。这种组合的特点是高吞吐导向不是低延迟导向一旦遇到对象分配量大、Young GC频繁的场景停顿会非常明显。而导出接口恰恰是典型的“短期大量对象堆积”读取两万行数据每行都变成若干DTO、字符串完整构建一个Excel文件中间产生的临时对象比常规查询高出好几个数量级。堆大小4G不算小问题出在比例失衡。默认的新生代和老年代比例是-XX:NewRatio2新生代大概是1.3G左右Eden区更大但Survivor空间很小。对象分配的时候如果Survivor放不下就会直接晋升到老年代老年代回收一旦启动停顿时间和内存量直接挂钩。从jstat里看到的现象也符合这个判断Young GC频率高老年代增长很快虽然有Full GC但频率还不算离谱因为服务运行一段时间后老年代被堆满才触发。可每次Young GC都伴随大量对象晋升这就不正常了——大部分临时对象应该在Survivor里被回收掉而不是跑进老年代。2.2 G1参数调整不是把堆调大而是让GC节奏可控因为服务需要长期在线、对响应时间有要求的我直接把垃圾收集器换成了G1。这里不是G1比Parallel GC更好而是G1更符合“低延迟、可控STW”的场景。替换后的核心参数是java -jar -Xms8g -Xmx8g -XX:UseG1GC -XX:MaxGCPauseMillis50 -XX:G1HeapRegionSize4m -XX:InitiatingHeapOccupancyPercent45 -XX:PrintGCDetails -XX:PrintGCDateStamps -Xloggc:gc.log解释一下几个关键选择-Xms和-Xmx保持一致避免运行期动态扩容动态扩容需要触发stop-the-world对线上服务不友好。-XX:G1HeapRegionSize4mG1把堆分成等大的RegionRegion太小会导致Region数量过多增大RSet维护开销Region太大则让混合回收粒度变粗。4G堆和8G堆比较常用4m或8m需要结合Region数量压测。-XX:MaxGCPauseMillis50这是目标停顿不是硬保证G1会据此调整YG和Mixed GC的行为。-XX:InitiatingHeapOccupancyPercent45老年代占比达到45%时启动并发标记周期。这个值默认也是45%实际场景里需要观察Mixed GC触发频率再微调。那段时间我特意留意了压缩指针的问题Java堆小于32G时默认开启-XX:UseCompressedOops对象引用占4字节如果因为调优把堆直接拉高到32G以上引用会变成8字节同量对象占用反而更多GC扫描成本也会上升。所以不是“内存越大越好”8G在导出一类服务上已经很舒适。调完G1参数后还需要配合代码层的对象分配优化否则GC参数只能兜底不能治本。这里有个容易被忽略的逻辑G1的并发标记周期要CPU参与如果分配速度太快占满缓冲区照样会退化成Full GC。所以JVM参数调优必须和对象分配优化一起做单调参数大概率无效。2.3 参数改完先看GC节奏而不是直接看接口耗时调参之后我先跑了三轮压测每轮5分钟然后打开gc.log观察三点Full GC是否明显减少Young GC的平均耗时是否稳定在几十毫秒内cause字段是不是经常出现Allocation Failure这个出现太频繁意味着对象分配压力还是在。从结果看Full GC基本消失Mixed GC偶尔触发Young GC平均停顿在30ms左右。结合接口P99已经从1.2s降到600ms左右说明JVM侧的瓶颈解掉了大半。没有一步到位压到110ms是因为代码层的四个热点还没处理GC虽然不堵了但线程池和锁还在消耗时间。3. 代码层被忽略的三个瓶颈字符串拼接、集合扩容、锁竞争3.1 循环内的字符串拼接正在悄悄制造海量临时对象Arthas的trace很快把第一个热点指到了ExcelBuilder.build。打开代码发现一个很典型的问题在循环里用拼接字符串。String content ; for (Row row : rows) { content row.getA() , row.getB() , row.getC() \n; }Java 8之后编译器会默认把转成StringBuilder.append()但关键问题是每次循环迭代都会new一个StringBuilder出来而且这个StringBuilder的初始容量未必足够循环次数一多扩容、复制、临时对象全来了。两万行数据就会创建两万多个临时对象而且这些对象生命周期极短正好是Young GC的“燃料”。把这段改成显式StringBuilder之后效果非常明显StringBuilder content new StringBuilder(2_000_000); for (Row row : rows) { content.append(row.getA()).append(,).append(row.getB()).append(,).append(row.getC()).append(\n); }这里还顺手做了一件更关键的事给StringBuilder一个合理的初始容量。两万行、每行大约80字节估算下来1.6MB到2MB足够直接给2_000_000的初始容量可以避免几乎所有的扩容复制。如果你对数据行数没把握也可以在循环外根据rows.size() * 96估算一个初值宁可多给一点也不要它在循环里反复扩容。类似的手法在DTO转换时也很常见。比如循环里反复调用new String、String.format这些都是对象分配大户。排查这类问题时可以盯住两点一个是在循环里有没有new对象另一个是对象是否只在当前迭代活一次。能用基本类型就用基本类型能重用builder就重用builder不要在循环体内创建生命周期很短的“大家伙”。3.2 ArrayList扩容与Map遍历看起来无所谓量大就成问题第二个热点是数据从数据库取出后批量塞到ArrayList里再遍历转成DTO列表。原代码是ListDTO dtoList new ArrayList(); for (Entity entity : entityList) { dtoList.add(convert(entity)); }这段代码问题不大但有个隐蔽点ArrayList默认容量是10当插入元素超过容量时会按照原来容量的一半进行扩容。两万行数据意味着从10到20000之间要经历十几次扩容每一次扩容都是一次Arrays.copyOf把原来数组复制到新数组。数据量小的时候无所谓数据量一大这部分就是纯浪费。我之前测过同样往ArrayList里塞两万个对象不预设容量的耗时比预设容量高出约20%。优化方法非常简单ListDTO dtoList new ArrayList(entityList.size());这条规则同样适用于HashMap。大家常背“HashMap默认容量16负载因子0.75”但很少有人意识到当插入数量超过12个时HashMap就会扩容到32再超过24时又扩容到64。如果你提前知道要放进多少个元素直接new HashMap(expectedSize)就能避免大量不必要的rehash和链表转树判断。还有一个经常被忽略的点遍历Map时如果只需要key或者value尽量用keySet或values不要entrySet之后取后者再getValue。entrySet本身没问题但如果在循环里对每个entry都做一次map.get(entry.getKey())等于把一半的时间浪费在重复查找上。导出DTO转换里我看到过这种写法每次循环都二次查询Map数据量一大也够受的。3.3 锁竞争改造导出线程池与输出缓冲第三个热点是synchronized锁住了输出流写入。整体逻辑是这样的多个线程并行处理Excel的分片数据然后共享一个OutputStream做最终写入。为了线程安全原代码直接在外面加了synchronizedsynchronized (outputStream) { outputStream.write(bytes); }这在数据量小时看不出问题可一旦数据量大两个线程同时写完分片后要抢锁写数据就是串行化。从Arthas的thread命令看到大量WAITING状态原因就在这里。仔细想想这个锁的粒度太大了写入之前的分片计算完全可以在锁外做真正需要同步的只是“把计算完的字节写入目标流”这一小段。优化方式是把“每个线程独立构建自己的分片缓冲”最后统一合并到输出ExecutorService executor Executors.newFixedThreadPool(4); ListFuturebyte[] futures new ArrayList(partCount); for (Part part : parts) { futures.add(executor.submit(() - buildPartBytes(part))); } try (ByteArrayOutputStream merged new ByteArrayOutputStream()) { for (Futurebyte[] future : futures) { merged.write(future.get()); } }这样旁路掉了共享输出流的锁竞争每个线程只操作自己的ByteArrayOutputStream最后归并。另一种更简单粗暴的方案是给每个分片一个独立的写入文件最后合并文件但代码改动量偏大在线服务里不划算。这里也顺带提一下AtomicLong和LongAdder的选择。如果只是做计数器高并发下AtomicLong的CAS竞争很严重JDK8里的LongAdder通过分段计数降低竞争适合统计等待时间、成功次数这类场景。导出生成过程中的统计项我用LongAdder替换了AtomicLong虽然不是主要瓶颈但属于“顺手优化”。4. 数据库侧配套优化慢SQL、索引失效与连接池参数4.1 explain查出来的三个SQL问题导出接口里最核心的一条SQL是从主表关联若干张附表取出筛选数据。慢日志里耗时超过1.8秒用explain看执行计划暴露了三个问题第一驱动表选反了。EXPLAIN结果里第一行是type: ALL全表扫描。主表筛选条件能过滤掉大部分数据却变成被驱动表实际上是另一张小表在前导致主表全扫。第二关联字段存在隐式类型转换。附表关联字段是varchar主表关联字段是bigint两者关联时MySQL需要对字符串列做转换才能比较索引直接失效。这一步是慢SQL最常见的隐形杀手明明字段上建了索引但类型不对索引就是用不上。第三LIKE %xxx%前置通配符。导出界面的关键字搜索用了like而且通配符在开头这类查询基本只能扫整列。如果确实需要模糊匹配一是换成前缀通配符二是考虑走搜索引擎或全文索引而不是在业务表上硬扛。当时的SQL简化后长这样SELECT a.*, b.name, c.status FROM main_table a LEFT JOIN sub_table b ON a.sub_id b.id LEFT JOIN type_table c ON c.id a.type_id WHERE a.user_id ? AND a.title LIKE %keyword% ORDER BY a.create_time DESC改法是分两步SELECT a.*, b.name, c.status FROM ( SELECT id FROM main_table WHERE user_id ? AND title LIKE keyword% ORDER BY create_time DESC LIMIT ? ) t JOIN main_table a ON a.id t.id LEFT JOIN sub_table b ON a.sub_id b.id LEFT JOIN type_table c ON c.id a.type_id ORDER BY a.create_time DESC;核心思想是“先缩小主表范围再关联取数”避免一开始就带着大字段做全表关联。这里也顺手把无意义的SELECT *换成了明确需要的列减少网络传包和对象转换成本。执行计划从ALL变成range扫描行数从两万多降到几百行SQL耗时从1.8秒降到120ms左右。4.2 批量提交避免一次事务写两万条导出功能里含有一个“生成本次导出文件记录”的操作原来每写一条记录就提交一次两万行相当于两万次事务提交。数据库的每次事务提交都有fsync成本网络往返更不用提。优化后改成每500条批量提交一次Connection conn dataSource.getConnection(); try (PreparedStatement ps conn.prepareStatement(sql)) { int batchCount 0; for (DataItem item : list) { ps.setLong(1, item.getId()); ... ps.addBatch(); if (batchCount % 500 0) { ps.executeBatch(); } } ps.executeBatch(); }这里注意executeBatch()并不是真正的单次提交要配合conn.setAutoCommit(false)和手动conn.commit()才能把批量操作合并成少次数事务。如果连接是从HikariCP拿的用完还要记得恢复autoCommit否则连接归还连接池后状态是错的。很多人调优到这个阶段就停了因为接口响应时间已经明显下降。但其实还有一个更隐蔽的坑线程池和数据库连接池存在数量错配。4.3 线程池与连接池的匹配关系导出接口使用了业务线程池核心线程数配置的是50而HikariCP的maximumPoolSize只有10。线程池里的线程每来一个请求就去连接池拿连接很快10个连接全被占满剩下的40个线程只能在连接池门口排队等待。当时用HikariCP的监控看到active达到10pending一直有值数据库连接池仿佛成了全系统的“共享阻塞队列”。优化并不是简单把连接池调大因为数据库的max_connections也有限。正确做法是让线程池和连接池互相匹配如果业务是IO密集型线程池核心数可以略多但连接池不能随之无限扩大。我给了一个比较保守的方案spring: datasource: hikari: maximum-pool-size: 15 minimum-idle: 5 connection-timeout: 3000 pool-name: ExportHikariPool线程池核心线程数从50降到20因为真正需要并发写的不是50个线程而是有限的几个分片任务。这里没有固定公式完全靠压测把连接池从10调到15线程池从50降到20观察接口P99和连接等待时间。结果不仅没变慢反而因为减少了线程上下文切换和排队P99又降了一些。5. 回归验证压测、预热与监控缺一不可5.1 压测不能只看平均值还要看长尾和GC所有代码和参数改完后进入回归验证阶段。优化前我跑了一轮压测作为基线优化后再跑一轮条件保持一致并发100持续5分钟数据量两万行。指标优化前优化后P991200ms110msP95980ms85ms平均响应300ms52msYoung GC次数/分钟60次8次Full GC次数有且频率上升基本为0数据库慢查询次数150这里特别提醒一句Java服务压测必须预热。JIT编译需要时间第一次跑压测时方法还是解释执行性能数据很难看。正确流程是先跑一两分钟“预请求”让热点方法触发JIT编译然后再正式压测。我当时就是先并发跑了几轮等Arthas里trace显示的方法耗时稳定后再记录数据。如果不预热优化前和优化后的对比根本没有参考价值甚至会把JIT编译优化当成“性能提升了”。5.2 GC日志和Arthas的二次确认防止“假优化”压测通过后我没有直接上线而是用gc.log和Arthas做了二次确认。打开日志关注三个字段Young GC耗时是否稳定Pause Full是否消失是否有Allocation Failure频繁触发。同时用Arthas的dashboard确认线程分布WAITING状态的线程从优化前的几十个降到了个位数CPU也重新变得平滑。如果压测数据好看但GC日志仍然异常我会很怀疑优化是否有效果。因为接口可能只是“碰巧跑得快”运行一两个小时后老年代涨上来Full GC又把性能打回原形。5.3 这次优化沉淀下来的操作清单整个案例做完后我把流程整理成了自己的排查模板也推荐给团队里刚接触性能优化的同学先看监控CPU、内存、GC、慢SQL、线程池一个都不能少。再用Arthas或JFR定位热点方法列出瓶颈清单不猜。JVM参数只调“有必要”的部分并在压测环境验证GC曲线。代码层重点检查循环内new对象、集合不预设容量、锁粒度太大。SQL侧跑explain确认索引、关联顺序、类型转换、通配符。最后统一压测预热后再比较优化前后的P99、P95和GC次数。这次优化最大的收获不是把接口压到了110ms而是让我彻底相信了一件事Java服务慢很多时候不是被一个“大问题”卡住而是被一堆“小问题”叠在一起拖慢的。每个问题单独看都不起眼但连起来就是用户感知到的超时和卡顿。写到这里我其实挺想感谢那次线上事故它逼着我把零散的优化知识串成了一条完整的排查链路这也是我为何在“JAVA优化之路”第三篇里没有继续堆参数而是完完整整记录了一次排查与改造成果。后续如果再遇到类似问题我会优先打开GC日志和线程栈而不是第一时间去改代码。