ScaleChain/scalechain

Memory Leak ByteBuf.release() was not called (Netty)

Closed this issue · 4 comments

  1. Problem

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.

  1. Repro
    ./run-prepare.sh
    ./run.sh 0

or

gradle clean test -i

  1. full log

22:35:05.098 [Thread-0] INFO i.s.b.chain.mining.BlockMining - Coin Miner stats : Candidate Tx Count : 0, Valid Tx Count : 0, Attachable Tx Count : 0
22:35:06.098 [Thread-0] INFO i.s.b.chain.mining.BlockMining - Coin Miner stats : Candidate Tx Count : 0, Valid Tx Count : 0, Attachable Tx Count : 0
22:35:06.230 [Thread-0] TRACE io.scalechain.wallet.Wallet - <Wallet register tx:Hash("5e648e3fb102686ff394995cf8d82d0698a48487b5baf1bd0c59844785bb0b88")> started.
22:35:06.231 [Thread-0] TRACE io.scalechain.wallet.Wallet - <Wallet register tx:Hash("5e648e3fb102686ff394995cf8d82d0698a48487b5baf1bd0c59844785bb0b88")> put outpoint : OutPoint(transactionHash=Hash("5e648e3fb102686ff394995cf8d82d0698a48487b5baf1bd0c59844785bb0b88"), outputIndex=0), wallet output : WalletOutput(blockindex=252, coinbase=true, spent=false, transactionOutput=TransactionOutput(value=5000000000L, lockingScript=LockingScript(Bytes.bytes("76a914202f69627026045247fd00bbef1692711705cf0988ac")) /* ops:ScriptOpList(operations=List(io.scalechain.blockchain.script.ops.OpDup@68b7225c,io.scalechain.blockchain.script.ops.OpHash160@4d633d5c,io.scalechain.blockchain.script.ops.OpPush@2e04e546,io.scalechain.blockchain.script.ops.OpEqualVerify@2b530d37,OpCheckSig(Script("76a914202f69627026045247fd00bbef1692711705cf0988ac")))) */ ))
22:35:06.231 [Thread-0] INFO i.s.blockchain.chain.Blockchain - Successfully have put the block in the best blockchain.
Height : 252, Hash : Hash("00000db2195aa2e2dd7096bb3c2adb24b928a1cebc7a8eaf0818248ad2cba7ad")
22:35:06.231 [Thread-0] WARN io.scalechain.blockchain.net.PeerSet - No connected peer to send the message : Block. Hash : Hash("00000db2195aa2e2dd7096bb3c2adb24b928a1cebc7a8eaf0818248ad2cba7ad")
22:35:06.231 [Thread-0] TRACE i.s.blockchain.cli.CoinMiner - Block Mined.
hash : Hash("00000db2195aa2e2dd7096bb3c2adb24b928a1cebc7a8eaf0818248ad2cba7ad")

