Open carl-mastrangelo opened 6 years ago
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)
@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?
@carl-mastrangelo done in #3422
@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.
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
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.
I haven't tracked down the responsible, but I ran with leak detection and found this: