direct buffers release issue

[tanimasaini]

Hi Tim,

I profiled my application in which I was using this client to make http calls. Direct buffer pool kept on increasing and it reached a limit in which netty was unable to allocate any direct buffer and it threw Out of memory error. I referenced the article http://netty.io/wiki/reference-counted-objects.html and enabled a flag (-Dio.netty.leakDetectionLevel=PARANOID) to check if there are any buffer leaks. Below is the some part of the output which indicated the leak in in http client code:
#5:

    io.netty.buffer.AdvancedLeakAwareByteBuf.getBytes(AdvancedLeakAwareByteBuf.java:223)
    io.netty.buffer.CompositeByteBuf.getBytes(CompositeByteBuf.java:687)
    io.netty.buffer.CompositeByteBuf.getBytes(CompositeByteBuf.java:40)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:677)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:1495)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:40)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:684)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:1490)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:40)
    com.mastfrog.netty.http.client.ResponseHandler.internalReceive(ResponseHandler.java:87)
    com.mastfrog.netty.http.client.MessageHandlerImpl.sendFullResponse(MessageHandlerImpl.java:268)
    com.mastfrog.netty.http.client.MessageHandlerImpl.channelRead(MessageHandlerImpl.java:226)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:182)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

#4:

    io.netty.buffer.AdvancedLeakAwareByteBuf.slice(AdvancedLeakAwareByteBuf.java:73)
    io.netty.buffer.CompositeByteBuf.addComponent0(CompositeByteBuf.java:173)
    io.netty.buffer.CompositeByteBuf.addComponent(CompositeByteBuf.java:112)
    com.mastfrog.netty.http.client.MessageHandlerImpl$ResponseState.append(MessageHandlerImpl.java:119)
    com.mastfrog.netty.http.client.MessageHandlerImpl.channelRead(MessageHandlerImpl.java:216)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:182)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

#3:

    io.netty.buffer.AdvancedLeakAwareByteBuf.order(AdvancedLeakAwareByteBuf.java:63)
    io.netty.buffer.CompositeByteBuf.addComponent0(CompositeByteBuf.java:173)
    io.netty.buffer.CompositeByteBuf.addComponent(CompositeByteBuf.java:112)
    com.mastfrog.netty.http.client.MessageHandlerImpl$ResponseState.append(MessageHandlerImpl.java:119)
    com.mastfrog.netty.http.client.MessageHandlerImpl.channelRead(MessageHandlerImpl.java:216)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:182)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

#2:

    io.netty.buffer.AdvancedLeakAwareByteBuf.release(AdvancedLeakAwareByteBuf.java:45)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:175)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

#1:

    io.netty.buffer.AdvancedLeakAwareByteBuf.retain(AdvancedLeakAwareByteBuf.java:709)
    io.netty.handler.codec.http.HttpObjectDecoder.decode(HttpObjectDecoder.java:294)
    io.netty.handler.codec.http.HttpClientCodec$Decoder.decode(HttpClientCodec.java:136)
    io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:268)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:168)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