22:35:06.231 [Thread-0] INFO i.s.b.chain.mining.BlockMining - Coin Miner stats : Candidate Tx Count : 0, Valid Tx Count : 0, Attachable Tx Count : 0
22:35:06.701 [Thread-0] 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.UnpooledByteBufAllocator.newDirectBuffer(UnpooledByteBufAllocator.java:96)
io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:124)
io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:871)
io.scalechain.io.InputOutputStream.fixedBytes(InputOutputStream.kt:20)
io.scalechain.blockchain.proto.codec.primitive.FixedByteArrayCodec.transcode(FixedByteArrayCodec.kt:13)
io.scalechain.blockchain.proto.codec.primitive.FixedReversedByteArrayCodec.transcode(FixedReversedByteArrayCodec.kt:10)
io.scalechain.blockchain.proto.codec.primitive.FixedReversedByteArrayCodec.transcode(FixedReversedByteArrayCodec.kt:8)
io.scalechain.blockchain.proto.codec.CodecInputOutputStream.transcode(interfaces.kt:21)
io.scalechain.blockchain.proto.codec.HashCodec.transcode(messageparts_codecs.kt:16)
io.scalechain.blockchain.proto.codec.BlockHeaderCodec.transcode(messageparts_codecs.kt:227)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.transcode(indexparts_codecs.kt:70)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.transcode(indexparts_codecs.kt:61)
io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:42)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.decode(indexparts_codecs.kt:61)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.decode(indexparts_codecs.kt:61)
io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:40)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.decode(indexparts_codecs.kt:61)
io.scalechain.blockchain.proto.codec.BlockInfoCodec.decode(indexparts_codecs.kt:61)
io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:160)
io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:168)
io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
io.scalechain.blockchain.storage.index.BlockDatabase$DefaultImpls.getBlockInfo(BlockDatabase.kt:40)
io.scalechain.blockchain.storage.BlockStorage$DefaultImpls.getBlockInfo(BlockStorage.kt:11)
io.scalechain.blockchain.storage.DiskBlockStorage.getBlockInfo(DiskBlockStorage.kt:49)
io.scalechain.blockchain.storage.DiskBlockStorage.putBlock(DiskBlockStorage.kt:128)
io.scalechain.blockchain.storage.BlockStorage$DefaultImpls.putBlock(BlockStorage.kt:28)
io.scalechain.blockchain.storage.DiskBlockStorage.putBlock(DiskBlockStorage.kt:49)
io.scalechain.blockchain.chain.Blockchain.putBlock(BlockChain.kt:191)
io.scalechain.blockchain.chain.processor.BlockProcessor.acceptBlock(BlockProcessor.kt:138)
io.scalechain.blockchain.net.BlockPropagator.propagate(BlockPropagator.kt:14)
io.scalechain.blockchain.cli.CoinMiner$thread$1.run(CoinMiner.kt:114)
22:35:06.702 [Thread-0] TRACE io.scalechain.wallet.Wallet - <Wallet register tx:Hash("bdfeb3618bcff947f27ca049134650eb0d38b165c25814d0fc1fc20111bf7244")> started.
22:35:06.702 [Thread-0] TRACE io.scalechain.wallet.Wallet - <Wallet register tx:Hash("bdfeb3618bcff947f27ca049134650eb0d38b165c25814d0fc1fc20111bf7244")> put outpoint : OutPoint(transactionHash=Hash("bdfeb3618bcff947f27ca049134650eb0d38b165c25814d0fc1fc20111bf7244"), outputIndex=0), wallet output : WalletOutput(blockindex=253, coinbase=true, spent=false, transactionOutput=TransactionOutput(value=5000000000L, lockingScript=LockingScript(Bytes.bytes("76a914202f69627026045247fd00bbef1692711705cf0988ac")) /* ops:ScriptOpList(operations=List(io.scalechain.blockchain.script.ops.OpDup@68b7225c,io.scalechain.blockchain.script.ops.OpHash160@4d633d5c,io.scalechain.blockchain.script.ops.OpPush@619183c1,io.scalechain.blockchain.script.ops.OpEqualVerify@2b530d37,OpCheckSig(Script("76a914202f69627026045247fd00bbef1692711705cf0988ac")))) */ ))
22:35:06.702 [Thread-0] INFO i.s.blockchain.chain.Blockchain - Successfully have put the block in the best blockchain.
Height : 253, Hash : Hash("00000e68118dd0b7023b81cd8943de481b32d829f250f73d9570c3e9bf2ac3f1")
22:35:06.702 [Thread-0] WARN io.scalechain.blockchain.net.PeerSet - No connected peer to send the message : Block. Hash : Hash("00000e68118dd0b7023b81cd8943de481b32d829f250f73d9570c3e9bf2ac3f1")
22:35:06.702 [Thread-0] TRACE i.s.blockchain.cli.CoinMiner - Block Mined.
hash : Hash("00000e68118dd0b7023b81cd8943de481b32d829f250f73d9570c3e9bf2ac3f1")

Fixed most of them except the following one:

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.buffer(AbstractByteBufAllocator.java:124)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:871)
    io.scalechain.io.InputOutputStream.fixedBytes(InputOutputStream.kt:20)
    io.scalechain.blockchain.proto.codec.primitive.VariableByteBufCodec.transcode(VariableByteBufCodec.kt:21)
    io.scalechain.blockchain.proto.codec.primitive.VariableStringCodec.transcode(VariableStringCodec.kt:20)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.transcode(walletparts_codecs.kt:97)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.transcode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:42)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:40)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:160)
    io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
    io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:168)
    io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
    io.scalechain.wallet.WalletStore.ownershipExists(WalletStore.kt:262)
    io.scalechain.wallet.Wallet.getWalletOutputOwnerships$scalechain_wallet(Wallet.kt:669)
    io.scalechain.wallet.Wallet.getWalletOutputOwnerships$scalechain_wallet(Wallet.kt:681)
    io.scalechain.wallet.Wallet.unregisterTransaction$scalechain_wallet(Wallet.kt:907)
    io.scalechain.wallet.Wallet.onRemoveTransaction(Wallet.kt:708)
    io.scalechain.blockchain.chain.TransactionMagnet.detachTransaction(TransactionMagnet.kt:239)
    io.scalechain.blockchain.chain.BlockMagnet.detachBlock(BlockMagnet.kt:31)
    io.scalechain.blockchain.chain.BlockMagnet.detachBlocksAfter(BlockMagnet.kt:55)
    io.scalechain.blockchain.chain.BlockMagnet.reorganize(BlockMagnet.kt:199)
    io.scalechain.blockchain.chain.Blockchain.putBlock(BlockChain.kt:213)
    io.scalechain.wallet.WalletAndChainSpec$1.invoke(WalletAndChainSpec.kt:123)
    io.scalechain.wallet.WalletAndChainSpec$1.invoke(WalletAndChainSpec.kt:57)
    io.kotlintest.TestBase$runTest$callable$1.call(TestBase.kt:124)
    java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    java.base/java.lang.Thread.run(Thread.java:833)
