问题背景描述
数据服务是通过SQL对外提供数据查询的服务平台，底层存储支持HBase和MySQL两种。用户首先在管理平台上配置好接口的SQL详情
业务方通过微服务接口根据生成的ID以及接口参数来完成数据的查询，由于HBase不支持SQL引擎的查询，我们基于calcite实现了一套简单的SQL On HBase解析逻辑。
服务发布以来已经支持了近两百个数据服务接口，在此期间系统运行均没有出现任何问题，响应延迟、吞吐量、并发量、机器资源利用率均在预期范围内。最近接了一个大的线上场景，高峰期内系统经常Full GC，请求响应经常超时，更有甚者，系统常常因为GC出现假死。
短期内先通过加大内存可以缓解问题发生的频率，但是偶尔也会有些机器出现频繁FGC。问题虽然得到缓解，但毕竟是个定时炸弹，需要分析其根本原因进行修复才能一劳永逸。
逻辑主要描述
逻辑主要分为下面步骤：
- 连接池中维护了HBase的连接（五分钟连接超时重建）
- 每次请求根据接口ID和输入参数拼接成完整的SQL语句
- 利用Calcite的Statement来执行每次请求
连接代码如下
Class.forName("org.apache.calcite.jdbc.Driver");
info = new Properties();
info.setProperty("lex", "JAVA");
log.info("Init HBase connection manager, refresh period [{}].", refreshPeriod);
connCache = CacheBuilder.newBuilder()
.refreshAfterWrite(refreshPeriod, TimeUnit.MINUTES)
.build(new CacheLoader<Integer, ConnectionWrapper>() {
@Override
public ConnectionWrapper load(Integer key) throws Exception {
long startTime = System.currentTimeMillis();
Connection connection = DriverManager.getConnection("jdbc:calcite:", info);
CalciteConnection calciteConn = connection.unwrap(CalciteConnection.class);
SchemaPlus rootSchema = calciteConn.getRootSchema();
int udfSize;
// 完成udf的schema注册
synchronized (spiFetcher.getUdfMap()) { // TODO 遍历与put操作之间的并发安全性待查
for (SpiFetcher.UDFInfo udfInfo : spiFetcher.getUdfMap().values()) {
// 注意，这里会将udfInfo.getName() + function的参数列表形成function signature,以便在sql中使用
rootSchema.add(udfInfo.getName(), udfInfo.getFunction());
}
udfSize = spiFetcher.getUdfMap().size();
}
VirtualTable<HbaseExtra> virtualTable = virtualTableService.select(key, HbaseExtra.class);
if (StringUtils.isBlank(virtualTable.getDb())) {
rootSchema.add(virtualTable.getTb(), new HBaseFilterableTable(HBaseConnManager.this.connection, virtualTable));
} else {
SchemaPlus newSchema = rootSchema.add(virtualTable.getDb(), new AbstractSchema());
newSchema.add(virtualTable.getTb(), new HBaseFilterableTable(HBaseConnManager.this.connection, virtualTable));
}
log.info("HBase connection cache load connection, key: {}, db: {}, tb: {}, elapse: {}ms.", key, virtualTable.getDb(), virtualTable.getTb(), System.currentTimeMillis() - startTime);
return ConnectionWrapper.builder()
.connection(connection)
.version(virtualTable.getGmtModify().getTime())
.udfSize(udfSize)
.build();
}
查询过程
public <T> T query(Integer tbId, String queryStr, Handler handler) throws SQLException {
Connection connection = connCache.getUnchecked(tbId).getConnection();
try (Statement st = connection.createStatement();
ResultSet rs = st.executeQuery(queryStr)) {
return handler.handle(rs);
} catch (SQLException e) {
throw e;
}
上面的代码符合正常的逻辑，资源也会及时释放，按理不会出现内存泄露的问题。
问题定位
内存发生泄露，经过相关jtools工具定位无果后，决定采用MAT工具进行分析。
MAT（Memory Analysis Tool）是一款专门用来Java内存分析检测的工具，具体大家可以去官网查看更详细的使用说明。
MAT使用详情
通过jmap -dump命令生成程序的内存镜像（此操作对线上程序有一定影响）。利用MAT工具打开下载生成的hprof文件，文件打开时候开启内存泄露检测选项。
内存检测报告
从图中可以发现VolcanoPlanner对象占用内存空间最多，占用近93.72%。点击
overview页面的Dominator Tree按钮来分析对象的引用关系
对象引用链路
搜索出VolcanoPlanner对象，右键选择查看所有的引用关系。
对象引用详情分析
左侧加粗的字体是字段的名称，如第一行的
planner表名VolcanoPlanner是RelOptCluster对象中planner字段引用的，以此类推，可以找到最上层的引用在CalciteJdbc41Factoryxx中的statementMap。这时候我们基本上梳理出了对象的引用路径关系。问题在于为什么这个map还持有这个引用？
下载calcite的源代码来分析相关情况，找到statementMap什么时候会释放相关的Statement。
protected void close_() {
if (!closed) {
closed = true;
if (openResultSet != null) {
AvaticaResultSet c = openResultSet;
openResultSet = null;
c.close();
}
try {
// inform the server to close the resource
connection.meta.closeStatement(handle);
} finally {
// make sure we don't leak on our side
connection.statementMap.remove(handle.id);
connection.flagMap.remove(handle.id);
}
// If onStatementClose throws, this method will throw an exception (later
// converted to SQLException), but this statement still gets closed.
connection.driver.handler.onStatementClose(this);
}
}
程序会在close_方法中释放对statement的引用，继续往上找什么场景下这个方法会被调用，我们很简单的就能找到其调用的地方。AvaticaStatement.close_：
protected void close_() {
if (!closed) {
closed = true;
if (openResultSet != null) {
AvaticaResultSet c = openResultSet;
openResultSet = null;
c.close();
}
try {
// inform the server to close the resource
connection.meta.closeStatement(handle);
} finally {
// make sure we don't leak on our side
connection.statementMap.remove(handle.id);
connection.flagMap.remove(handle.id);
}
// If onStatementClose throws, this method will throw an exception (later
// converted to SQLException), but this statement still gets closed.
connection.driver.handler.onStatementClose(this);
}
}
在前面的查询中我们可以看到利用try-catch的相关特性会关闭相关的连接数。那为什么此处没有调用呢？左思右想都觉得不可能，根据经验，很有可能是其子类复写了相关的方法。
最终可以找到在CalciteStatement类中有该方法的override
@Override protected void close_() {
if (!closed) {
closed = true;
final CalciteConnectionImpl connection1 =
(CalciteConnectionImpl) connection;
connection1.server.removeStatement(handle);
if (openResultSet != null) {
AvaticaResultSet c = openResultSet;
openResultSet = null;
c.close();
}
// If onStatementClose throws, this method will throw an exception (later
// converted to SQLException), but this statement still gets closed.
connection1.getDriver().handler.onStatementClose(this);
}
}
可以看到，此处并没有释放相关的statement对象，怀疑就是此处的问题，我们自己代码中手动释放statement，然后观察整个内存的变化，发生每次GC后内存均会回到40%左右的水位线，测试一天后也没有出现内存泄露的问题，问题得到解决。
去calcite issuse中没有找到相关的issue，查看下最新的版本，该问题得到了解决（override方法去掉了，其实不知道当初作者为什么要重新这个方法，其实这个方法里面释放的资源都是父类中创建的资源，本着谁创建谁释放的原则，此处无必要重写）。
回顾总结
上述内容主要的目的是希望借助这个场景说明下怎么来定位常见的内存泄露的问题，希望读者能够从中学习常见的定位方法和思路，真正能够应用到自己遇到的问题中。同时在工作中，不要轻易的放过一个问题，一定要做到知根知底，找到问题的root cause。
思考题：
- 既然出现内存泄露，为什么之前运行这么长时间均没有出现？
- 代码中还有哪些可以进一步优化的地方？
