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.

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

Resource leak in netty tests #3353

Open
carl-mastrangelo opened this issue Aug 16, 2017 · 42 comments · May be fixed by #11593
Open

Resource leak in netty tests #3353

carl-mastrangelo opened this issue Aug 16, 2017 · 42 comments · May be fixed by #11593
Labels
Milestone

Comments

@carl-mastrangelo
Copy link
Contributor

I haven't tracked down the responsible, but I ran with leak detection and found this:

Aug 16, 2017 10:58:18 AM io.netty.util.ResourceLeakDetector reportTracedLeak
SEVERE: LEAK: ByteBuf.release() was not called before it's garbage-collected. See http://netty.io/wiki/reference-counted-objects.html for more information.
WARNING: 3 leak records were discarded because the leak record count is limited to 4. Use system property io.netty.leakDetection.maxRecords to increase the limit.
Recent access records: 4
#4:
	io.netty.buffer.AdvancedLeakAwareByteBuf.release(AdvancedLeakAwareByteBuf.java:936)
	io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:84)
	io.netty.util.ReferenceCountUtil.safeRelease(ReferenceCountUtil.java:109)
	io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:256)
	io.netty.channel.embedded.EmbeddedChannel.doWrite(EmbeddedChannel.java:723)
	io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:872)
	io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:839)
	io.netty.channel.embedded.EmbeddedChannel$EmbeddedUnsafe$1.flush(EmbeddedChannel.java:819)
	io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1321)
	io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:191)
	io.netty.handler.codec.http2.Http2ConnectionHandler.channelReadComplete(Http2ConnectionHandler.java:509)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:398)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:380)
	io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:373)
	io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1364)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:398)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:380)
	io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:941)
	io.netty.channel.embedded.EmbeddedChannel.flushInbound(EmbeddedChannel.java:359)
	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:320)
	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)
	io.grpc.netty.NettyServerHandlerTest.manualSetUp(NettyServerHandlerTest.java:163)
	io.grpc.netty.NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail(NettyServerHandlerTest.java:356)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:498)
	org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:49)
	org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:73)
	org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:273)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)
	org.junit.runners.ParentRunner$3.run(ParentRunner.java:240)
	org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:65)
	org.junit.runners.ParentRunner.runChildren(ParentRunner.java:238)
	org.junit.runners.ParentRunner.access$000(ParentRunner.java:55)
	org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:231)
	org.junit.runners.ParentRunner.run(ParentRunner.java:316)
#3:
	io.netty.buffer.AdvancedLeakAwareByteBuf.retain(AdvancedLeakAwareByteBuf.java:924)
	io.netty.buffer.AdvancedLeakAwareByteBuf.retain(AdvancedLeakAwareByteBuf.java:35)
	io.netty.util.ReferenceCountUtil.retain(ReferenceCountUtil.java:36)
	io.netty.channel.embedded.EmbeddedChannel.doWrite(EmbeddedChannel.java:721)
	io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:872)
	io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:839)
	io.netty.channel.embedded.EmbeddedChannel$EmbeddedUnsafe$1.flush(EmbeddedChannel.java:819)
	io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1321)
	io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776)
	io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768)
	io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749)
	io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:191)
	io.netty.handler.codec.http2.Http2ConnectionHandler.channelReadComplete(Http2ConnectionHandler.java:509)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:398)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:380)
	io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:373)
	io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1364)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:398)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:380)
	io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:941)
	io.netty.channel.embedded.EmbeddedChannel.flushInbound(EmbeddedChannel.java:359)
	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:320)
	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)
	io.grpc.netty.NettyServerHandlerTest.manualSetUp(NettyServerHandlerTest.java:163)
	io.grpc.netty.NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail(NettyServerHandlerTest.java:356)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:498)
	org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:49)
	org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:73)
	org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:273)
#2:
	Hint: 'DefaultChannelPipeline$HeadContext#0' will handle the message from this point.
	io.netty.channel.DefaultChannelPipeline.touch(DefaultChannelPipeline.java:116)
	io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:810)
	io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:723)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writeSettingsAck(DefaultHttp2FrameWriter.java:260)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.CGLIB$writeSettingsAck$6(<generated>)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d$$FastClassByMockitoWithCGLIB$$af30f311.invoke(<generated>)
	org.mockito.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:216)
	org.mockito.internal.creation.AbstractMockitoMethodProxy.invokeSuper(AbstractMockitoMethodProxy.java:10)
	org.mockito.internal.invocation.realmethod.CGLIBProxyRealMethod.invoke(CGLIBProxyRealMethod.java:22)
	org.mockito.internal.invocation.realmethod.FilteredCGLIBProxyRealMethod.invoke(FilteredCGLIBProxyRealMethod.java:27)
	org.mockito.internal.invocation.InvocationImpl.callRealMethod(InvocationImpl.java:108)
	org.mockito.internal.stubbing.answers.CallsRealMethods.answer(CallsRealMethods.java:36)
	org.mockito.internal.handler.MockHandlerImpl.handle(MockHandlerImpl.java:93)
	org.mockito.internal.handler.NullResultGuardian.handle(NullResultGuardian.java:29)
	org.mockito.internal.handler.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:38)
	org.mockito.internal.creation.MethodInterceptorFilter.intercept(MethodInterceptorFilter.java:51)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.writeSettingsAck(<generated>)
	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writeSettingsAck(DecoratingHttp2FrameWriter.java:75)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionEncoder.writeSettingsAck(DefaultHttp2ConnectionEncoder.java:264)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:419)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:635)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:542)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:118)
	io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:373)
	io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:244)
	io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:433)
	io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:492)
	io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:431)
	io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:317)
	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)
	io.grpc.netty.NettyServerHandlerTest.manualSetUp(NettyServerHandlerTest.java:163)
	io.grpc.netty.NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail(NettyServerHandlerTest.java:356)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:498)
	org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:49)
	org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:73)
	org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:273)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)

