最近忙着做新的项目,主要是负载对老系统进行重构,但是现在每天大概会收到上百条老系统生产环境的GC超时告警,生产环境是GC时长超过2秒会告警,而且随着时间的推移,部分实例的GC时长已经接近3秒,一个是天天收到告警比较烦,二个是比较好奇为什么会出现这么频繁的GC告警。系统的话大概是日均百万级流量,查看了一下生产环境的部署情况,产生GC告警的服务大概部署了40个实例,默认Parallel Old老年代垃圾回收器目前老年代大小600M左右,按道理来说是不应该产生如此多的GC告警的,一个生产环境对一个600M的老年代进行GC都会超时应该是有啥特殊原因。
搞了其中一个实例的堆栈下来看了下。
看了下堆栈中的对象比较异常的就是有300万的CompletableFuture对象。
继续跟踪节点信息,发现某一个CourentHashMap的大小就是26万,第一时间想到的就是这里发生了内存泄漏,此外老年代只有600M的大小但是却频繁发生GC超时,这里先猜测是对较大CourentHashMap的进行垃圾回收的时候会比较耗时,这个得下来再充充电,大胆猜测当空间复杂度不是问题的时候,问题一定出现在时间复杂度上。
先分析一下为什么会产生内存泄漏,接下来看一下对象生成并存放的代码。
public CompletableFuture<EslEvent> sendBackgroundApiCommand(Channel channel, final String command) {
return sendApiSingleLineCommand(channel, command)
.thenComposeAsync(result -> {
if (result.hasHeader(Name.JOB_UUID)) {
final String jobId = result.getHeaderValue(Name.JOB_UUID);
final CompletableFuture<EslEvent> resultFuture = new CompletableFuture<>();
backgroundJobs.put(jobId, resultFuture);
return resultFuture;
} else {
final CompletableFuture<EslEvent> resultFuture = new CompletableFuture<>();
resultFuture.completeExceptionally(new IllegalStateException("Missing Job-UUID header in bgapi response"));
return resultFuture;
}
}, backgroundJobExecutor);
sendApiSingleLineCommand这个方法执行完成过后异步的去往CourentHashMap里面丢数据(backgroundJobs.put(jobId, resultFuture);),那么接下来就看一下sendApiSingleLineCommand的代码。
public CompletableFuture<EslMessage> sendApiSingleLineCommand(Channel channel, final String command) {
final CompletableFuture<EslMessage> future = new CompletableFuture<>();
syncLock.lock();
try {
apiCalls.add(future);
channel.writeAndFlush(command + MESSAGE_TERMINATOR);
} finally {
syncLock.unlock();
}
return future;
}
代码很清晰,这里是往channel写完就直接返回future过后会被上文提到的异步往CourentHashMap里面丢数据,我们可以看到异步丢数据是没有任何限制的,那很显然就应该关心future是如何从CourentHashMap里面被移除的。
protected void channelRead0(ChannelHandlerContext ctx, EslMessage message) throws Exception {
final String contentType = message.getContentType();
if (contentType.equals(Value.TEXT_EVENT_PLAIN) ||
contentType.equals(Value.TEXT_EVENT_XML)) {
// transform into an event
final EslEvent eslEvent = new EslEvent(message);
if ("BACKGROUND_JOB".equals(eslEvent.getEventName())) {
final String backgroundUuid = eslEvent.getEventHeaders().get(EslEventHeaderNames.JOB_UUID);
final CompletableFuture<EslEvent> future = backgroundJobs.remove(backgroundUuid);
if (null != future) {
future.complete(eslEvent);
}
} else {
handleEslEvent(ctx, eslEvent);
}
} else {
handleEslMessage(ctx, message);
}
看上面的代码,其实结果已经很显然了,因为往CourentHashMap里面丢数据和移除数据都没有任何同步机制,如果在执行remove操作(backgroundJobs.remove(backgroundUuid);)的时候还没有执行过put操作,put操作就会在remove之后被执行,便发生了内存泄漏,这个错误其实很低级,开源代码的后续版本其实也解决了这个问题,出问题的原因是错误的引起了第三方开发者二次开发的包,而在使用二次开发的包的时候打包了错误的版本。