背景
staging 环境,某个车联网服务内存出现了内存泄露,相关同学在 06-14 及 06-15 两天分别采集了两个 dump 文件,以下简单记录分析过程。
内存泄露最常用的排查工具是 Eclipse Memory Analyzer (MAT),使用 MAT 打开两个 dump 文件。
首先看 Leak Suspects
疑点一:JarFile
org.springframework.boot.loader.jar.JarFile
是 Spring Boot 的类加载器,用于加载 jar 包。
猜测此问题与 Druid issue-3808 类似:
- 所有 jar 包被加载的次数几乎相同;
- 内存 dump 中相关对象的数量只有几千个,和请求量无关,更像是某些定时任务在做类加载:
- 06-14 的 dump 中加载次数约为 3250;
- 06-15 的 dump 中加载次数约为 1260;
可以通过升级或降级 mysql-connector-java
版本进行验证。
疑点二:LockPubSub
org.redisson.pubsub.LockPubSub
是 Redisson 的分布式锁实现,用于分布式锁的订阅和消息通知:加锁对象如果已经被锁定需要等待的时候,通过 pubsub 订阅消息注册一个 listener 来等待锁资源。
分析 06-14 的内存 dump,发现 key 7e5axxxc00:gateway:xx:zz:msg:task:lock:c53fxxxaa13a
的 listeners 达到 33206 个,内存占用达到 1.32 GB。
此问题与 redisson-issues-3577有些相似,但我在日志中没有找到这个服务锁的 timeout 日志(可能因为业务代码没打印),而只有获取锁失败的日志。
另外,业务日志中只有释放锁的日志,而没有加锁的日志(也可能因为业务代码没打印)。
进一步分析
1、对内存泄露部分的 char 数组进行聚合的结果(2.12 GB 的内存泄露,日志信息 1.66GB,占比接近 80%):
2、其中一个 char 数组到 gc roots 的路径:
这也是内存泄露的路径:OpenTelemetry 在做链路追踪时,会将一次 gRPC、HTTP 调用或 MQ 消费过程中的 Metrics 以及日志信息都放到它的 Context 对象中,这次调用或消费不结束,这些内存就会被引用而释放;业务使用分布式锁的方式可能存在问题,导致很多请求无法结束,大量对象存活无法释放。
3、以下为该服务打印日志的频率监控—-每分钟几千条日志。
4、另外通过Kibana 查询发现,有很多动辄几十 KB 的业务日志(敏感数据就不贴图了)。
5、服务的 GC 信息
综合上述信息,可以确定服务内存泄露,高概率是大日志导致的。
解决方法
- 升级或降级
mysql-connector-java
版本 - 避免大日志