Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ByteBuf.release() was not called before it's garbage-collected. #115

Closed
benjchristensen opened this issue May 6, 2014 · 6 comments
Closed

ByteBuf.release() was not called before it's garbage-collected. #115

benjchristensen opened this issue May 6, 2014 · 6 comments
Labels
bug
Milestone
0.3.7

Comments

@benjchristensen
Copy link
Member

Getting this error:

May 06, 2014 2:54:14 PM io.netty.util.ResourceLeakDetector reportLeak
SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected. Enable advanced leak reporting to find out where the leak occurred. To enable advanced leak reporting, specify the JVM option '-Dio.netty.leakDetectionLevel=advanced' or call ResourceLeakDetector.setLevel()

Here is the output of what I'm running:

###############################################################################
Step: 1  Interval: 20000micros  Rate: 50/s
###############################################################################

Total => Success: 237 Error: 0   Last 10s => Success: 23/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 105  100th: 164
May 06, 2014 2:54:14 PM io.netty.util.ResourceLeakDetector reportLeak
SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected. Enable advanced leak reporting to find out where the leak occurred. To enable advanced leak reporting, specify the JVM option '-Dio.netty.leakDetectionLevel=advanced' or call ResourceLeakDetector.setLevel()
Total => Success: 480 Error: 0   Last 10s => Success: 48/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 64  100th: 164
Total => Success: 725 Error: 0   Last 10s => Success: 47/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 62
Total => Success: 969 Error: 0   Last 10s => Success: 47/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
Total => Success: 1213 Error: 0   Last 10s => Success: 47/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
Total => Success: 1458 Error: 0   Last 10s => Success: 48/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
###############################################################################
Step: 2  Interval: 10000micros  Rate: 100/s
###############################################################################

Total => Success: 1930 Error: 0   Last 10s => Success: 70/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
Total => Success: 2406 Error: 0   Last 10s => Success: 93/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 53
Total => Success: 2882 Error: 0   Last 10s => Success: 93/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 53
Total => Success: 3360 Error: 0   Last 10s => Success: 93/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
Total => Success: 3837 Error: 0   Last 10s => Success: 93/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52
Total => Success: 4315 Error: 0   Last 10s => Success: 93/s Error: 0/s    Latency => 50th: 51  90th: 52  99th: 52  100th: 52

...

###############################################################################
Step: 9  Interval: 400micros  Rate: 2500/s
###############################################################################

Total => Success: 160439 Error: 0   Last 10s => Success: 1671/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 52
Total => Success: 170995 Error: 0   Last 10s => Success: 1877/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 52
Total => Success: 181580 Error: 0   Last 10s => Success: 2079/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 60
Total => Success: 192176 Error: 0   Last 10s => Success: 2081/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 60
Total => Success: 202758 Error: 0   Last 10s => Success: 2080/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 213333 Error: 0   Last 10s => Success: 2078/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
###############################################################################
Step: 10  Interval: 333micros  Rate: 3000/s
###############################################################################

Total => Success: 223903 Error: 0   Last 10s => Success: 2077/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 236376 Error: 0   Last 10s => Success: 2267/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 248890 Error: 0   Last 10s => Success: 2457/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 261412 Error: 0   Last 10s => Success: 2460/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 273923 Error: 0   Last 10s => Success: 2460/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 286474 Error: 0   Last 10s => Success: 2462/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 298975 Error: 0   Last 10s => Success: 2461/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 53
Total => Success: 311484 Error: 0   Last 10s => Success: 2457/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 323979 Error: 0   Last 10s => Success: 2456/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 336484 Error: 0   Last 10s => Success: 2456/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 349009 Error: 0   Last 10s => Success: 2460/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 361491 Error: 0   Last 10s => Success: 2457/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 53
Total => Success: 373980 Error: 0   Last 10s => Success: 2452/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 386481 Error: 0   Last 10s => Success: 2456/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 399005 Error: 0   Last 10s => Success: 2459/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 52
Total => Success: 411480 Error: 0   Last 10s => Success: 2456/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 424046 Error: 0   Last 10s => Success: 2460/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
Total => Success: 436599 Error: 0   Last 10s => Success: 2469/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 449132 Error: 0   Last 10s => Success: 2465/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 461638 Error: 0   Last 10s => Success: 2461/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 53
Total => Success: 474181 Error: 0   Last 10s => Success: 2462/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 486643 Error: 0   Last 10s => Success: 2457/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 58
Total => Success: 499143 Error: 0   Last 10s => Success: 2453/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 55
Total => Success: 511503 Error: 0   Last 10s => Success: 2442/s Error: 0/s    Latency => 50th: 50  90th: 51  99th: 51  100th: 59
@benjchristensen
Copy link
Member Author

Code => https://github.com/benjchristensen/WSPerfLab/blob/master/ws-client/src/main/java/perf/client/WSClient.java