#1:
	io.netty.buffer.AdvancedLeakAwareByteBuf.writeInt(AdvancedLeakAwareByteBuf.java:558)
	io.netty.handler.codec.http2.Http2CodecUtil.writeFrameHeaderInternal(Http2CodecUtil.java:260)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writeSettingsAck(DefaultHttp2FrameWriter.java:259)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.CGLIB$writeSettingsAck$6(<generated>)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d$$FastClassByMockitoWithCGLIB$$af30f311.invoke(<generated>)
	org.mockito.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:216)
	org.mockito.internal.creation.AbstractMockitoMethodProxy.invokeSuper(AbstractMockitoMethodProxy.java:10)
	org.mockito.internal.invocation.realmethod.CGLIBProxyRealMethod.invoke(CGLIBProxyRealMethod.java:22)
	org.mockito.internal.invocation.realmethod.FilteredCGLIBProxyRealMethod.invoke(FilteredCGLIBProxyRealMethod.java:27)
	org.mockito.internal.invocation.InvocationImpl.callRealMethod(InvocationImpl.java:108)
	org.mockito.internal.stubbing.answers.CallsRealMethods.answer(CallsRealMethods.java:36)
	org.mockito.internal.handler.MockHandlerImpl.handle(MockHandlerImpl.java:93)
	org.mockito.internal.handler.NullResultGuardian.handle(NullResultGuardian.java:29)
	org.mockito.internal.handler.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:38)
	org.mockito.internal.creation.MethodInterceptorFilter.intercept(MethodInterceptorFilter.java:51)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.writeSettingsAck(<generated>)
	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writeSettingsAck(DecoratingHttp2FrameWriter.java:75)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionEncoder.writeSettingsAck(DefaultHttp2ConnectionEncoder.java:264)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:419)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:635)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:542)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:118)
	io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:373)
	io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:244)
	io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:433)
	io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:492)
	io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:431)
	io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:317)
	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)
	io.grpc.netty.NettyServerHandlerTest.manualSetUp(NettyServerHandlerTest.java:163)
	io.grpc.netty.NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail(NettyServerHandlerTest.java:356)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:498)
	org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:49)
	org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:73)
	org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:273)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

Created at:
	io.netty.util.ResourceLeakDetector.track(ResourceLeakDetector.java:237)
	io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:331)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:181)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:172)
	io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:109)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writeSettingsAck(DefaultHttp2FrameWriter.java:258)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.CGLIB$writeSettingsAck$6(<generated>)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d$$FastClassByMockitoWithCGLIB$$af30f311.invoke(<generated>)
	org.mockito.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:216)
	org.mockito.internal.creation.AbstractMockitoMethodProxy.invokeSuper(AbstractMockitoMethodProxy.java:10)
	org.mockito.internal.invocation.realmethod.CGLIBProxyRealMethod.invoke(CGLIBProxyRealMethod.java:22)
	org.mockito.internal.invocation.realmethod.FilteredCGLIBProxyRealMethod.invoke(FilteredCGLIBProxyRealMethod.java:27)
	org.mockito.internal.invocation.InvocationImpl.callRealMethod(InvocationImpl.java:108)
	org.mockito.internal.stubbing.answers.CallsRealMethods.answer(CallsRealMethods.java:36)
	org.mockito.internal.handler.MockHandlerImpl.handle(MockHandlerImpl.java:93)
	org.mockito.internal.handler.NullResultGuardian.handle(NullResultGuardian.java:29)
	org.mockito.internal.handler.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:38)
	org.mockito.internal.creation.MethodInterceptorFilter.intercept(MethodInterceptorFilter.java:51)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter$$EnhancerByMockitoWithCGLIB$$a575c56d.writeSettingsAck(<generated>)
	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writeSettingsAck(DecoratingHttp2FrameWriter.java:75)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionEncoder.writeSettingsAck(DefaultHttp2ConnectionEncoder.java:264)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:419)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:635)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:542)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:160)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:118)
	io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:373)
	io.netty.handler.codec.http2.Http2ConnectionHandler$PrefaceDecoder.decode(Http2ConnectionHandler.java:244)
	io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:433)
	io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:492)
	io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:431)
	io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:317)
	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)
	io.grpc.netty.NettyServerHandlerTest.manualSetUp(NettyServerHandlerTest.java:163)
	io.grpc.netty.NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail(NettyServerHandlerTest.java:356)
	sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	java.lang.reflect.Method.invoke(Method.java:498)
	org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
	org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:49)
	org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:73)
	org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:273)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
	org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

@ejona86 ejona86 added this to the Next milestone Aug 29, 2017
@alexvas
Copy link

