上周四凌晨两点手机上的监控告警突然疯狂震动生产环境订单核心服务的 Full GC 频率直接超出阈值接口超时率冲到 16%下游支付回调大面积失败。值班的实习生电话打过来的时候我刚睡下不到四十分钟头都是懵的摸过电脑就开始连 VPN 登跳板机。本来以为就是常规的内存泄漏要么是哪个地方缓存没清要么是大对象一次性加载太多。结果前前后后折腾了整整三天踩了好几个想当然的坑走了无数弯路最后找到根因的时候说出来都有点哭笑不得 —— 但还是老老实实把整个过程记下来。线上排查这事儿经验都是踩坑踩出来的说不定你哪天也会在同样的地方绕圈子。告警初现先摸 GC 情况登到服务器上第一件事先确认进程还活着ps -ef | grep order拿到 PID直接上 jstat 看 GC 概况。bash运行jstat -gcutil 28467 1000 10输出大概是这么个状态plaintextS0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 98.23 97.45 94.12 93.45 91.20 1246 32.456 128 214.342 246.798 0.00 98.23 98.11 94.12 93.45 91.20 1247 32.481 128 214.342 246.823当时心里咯噔一下。老年代占比 94%Full GC 触发了 128 次单次耗时快两秒而且 GC 之后老年代占比几乎没下来 —— 这说明大部分对象都是强引用存活回收不掉基本就是内存泄漏没跑了。顺便看了下新生代Eden 区满得飞快YGC 一分钟能来两三次说明还在持续不断生成新对象。正常情况下我们这个服务 YGC 大概十分钟一次这明显不对。第一次踩坑dump 差点把磁盘干满按常规流程内存泄漏肯定要 dump 堆内存下来分析。当时脑子有点不清醒直接就敲了命令bash运行jmap -dump:formatb,fileorder.hprof 28467敲完等了半分钟没反应再看终端提示磁盘空间不足。当时人瞬间清醒了赶紧df -h看了下/data 目录只剩 600 多 M而我们堆内存设的是 8Gdump 出来至少六七 G。更糟的是dump 虽然失败了但生成的临时文件占了几百 M把磁盘彻底占满了服务日志写不进去直接触发了更严重的告警。没办法先摘了故障节点的流量删了临时文件和旧日志腾空间。这里必须提个醒生产环境 dump 堆内存一定要先看磁盘空间最好写到专门的大数据盘别写系统盘或者日志盘不然很容易把盘打满直接搞挂服务血的教训。摘了流量之后服务压力降下来GC 频率也缓了点。找了个空闲大盘目录重新 dump 了一份大概 7.2Gscp 到本地慢慢分析。MAT 初分析错把缓存当元凶用 MAT 打开 hprof 文件先看 Histogram存活对象数量排第一的是 OrderDTO足足 13 万多个占了差不多 3G 内存。排第二的是 String大部分都是订单号和用户 ID。当时第一反应本地缓存泄漏了。我们服务里确实有个本地缓存用 ConcurrentHashMap 实现存热点订单数据带过期时间。之前就出过一次缓存过期逻辑写反的问题所以第一时间就怀疑到它头上。顺着引用链往上扒发现这些 OrderDTO 确实大部分都被一个叫orderCache的 ConcurrentHashMap 引用着。当时还挺得意觉得这么快就定位到了转头就去翻缓存代码。代码里缓存的过期逻辑是每个 value 包一层带过期时间戳然后有个定时任务每小时清理一次过期的 key。当时一看就骂了哪个天才写的一小时清一次订单热点数据最多存五分钟一小时清理一次缓存不越积越多才怪。没多想直接把清理周期改成十分钟还加了个容量上限超过 1 万条自动淘汰最老的。改完打包灰度发布了一个节点观察了两个小时GC 频率确实降下来了老年代占比稳定在 30% 左右。当时觉得问题解决了还跟实习生说你看就是缓存清理不及时的问题以后写缓存注意点。然后就回去补觉了。结果周五上午十点又告警了。调参治标好了半天又炸了告警过来的时候我人都傻了。昨天明明修了缓存怎么又炸了登上去一看老年代又涨到 90% 了Full GC 又开始频繁触发。这时候就有点慌了难道不是缓存的问题再看缓存大小已经被限制在 1 万条撑死也就几百 M不可能占 3 个 G。那剩下的对象哪来的当时有点病急乱投医怀疑是 JVM 参数设置不合理。我们的参数是-Xms8g -Xmx8g -Xmn2g新生代只有 2G会不会是对象太多新生代放不下直接晋升老年代了说干就干把新生代调到 4G还加了-XX:MaxTenuringThreshold15让对象在新生代多熬几次 YGC 再进老年代。改完重启确实又好了老年代增长速度慢了很多。但我心里清楚这是治标不治本。如果真的有内存泄漏不管新生代多大最后老年代还是会满只是时间问题。果然周五晚上八点又告警了。这时候我才意识到问题没那么简单之前的方向错了。二次 dump对比存活对象找差异这次不敢大意了专门挑了低峰期在两个不同时间点各 dump 了一份堆内存间隔一小时专门对比存活对象的增长情况。先用jmap -histo:live看了下存活对象排除缓存里的 1 万条 OrderDTO还有 12 万条不知道哪来的。而且一小时之内OrderDTO 又多了八千多个这明显不正常我们正常一小时订单量也就一千多。这时候就不能只看大对象排行榜了得扒深层引用链。用 MAT 的支配树功能一点点往下挖发现除了 orderCache 的引用还有大量 OrderDTO 的引用来自一个个 Thread 对象每个线程里都有一个 ArrayList里面存着几十到几百个 OrderDTO 不等。Thread 对象ArrayList第一反应是 ThreadLocal。我们代码里确实有很多地方用 ThreadLocal 存上下文比如用户信息、请求 ID 这些。但是正常 web 请求拦截器最后都会清理 ThreadLocal 啊怎么会累积这么多然后数了一下持有 OrderDTO 的线程一共有 47 个名字都是business-thread-pool-xxx。看到这个线程名我心里一下就有数了 —— 这是我们业务线程池的线程专门跑定时任务和异步回调的。根因确认线程池复用留下的烂摊子顺着线程找下去果然每个线程的 ThreadLocalMap 里都有一个 RequestContext 的 key对应的 value 是一个 Context 对象里面有个叫traceBizData的 ArrayList那些 OrderDTO 全存在这个 List 里。RequestContext 是我们之前封装的公共工具类用来存当前请求的链路数据方便日志打印和问题排查。里面有个addBizData方法业务代码里可以把关键业务对象塞进去打印错误日志的时候会自动带出来。正常的 HTTP 请求在 Spring 拦截器的afterCompletion方法里会调用RequestContext.clear()清空所有数据所以不会有问题。但是定时任务和异步线程不走 Spring 拦截器更坑的是写定时任务的同事为了方便排查问题在循环查询订单的逻辑里每查一个订单就调用一次RequestContext.addBizData(order)想着跑完任务日志里能看到处理过的订单。然后他没在任务结束的时候调用 clear 方法。我们的业务线程池是核心线程数 50 的固定线程池线程常驻不会销毁。也就是说这 50 个线程每次跑定时任务都会往自己 ThreadLocal 里的 ArrayList 加一堆订单对象跑完也不清下次跑接着加越积越多。算一笔账每天跑 24 次定时任务每次处理 1000 个订单一天下来每个线程就存了几千个订单对象50 个线程加起来十几万条对象占 3G 多内存完全对得上。而且因为这些对象被 ThreadLocal 强引用着只要线程不死就永远回收不掉只能眼睁睁看着老年代一点点被占满最后频繁 Full GC。当时找到根因的时候我盯着屏幕愣了好半天。说复杂吧其实就是个 ThreadLocal 没清理的低级错误说简单吧前前后后折腾了三天绕了无数弯路谁能想到问题出在一个没人注意的公共工具类上。修复上线紧急止血 长期方案找到原因就好办了。紧急修复很简单在定时任务的方法外层包一层 try-finallyfinally 里调用RequestContext.clear()。改完上线观察了一晚上老年代占比稳定在 25% 左右YGC 频率也恢复正常Full GC 彻底没了。但这只是治标。总不能以后所有异步任务、线程池里的代码都要手动记得清 ThreadLocal 吧只要有人忘写一次就可能再出一次线上事故。所以后面又做了几个长期的优化给 RequestContext 加了一个 execute 方法用函数式接口包裹业务逻辑执行完自动清理不用手动写 finally。大概长这样java运行public static T T execute(SupplierT supplier) { try { return supplier.get(); } finally { clear(); } }以后异步任务里要用到上下文的统一用这个方法从机制上避免漏清理。给所有自定义的线程池都加了装饰器提交任务的时候自动包裹清理逻辑。用 ThreadPoolExecutor 的beforeExecute和afterExecute也能做但我们用了装饰器模式更灵活一点。加了监控项定期采集老年代增长速率、存活对象 Top10还有线程池的线程状态一旦出现异常增长提前告警不用等 Full GC 炸了才发现。补了团队的代码规范专门加了 ThreadLocal 的使用规则禁止在 ThreadLocal 里存大对象和集合只要涉及线程池复用必须保证清理逻辑公共工具类必须提供自动清理的封装不能只暴露手动清理方法写在最后这次事故折腾了整整三天说起来都是些很基础的知识点但真到了线上排查的时候很容易被表面现象带偏走很多弯路。做技术这么多年见过太多线上事故根源往往都不是什么高深的技术难题就是一些不起眼的小细节一些想当然的 “应该没问题”。比如默认公共组件是靠谱的默认写代码的人会记得清理默认定时任务和 web 请求走一样的链路。但线上环境从来不会跟你讲 “默认”只要有一个地方没考虑到它就会在你最意想不到的时候炸给你看。还有一点感触很深线上排查千万不要急着下结论。我第一次看到缓存引用的时候想当然就定了性结果白白浪费了时间。遇到问题多问几个 “为什么”多验证几次不要看到一个疑似原因就觉得找到了根因。毕竟线上故障不会因为你觉得修好了就真的好了它只会在你放松警惕的时候再给你一巴掌。