@benjchristensen
Copy link
Member Author

With this property: -Dio.netty.leakDetectionLevel=paranoid

###############################################################################
Step: 1  Interval: 20000micros  Rate: 50/s
###############################################################################

May 06, 2014 3:06:03 PM io.netty.util.ResourceLeakDetector reportLeak
SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected.
Recent access records: 4
#4:
    io.netty.buffer.AdvancedLeakAwareByteBuf.release(AdvancedLeakAwareByteBuf.java:45)
    io.netty.handler.codec.http.DefaultHttpContent.release(DefaultHttpContent.java:72)
    io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:68)
    io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:91)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:153)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
#3:
    io.netty.buffer.AdvancedLeakAwareByteBuf.slice(AdvancedLeakAwareByteBuf.java:73)
    io.netty.buffer.CompositeByteBuf.addComponent0(CompositeByteBuf.java:172)
    io.netty.buffer.CompositeByteBuf.addComponent(CompositeByteBuf.java:111)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:189)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:50)
    io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:153)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
#2:
    io.netty.buffer.AdvancedLeakAwareByteBuf.order(AdvancedLeakAwareByteBuf.java:63)
    io.netty.buffer.CompositeByteBuf.addComponent0(CompositeByteBuf.java:172)
    io.netty.buffer.CompositeByteBuf.addComponent(CompositeByteBuf.java:111)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:189)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:50)
    io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:153)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
#1:
    io.netty.buffer.AdvancedLeakAwareByteBuf.retain(AdvancedLeakAwareByteBuf.java:709)
    io.netty.handler.codec.http.DefaultHttpContent.retain(DefaultHttpContent.java:60)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:188)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:50)
    io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:153)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
Created at:
    io.netty.util.ResourceLeakDetector.open(ResourceLeakDetector.java:196)
    io.netty.buffer.AbstractByteBufAllocator.toLeakAwareBuffer(AbstractByteBufAllocator.java:42)
    io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:247)
    io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:155)
    io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:146)
    io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:83)
    io.netty.buffer.ByteBufUtil.readBytes(ByteBufUtil.java:265)
    io.netty.handler.codec.http.HttpObjectDecoder.decode(HttpObjectDecoder.java:319)
    io.netty.handler.codec.http.HttpClientCodec$Decoder.decode(HttpClientCodec.java:136)
    io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:362)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:139)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
May 06, 2014 3:06:03 PM io.netty.util.ResourceLeakDetector reportLeak
SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected.
Recent access records: 0
Created at:
    io.netty.util.ResourceLeakDetector.open(ResourceLeakDetector.java:196)
    io.netty.buffer.CompositeByteBuf.<init>(CompositeByteBuf.java:59)
    io.netty.buffer.Unpooled.compositeBuffer(Unpooled.java:355)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:149)
    io.netty.handler.codec.http.HttpObjectAggregator.decode(HttpObjectAggregator.java:50)
    io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:89)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:153)
    io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:148)
    io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:338)
    io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:324)
    io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785)
    io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126)
    io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:485)
    io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:452)
    io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:346)
    io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
    java.lang.Thread.run(Thread.java:745)
Total => Success: 238 Error: 0   Last 10s => Success: 23/s Error: 0/s    Latency => 50th: 55  90th: 56  99th: 133  100th: 186
Total => Success: 482 Error: 0   Last 10s => Success: 48/s Error: 0/s    Latency => 50th: 55  90th: 56  99th: 87  100th: 186

@NiteshKant NiteshKant added the bug label May 7, 2014
@headinthebox
Copy link

Ran into this today as well.

That said, so far loving RxNetty!!!!

NiteshKant pushed a commit to NiteshKant/RxNetty that referenced this issue Jul 3, 2014
Fixes issue ReactiveX#115
b1a279e 
Content callbacks for client response and server request were not getting released.
@NiteshKant NiteshKant added this to the 0.3.7 milestone Jul 3, 2014
@NiteshKant NiteshKant self-assigned this Jul 3, 2014
NiteshKant added a commit that referenced this issue Jul 4, 2014
@NiteshKant
Merge pull request #170 from NiteshKant/master
2d9ba0c 
Fixes issue #115
@NiteshKant
Copy link
Member

Thanks @normanmaurer for finding the leak source!

@normanmaurer
Copy link

@NiteshKant Yay.. Your are welcome buddy <3

@NiteshKant
Copy link
Member

For the record, the leak was for the HttpServerRequest and HttpClientResponse content callbacks. The content buffer was not released post callback on the content subject in both the cases.

@venkatraghavang venkatraghavang mentioned this issue Mar 26, 2015
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
0.3.7
Development

No branches or pull requests
4 participants
@normanmaurer @benjchristensen @NiteshKant @headinthebox