alexvas commented Aug 30, 2017

BTW, I see slightly different stacktrace at our production grpc-based backend:

[07:12:15,418] [grpc-default-worker-ELG-3-11] ERROR io.netty.util.ResourceLeakDetector ~ LEAK: ByteBuf.release() was not called before it's garbage-collected. See http://n
etty.io/wiki/reference-counted-objects.html for more information.
WARNING: 107 leak records were discarded because the leak record count is limited to 4. Use system property io.netty.leakDetection.maxRecords to increase the limit.
Recent access records: 4
#4:
        io.netty.buffer.AdvancedLeakAwareByteBuf.readBytes(AdvancedLeakAwareByteBuf.java:498)
        io.grpc.netty.NettyReadableBuffer.readBytes(NettyReadableBuffer.java:60)
        io.grpc.internal.CompositeReadableBuffer$3.readInternal(CompositeReadableBuffer.java:95)
        io.grpc.internal.CompositeReadableBuffer$ReadOperation.read(CompositeReadableBuffer.java:216)
        io.grpc.internal.CompositeReadableBuffer.execute(CompositeReadableBuffer.java:174)
        io.grpc.internal.CompositeReadableBuffer.readBytes(CompositeReadableBuffer.java:91)
        io.grpc.internal.ReadableBuffers$BufferInputStream.read(ReadableBuffers.java:327)
        io.grpc.protobuf.lite.ProtoLiteUtils$2.parse(ProtoLiteUtils.java:133)
        io.grpc.protobuf.lite.ProtoLiteUtils$2.parse(ProtoLiteUtils.java:79)
        io.grpc.MethodDescriptor.parseRequest(MethodDescriptor.java:280)
        io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.messageRead(ServerCallImpl.java:246)
        io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1.runInContext(ServerImpl.java:571)
        io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
        io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:102)
        java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        java.lang.Thread.run(Thread.java:748)
#3:
        io.netty.buffer.AdvancedLeakAwareByteBuf.readUnsignedByte(AdvancedLeakAwareByteBuf.java:402)
        io.grpc.netty.NettyReadableBuffer.readUnsignedByte(NettyReadableBuffer.java:55)
        io.grpc.internal.CompositeReadableBuffer$1.readInternal(CompositeReadableBuffer.java:71)
        io.grpc.internal.CompositeReadableBuffer$ReadOperation.read(CompositeReadableBuffer.java:216)
        io.grpc.internal.CompositeReadableBuffer.execute(CompositeReadableBuffer.java:174)
        io.grpc.internal.CompositeReadableBuffer.readUnsignedByte(CompositeReadableBuffer.java:74)
        io.grpc.internal.AbstractReadableBuffer.readInt(AbstractReadableBuffer.java:48)
        io.grpc.internal.MessageDeframer.processHeader(MessageDeframer.java:330)
        io.grpc.internal.MessageDeframer.deliver(MessageDeframer.java:232)
        io.grpc.internal.MessageDeframer.request(MessageDeframer.java:143)
        io.grpc.internal.AbstractStream$TransportState.requestMessagesFromDeframer(AbstractStream.java:195)
        io.grpc.netty.NettyServerStream$Sink$1.run(NettyServerStream.java:90)
        io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
        io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
        io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
        io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
        io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
        java.lang.Thread.run(Thread.java:748)
#2:
        io.netty.buffer.AdvancedLeakAwareByteBuf.readUnsignedByte(AdvancedLeakAwareByteBuf.java:402)
        io.grpc.netty.NettyReadableBuffer.readUnsignedByte(NettyReadableBuffer.java:55)
        io.grpc.internal.CompositeReadableBuffer$1.readInternal(CompositeReadableBuffer.java:71)
        io.grpc.internal.CompositeReadableBuffer$ReadOperation.read(CompositeReadableBuffer.java:216)
        io.grpc.internal.CompositeReadableBuffer.execute(CompositeReadableBuffer.java:174)
        io.grpc.internal.CompositeReadableBuffer.readUnsignedByte(CompositeReadableBuffer.java:74)
        io.grpc.internal.AbstractReadableBuffer.readInt(AbstractReadableBuffer.java:47)
        io.grpc.internal.MessageDeframer.processHeader(MessageDeframer.java:330)
        io.grpc.internal.MessageDeframer.deliver(MessageDeframer.java:232)
        io.grpc.internal.MessageDeframer.request(MessageDeframer.java:143)
        io.grpc.internal.AbstractStream$TransportState.requestMessagesFromDeframer(AbstractStream.java:195)
        io.grpc.netty.NettyServerStream$Sink$1.run(NettyServerStream.java:90)
        io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
        io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
        io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
        io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
        io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
        java.lang.Thread.run(Thread.java:748)
