误用Freemarker标签和SpringJDBC预编译功能导致的内存泄露问题分析

一. 问题描述

        本人所在的项目组项目已经运行快一年了，功能性能都比较稳定。但是最近发布了一个版本，只是业务上增加了一些数据量，最终效果却是在持续运行的过程中，出现OOM异常。之前也发过一些版本，做过一些类似的调整，都没有出现性能问题，而这个版本却出现了，着实手忙脚乱了一阵子。

二. 项目背景

         项目是一个为前台提供服务的后台应用。出问题的功能主要做的事情是：通过各个表的基础数据，进行计算，得到一个结果数据，并入库。而且明确是在执行这个功能的时候出的问题。我们在上线之前，也做过性能测试，持续跑了很久也没有出现这样的问题。

        所用的技术是Spring（包括jdbc，都是3.0以上的版本）。        数据库用的MySQL，数据库操作使用类似mybatis的方式：结合了FreeMarker和sql标签。

        数据入库的方式，一般都是使用单条insert语句sql标签，再通过batchUpdate方法，在同一个事务中执行批量sql调用操作。我们为了提高结果数据的入库效率，使用insert into tablename (colum1,…,columN)values (…),(…),…,(…) 这种方式，将数据合并到一条sql中入库。但是mybatis的:param（冒号加参数名是SpringJDBC接受的一种传参方式）不支持传递 (…),(…),…,(…) 这样的参数（因为SpringJDBC会将:param解析成?占位符，然后insert into tablename (colum1,…,columN)values ? 这个语句不符合PreparedStatement的语法，报异常）。于是我们采用${param}方式，在FreeMarker层解析，直接拼接出包括具体值的完整的insert语句。

        操作系统Linux，JDK1.6版本，应用服务器用的是IBM的websphere集群。

三. 问题定位

        在一年前发布初始版本前，我们也曾出现过OOM异常。当时的解决方案，一方面调大JVM启动内存和最大内存，另一方面，在运算过程中用来存储计算结果的List、Map之类的“大集合”，手动clear操作，减轻GC压力（为什么能减轻？和GC策略有关，不细说了）。

        时隔一年，又出现这样的问题，我们第一反应还是检查有没有正确处理新增的“大集合”。结果是没问题的。

        看来想通过代码走读来解决问题是行不通了，只好试着做一下内存分析、线程分析、GC分析（老实讲，没怎么用过，现学现卖）。

        先看GC分析。用的是IBM提供的ga16.jar工具（IBM Pattern Modeling and Analysis Tool forJava Garbage Collector）。拉了一段时间的GC日志分析了下，结果如下图：

        图1

        从功能开始执行，虽然有GC，但是消耗的速度大于GC的程度。这样看来，即使分配的内存再调大一些，也许能解决当下的问题，但是将来如果结果数据继续增大，可能还会出现同样的问题，治标不治本。

        再看线程分析的结果。使用工具jca452.jar（IBM Thread and Monitor Dump Analyzer for Java）分析javaCore文件：

图2

图3

       看起来数据库操作那块有问题的。我们排查了数据库当时的运行情况，是非常良好的：系统负载正常，连接数正常。因此，初步确定是服务端操作数据库那块有问题。

最后我们再分析当时的内存dump文件。工具是ha426.jar（IBM HeapAnalyzer）。通过此工具的“泄露嫌疑”排序功能发现，消耗内存较多的是org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate这个类里面的某个LinkedHashMap对象占用内存较大。我们看看NamedParameterJdbcTemplate源码，把相关代码段抠出来：

<span style="font-size:18px;">public class NamedParameterJdbcTemplate implements NamedParameterJdbcOperations {.../** Cache of original SQL String to ParsedSql representation */private final Map<String, ParsedSql> parsedSqlCache =new LinkedHashMap<String, ParsedSql>(DEFAULT_CACHE_LIMIT, 0.75f, true) {@Overrideprotected boolean removeEldestEntry(Map.Entry<String, ParsedSql> eldest) {return size() > getCacheLimit();}};.../** * Obtain a parsed representation of the given SQL statement. * <p>The default implementation uses an LRU cache with an upper limit * of 256 entries. * @param sql the original SQL * @return a representation of the parsed SQL statement */protected ParsedSql getParsedSql(String sql) {if (getCacheLimit() <= 0) {return NamedParameterUtils.parseSqlStatement(sql);}synchronized (this.parsedSqlCache) {ParsedSql parsedSql = this.parsedSqlCache.get(sql);if (parsedSql == null) {parsedSql = NamedParameterUtils.parseSqlStatement(sql);this.parsedSqlCache.put(sql, parsedSql);}return parsedSql;}}}</span>

        此类实现一个接口，成员属性只有parsedSqlCache是LinkedHashMap类型的。通过属性的注释，以及和它直接相关的方法签名看出，parsedSqlCache是用来缓存预编译的sql的。

        那么为什么这个parsedSqlCache会很大呢？这和我们处理SQL标签的顺序有关。我们会在调用getParsedSql方法之前，对SQL标签进行FreeMarker解析，将${param}替换掉。这样，getParsedSql方法的sql入参就变成insert into tablename (colum1,…,columN) values (…),(…),…,(…)这样的一个超长SQL了。要知道，我们结果表字段很多，而且每个字段也都很大，这样组成的超长记录数SQL，一条SQL就能达到几十兆。因为每个insert拼接的条目记录不一样，每一条SQL都是一条新的，在parsedSqlCache没有值，因此每来一条SQL都会put到parsedSqlCache中，parsedSqlCache的size默认为256。这样算来，内存消耗是很大的，而且这些SQL的句柄被parsedSqlCache持有，是强引用，因此GC也回收不了。

        症结找到了，就好办了。要么调整FreeMarker的解析顺序，要么调整SQL标签的使用方式。考虑到FreeMarker解析那块是共方法，修改的话影响很大，最终我们选择使用:param方式传参，构建单条insert固定句式，然后在一个事务中批量执行不同记录的insert操作。问题得以解决。

        除了以上两种方法以外，还可以通过调整NamedParameterJdbcTemplate类属性的方式，不使用SQL缓存措施。仔细看下getParsedSql方法的第一行：if (getCacheLimit() <= 0) 。这个判断，如果parsedSqlCache的size设置为空，则直接解析入参SQL，不做缓存处理。但是这样的话，常规SQL处理也没有预处理缓存了，会降低SQL执行效率。看怎么取舍吧！

        以上是这次内存泄露问题的一个小结，希望对大家有所启发。