[JAVA-2302] Memory leak on Java async driver + Netty 4.1.x Created: 09/Sep/16  Updated: 19/Oct/16  Resolved: 19/Sep/16

Status: Closed
Project: Java Driver
Component/s: Async
Affects Version/s: 3.3.0
Fix Version/s: 3.4.0-rc1, 3.4.0

Type: Bug Priority: Major - P3
Reporter: Frederico Ferro Schuh Assignee: Ross Lawley
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Java 8, Vert.x 3.3.2, CentOS Linux release 7.2.1511 (Core)


Attachments: Java Source File TestMongoNettyLeak.java    
Issue Links:
Duplicate
is duplicated by JAVA-2157 Java driver stops connecting to one s... Closed

 Description   

We've been using Netty as the MongoDB transport in our Java application and it's been working fine.
However, since upgrading to Netty 4.1, we began running into memory leaks.
The errors look like the following:

com.mongodb.MongoException: failed to allocate 16777216 byte(s) of direct memory (used: 4596957223, max: 4608491520)

It starts happening after doing lots of Mongo queries.
By changing the transport back to the default NIO2, the leak is gone and everything works again.

We hope we can go back to using Netty though, as it performs better.

The issue happened with both Netty 4.1.1 and 4.1.4. It seems related to Netty 4.1.x releases in general.
We're using the async driver 3.3.0 and RX driver 1.2.0 (though RX is probably unrelated to the problem).



 Comments   
Comment by Frederico Ferro Schuh [ 20/Sep/16 ]

Great news Ross.
We'll be testing your fix under heavy load and I'll report back here if we detect any further leaks.

Comment by Githook User [ 19/Sep/16 ]

Author:

{u'username': u'rozza', u'name': u'Ross Lawley', u'email': u'ross.lawley@gmail.com'}

Message: Netty fixes

Update Netty to 4.1.5.final
Fix leak in NettyStream
Made connection string streamType the authorative setting for the streamFactoryFactory
Added deprecation warning in NettyByteBuf

JAVA-2302
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/b952e419d955fec927bb16b8f1fba2e680ff6a66

Comment by Ross Lawley [ 16/Sep/16 ]

Thanks fschuh,

Your test program was instrumental in identifying a leak. Once the leak was fixed I was no longer able to hit your issue, I ran the test to 100k iterations.

Ross

Comment by Ross Lawley [ 16/Sep/16 ]

PR: https://github.com/rozza/mongo-java-driver/pull/162

Comment by Frederico Ferro Schuh [ 16/Sep/16 ]

Hello Ross,

sorry for not posting the whole stack trace before.
I've came up with a test case that reproduces the issue.
It's just a simple test that runs an upsert and a query (with index creation) in an infinite loop.

Please set the max heap size as small as you can.
With a 50 mb heap you can get the error to show very quickly (it happened after about 16000 iterations here, on Linux CentOS 7).

Tested with Netty 4.1.1 Final.

Heres what the stack trace looks like:

Exception in thread "main" com.mongodb.MongoInternalException: Unexpected exception
at com.mongodb.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:487)
at com.mongodb.connection.InternalStreamConnection.access$1900(InternalStreamConnection.java:66)
at com.mongodb.connection.InternalStreamConnection$3.failed(InternalStreamConnection.java:451)
at com.mongodb.connection.netty.NettyStream.readAsync(NettyStream.java:221)
at com.mongodb.connection.netty.NettyStream.handleReadResponse(NettyStream.java:255)
at com.mongodb.connection.netty.NettyStream.access$800(NettyStream.java:62)
at com.mongodb.connection.netty.NettyStream$InboundBufferHandler.exceptionCaught(NettyStream.java:314)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:278)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:249)
at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:278)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:249)
at io.netty.channel.DefaultChannelPipeline$HeadContext.exceptionCaught(DefaultChannelPipeline.java:1281)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:278)
at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:257)
at io.netty.channel.DefaultChannelPipeline.fireExceptionCaught(DefaultChannelPipeline.java:893)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.handleReadException(AbstractNioByteChannel.java:93)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:134)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:563)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:504)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:418)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:390)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:742)
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
at java.lang.Thread.run(Thread.java:745)
Caused by: io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 8192 byte(s) of direct memory (used: 50723840, max: 50724864)
at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:592)
at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:546)
at io.netty.buffer.UnpooledUnsafeNoCleanerDirectByteBuf.allocateDirect(UnpooledUnsafeNoCleanerDirectByteBuf.java:30)
at io.netty.buffer.UnpooledUnsafeDirectByteBuf.<init>(UnpooledUnsafeDirectByteBuf.java:68)
at io.netty.buffer.UnpooledUnsafeNoCleanerDirectByteBuf.<init>(UnpooledUnsafeNoCleanerDirectByteBuf.java:25)
at io.netty.buffer.UnsafeByteBufUtil.newUnsafeDirectByteBuf(UnsafeByteBufUtil.java:625)
at io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:265)
at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:170)
at io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:131)
at io.netty.channel.DefaultMaxMessagesRecvByteBufAllocator$MaxMessageHandle.allocate(DefaultMaxMessagesRecvByteBufAllocator.java:73)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:111)
... 7 more

Comment by Ross Lawley [ 15/Sep/16 ]

Hi,

I've been unable to reproduce this issue. Do you have a test case that causes it? Also a stacktrace might throw more light on the cause.

Ross

Comment by Frederico Ferro Schuh [ 09/Sep/16 ]

Thanks for the quick response Ross.
Let me know if you need more info on my side.

Comment by Ross Lawley [ 09/Sep/16 ]

Hi fschuh,

Thanks for the ticket, we currently test against netty 4.0.x. From what you describe it seems there is some behavioural changes in the 4.1.x series. I'll investigate and see if we can trigger the same error and determine a fix.

Ross

Generated at Thu Feb 08 08:56:52 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.