#1:
        io.netty.buffer.AdvancedLeakAwareByteBuf.readUnsignedByte(AdvancedLeakAwareByteBuf.java:402)
        io.grpc.netty.NettyReadableBuffer.readUnsignedByte(NettyReadableBuffer.java:55)
        io.grpc.internal.CompositeReadableBuffer$1.readInternal(CompositeReadableBuffer.java:71)
        io.grpc.internal.CompositeReadableBuffer$ReadOperation.read(CompositeReadableBuffer.java:216)
        io.grpc.internal.CompositeReadableBuffer.execute(CompositeReadableBuffer.java:174)
        io.grpc.internal.CompositeReadableBuffer.readUnsignedByte(CompositeReadableBuffer.java:74)
        io.grpc.internal.AbstractReadableBuffer.readInt(AbstractReadableBuffer.java:46)
        io.grpc.internal.MessageDeframer.processHeader(MessageDeframer.java:330)
        io.grpc.internal.MessageDeframer.deliver(MessageDeframer.java:232)
        io.grpc.internal.MessageDeframer.request(MessageDeframer.java:143)
        io.grpc.internal.AbstractStream$TransportState.requestMessagesFromDeframer(AbstractStream.java:195)
        io.grpc.netty.NettyServerStream$Sink$1.run(NettyServerStream.java:90)
        io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
        io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
        io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
        io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
        io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
        java.lang.Thread.run(Thread.java:748)
Created at:
        io.netty.util.ResourceLeakDetector.track(ResourceLeakDetector.java:237)
        io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:331)
        io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:181)
        io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:172)
        io.netty.buffer.AbstractByteBufAllocator.ioBuffer(AbstractByteBufAllocator.java:133)
        io.netty.channel.DefaultMaxMessagesRecvByteBufAllocator$MaxMessageHandle.allocate(DefaultMaxMessagesRecvByteBufAllocator.java:80)
        io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:122)
        io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:644)
        io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:579)
        io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:496)
        io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:458)
        io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
        io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
        java.lang.Thread.run(Thread.java:748)

@carl-mastrangelo
Copy link
Contributor Author

@alexvas What you are seeing is a different bug. Would you mind filing a separate issue? This one is specifically for tests. (and thus not as urgent as yours)

@ericgribkoff Message deframing change possibly?

@alexvas
Copy link

alexvas commented Aug 30, 2017

@carl-mastrangelo done in #3422

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 4, 2024

@kannanjgithub As per the defect details I can run the whole test class as well as single unit test (NettyServerHandlerTest.headersWithInvalidContentTypeShouldFail()) which is mentioned in error logs of the defect successfully.

PFA the Successful Test class which ran in my local machine.
image

Even I tried some of the approaches/details which is mentioned in the below documentation for finding the Resource leaks in unit tests but unable to see any.
https://netty.io/wiki/reference-counted-objects.html

Also has you mentioned earlier some classes are mocked which are going to used in the setup() method the get required streamListner/streamTraces object instance from Factory which is required by all the tests otherwise we will be getting NPE saying streamTracerFactory is null.

Need to have a connect and have more discussion on the same with you to make sure I am not missing anything to see this issue

@vinodhabib
Copy link
Contributor

As per the suggestion from @kannanjgithub working in the direction to enable to info/debug logs through logback.xml for the UT case to re-produce issue and the same in progress.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 8, 2024

@kannanjgithub As per your suggestion I am able to configure logback.xml and enable the loggers for UT cases but still it’s not showing required stack trace with any resource leakage issues/errors as mentioned in the defect.
PFA the log info which is set for DEBUG level. Also tried with TRACE level but not much info printed in the logs

image

We need to have connect and discuss more on this to make sure we are not missing anything to Reproduce this issue. Please suggest.

@kannanjgithub
Copy link
Contributor

Can we try using the older Netty dependencies from before the time this issue got reported and see if we are able to repro it? We can try with netty 4.0.50 (release history for netty) netty-tcnative 2.0.5 (release history for netty-tcnative) and run the test. You need to modify the netty and nettytcnative versions in gradle/libs.versions.toml.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 11, 2024

@kannanjgithub tried with above mentioned old versions for netty and netty-tcnnative along multiple combination versions but most of them are giving issues with project build phase as mentioned in below snippet also followed some of the working combinations for above libraries mentioned in the "https://github.com/vinodhabib/grpc-java/blob/master/SECURITY.md" but here also initial combinations are failing at build level. not sure the old libraries available in the maven antifactory as i am not able to access the same to check.

image

Please suggest further? are you able to build the grpc-java project with Old versions of netty as mentioned above @kannanjgithub?

@ejona86
Copy link
Member

ejona86 commented Jul 12, 2024

For this we need to enable the leak detector at PARANOID level. https://netty.io/wiki/reference-counted-objects.html#leak-detection-levels

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 15, 2024

