记一次Netty堆外内存溢出OutOfDirectMemoryError

简介

最近项目上线,隔几天就出现一次OutOfDirectMemoryError,项目使用netty进行网络数据处理,笔者输出这篇文章记录分析与处理的过程,分享给所有读者,希望能帮助到遇到同样问题的人。(备注:本篇文章为笔者模拟当时的情况,还原问题处理过程。)

错误信息

10:14:02.857 [AlarmFile-7-2] WARN netty.channel.DefaultChannelPipeline[1152]An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 16777216 byte(s) of direct memory (used: 1073741824, max: 1073741824)
    at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:802) ~[netty-common-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:731) ~[netty-common-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena$DirectArena.allocateDirect(PoolArena.java:648) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena$DirectArena.newChunk(PoolArena.java:623) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena.allocateNormal(PoolArena.java:202) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena.tcacheAllocateSmall(PoolArena.java:172) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena.allocate(PoolArena.java:134) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PoolArena.allocate(PoolArena.java:126) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:395) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    at io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:116) ~[netty-buffer-4.1.72.Final.jar:4.1.72.Final]
    ...

日志显示OutOfDirectMemoryError,来自程序中netty分配堆外内存的时候。

问题分析

跟踪堆外内存

先跟踪一下堆外内存使用情况,netty里提供了相应的api查询堆外内存使用情况,在程序中添加如下代码:

LOG.info("directmemory use:{}, max:{}",
PlatformDependent.usedDirectMemory(), PlatformDependent.maxDirectMemory());

然后跟踪一下日志:

10:17:48.178 [*******-4-4] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:53.373 [*******-4-1] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:57.467 [*******-4-4] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:57.599 [*******-4-4] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:57.617 [*******-4-2] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:58.638 [*******-4-1] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:58.748 [*******-4-4] INFO ****************[66]directmemory use:234881024, max:1073741824
10:17:59.540 [*******-4-2] INFO ****************[66]directmemory use:234881024, max:1073741824
...
10:50:51.873 [*******-4-2] INFO ****************[66]directmemory use:268435456, max:1073741824
10:50:58.220 [*******-4-4] INFO ****************[66]directmemory use:268435456, max:1073741824
10:50:58.973 [*******-4-5] INFO ****************[66]directmemory use:268435456, max:1073741824
...
11:08:49.983 [*******-4-5] INFO ****************[66]directmemory use:301989888, max:1073741824
11:08:52.401 [*******-4-1] INFO ****************[66]directmemory use:301989888, max:1073741824
11:08:53.459 [*******-4-2] INFO ****************[66]directmemory use:301989888, max:1073741824

观察到的现象是:堆外内存一直增长不降,没有回收,这种情况大概率是代码中出现了内存泄露。

Dump分析

先用arthas抓几个dump看看情况

java -jar arthas-boot.jar
...
heapdump /tmp/*****-08291045-dump.hprof

在这里插入图片描述
在这里插入图片描述
抓取了2个时间点的dump文件,发现堆外内存中netty的PooledUnsafeDirectByteBuf数量增长很多。
到这里只能知道是代码中ByteBuf引起的,但具体是哪里的ByteBuf引起的呢?

定位泄露堆栈

netty的官方文档,有两种方式可以 打印出泄漏的详细信息
第一种是在netty定义时添加如下代码:

ResourceLeakDetector.setLevel(ResourceLeakDetector.Level.ADVANCED);

第二种是在jvm中添加如下参数:

-Dio.netty.leakDetectionLevel=advanced

这里笔者选用第二种方式,添加参数后重新启动项目,观察错误日志:

16:48:33.249 [808-TCP-4-1] ERROR netty.util.ResourceLeakDetector[319]LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html for more information.
Recent access records: 
#1:
	io.netty.buffer.AdvancedLeakAwareByteBuf.readUnsignedInt(AdvancedLeakAwareByteBuf.java:443)
	com.*****.***********.******.protostar.schema.NumberPSchema$DWORD2Long.readAndSet(NumberPSchema.java:177)
	com.*****.***********.******.protostar.schema.RuntimeSchema.mergeFrom(RuntimeSchema.java:63)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decryptMessage(JTMessageDecoder.java:160)
	...
#2:
	io.netty.buffer.AdvancedLeakAwareByteBuf.readBytes(AdvancedLeakAwareByteBuf.java:497)
	com.*****.***********.******.protostar.schema.StringSchema$STR.readFrom(StringSchema.java:58)
	com.*****.***********.******.protostar.schema.StringSchema$STR.readFrom(StringSchema.java:38)
	com.*****.***********.******.protostar.Schema.readFrom(Schema.java:17)
	...
#3:
	io.netty.buffer.AdvancedLeakAwareByteBuf.getUnsignedByte(AdvancedLeakAwareByteBuf.java:161)
	io.netty.buffer.ByteBufUtil$HexUtil.hexDump(ByteBufUtil.java:1496)
	io.netty.buffer.ByteBufUtil$HexUtil.access$000(ByteBufUtil.java:1420)
	io.netty.buffer.ByteBufUtil.hexDump(ByteBufUtil.java:143)
	io.netty.buffer.ByteBufUtil.hexDump(ByteBufUtil.java:135)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decrypt(JTMessageDecoder.java:238)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decryptMessage(JTMessageDecoder.java:145)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decode(JTMessageDecoder.java:128)
	...
#4:
	io.netty.buffer.AdvancedLeakAwareByteBuf.writeBytes(AdvancedLeakAwareByteBuf.java:611)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decrypt(JTMessageDecoder.java:237)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decryptMessage(JTMessageDecoder.java:145)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decode(JTMessageDecoder.java:128)
	...
Created at:
	io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:402)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
	io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:116)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decrypt(JTMessageDecoder.java:229)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decryptMessage(JTMessageDecoder.java:145)
	com.*****.***********.******.protocol.codec.JTMessageDecoder.decode(JTMessageDecoder.java:128)
	...

打印的错误堆栈里就可以看到具体泄露的地方了。
找到这些泄露的地方,我们做release释放就可以解决问题了。

解决问题

对泄露的bytebuf确保释放即可:

private void decryptMessage(...) {
    // ...
    try {
        // ...
    } catch (Exception e) {
        throw e;
    } finally {
    	// 释放 release 或者 ReferenceCountUtil.safeRelease(buf);   
        buf.release(); 
    }
}

更新程序后上线,观察运行情况,堆外内存没有再出现异常情况。

  • 3
    点赞
  • 25
    收藏
    觉得还不错? 一键收藏
  • 打赏
    打赏
  • 1
    评论
评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

pezynd

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付:¥1
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值