文章目录
- 1. 问题发生
- 2. 排查过程
- 2.1 初步排查
- 2.2 Visual VM 内存分析
- 2.3 代码分析
1. 问题发生
线上突发告警,笔者负责的一个服务老年代内存使用率到达 75% 阈值,于是立即登录监控系统查看数据。拉长时间周期,查看最近 7 天的 GC 和老年代内存占用,监控截图如下。可以看到老年代占用内存的最低点在逐步抬升,初步判断是发生了内存泄露
2. 排查过程
2.1 初步排查
从监控上看,这个服务的两个实例老年代内存占用情况并不一致,其中疑似发生内存泄露的是跑脚本的机器。于是登录到目标机器,首先执行 jmap -histo 1 | head -n 100
命令查看目标进程的堆内存占用前 100 的对象,发现其中 SkyWalking 的一个 trace 追踪对象 NoopSpan 实例总数达到了 2600 万之巨,内存占用也达到 600M,明显不正常
2.2 Visual VM 内存分析
由于生产环境控制严格,不允许在线 dump 堆内存数据,于是在预发环境执行 jmap -dump:format=b,file=/tmp/dump 1
命令,将有相同问题的 java 进程的堆内存 dump 下来。下载拿到 dump 文件后,需要打开 VisualVM 加载该文件,以下为操作步骤
-
首先打开 VisualVM,点击截图中的按钮加载 dump 文件
-
dump 文件加载后,点击截图中框出来的按钮,切换选项卡为查看对象
-
由于笔者初步排查已经确定了可疑的实例为 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)导致内存泄露
-
确定了引用链,则可以看到 NoopSpan 应该是被封装为 LinkedList 的节点被保存在对象TracingContext#1 的内部链表
activeSpanStack
中。此时查看该对象的链表的具体元素数据,可以看到总共有1万多个元素,点开第一个节点,查看该 LocalSpan 的名称,确定当前 SkyWalking 的 trace 记录的起点为这个 LocalSpan 的创建
2.3 代码分析
-
在项目中搜索上一节分析出的 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; }
-
我们知道,在线程池环境下使用 ThreadLocal 如果忘记 remove 很容易发生内存泄漏。继续阅读源码,发现 ThreadLocal 被移除的触发点在
ContextManager#stopSpan()
方法,该方法每调用一次就会将之前添加到 TracingContext 内部的activeSpanStack
链表中的 Span 移除,直到链表元素数量为 0 才会去 remove 掉 ThreadLocalpublic 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) { // } }
-
此时回到项目代码一看,问题一目了然,代码中创建了 LocalSpan 但是没有调用相关方法把它 stop 掉,导致 LocalSpan 一直在 TracingContext 内部的
activeSpanStack
链表中堆积,并且由于链表前后指针的存在无法回收,最终导致了内存泄漏