SpringBoot的脚本引擎初始化也会导致OOM？你意想不到的坑点

• 1 前言

• 2 问题背景

• 3 问题定位

• 3.1 内存基本情况分析

• 3.2 一次失败的日志内存占用消除

• 3.3 一个奇怪的类：StringSequence？

• 3.4 StringSequence消失了？

• 3.5 谁在使用脚本引擎？

• 3.6 终显庐山真面目

• 4 深度分析

• 4.1 内存占用风险之：SPI加载ScriptEngineFactory

• 4.2 内存占用风险之：脚本引擎的资源消耗

• 4.3 内存占用风险之：类加载

• 5 总结

1 前言

项目运行过程中，我们一定都遇到过OOM的问题，大家也一定在想，OOM的问题能够有多特殊？我来简单举例，我们在排查问题中遇到的奇葩问题：

• 排查过程中，明明发现了占用了大量内存的实例对象，为什么在项目里面会找不到相关代码呢？

• 百度都不灵了，竟然也找不到这个类的任何信息？

• SpringBoot的启动在本地和服务器中的启动竟然还有这种差别？

• SpringBoot的脚本引擎初始化竟然也会导致OOM？

让我们带着这一系列的问题来看本次的文章。

2 问题背景

侠客汇作为二手回收商圈的第一款社交领域的APP，社交相关信息主要分布在找同行、做生意、同行圈和推荐四个页面。在同行圈推荐过程中需要完整的将用户相关信息和用户发布的帖子信息进行展示，这些展示数据是我们实时请求的，需要实时进行计算，所以我们采用多线程异步执行来提升性能。在我们紧锣密鼓的研发过程中，测试同学发现，服务总是莫名其妙的挂掉，之后就发生了如下对话：

测试同学：XXX，你快帮忙看一下，同行圈的列表刷一会就没数据了，你的服务动不动就挂掉，怎么回事啊。

研发同学：是不是测试环境有问题啊，访问的数据太多了？毕竟我们这个是实时计算的，多个线程在跑任务，不行加个内存试一下？

随后，我们的测试环境内存从4G调整到了8G，果然好了一点，但是好景不长，没有多久，又开始重复出现了当前问题。

测试同学：加了内存，还不行啊，你快看看吧，这个影响测试进度了。

研发同学：行，我看看具体怎能回事。

接下来看我们的特殊OOM问题的排查流程。

3 问题定位

服务部署过程中没有任何的报错信息，而且，在服务的运行过程中也没有明显的报错信息，而是在运行一段时间之后出现了这种错误。那么，大概率是内存的问题，先按照OOM的常规排查思路，按部就班的来。

3.1 内存基本情况分析

老规矩，jps抓一下业务服务进程的进程号。

因为业务场景是在项目运行一段时间后才出现的，必要是要一定的数据累计才行。我们需要借用工具压测一波， 通过apifox，20个并发压一波，同时借助jmap、jstat看一下内存和垃圾回收情况（GC）。

首先看一下我们的内存情况，执行命令：jmap -heap 44

对上述图片的内容进行分析。

首先，From Space 的使用率达到了惊人的百分之百，这就意味着from Space 中的内存已被完全占用，没有可用空间来分配新的对象。这可能导致应用程序在尝试分配新对象时遇到内存不足的问题。同时Java 虚拟机会触发一次GC来释放内存。这通常会导致暂停应用程序的执行，影响应用程序的响应时间。

其次，Concurrent Mark-Sweep generation的使用率也达到了80%，对于长时间运行的应用程序，这可能意味着对象的存活率较高，可能会导致频繁的垃圾回收。如果频繁发生这种情况，可能会导致性能下降，因为每次 GC 都需要暂停应用程序，而且如果在垃圾回收后，From Space仍然无法找到足够的空间来分配新对象，应用程序可能会抛出OutOfMemoryError，导致程序崩溃或无法正常运行，这就和我们的当前业务场景很相似了。

根据以上的结论，我们再来看一下GC的情况，执行命令：jstat -gcutil 6556 1000 100