@ejona86 Thanks for your reply as per your above suggestion I tried with using the JVM option ( -Dio.netty.leakDetection.level=paranoid') for NettyServerHandlerTest and able to see the below error with leakage issue.

14:03:18.643 [Time-limited test] ERROR io.netty.util.ResourceLeakDetector - 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: 
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)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writePing(DefaultHttp2FrameWriter.java:339)
	java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	java.base/java.lang.reflect.Method.invoke(Method.java:578)
	org.mockito.internal.util.reflection.ReflectionMemberAccessor.invoke(ReflectionMemberAccessor.java:48)
	org.mockito.internal.stubbing.defaultanswers.ForwardsInvocations.answer(ForwardsInvocations.java:49)
	org.mockito.internal.handler.MockHandlerImpl.handle(MockHandlerImpl.java:110)
	org.mockito.internal.handler.NullResultGuardian.handle(NullResultGuardian.java:29)
	org.mockito.internal.handler.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:34)
	org.mockito.internal.creation.bytebuddy.MockMethodInterceptor.doIntercept(MockMethodInterceptor.java:82)
	org.mockito.internal.creation.bytebuddy.MockMethodInterceptor.doIntercept(MockMethodInterceptor.java:56)
	org.mockito.internal.creation.bytebuddy.MockMethodInterceptor$DispatcherDefaultingToRealMethod.interceptAbstract(MockMethodInterceptor.java:161)
	io.netty.handler.codec.http2.Http2FrameWriter$MockitoMock$2041439246.writePing(Unknown Source)
	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writePing(DecoratingHttp2FrameWriter.java:80)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionEncoder.writePing(DefaultHttp2ConnectionEncoder.java:337)
	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writePing(DecoratingHttp2FrameWriter.java:80)
	io.grpc.netty.Http2ControlFrameLimitEncoder.writePing(Http2ControlFrameLimitEncoder.java:80)
	io.grpc.netty.NettyServerHandler$GracefulShutdown.start(NettyServerHandler.java:1074)
	io.grpc.netty.NettyServerHandler$3.run(NettyServerHandler.java:393)
	io.grpc.internal.MaxConnectionIdleManager$2.run(MaxConnectionIdleManager.java:79)
	io.grpc.internal.LogExceptionRunnable.run(LogExceptionRunnable.java:42)
	io.grpc.netty.NettyHandlerTestBase$FakeClockScheduledNettyFuture$1.run(NettyHandlerTestBase.java:177)
	io.grpc.internal.FakeClock$ScheduledTask.run(FakeClock.java:98)
	io.grpc.internal.FakeClock.runDueTasks(FakeClock.java:310)
	io.grpc.internal.FakeClock.forwardTime(FakeClock.java:369)
	io.grpc.internal.FakeClock.forwardNanos(FakeClock.java:378)
	io.grpc.netty.NettyServerHandlerTest.maxConnectionIdle_goAwaySent_pingAck(NettyServerHandlerTest.java:949)
	java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	java.base/java.lang.reflect.Method.invoke(Method.java:578)

But the problem is I am unable to reproduce the same error with individual UT case running (i,e UT case where I can see the same issue while running the complete test class which I can see in the trace logs) as that will be helpful for me to Debug the issue. Any Suggestions here?

@ejona86 @kannanjgithub Expected fix for this issue is we should not see this above Leakage error while running the NettyServerHandlerTest class, right? Please confirm.

Further Analysis/Debug in progress for the same.

@ejona86
Copy link
Member

ejona86 commented Jul 15, 2024

These sorts of failures won't tend to show up if you run a single test by itself, because it requires the GC running to notice the object was leaked. You might be able to add an @After with GcFinalization.awaitFullGc() to trigger it for a single test.

@vinodhabib
Copy link
Contributor

Thanks for the suggestions @ejona86. I will look into this.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 16, 2024

@ejona86 Tried the above suggestion for NettyServerHandlerTest class but it's not giving the Leakage issue for individual test, also not sure I am missing something as I don't see any existing reference for the same in the grpc-java codebase.
please correct me if anything is wrong in the below changes.
Thanks in Advance
image

@ejona86
Copy link
Member

ejona86 commented Jul 16, 2024

ResourceLeakDetector checks for leaks on certain ByteBuf operations, so after the GC, create a new ByteBuf.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 17, 2024

@ejona86 I tried your above suggestions but still not getting the leakage info while running the single UT case, can see the below tearDown method is getting called after every individual UT run in NettyServerHandlerTest class.
Also tried some of the suggestions from above netty reference counted objects documentation but still its same.

image

Looks like we need to connect on this and discuss further along with @kannanjgithub, please let us know your suitable time/availability.

@ejona86
Copy link
Member

ejona86 commented Jul 17, 2024

@vinodhabib, it sounds like you already have a reproduction, just not as small of a reproduction as you want. NettyServerHandlerTest runs in ~3 seconds, so that should be fast enough to work with. I suggest looking into the leak information you've already gathered. If we need to meet to discuss that, we can; I'll let kannanjgithub create any meetings as appropriate.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 18, 2024

@ejona86 Thanks for your response. Yes, I am already working in this direction as you mentioned above but I feel debug process will be more effective with Single UT case instead of checking all the 66 UT at once.
Anyways Further Analysis/Debug in progress for the same.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 19, 2024

@ejona86 @kannanjgithub I was going through the Individual UT cases and trying to close the created ByteBuf operations in the finally block but still the same Leakage issue is coming as per suggestion in the netty document for reference counted objects to fix the leakage in JUnit's as mentioned in the below snippet.
Also tried same applying in the multiple common methods as well like manualSetUp(), initChannel(), channelRead() etc but don't see any impacts.
image

Note: ReferenceCountUtil.releaseLater() is deprecated but still tried.

Currently I am blocked with this issue and not sure like this is just a test issue at netty or it's a code issue? also not sure like my analysis is going in right direction?