09:46:56.800 [pool-2-thread-1] 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.UnpooledByteBufAllocator.newDirectBuffer(UnpooledByteBufAllocator.java:96)
    io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:188)
    io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:124)
    io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:871)
    io.scalechain.io.InputOutputStream.fixedBytes(InputOutputStream.kt:20)
    io.scalechain.blockchain.proto.codec.primitive.VariableByteBufCodec.transcode(VariableByteBufCodec.kt:21)
    io.scalechain.blockchain.proto.codec.primitive.VariableStringCodec.transcode(VariableStringCodec.kt:20)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.transcode(walletparts_codecs.kt:97)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.transcode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:42)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:40)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.proto.codec.OwnershipDescriptorCodec.decode(walletparts_codecs.kt:94)
    io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:160)
    io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
    io.scalechain.blockchain.storage.index.KeyValueDatabase$DefaultImpls.getObject(KeyValueDatabase.kt:168)
    io.scalechain.blockchain.storage.index.RocksDatabase.getObject(RocksDatabase.kt:47)
    io.scalechain.wallet.WalletStore.putPrivateKeys(WalletStore.kt:246)
    io.scalechain.wallet.Wallet.newAddress(Wallet.kt:615)
    io.scalechain.wallet.WalletPerformanceSpec.prepareTestTransactions(WalletPerformanceSpec.kt:62)
    io.scalechain.wallet.WalletPerformanceSpec.prepareTestTransactions$default(WalletPerformanceSpec.kt:42)
    io.scalechain.wallet.WalletPerformanceSpec$1.invoke(WalletPerformanceSpec.kt:119)
    io.scalechain.wallet.WalletPerformanceSpec$1.invoke(WalletPerformanceSpec.kt:107)
    io.kotlintest.TestBase$runTest$callable$1.call(TestBase.kt:124)
    java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    java.base/java.lang.Thread.run(Thread.java:833)

Fixed all leaks. Unit tests and e2e tests passed.

Found a leak while running run.sh

repro steps :
open five tabs and run following commands for each
run.sh 0
run.sh 1
run.sh 2
run.sh 3
run.sh 4

22:39:50.958 [Thread-0] 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.buffer(AbstractByteBufAllocator.java:124)
io.netty.buffer.AbstractByteBuf.readBytes(AbstractByteBuf.java:871)
io.scalechain.io.InputOutputStream.fixedBytes(InputOutputStream.kt:20)
io.scalechain.blockchain.proto.codec.BitcoinMessageEnvelopeCodec.transcode(BitcoinMessageEnvelope.kt:121)
io.scalechain.blockchain.proto.codec.BitcoinMessageEnvelopeCodec.transcode(BitcoinMessageEnvelope.kt:88)
io.scalechain.blockchain.proto.codec.Codec$DefaultImpls.decode(interfaces.kt:42)
io.scalechain.blockchain.proto.codec.BitcoinMessageEnvelopeCodec.decode(BitcoinMessageEnvelope.kt:88)
io.scalechain.blockchain.proto.codec.BitcoinMessageEnvelopeCodec.decode(BitcoinMessageEnvelope.kt:88)
io.scalechain.blockchain.proto.codec.BitcoinProtocolCodec.decode(BitcoinProtocolCodec.kt:29)
io.scalechain.blockchain.net.p2p.BitcoinProtocolDecoder.decode(BitcoinProtocolDecoder.java:55)
io.scalechain.blockchain.net.p2p.BitcoinProtocolDecoder.decode(BitcoinProtocolDecoder.java:33)
io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1371)
io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1234)
io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1283)
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722)
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658)
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584)
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496)
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
java.base/java.lang.Thread.run(Thread.java:833)

The above leak happened because:
ByteBuf, which is allocated by netty is not released resulting in a memory leak error
BitcoinMessageEnvelopeCodec.transcode method reads bytes w/ io.fixedBytes but the ByteBuf is not released.
Need to release ByteBuf.

io.scalechain.io.InputOutputStream.fixedBytes(InputOutputStream.kt:20)
io.scalechain.blockchain.proto.codec.BitcoinMessageEnvelopeCodec.transcode(BitcoinMessageEnvelope.kt:121)

Will fix this issue in the following issue.
#141 Remove copy of payloads in BitcoinMessageEnvelop