Java 使用 VisualVM 排查内存泄露

布满荆棘的人生 2023-10-12 12:24 70阅读 0赞

#### 文章目录 ####

*  1. 问题发生
 *  2. 排查过程
 *   *   *  2.1 初步排查
         *  2.2 Visual VM 内存分析
         *  2.3 代码分析

## 1. 问题发生 ##

线上突发告警，笔者负责的一个服务老年代内存使用率到达 75% 阈值，于是立即登录监控系统查看数据。拉长时间周期，查看最近 7 天的 GC 和老年代内存占用，监控截图如下。可以看到老年代占用内存的最低点在逐步抬升，初步判断是发生了内存泄露

![在这里插入图片描述][143384c3be0b4f1184d3507682dca66d.png_pic_center]

## 2. 排查过程 ##

#### 2.1 初步排查 ####

从监控上看，这个服务的两个实例老年代内存占用情况并不一致，其中疑似发生内存泄露的是跑脚本的机器。于是登录到目标机器，首先执行 `jmap -histo 1 | head -n 100` 命令查看目标进程的堆内存占用前 100 的对象，发现其中 SkyWalking 的一个 trace 追踪对象 NoopSpan 实例总数达到了 2600 万之巨，内存占用也达到 600M，明显不正常  
![在这里插入图片描述][516c6612c17f4f4698981ebba096504c.jpeg_pic_center]

#### 2.2 Visual VM 内存分析 ####

由于生产环境控制严格，不允许在线 dump 堆内存数据，于是在预发环境执行 `jmap -dump:format=b,file=/tmp/dump 1` 命令，将有相同问题的 java 进程的堆内存 dump 下来。下载拿到 dump 文件后，需要打开 VisualVM 加载该文件，以下为操作步骤

1.  首先打开 VisualVM，点击截图中的按钮加载 dump 文件  
    ![在这里插入图片描述][27aca51aff7e45f494e359cf5ef61058.png_pic_center]
2.  dump 文件加载后，点击截图中框出来的按钮，切换选项卡为查看对象  
    ![在这里插入图片描述][1c6d0786a4e846c2821b6587c2568f0c.png_pic_center]
3.  由于笔者初步排查已经确定了可疑的实例为 NoopSpan，故在对象选项卡界面直接过滤该对象，并展示其 `相关引用、GC root`。需注意 `GC root` 是引用链的起点，从 VisualVM 的分析可以看到 NoopSpan 的实例都是以 LinkedList 节点的形式存在，引用链条为 `FastThreadLocalThread -> threadLocals(ThreadLocalMap) -> table(ThreadLocalMap$Entry[] 数组) -> [1](ThreadLocalMap$Entry 数组第一个元素) -> value(键值对 ThreadLocalMap$Entry 的值) -> activeSpanStack (SkyWalking 的 TracingContext 内部暂存 span 的 LinkedList) -> 链表的一级级前后指针`，至此可以猜测是 ThradLocal 使用不当(例如 ThreadLocal 使用后没有remove)导致内存泄露  
    ![在这里插入图片描述][520beb3ee9894e06b454682c51d20492.png_pic_center]
4.  确定了引用链，则可以看到 NoopSpan 应该是被封装为 LinkedList 的节点被保存在对象TracingContext\#1 的内部链表 `activeSpanStack` 中。此时查看该对象的链表的具体元素数据，可以看到总共有1万多个元素，点开第一个节点，查看该 LocalSpan 的名称，确定当前 SkyWalking 的 trace 记录的起点为这个 LocalSpan 的创建  
    ![在这里插入图片描述][d6b50790f8cf415787f417819bf081a7.png_pic_center]

#### 2.3 代码分析 ####

1.  在项目中搜索上一节分析出的 LocalSpan 名称，发现创建该 Span 主要是为了在多线程环境下跨线程传递 trace，创建入口为 `ContextManager#createLocalSpan()` 方法。这个方法会创建 Trace 上下文对象 TracingContext 并将其设置到 ThreadLocal 中，创建出 TracingContext 对象后还会调用其相关方法创建 LocalSpan 对象，并将创建的 LocalSpan 对象存入 TracingContext 内部的 `activeSpanStack` 链表。至此基本印证了 VisualVM 的引用分析，大致确定是 ThreadLocal 的使用导致了内存泄露
    
        public static AbstractSpan createLocalSpan(String operationName) {
              
             operationName = StringUtil.cut(operationName, OPERATION_NAME_THRESHOLD);
             AbstractTracerContext context = getOrCreate(operationName, false);
             return context.createLocalSpan(operationName);
         }
        
         private static AbstractTracerContext getOrCreate(String operationName, boolean forceSampling) {
              
             AbstractTracerContext context = CONTEXT.get();
             if (context == null) {
              
                 if (StringUtil.isEmpty(operationName)) {
              
                     if (logger.isDebugEnable()) {
              
                         logger.debug("No operation name, ignore this trace.");
                     }
                     context = new IgnoredTracerContext();
                 } else {
              
                     if (EXTEND_SERVICE == null) {
              
                         EXTEND_SERVICE = ServiceManager.INSTANCE.findService(ContextManagerExtendService.class);
                     }
                     context = EXTEND_SERVICE.createTraceContext(operationName, forceSampling);
                 }
                 CONTEXT.set(context);
             }
             return context;
         }
2.  我们知道，在线程池环境下使用 ThreadLocal 如果忘记 remove 很容易发生内存泄漏。继续阅读源码，发现 ThreadLocal 被移除的触发点在 `ContextManager#stopSpan()` 方法，该方法每调用一次就会将之前添加到 TracingContext 内部的 `activeSpanStack` 链表中的 Span 移除，直到链表元素数量为 0 才会去 remove 掉 ThreadLocal
    
        public static void stopSpan() {
              
             final AbstractTracerContext context = get();
             if (Objects.isNull(context)) {
              
                 return;
             }
             stopSpan(context.activeSpan(), context);
        
         }
         private static void stopSpan(AbstractSpan span, final AbstractTracerContext context) {
              
             try {
              
                 if (context.stopSpan(span)) {
              
                     CONTEXT.remove();
                     RUNTIME_CONTEXT.remove();
                 }
             } catch (Throwable t) {
              
                 //
             }
         }
3.  此时回到项目代码一看，问题一目了然，代码中创建了 LocalSpan 但是没有调用相关方法把它 stop 掉，导致 LocalSpan 一直在 TracingContext 内部的 `activeSpanStack` 链表中堆积，并且由于链表前后指针的存在无法回收，最终导致了内存泄漏

[143384c3be0b4f1184d3507682dca66d.png_pic_center]: https://img-blog.csdnimg.cn/143384c3be0b4f1184d3507682dca66d.png#pic_center
[516c6612c17f4f4698981ebba096504c.jpeg_pic_center]: https://img-blog.csdnimg.cn/516c6612c17f4f4698981ebba096504c.jpeg#pic_center
[27aca51aff7e45f494e359cf5ef61058.png_pic_center]: https://img-blog.csdnimg.cn/27aca51aff7e45f494e359cf5ef61058.png#pic_center
[1c6d0786a4e846c2821b6587c2568f0c.png_pic_center]: https://img-blog.csdnimg.cn/1c6d0786a4e846c2821b6587c2568f0c.png#pic_center
[520beb3ee9894e06b454682c51d20492.png_pic_center]: https://img-blog.csdnimg.cn/520beb3ee9894e06b454682c51d20492.png#pic_center
[d6b50790f8cf415787f417819bf081a7.png_pic_center]: https://img-blog.csdnimg.cn/d6b50790f8cf415787f417819bf081a7.png#pic_center