metaspace 和 groovy

最近线上遇到个问题,简单来说就是 metaspace oom。

现象

异常日志是 metaspace oom, 堆栈阻塞在 groovy classLoader loadclass 的堆栈上。

我们的业务上确实嵌入了 groovy 代码, 动态执行, 但是 该groovy 代码并不会被频繁更新。

深入排查问题的时候遇到几个很奇怪的现象

  1. 重现打印 jstat -gcutil, 发现 metaspace 百分比并不高 每次都不同,22+%, 50+%, 90+% 都有
  2. 抛出异常的时候 老年代也不高,说明只能是 metaspace 的原因
  3. 调大 metaspace 后确实能恢复,说明 metaspace 确实不够用, 分别对metaspace 调大到 500M, 700M, 1G metaspace 的白分别都是90+%
  4. 查看实际的 metaspace 空间占用后,发现,虽然高并发下,一开始会占用300多mb 的metaspace,但是在运行一段时间后,会减少,并回落到正常水平。

下面将逐步分析

jstat 显示metaspace不正确

首先,由于已知问题一定是metaspace 溢出, 只是不清楚为啥jstat 显示不正确。

由于 metaspace 属于堆外内存, jmap 查不到。

然而,java8 新引入了 Native Memory Tracking 通过jcmd 查, 确实观测到了metaspace 不断增长的现象, 并且同时,jstat 并不增长。

附: 查看metaspace 方法,在运行java进程上添加参数

1
2
3
-XX:NativeMemoryTracking=summary
-XX:+UnlockDiagnosticVMOptions
-XX:+PrintNMTStatistics

运行期执行 jcmd {pid} VM.native_memory summary 观测

然后研究了 groovy 的classloader 之后便打算重现出来。

由于 groovy 的classloader 是自己的classloader, 于是这里也写一个classloader, 模拟class泄漏的情况,观察 jstat 是否不变

代码在gist

然后, 启动后,同时 打印jcmd 和 jstat 可以明显观察到, jstat metaspace 不变, jcmd 的 Class 区不断增大的现象, 直至oom

结论: jstat 只能追踪到 AppClassLoader 和 ExtClassloader 和 Bootstrap, 其他的 自定义的 classloader load 的类,会进 metaspace, 但是jstat 无法追踪到。

groovy 为何占用这么多metaspce?

首先,在研究groovy 为啥占用 metaspace 之前,先对线上的现象做了详细的观察。

  1. 和并发有关,流量大的时候,必现oom, 流量小不会出现
  2. 调大 metaspace 空间后,长期运行正常,metaspace 没有增长,而是保持在一个固定范围内,说明 我们现有的使用 groovy 的方式并没有问题,不存在内存泄漏。

猜测:

groovy 一定存在一种缓存class的机制,并且,他对这个缓存 并没有线程安全的控制。

首先,执行groovy 脚本需要经过以下几个步骤

  1. 初始化 groovy scriptEngine
  2. eval 脚本
  3. 填入参数, invokeFunction

这里主要测试了以下几种情况

  1. 并发执行 步骤2
  2. 并发执行 步骤3

结果

注意: 运行时, 添加jvm启动参数 -verbose 可见类加载日志

情况1 结果

1
2
3
4
5
6
7
8
9
10
11
12
[Loaded Script14 from file:/groovy/script]
[Loaded Script15 from file:/groovy/script]
[Loaded Script2 from file:/groovy/script]
[Loaded Script9 from file:/groovy/script]
[Loaded Script18 from file:/groovy/script]
[Loaded Script20 from file:/groovy/script]
[Loaded Script17 from file:/groovy/script]
[Loaded sun.reflect.GeneratedConstructorAccessor5 from __JVM_DefineClass__]
[Loaded Script8 from file:/groovy/script]
[Loaded sun.reflect.GeneratedConstructorAccessor6 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor7 from __JVM_DefineClass__]
[Loaded Script16 from file:/groovy/script]

情况2 结果

1
2
3
4
5
6
7
8
9
10
[Loaded org.apache.commons.lang.StringUtils$contains$0 from file:/Users/caorong/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar]
[Loaded com.google.common.collect.Lists$Partition from file:/Users/caorong/.m2/repository/com/google/guava/guava/19.0/guava-19.0.jar]
[Loaded org.apache.commons.lang.StringUtils$contains from file:/Users/caorong/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar]