I found one similar issue related to Resource Leak (#9563) which was already merged which says about fix at code level of removing the deadline and disableRetry()
I can see this fix is already in my defect branch (created from master branch).

Need your help/support on this, better if we schedule a meeting on this to discuss more.

@ejona86
Copy link
Member

ejona86 commented Jul 22, 2024

Randomly modifying reference counts generally won't get you far. You need to look at where the buffer was created, and use that to help you understand where it should have been closed.

Looking at the original stack trace, as an example, was on the read path. And was a buffer created by grpc/netty in response to the read frame and would have been sent back out on the channel. So in this case the buffer would have been passed to the test via the EmbeddedChannel.outboundMessages() queue. The test should have processed the entries in the queue and freed them.

	io.netty.handler.codec.http2.DecoratingHttp2FrameWriter.writeSettingsAck(DecoratingHttp2FrameWriter.java:75)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionEncoder.writeSettingsAck(DefaultHttp2ConnectionEncoder.java:264)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:419)
	io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$PrefaceFrameListener.onSettingsRead(DefaultHttp2ConnectionDecoder.java:635)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readSettingsFrame(DefaultHttp2FrameReader.java:542)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:263)
	io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader
...
 	io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935)
 	io.netty.channel.embedded.EmbeddedChannel.writeInbound(EmbeddedChannel.java:317)
 	io.grpc.netty.NettyHandlerTestBase.channelRead(NettyHandlerTestBase.java:140)

For the one you posted earlier:

	io.grpc.netty.Http2ControlFrameLimitEncoder.writePing(Http2ControlFrameLimitEncoder.java:80)
	io.grpc.netty.NettyServerHandler$GracefulShutdown.start(NettyServerHandler.java:1074)
	io.grpc.netty.NettyServerHandler$3.run(NettyServerHandler.java:393)
	io.grpc.internal.MaxConnectionIdleManager$2.run(MaxConnectionIdleManager.java:79)
	io.grpc.internal.LogExceptionRunnable.run(LogExceptionRunnable.java:42)
	io.grpc.netty.NettyHandlerTestBase$FakeClockScheduledNettyFuture$1.run(NettyHandlerTestBase.java:177)
	io.grpc.internal.FakeClock$ScheduledTask.run(FakeClock.java:98)

That stack shows a timer fired and caused the shutdown of the channel (probably maxConnectionAge or maxConnectionIdle). During the shutdown process it sends a PING and expects a PING ack in reply. That ping would be in the same EmbeddedChannel.outboundMessages() queue. So the test didn't process the ping correctly... Or another option in this case is "the test didn't expect this code to run" and the timer was firing unexpectedly. But that seems unlikely, since we see the test is for maxConnectionIdle:

	io.grpc.netty.NettyServerHandlerTest.maxConnectionIdle_goAwaySent_pingAck(NettyServerHandlerTest.java:949)

And looking at the test, it doesn't free a single message from outboundMessages(). So take a look at EmbeddedChannel.outboundMessages() and see if there's buffers to free.

@vinodhabib
Copy link
Contributor

vinodhabib commented Jul 23, 2024

@ejona86 Thanks for the Reply.
I can see EmbeddedChannel.outboundMessages() is part of netty-transport jar and I can't update anything here to apply the method to free the buffer as its not part of grpc-java project. please correct me if I am wrong.
do we need to fix anything on the code side as per your above comment? Further looking into it, please suggest?

@kannanjgithub
Copy link
Contributor

kannanjgithub commented Jul 23, 2024

In NettyServerHandler::handlerAdded there is a ChannelHandlerContext passed by the grpc server side code, and during the grpc server's handling of a rpc read or write, the code sending this context that wraps the EmbeddedChannel will have the responsibility of freeing up buffers. That should be already existing and be occurring when an rpc gets handled, and that may be in another layer of code outside the grpc netty package, or lie in some post processing code path in grpc netty code that gets called during real rpc invocation.
Unit tests should ideally be localized to the package and the behavior being tested and that's what is being done here.
In NettyHandlerTestBase we construct a ChannelHandlerContext wrapping an EmbeddedChannel, to focus on unit testing certain behaviors during read and write rpc handling. So the responsibility of freeing up buffers then lies with the test code, which is apparently missing as shown by leak detection.

@ejona86
Copy link
Member

ejona86 commented Aug 2, 2024

FYI: I just stumbled on an old branch of mine. It might be helpful, but I make no guarantees. I see channel().releaseOutbound(); which would help for some of the cases you saw. But there's more going on.

master...ejona86:grpc-java:netty-leak-detector-in-tests

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 6, 2024

@ejona86 Thanks for the above response and suggestion.
After going through the above changes and applying them in netty tests i can see around 70% of the test are working fine without any leakage error.

Remaining 30% Tests still giving Leakage error randomly along with 3 UT Failures (currently disabled locally)

Further working on them.

Failed UT:
NettyServerHandlerTest.streamErrorShouldNotCloseChannel()
NettyServerHandlerTest.clientHalfCloseShouldForwardToStreamListener()
NettyServerHandlerTest.headersWithErrAndEndStreamReturnErrorButNotThrowNpe()

UT which are Failing Randomly with Leakage Error :
NettyServerHandlerTest.inboundDataShouldForwardToStreamListener

NettyHandlerTestBase.windowUpdateMatchesTarget
NettyHandlerTestBase.bdpPingWindowResizing
NettyHandlerTestBase.bdpPingLimitOutstanding
NettyHandlerTestBase.testPingBackoff
NettyHandlerTestBase.dataSizeSincePingAccumulates

cc : @kannanjgithub

@vinodhabib
Copy link
Contributor