Created at:
io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:259)
io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:155)
io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:146)
io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:107)
io.netty.channel.AdaptiveRecvByteBufAllocator$HandleImpl.allocate(AdaptiveRecvByteBufAllocator.java:104)
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:117)
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
java.lang.Thread.run(Thread.java:745)
[ERROR] 29 May 2015 12:25:34,480 (io.netty.util.ResourceLeakDetector:error:171)
LEAK: ByteBuf.release() was not called before it's garbage-collected.
Recent access records: 0
Created at:
io.netty.buffer.CompositeByteBuf.(CompositeByteBuf.java:60)
io.netty.buffer.AbstractByteBufAllocator.compositeDirectBuffer(AbstractByteBufAllocator.java:191)
io.netty.buffer.AbstractByteBufAllocator.compositeDirectBuffer(AbstractByteBufAllocator.java:186)
io.netty.buffer.AbstractByteBufAllocator.compositeBuffer(AbstractByteBufAllocator.java:161)
com.mastfrog.netty.http.client.MessageHandlerImpl$ResponseState.(MessageHandlerImpl.java:106)
com.mastfrog.netty.http.client.MessageHandlerImpl.state(MessageHandlerImpl.java:135)
com.mastfrog.netty.http.client.MessageHandlerImpl.channelRead(MessageHandlerImpl.java:188)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:182)
io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
java.lang.Thread.run(Thread.java:745)
[ERROR] 29 May 2015 12:25:34,481 (io.netty.util.ResourceLeakDetector:error:171)
LEAK: ByteBuf.release() was not called before it's garbage-collected.
Recent access records: 5
#5:

    io.netty.buffer.AdvancedLeakAwareByteBuf.getBytes(AdvancedLeakAwareByteBuf.java:223)
    io.netty.buffer.CompositeByteBuf.getBytes(CompositeByteBuf.java:687)
    io.netty.buffer.CompositeByteBuf.getBytes(CompositeByteBuf.java:40)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:677)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:1495)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:40)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:684)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:1490)
    io.netty.buffer.CompositeByteBuf.readBytes(CompositeByteBuf.java:40)
    com.mastfrog.netty.http.client.ResponseHandler.internalReceive(ResponseHandler.java:87)
    com.mastfrog.netty.http.client.MessageHandlerImpl.sendFullResponse(MessageHandlerImpl.java:268)
    com.mastfrog.netty.http.client.MessageHandlerImpl.channelRead(MessageHandlerImpl.java:226)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:182)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:147)
    io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)
    io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:130)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
    io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
    java.lang.Thread.run(Thread.java:745)

I tried to release the buffers in the http client code but was unable to do it properly. Can you help me fix the issue and give me some pointers for it.

Thanks & Regards,
Tanima

[timboudreau]

Could you post some code that, if it runs long enough (or with a small enough memory size), will reproduce the problem?

Also, running with -Dio.netty.leakDetectionLevel=advanced might help.

If you can reproduce it using the experimental 1.6.1.2-netty-5 version, Netty 5's leak detection is better than Netty 4's. The problem with these stack traces is they don't show where the ByteBuf was allocated. Definitely somewhere, there's a missing call to release(); the question is where.

[tanimasaini]

I am unable to use 1.6.1.2-netty-5 version. I am getting the following error while downloading this artifact

