原创深度技术教程 | 阅读约 12 分钟上周三下午 3 点运维群突然炸了——订单服务的响应时间从平均 200ms 飙到了 5 秒以上偶发超时报错。打开监控一看JVM 的 Full GC 频率达到了惊人的每 3 分钟一次每次耗时 2-4 秒。这台机器的配置可不低8 核 16G按理说跑个 Spring Boot 订单服务绰绰有余。本次故障排查的完整路径如下 监控告警: 响应超时 │ ▼ jstat 观测: Full GC 每 3 分钟一次 │ ▼ GC 日志分析 → 触发原因: Allocation Failure │ ▼ jmap dump 堆快照 → MAT 分析 │ Druid LinkedBlockingQueue 占 1.2GB │ ▼ 代码审查 → N1 查询 TEXT 字段全量加载 │ ├──────────────┬──────────────┐ ▼ ▼ ▼ 改批量查询 调 Druid 调 JVM GC IN 子句替代 连接池参数 G1 IHOP 参数 │ │ │ └──────────────┴──────────────┘ │ ▼ 压测验证: P50 2.3s → 87ms ✅一、故障画像先看清问题全貌1.1 环境信息项目配置JDK 版本OpenJDK 11.0.18堆内存-Xms4g -Xmx4gGC 策略G1GC默认应用框架Spring Boot 2.7 MyBatis-Plus业务场景订单查询/创建QPS 约 300机器配置8C16G容器化部署1.2 初步现象# 用 jstat 观察 GC 情况 jstat -gcutil pid 1000连续观察 30 秒的输出让人倒吸一口凉气S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 89.21 45.32 92.67 96.12 93.45 1423 34.567 87 189.234 223.801 0.00 89.21 56.43 93.01 96.12 93.45 1424 34.589 87 189.234 223.823 0.00 89.21 67.89 93.45 96.12 93.45 1425 34.612 87 189.234 223.846 0.00 89.21 78.34 94.12 96.12 93.45 1426 34.635 87 189.234 223.869 0.00 89.21 89.76 94.89 96.12 93.45 1427 34.658 88 192.456 227.114 ← Full GC! 0.00 89.21 12.34 63.21 96.12 93.45 1428 34.680 88 192.456 227.136关键指标解读指标数值健康值判断老年代使用率 (O)92-95% 70%❌ 高危Full GC 次数 (FGC)87 → 88接近 0❌ 频繁Full GC 总耗时 (FGCT)189s → 192s 10s❌ 严重元空间使用率 (M)96.12% 80%⚠️ 偏高Young GC 频率约 1 次/秒-⚠️ 偏快但可解释初步判断老年代几乎打满对象持续晋升导致 Full GC 频繁。同时元空间接近满载可能存在类加载泄漏。二、三层排查从现象到根因2.1 第一层GC 日志分析G1 的 GC 日志信息量巨大重点看 Mixed GC 和 Full GC 的触发原因。# 开启 GC 日志临时重启加参数 -XX:PrintGCDetails \ -XX:PrintGCDateStamps \ -XX:PrintGCTimeStamps \ -XX:PrintAdaptiveSizePolicy \ -Xloggc:/var/log/app/gc.log截取典型 Full GC 片段2025-06-18T15:12:34.5670800: 12456.789: [Full GC (Allocation Failure) [Eden: 0.0B(256.0M)-0.0B(256.0M) Survivors: 0.0B-0.0B Heap: 3.8G(4.0G)-2.1G(4.0G)], 2.3456789 secs]根因确认Allocation Failure— 对象分配时老年代剩余空间不够触发了 Full GC。注意这不是并发标记失败Concurrent Mark Failure而是没有足够连续空间分配大对象。2.2 第二层堆内存快照分析# 触发 Full GC 后立即 dump保留干净的快照 jmap -dump:live,formatb,file/tmp/heap_after_fullgc.hprof pid用 MATMemory Analyzer Tool打开Leak Suspects Report直接指出问题Problem Suspect 1: One instance of com.alibaba.druid.pool.DruidDataSource loaded by sun.misc.Launcher$AppClassLoader 0x780000000 occupies 1,234,567,890 (35.21%) bytes. The memory is accumulated in one instance of java.util.concurrent.LinkedBlockingQueue$Node loaded by system class loader.Druid 连接池的LinkedBlockingQueue占用了 1.2GB继续深挖发现DruidDataSource中有一个字段// Druid 连接池内部的回收连接队列 private LinkedBlockingQueueDruidPooledConnection connections;这个队列里积压了超过800 个连接对象每个连接持有大量PreparedStatement缓存和结果集缓冲区。2.3 第三层代码层根因定位追到业务代码发现一个经典的数据库操作模式Service public class OrderService { Autowired private JdbcTemplate jdbcTemplate; /** * 批量订单查询 —— 问题代码 */ public ListOrderDTO batchQuery(ListLong orderIds) { ListOrderDTO results new ArrayList(); for (Long orderId : orderIds) { // 每次循环新开连接且没有正确释放 try (Connection conn dataSource.getConnection()) { String sql SELECT o.*, oi.*, ol.* FROM t_order o LEFT JOIN t_order_item oi ON o.id oi.order_id LEFT JOIN t_order_log ol ON o.id ol.order_id WHERE o.id ?; // 查询结果包含大量 TEXT 字段商品描述、备注等 ListMapString, Object rows jdbcTemplate.queryForList(sql, orderId); // 结果对象转换 —— 持有所有原始数据 results.add(convertToDTO(rows)); } // try-with-resources 会关闭连接 } return results; } }三个致命问题问题影响严重度N1 循环内获取连接每次迭代从连接池借新连接批量 500 个 ID 借还 500 次 致命连接未立即归还池虽然try-with-resources关连接但 Druid 的回收连接会先进队列缓冲再归还 严重TEXT 字段全量加载每次查询加载所有大字段JDBC ResultSet 底层byte[]在连接关闭前不释放 严重根因链N1 循环借连接 → Druid 连接回收队列积压 800 连接 → 每个连接持有 byte[] 缓冲区TEXT字段 → 老年代被大对象填满 → Full GC 频繁三、优化方案三板斧先看清问题的全貌——从请求到 Full GC 的完整链路┌─────────────────────────────────────────────────────┐ │ 请求进入 │ │ POST /api/orders/batch { ids: [1,2,3,...,500] } │ └─────────────────────┬───────────────────────────────┘ ▼ ┌─────────────────────────────────────────────────────┐ │ OrderService.batchQuery() │ │ ┌─────────────────────────────────────────────┐ │ │ │ for (id : orderIds) { // 500 次循环! │ │ │ │ conn ds.getConnection() ← 每次借连接 │ │ │ │ SELECT * FROM ... WHERE id ? │ │ │ │ TEXT 字段 → byte[] 缓冲区 │ │ │ │ conn.close() → 进 Druid 回收队列(积压!) │ │ │ │ } │ │ │ └─────────────────────────────────────────────┘ │ └─────────────────────┬───────────────────────────────┘ ▼ ┌─────────────────────────────────────────────────────┐ │ Druid 连接池 │ │ ┌──────────────────────────────────────┐ │ │ │ LinkedBlockingQueueConnection │ │ │ │ ████████████████████████████ 800个 │ │ │ │ 每个连接持有 byte[] 缓冲区(含TEXT数据) │ │ │ │ → 累计 1.2GB 无法被 GC 回收! │ │ │ └──────────────────────────────────────┘ │ └─────────────────────┬───────────────────────────────┘ ▼ ┌─────────────────────────────────────────────────────┐ │ JVM 堆 (4GB) │ │ ┌─────────┬──────────────────────────────────┐ │ │ │ Young │ Old Gen: ████████████████ 92% │ │ │ │ Gen │ ↑ Allocation Failure → Full GC │ │ │ └─────────┴──────────────────────────────────┘ │ └─────────────────────────────────────────────────────┘3.1 第一板斧改批量查询治本/** * 优化后的批量查询 —— 使用 IN 子句一次搞定 */ public ListOrderDTO batchQueryOptimized(ListLong orderIds) { if (CollectionUtils.isEmpty(orderIds)) { return Collections.emptyList(); } // 分批处理避免 IN 子句过长 ListOrderDTO allResults new ArrayList(); ListListLong batches Lists.partition(orderIds, 200); for (ListLong batch : batches) { String placeholders batch.stream() .map(id - ?) .collect(Collectors.joining(,)); String sql String.format( SELECT o.id, o.order_no, o.status, o.amount, oi.product_name, oi.quantity, // 只选需要的字段 ol.operation, ol.create_time FROM t_order o LEFT JOIN t_order_item oi ON o.id oi.order_id LEFT JOIN t_order_log ol ON o.id ol.order_id WHERE o.id IN (%s), placeholders); // 指定字段类型避免不必要的类型转换 Object[] params batch.toArray(); int[] argTypes new int[batch.size()]; Arrays.fill(argTypes, Types.BIGINT); ListOrderDTO batchResults jdbcTemplate.query( sql, params, argTypes, new OrderDTOMapper() // 自定义 RowMapper只映射需要字段 ); allResults.addAll(batchResults); } return allResults; }优化要点优化项优化前优化后收益数据库交互次数500 次/请求3 次/请求分 3 批减少 99.4%连接借用次数500 次1 次循环内复用池压力降至 1/500单次查询字段数~40 个SELECT *8 个内存占用减 70%RowMapperqueryForList全加载自定义 RowMapper零中间 Map 对象3.2 第二板斧优化 Druid 连接池参数Druid 的回收连接有一个内部缓冲队列默认行为在批量归还时会导致短时积压spring: datasource: druid: # 连接池核心参数 initial-size: 5 min-idle: 5 max-active: 20 # ← 从 100 降到 208核机器足够了 max-wait: 3000 # ← 获取连接超时 3s快速失败优于排队 # 关键回收连接策略 phy-timeout-millis: 1800000 # 物理连接存活 30 分钟 min-evictable-idle-time-millis: 300000 # 空闲 5 分钟回收 time-between-eviction-runs-millis: 60000 # 每分钟检查一次 # 关闭 Druid 的使用后缓冲归还 # 这会让连接立即归还到池而非进入回收队列 remove-abandoned: false # 不在生产开这个用下面代替 # 连接验证 —— 防止拿到已断开的连接 test-while-idle: true validation-query: SELECT 13.3 第三板斧JVM 参数调优# 优化后的 JVM 参数 -Xms4g -Xmx4g # 堆内存保持 4G -XX:UseG1GC # G1GC -XX:MaxGCPauseMillis200 # 目标最大暂停 200ms -XX:G1HeapRegionSize4m # Region 大小 4M堆 4G / 2048 2M取 4M -XX:InitiatingHeapOccupancyPercent35 # 老年代 35% 触发并发标记默认 45% -XX:G1ReservePercent10 # 保留 10% 给晋升默认 10% -XX:ConcGCThreads2 # 并发 GC 线程数 -XX:ParallelGCThreads6 # 并行 GC 线程数 -XX:ParallelRefProcEnabled # 并行处理引用 -XX:ExplicitGCInvokesConcurrent # System.gc() 触发并发 GC 而非 Full GC -XX:HeapDumpOnOutOfMemoryError # OOM 时 dump -XX:HeapDumpPath/var/log/app/ # dump 路径关键调整说明关键参数: InitiatingHeapOccupancyPercent 旧值: 45 (默认) 新值: 35 G1 在 45% 老年代占用时才开始并发标记。我们的场景中大量大对象在短时间内 涌入老年代45% 时已经来不及标记完成导致 Full GC。 降到 35% 后并发标记有更多时间窗口Mixed GC 可以更早介入 Full GC 次数从 80 次/小时降到 1-2 次/小时。四、效果验证4.1 上线前后对比压测数据模拟生产流量 300 QPS指标优化前优化后改善幅度平均响应时间 (P50)2,340 ms87 ms↓ 96.3%99 分位响应时间 (P99)8,560 ms312 ms↓ 96.4%Full GC 频率~20 次/小时0.5 次/小时↓ 97.5%单次 Full GC 耗时2-4 秒0.5-1 秒↓ 60%老年代平均使用率92%48%↓ 44%Young GC 平均耗时45 ms18 ms↓ 60%吞吐量210 QPS335 QPS↑ 59.5%⚠️ 注以上数据来自压测环境模拟生产效果可能因业务负载略有差异仅供参考。4.2 GC 日志对比优化前[GC pause (G1 Evacuation Pause) (young), 0.0451234 secs] [Full GC (Allocation Failure) 3.8G-2.1G(4.0G), 3.2345678 secs] ← 频繁出现优化后[GC pause (G1 Evacuation Pause) (young), 0.0181234 secs] [GC pause (G1 Evacuation Pause) (mixed), 0.0345678 secs] ← Mixed GC 替代了 Full GC4.3 jstat 对比优化后连续观察S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 87.32 34.21 45.67 78.23 72.12 1567 28.345 2 3.456 31.801 0.00 87.32 56.43 46.12 78.23 72.12 1568 28.367 2 3.456 31.823 0.00 87.32 78.89 46.89 78.23 72.12 1569 28.389 2 3.456 31.845 ... (10 分钟后) 0.00 89.12 23.45 48.23 78.23 72.12 1602 29.012 2 3.456 32.468老年代稳定在 45-50%Full GC 几乎消失。五、总结与最佳实践复盘要点层级问题教训代码层N1 循环内获取连接批量操作必须用 IN/JOIN避免循环内getConnection()连接池Druid 回收队列积压max-active不要盲目设大8C16G 配 20 个连接就够SQL 层SELECT *加载大字段只选需要的列TEXT/BLOB 字段按需加载JVM 层IHOP默认 45% 太保守大对象多的场景降到 35%给 Mixed GC 留时间窗口监控发现滞后Full GC 频率应作为核心告警指标阈值设 5 次/小时检查清单下次遇到 GC 问题按这个顺序排查jstat -gcutil pid 1000— 看 FGC 频率和 YGCT/FGCT 占比GC 日志— 看 Full GC 触发原因Allocation FailurevsErgonomicsjmap -histo:live pid— 统计存活对象 Top 20MAT 堆 dump 分析— 找 Dominator Tree 中的大户代码审查— 检查连接池使用、大对象创建、缓存策略调整参数 → 压测验证 → 灰度上线文章摘要本文通过一次线上 Full GC 频繁的真实案例完整呈现 JVM 调优的三层排查方法——GC 日志分析定位根因类型、堆 dump 分析找到内存大户Druid 连接池积压 1.2GB、代码审查发现 N1 查询模式。优化采用三板斧用 IN 子句替代循环内 getConnection、调优 Druid 连接池回收策略、调整 G1 的 IHOP 参数。优化后响应时间从 2.3s 降至 87msFull GC 频率降低 97.5%。