果不其然，GC展示的情况和我们上面分析的内容基本一致。内存占用，尤其是老年代内存占用很高，流量打进来后，ygc次数快速上升，紧着ygc伴随的是fgc。

再次对当前图片的参数进行分析,内存不够用通常就是以下几种情况：

1.内存泄漏，应用程序占用的内存未能被释放，导致可用内存逐渐减少。但是内存泄漏是一个长期的过程，而且从Eden区和old区的使用率可以看出，gc过程会伴随比较彻底的内存回收，无明显的堆内存泄漏特征。

2.参数设置不合理，在测试环境，没有大量用户，不需要太大的参数，再说，我们已经调整了内存参数了，看来并没有彻底解决问题。

3.频繁创建对象，垃圾回收器来不及回收导致了OOM。

根据我们以上的结论，排除1和2两种场景，重点排查第三种情况这个问题。

3.2 一次失败的日志内存占用消除

在以上的分析中，我们已经推论，是堆内存被不合理的使用了，那就看一下堆内存中实例创建的情况。

执行命令：jmap -histo 3688 | more

在以上的堆内存的实例对象中，我们发现了一个可疑项，为什么有这么多日志事件呢？我们知道，通常来讲，为保证系统性能，日志是异步刷盘的。难道是日志的缓冲队列太大，导致OOM了？我们先排除一下可疑的选项。

但修改日志全局打印配置，比如控制日志级别，貌似比想象的要麻烦。通过多方尝试，最后找到了这个虚拟机入参，统一控制异步日志的事件队列：-DAsyncLoggerConfig.RingBufferSize=128。

我们将相关的参数添加之后，重新进行压测，再次查看堆内存的实例信息。

发现logger事件队列在视线里消失了，但是OOM的情况依然存在，说明我们只是排除了干扰项， 并没有实际的解决问题

3.3 一个奇怪的类：StringSequence？

继续排查，等等，好像发现了一个奇怪的东西，这StringSequence是什么东西？

既然存在的可疑选项，我们就继续排查，先去项目代码里面看一下，这个类到底是做什么用的。让人崩溃的事情发生了，搜遍了整个项目，没有搜到这个类的任何信息。即使动用搜索引擎，也没有找到相关说明。

不过，看上去，是一个Springboot的内置的东西。我们知道，Springboot会将所有的资源统一打包成一个fatjar，保证一个jar包就能启动整个服务，以实现微服务化。我们解压一下项目的jar包，按图索骥一下。

果然，这个StringSequence是springboot内置的东西。这种不是常用的类，居然有这么多实例，就非常值得怀疑，可以重点排查。

但是，项目源码里没有，那本地debug也排查不了它啊，那要不dump内存，分析一下？但服务器上的dump文件比较大，下载比较麻烦。

我们只能另辟蹊径，在本地启动，然后dump文件分析。这样操作更灵活，也省得去服务器上下载dump文件了。

3.4 StringSequence消失了？

idea里修改启动入参，然后开始让整个项目run起来，希望揭开庐山真面目。

可是，这个奇怪的StringSequnce居然又消失了？

…… 不对，有问题。刚才都说了，SpringBoot是用单一的fatjar包去启动的，那会不会是IDEA测试和服务器上的项目启动方式有区别呢？我们可以看一下idea的启动相关信息。拷贝idea控制台启动信息第一行就是了。

果然，idea和SpringBoot的原生启动方式是不一样的！idea是classpath+原生的main方法启动Springboot的。而通常，Springboot是一个fatjar启动。

如果是这样，那么想复现pod环境的问题，我们也改成jar包方式启动，再试一下。

去项目target目录找到打包的boot jar包，然后把classpath和idea的agent虚拟机入参去掉，重新启动。

启动成功、那个熟悉又陌生的StringSequence又回来了。

dump heap内存，然后就可以揭开这个奇怪的StringSequence的庐山真面目了。

3.5 谁在使用脚本引擎？

开始dump内存，执行命令：jmap -dump:live,format=b,file=dump.hprof 21896。

我们主要分析内存中类及对应的实例信息，决定用jhat命令，分析dump文件。