Failed to collect dependencies at com.mastfrog:netty-http-client:jar:1.6.1.2-netty-5: Failed to read artifact descriptor for com.mastfrog:netty-http-client:jar:1.6.1.2-netty-5: Could not find artifact com.mastfrog:mastfrog-parent:pom:1.6.1.2-netty-5 in timboudreau-builds (http://timboudreau.com/builds/plugin/repository/everything/)

[timboudreau]

Yeah, there's not a public build of the netty-5 stuff. The way to do it
would be (assuming Linux or Mac OS):

git clone https://github.com/timboudreau/mastfrog-parent
cd mastfrog-parent
git submodule init
git submodule update
git co netty-5
mvn -f parent/pom.xml install
mvn install

That will build it and everything it needs.

On Mon, Jun 1, 2015 at 2:01 AM, tanimasaini notifications@github.com
wrote:

I am unable to use 1.6.1.2-netty-5 version. I am getting the following
error while downloading this artifact

Failed to collect dependencies at
com.mastfrog:netty-http-client:jar:1.6.1.2-netty-5: Failed to read artifact
descriptor for com.mastfrog:netty-http-client:jar:1.6.1.2-netty-5: Could
not find artifact com.mastfrog:mastfrog-parent:pom:1.6.1.2-netty-5 in
timboudreau-builds (
http://timboudreau.com/builds/plugin/repository/everything/)

—
Reply to this email directly or view it on GitHub
#7 (comment)
.

http://timboudreau.com

[timboudreau]

Sorry, "co" -> "checkout" - it's an alias set in my .gitconfig - old habits
from the days of CVS :-)

On Mon, Jun 1, 2015 at 2:39 AM, tanimasaini notifications@github.com
wrote:

What does the following command do?
git co netty-5

i am getting an error for this
git: 'co' is not a git command. See 'git --help'.

—
Reply to this email directly or view it on GitHub
#7 (comment)
.

http://timboudreau.com

[timboudreau]

Are you using HttpClient or TestHarness? I'm testing a couple of places I could call release() internally, but nothing that doesn't cause an exception for decrementing the reference count below zero in one or another case.

For the TestHarness, I think the solution is to copy the bytes onto the Java heap (since assertions will touch the ByteBufs, etc. after the HTTP request has completed), so any ByteBufs used while doing the request can be released.

That's unacceptable in HttpClient, since half the point of using off-heap buffers is to not do those sorts of memory copies. So it may be that there needs to be a call on RequestBuilder or similar that releases any held buffers - not nice for people used to garbage collection, but it's the price of using reference-counted things.

But I would like to figure out what buffer it is that is the culprit - an individual chunk from chunked encoding? An aggregate buffer in a FullHttpResponse? Something else.

[vitaliy-kuzmich]

I have the same issue with HttpClient. I used ssl, I wrapped in try catch but that way does not working..In most cases that lines uses DefaultHttpContent and DefaultLastHttpContent

[wjzhuf]

我也发现了这个问题，后来跟踪代码，我发现在ResponseHandler 类中的 internalReceive 方法中的finally代码块增加一部分关闭ByteBuf 就没再出现 leak 问题。

增加代码如下 ： io.netty.util.ReferenceCountUtil.release(content);

之前没加这段代码的时候测试大概2分钟出现leak问题(600线程)，修改后目前看测试了5分钟问题还没出现，不知是否彻底解决问题。

protected void internalReceive(HttpResponseStatus status, HttpHeaders headers, ByteBuf content) {
try {
if (status.code() > 399) {
onErrorResponse(status, headers, content.readCharSequence(content.readableBytes(), CharsetUtil.UTF_8).toString());
return;
}
MediaType mediaType = null;
if (headers.contains(HttpHeaderNames.CONTENT_TYPE)) {
try {
mediaType = MediaType.parse(headers.get(HttpHeaderNames.CONTENT_TYPE));
} catch (Exception ex) {
//do nothing
}
}
T o = mediaType == null ? marshallers.read(type, content) : marshallers.read(type, content, mediaType);
_doReceive(status, headers, type.cast(o));
} catch (Exception ex) {
content.resetReaderIndex();
try {
String s = Streams.readString(new ByteBufInputStream(content), "UTF-8");
onErrorResponse(HttpResponseStatus.REQUESTED_RANGE_NOT_SATISFIABLE, headers, s);
} catch (IOException ex1) {
ex.addSuppressed(ex1);
}
Exceptions.chuck(ex);
} finally {
//2018-01-24 修改测试
io.netty.util.ReferenceCountUtil.release(content);

                    latch.countDown();
    }
}

[timboudreau]

The above fix would work, if it could be guaranteed that no code that was passed the content ByteBuf was still referencing it. Alas, that is not true even for the unit tests for this library itself; and definitely not true for the adjacent netty-http-test-harness which relies on being able to make assertions about the content after it has been received.

What's needed is a non-trivial, probably breaking change: To pass the ByteBuf in some wrapper object which sets a flag if the content is accessed, so it is only released if it was not touched; if it is, whatever code accessed it is responsible for releasing it. The alternative is to copy the entire content into a heap byte buffer which will be released on garbage collection - but for large content, that will be a memory-buster and performance killer.

For now, workarounds:

1. Client code should release the content ByteBuf (for all responses received), or
2. Set the ByteBufAllocator to one of Netty's non-reference-counting ones when setting up the client, and let the garbage collector take care of it

[wjzhuf]

@tanimasaini yes thank you