[Loaded com.xxxx.IpConvertUtil$getIpFromString$3 from file:/Users/caorong/.m2/repository/com/xxxxx/0.0.3-SNAPSHOT/xxxxx-0.0.3-SNAPSHOT-test.jar]
[Loaded com.xxxx.IpConvertUtil$getIpFromString$4 from file:/Users/caorong/.m2/repository/com/xxxxx/0.0.3-SNAPSHOT/xxxxx-0.0.3-SNAPSHOT-test.jar]
[Loaded com.xxxx.IpConvertUtil$getIpFromString$1 from file:/Users/caorong/.m2/repository/com/xxxxx/0.0.3-SNAPSHOT/xxxxx-0.0.3-SNAPSHOT-test.jar]
[Loaded com.xxxx.IpConvertUtil$getIpFromString$0 from file:/Users/caorong/.m2/repository/com/xxxxx/0.0.3-SNAPSHOT/xxxxx-0.0.3-SNAPSHOT-test.jar]
[Loaded com.xxxx.IpConvertUtil$getIpFromString$5 from file:/Users/caorong/.m2/repository/com/xxxxx/0.0.3-SNAPSHOT/xxxxx-0.0.3-SNAPSHOT-test.jar]

可见, 这2种情况均会造成重复load 类

groovy 均没有对重复加载类这种情况做限制。

源码分析

注意: 以下源码版本为 groovy-all-2.4.7

情况1分析

源码在 GroovyScriptEngineImpl.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
 Class getScriptClass(String script)
throws CompilationFailedException {

// classMap为全局的缓存,对每一个script 缓存下他的class
Class clazz = classMap.get(script);
if (clazz != null) {
return clazz;
}
// 内部真正将 script parse 为 class
clazz = loader.parseClass(script, generateScriptName());
classMap.put(script, clazz);
return clazz;
}

// parseClass 内部
public Class parseClass(GroovyCodeSource codeSource, boolean shouldCacheSource) throws CompilationFailedException {
// 重锁, 保证一个script 的parse过程串行
synchronized (sourceCache) {
Class answer = sourceCache.get(codeSource.getName());
if (answer != null) return answer;
answer = doParseClass(codeSource);
if (shouldCacheSource) sourceCache.put(codeSource.getName(), answer);
return answer;
}
}

首先, 将脚本动态parse为 class是一个比较慢的操作,当多线程下,会造成多个线程都进入 内部parseClass 的锁。 造成排队,并且依次parse 多个 重复class。

情况2分析

情况2, 代码执行的入口为 CallSiteArray

这里稍微拓展以下 groovy 执行脚本的原理,具体可以参考这篇文章, 也可以将 groovy 脚本 反编译后一看便知,他会把脚本都转换成 一个个 callSiteArray的静态函数。

然后,eval 的时候,仅会把import 的类给事先load。但是,脚本内部的一些静态函数会在执行时动态 load,而这正是造成了脚本被并发执行时重复load 的原因。

源码见 ClassInfo.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
public static ClassInfo getClassInfo (Class cls) {
LocalMap map = getLocalClassInfoMap();
if (map!=null) return map.get(cls);
return (ClassInfo) globalClassValue.get(cls);
}

private static LocalMap getLocalClassInfoMap() {
ThreadLocalMapHandler handler = localMapRef.get();
SoftReference<LocalMap> ref=null;
if (handler!=null) ref = handler.get();
LocalMap map=null;
if (ref!=null) map = ref.get();
return map;
}

我们知道, classloader 不能load 重复的类, 所以,如果加载了多个重复的类,她会在最后添加一个自增的数字,这也是为啥情况2的结果日志,会有很多 $x

代码见 ClassLoaderForClassArtifacts.java

1
2
3
4
5
6
7
8
9
10
public String createClassName(Method method) {
final String name;
final String clsName = klazz.get().getName();
if (clsName.startsWith("java."))
name = clsName.replace('.','_') + "$" + method.getName();
else
name = clsName + "$" + method.getName();
int suffix = classNamesCounter.getAndIncrement();
return suffix == -1? name : name + "$" + suffix;
}

同样的 map,和情况1一样,由于load 慢,造成了重复加载

groovy 为啥占用了metaspace 后,在一段时间后,会回收

groovy 内部存在一个缓存机制。

首先,抛出一个结论,类只有在他所属的类加载器被回收后, 才会被回收。

而 groovy 的 class 和 她的 classloader , 都是 softReference,他直接靠jvm 的gc机制,将classloader unload 了,

这也是为啥, 高并发下, metaspace 会在一开始增高, 之后会慢慢降低到正常水平。

至于 groovy 的类加载的缓存机制将在后面一片文章在深入写, 这里就不继续扩展。

总结

最后说一下在高并发场景下使用groovy 脚本的最佳(减少重复类)实践

  1. 同样的 script 保证只有一个 scriptEngine 操作他
  2. 同样的 script 在业务层在并发操作之前事先eval
  3. script里面尽量减少外部类的依赖,如果需要依赖,有条件的话最好预热调用一次(让外部类编译好)。
avatar

lelouchcr's blog