执行命令：jhat -J-Xmx4g dump.hprof ，加载堆转储文件。它将分析文件并启动一个 HTTP 服务器，允许你通过浏览器访问分析结果。

接下来，我们一步步寻找那个奇怪的StringSequence。

1.查询虚拟机所有类对应实例的统计信息,在当前的class页面可以看到很多信息，但是我们关注的是实例化对象的内存使用，所以，我们需要关心的是show instance counts for all class这个视图，看图片可以知道，这个视图有两个

• Including: 这个统计信息包含了所有类的实例，包括被 GC 标记为可达的（即仍然在使用中的对象）和不可达的（即可能已被回收但在堆转储中仍然存在的对象）。这个视图可以帮助你了解整个堆中存在的所有对象。

• Excluding: 这个统计信息则只包括当前仍然在使用的实例，即被 GC 标记为可达的对象。这个视图更关注于应用程序当前活跃的内存使用情况。

我们的问题是内存被大量占用，所以，我们直接关注excluding这个视图。

2.查询StringSequence类下边的所有实例列表

我们发现，当前视图的展示数量和控制台的显示数据差异比较大，怀疑是应该和dump那一时刻的垃圾回收行为有关，带着疑问，继续排查。

3.查询实例的字段值等详细信息

就是这里了，实例有个字段叫source，然后这个字段值是"file:/C:/Users/Administrator/IdeaProjects/hero_search/service/target/hero_search.jar!/BOOT-INF/lib/transport-netty4-client-7.6.2.jar!/META-INF/services/javax.script.ScriptEngineFactory "。

类看起来很陌生，不太像是我们常用的。不过javax.script.ScriptEngineFactory应该是一个线索。我们尝试搜一下。

看上去是一个脚本引擎，支持动态性的。那到底是谁在使用呢？还是没有明确的调用点。

内存分析只能解决数据是什么的问题，但不能解决方法链路问题。那么如何更方便的解决调用链路的问题呢？而且还得考虑到StringSequence是Springboot内置的，不在项目源码，不能用idea debug。所以，接下来只能通过其他的工具进行排查具体的调用链路问题。

3.6 终显庐山真面目

让我们定位一下到底是谁在初始化StringSequence。

关于arthas使用，可以参考arthas官网（https://arthas.aliyun.com/doc/），接入、使用都很简单，功能强大。

接下来组装一下命令：

1.由于我们要定位方法的调用链路，所以用stack命令。

2.由于我们要跟踪构造器，所以对应的是init方法。

3.由于请求过多会导致控制台打印乱序，可以限制一下命令的触发条件。

从StringSequence的构造函数可以看出，其第一个入参一定是上文提到的source字段。

综上，我们最终定位StringSequence初始化链路的arthas命令为：

stack org.springframework.boot.loader.jar.StringSequence'params[0].contains("hero_search.jar!/BOOT-INF/lib/transport-netty4-client-7.6.2.jar!/META-INF/services/javax.script.ScriptEngineFactory")'

元凶现身了。一个脚本引擎的频繁初始化代码。和刚才的脚本引擎使用的猜测也对上了

两层for循环调evaluate，然后evaluate里面重复初始化脚本引擎，那内存肯定不够用，必须改掉。

经查询，脚本引擎线程安全，可以并发情况下全局复用。所以，去掉每次初始化的成本，改造成一个全局可复用的引擎，再看看效果。

果然，那个奇怪的StringSequence消失了。内存也不会频繁的OOM了。谜底揭开，问题终于被彻底解决！！！

4 深度分析

问题定位只是直接目标，但疑问仍在：为什么一个引擎会占用这么多资源呢？这里可以继续分析一下，以获得更多的认知。

4.1 内存占用风险之：SPI加载ScriptEngineFactory

我们从调用栈可以看出，脚本引擎初始化需要ScriptEngineFactory，而ScriptEngineFactory加载用到了java的SPI机制。SPI机制的实现原理是遍历classpath下的所有jar包的META-INF/services目录，获取匹配的接口实现类。而这个过程依赖的是classloader的加载资源的能力。