Fixed below 3 UT cases for Leakage issue and Its working as Expected. further UT fixes are in progress.

NettyHandlerTestBase.bdpPingWindowResizing
NettyHandlerTestBase.bdpPingLimitOutstanding
NettyHandlerTestBase.testPingBackoff

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 9, 2024

@kannanjgithub @ejona86 with my continuous analysis i can see below are the 4 UT's which are failing so frequently/intermittently with Leakage issue even after free up the buffer as i can see in the debug mode the outbound messages getting released after execution of this channel().releaseOutbound() call.

NettyHandlerTestBase.windowUpdateMatchesTarget
NettyHandlerTestBase.bdpPingWindowResizing
NettyHandlerTestBase.bdpPingLimitOutstanding
NettyHandlerTestBase.testPingBackoff

Further looking into these and other Failed UT's which are commented currently.

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 9, 2024

@kannanjgithub Fixed below 4 Failing UTs at Netty Server and Client Handler Tests.

NettyServerHandlerTest.streamErrorShouldNotCloseChannel()
NettyServerHandlerTest.clientHalfCloseShouldForwardToStreamListener()
NettyServerHandlerTest.headersWithErrAndEndStreamReturnErrorButNotThrowNpe()

NettyClientHandlerTest.sendFrameShouldSucceed()

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 12, 2024

@kannanjgithub Out of 4 UTs now with recent changes 2 UTs got Fixed and 2 are Frequently Failing. Further Analysis/Debug/Fix in progress for the below Failing UTs.

NettyHandlerTestBase.testPingBackoff
NettyHandlerTestBase.windowUpdateMatchesTarget

Note : Validated the same by commenting these 2 UTs locally.

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 19, 2024

Hi @kannanjgithub @ejona86 As per my recent Analysis found like below are the 4 UT's in NettyHandlerTestBase are tightly coupled or inter dependent on each other as i can see when i run UT's 1 & 2 with commenting/disable UT's 3 and 4, I don't see any leakage issue and its stable.

  1. NettyHandlerTestBase.bdpPingWindowResizing
  2. NettyHandlerTestBase.bdpPingLimitOutstanding
  3. NettyHandlerTestBase.windowUpdateMatchesTarget
  4. NettyHandlerTestBase.testPingBackoff

When i run the UT's with uncommenting/enable 3 & 4, I can see the Leakage issue in UT's 1 & 2 also in 3 & 4 with Leakage error with most of the time with method readXCopies(1, data1Kb); which is called multiple times with different params/input.

While debug these UT's (3 and 4) i found like resource was not closed then i have called channel().releaseOutbound() in all the possible places to release the buffer but still the UT's giving the intermittent leakage behavior.

Please suggest and need your help/support here with these UTs (3 & 4)

Stack Trace of the Leakage Error in UT 3 & 4 with readXCopies(1, data1Kb); most of the times.

image image image image image

@kannanjgithub
Copy link
Contributor

The unreleased ByteBuf mentioned in the stacktrace is not about the outbound queue messages. The ByteBuf created in NettyHandlereTestBase::grpcFrame needs to be released.

@vinodhabib
Copy link
Contributor

@kannanjgithub As discussed in today's call below changes in the readXcopies() method not making any difference behavior is still same.

private void readXCopies(int copies, byte[] data) throws Exception {
for (int i = 0; i < copies; i++) {
ByteBuf grpcDataFrame = grpcDataFrame(STREAM_ID, false, data);
channelRead(grpcDataFrame); // buffer it
grpcDataFrame.clear();
stream().request(1); // consume it
channel().releaseOutbound();
}
}

Further i will look into NettyHandlereTestBase::grpcFrame as per your above comment.

@kannanjgithub
Copy link
Contributor

My suggestion was to call ByteBuf.release(), not ByteBuf.clear().

@ejona86
Copy link
Member

ejona86 commented Aug 19, 2024

You can't modify the frame after you've passed it to channelRead(); the test no longer "owns" it and it will cause corruption. Looking at the channelReady() + request(1), this is delivering messages to the application. That uses a StreamListener (ClientStreamListener or ServerStreamListener, depending on which extending class). Looking at the test, it doesn't do anything with these messages from the application's API.