SpringBoot为了将业务jar包封装在其fatJar里，替换系统类加载器为LaunchedURLClassLoader,而LaunchedURLClassLoader加载资源过程会遍历所有的业务jar包，并且每一个jar包的遍历过程中，会实例化一个StringSequence。这个也就解释了StringSequence内容为啥都是类似 "file:/C:/Users/Administrator/IdeaProjects/hero_search/service/target/hero_search.jar!/BOOT-INF/lib/transport-netty4-client-7.6.2.jar!/META-INF/services/javax.script.ScriptEngineFactory" 的字符串。因为需要遍历每个jar包尝试获取匹配的资源。

也解释了为啥会有这么多StringSequence的实例，因为项目引用jar包比较多，需要遍历279个path。

同时，部分解释了，为啥引擎实例化耗费资源：SPI的遍历jar包的机制是原因之一。

4.2 内存占用风险之：脚本引擎的资源消耗

我们刚才分析了脚本引擎初始化过程中，SPI的资源消耗。那脚本引擎本身资源消耗如何呢。因为从代码上看，ScriptEngine也会重复初始化，其实例的内存占用影响同样很关键。

我们可以借用arthas 的vmtool 分析一下脚本引擎的内存占用情况。

获取javax.script.ScriptEngine的一个实例，打印其成员变量,对应arthas命令为：

vmtool --action getInstances --className javax.script.ScriptEngine --express 'instances[0]'

可以看到，项目实例化的脚本引擎为NashornScriptEngine。其初始化需要很多配置，成本很高。

以gobal成员变量为例，我们可以简单看一下其字段数量：

vmtool --action getInstances --className javax.script.ScriptEngine --express 'instances[0].global.getClass().getDeclaredFields().length'

可以看到，一个global实例有126个成员变量，就这数量也足够恐怖了。

4.3 内存占用风险之：类加载

对于动态脚本，java的实现方案一般是通过动态类去支持，那重复创建脚本引擎会有什么影响呢？

答案是：每个引擎都有脚本生成动态类的缓存，重复初始化，会使缓存失效，导致重复地生成动态类，给GC造成很大压力。

代码路径：jdk.nashorn.internal.runtime.Context#compile

我们可以打开类加载监控,复现一下类加载、卸载的场景(vm新增启动入参：-verbose:class)

如下图，从控制台日志中，捕获到了18w次动态脚本引发的类加载事件。

我们知道，类卸载的条件非常苛刻，所以这里面会存在内存泄漏吗？

答案是不会。因为引擎对于脚本的动态类加载，自定义了一个类加载器。这样，当引擎及脚本不再使用，类加载器也会被回收，从而动态加载的类也会被卸载。（前提是服务器有充裕的资源去回收）

代码路径：jdk.nashorn.internal.runtime.Context#compile

如下图，从控制台日志中，捕获到了15w次和动态脚本相关的类卸载事件。

综上，重复创建ScprintEngine（实现类为NashornScriptEngine）的成本非常高，使用中一定要谨慎。

5 总结

整体排查问题的过程，其实也是对我们自身知识储备以及处理问题经验的一个考量。

首先要大胆的设想和怀疑，排除掉一些干扰项，例如，我们第一次排除的日志内存占用，对StringSequence实例出现产生的怀疑。

其次，要综合考量虚拟机提供的参数，我们根据内存的使用率判断出GC的大概情况，又根据多次GC时新生代和老年代的参数变化，排除了内存泄漏的可能，最终判断出是对象频繁创建，GC来不及回收导致的OOM。

再次，问题是否真的解决，还是要通过验证来判断，在我们修复完成之后，发现我们怀疑的干扰项没有再次出现，而且相关的OOM问题，也没有再次出现，说明问题彻底的被解决。

最终，是我们真正获得成长的部分，问题的产生一定是有原因的，这个原因背后的逻辑需要我们及时复盘，在本次问题中，从脚本引擎的初始化，我们想到了SPI的加载脚本的过程，想到了脚本的资源消耗，想到了类加载的过程，以往，一些概念性的东西，在此刻，与我们的实践过程完美的结合。

关于作者

朱洪旭   侠客汇JAVA开发工程师

道阻且长，拥抱变化；而困而知，且勉且行。