The buffers are most likely stuck in streamListenerMessageQueue (there's one in each of NettyClientHandlerTest and NettyServerHandlerTest).

@vinodhabib
Copy link
Contributor

vinodhabib commented Aug 20, 2024

My suggestion was to call ByteBuf.release(), not ByteBuf.clear().

@kannanjgithub if if use the ByteBuf.release() then i will get below Exception so i used ByteBuf.clear()

image

@vinodhabib
Copy link
Contributor

@ejona86 Thanks for your above suggestion and i will look into it further.

@vinodhabib
Copy link
Contributor

vinodhabib commented Sep 5, 2024

@kannanjgithub I tried all the possible ways to release the buffer (around dataFrame() method ) for the pending 2 UT's mentioned above in previous comments also tried the suggestions (around streamListenerMessageQueue) but still facing the same and below is the only common issue as mentioned in the snippet as per the log stack trace.

Kindly suggest.

Note : Dropped a mail with details about all tried approaches for the same.

image

@ejona86
Copy link
Member

ejona86 commented Sep 5, 2024

@vinodhabib, the grpcDataFrame are messages sent on an RPC but never read. The data needs to be consumed via streamTransportState... and there's no stream object, so... seems like requestMessagesFromDeframerForTesting() to request messages and streamListenerMessageQueue to close the InputStreams holding the messages. (At least that's how it'd look on client-side.)

@vinodhabib
Copy link
Contributor

@vinodhabib, the grpcDataFrame are messages sent on an RPC but never read. The data needs to be consumed via streamTransportState... and there's no stream object, so... seems like requestMessagesFromDeframerForTesting() to request messages and streamListenerMessageQueue to close the InputStreams holding the messages. (At least that's how it'd look on client-side.)

@ejona86 @kannanjgithub was working on this suggested approach and simulated similar changes in NettyServerHandlerTest class.
I can see the behavior as you mentioned above like there are some messages available/stuck in the streamListenerMessageQueue ( while running Complete NettyServerHandlerTest messages are available and no messages while running single UT NettyHandlerTestBase.windowUpdateMatchesTarget which has leakage issue)
Also I tried to release the same using new simulated changes, messages are getting released but still no impact on the resource leakage problem, even after this change the leakage issue still persist as mentioned in the previous comments with 4 UT's which are inter-related.

Kindly suggest further on the same.

Below is the code snippet and console statements which says the messages got released.

    byte[] data = initXkbBuffer(1);
    int wireSize = data.length + 5; // 5 is the size of the header
    System.out.println("windowUpdateMatchesTarget->streamTransportState="+ streamTransportState);

    streamTransportState.requestMessagesFromDeframerForTesting(1);

    ByteBuf frame = grpcDataFrame(3, false, data);
    channelRead(frame);
    channel().releaseOutbound();
    int accumulator = wireSize;
    // 40 is arbitrary, any number large enough to trigger a window update would work
    for (int i = 0; i < 40; i++) {
      channelRead(grpcDataFrame(3, false, data));
      channel().releaseOutbound();
      accumulator += wireSize;
    }

    System.out.println("before close streamListenerMessageQueue=" + streamListenerMessageQueue.size());
    
    for (int i = 0; streamListenerMessageQueue.size() > 0 ; i++) {
      InputStream message = streamListenerMessageQueue.poll();
      message.close();
    }
    
   System.out.println("after close streamListenerMessageQueue=" + streamListenerMessageQueue.size());
manualSetUp->streamTransportState=io.grpc.netty.NettyServerHandlerTest$TransportStateImpl@ff8018f
windowUpdateMatchesTarget->streamTransportState=io.grpc.netty.NettyServerHandlerTest$TransportStateImpl@ff8018f
before close streamListenerMessageQueue=8
after close streamListenerMessageQueue=0
[MockitoHint] NettyServerHandlerTest.windowUpdateMatchesTarget (see javadoc for MockitoHint):

@kannanjgithub
Copy link
Contributor

but still no impact on the resource leakage problem, even after this change the leakage issue still persist

Please provide the leak detection error message that occurs even after the changes.

@vinodhabib
Copy link
Contributor

but still no impact on the resource leakage problem, even after this change the leakage issue still persist

Please provide the leak detection error message that occurs even after the changes.

manualSetUp->streamTransportState=io.grpc.netty.NettyServerHandlerTest$TransportStateImpl@4cbbf366
Sep 26, 2024 2:11:44 PM io.netty.util.ResourceLeakDetector reportTracedLeak
SEVERE: 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: 
Created at:
	io.netty.buffer.UnpooledByteBufAllocator.newDirectBuffer(UnpooledByteBufAllocator.java:96)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
	io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
	io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:116)
	io.netty.handler.codec.http2.DefaultHttp2FrameWriter.writeData(DefaultHttp2FrameWriter.java:182)
	io.grpc.netty.NettyHandlerTestBase.dataFrame(NettyHandlerTestBase.java:310)
	io.grpc.netty.NettyHandlerTestBase.grpcDataFrame(NettyHandlerTestBase.java:305)
	io.grpc.netty.NettyHandlerTestBase.windowUpdateMatchesTarget(NettyHandlerTestBase.java:464)

@ejona86
Copy link
Member

ejona86 commented Sep 26, 2024

    for (int i = 0; streamListenerMessageQueue.size() > 0 ; i++) {
      InputStream message = streamListenerMessageQueue.poll();
      message.close();
    }

That is broken. i is increasing and size() is decreasing, so there will be messages left. Use something like while (!streamListenerMessageQueue.isEmpty()) or while ((message = streamListenerMessageQueue.poll()) != null) instead.

@kannanjgithub
Copy link
Contributor

    for (int i = 0; streamListenerMessageQueue.size() > 0 ; i++) {
      InputStream message = streamListenerMessageQueue.poll();
      message.close();
    }

That is broken. i is increasing and size() is decreasing, so there will be messages left. Use something like while (!streamListenerMessageQueue.isEmpty()) or while ((message = streamListenerMessageQueue.poll()) != null) instead.

I don't see a problem with the loop. i is unused (and it should have just been a while loop) but the condition to continue the loop (streamListenerMessageQueue.size() > 0 ) is correct.

@ejona86
Copy link
Member

ejona86 commented Sep 27, 2024

Oh, I see. It just didn't use i. So it was a strange while loop.

@vinodhabib vinodhabib linked a pull request Oct 3, 2024 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants