You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@bookkeeper.apache.org by GitBox <gi...@apache.org> on 2022/09/08 10:27:42 UTC
[GitHub] [bookkeeper] zymap commented on pull request #3383: Consolidate Netty channel flushes to mitigate syscall overhead
zymap commented on PR #3383:
URL: https://github.com/apache/bookkeeper/pull/3383#issuecomment-1240526858
Hi @merlimat, we found [a test ](https://github.com/apache/pulsar/issues/17520)failed in pulsar which was caused by this fix.
I write [a test](https://github.com/zymap/bookkeeper/pull/16/files#diff-c039963d623f2673faea219fc952ea189bafa935e48b26c32e1ff69e1256fbacR45) to verify that. It will fail when open a ledger with recovery at here https://github.com/apache/bookkeeper/blob/be7053b850a3ad53c09baeac15b01cabc8e9412a/bookkeeper-server/src/main/java/org/apache/bookkeeper/proto/PacketProcessorBase.java#L139
<details>
2022-09-08T18:12:24,810 - INFO - [bookie-io-13-1:ReadEntryProcessor@61] - Thread name bookie-io-13-1 @ processPacket
2022-09-08T18:12:24,810 - WARN - [bookie-io-13-1:ReadEntryProcessor@71] - Ledger: 0 fenced by: /127.0.0.1:65535
2022-09-08T18:12:24,810 - INFO - [bookie-io-13-1:ReadEntryProcessor@86] - Fence result is not empty
2022-09-08T18:12:24,810 - INFO - [bookie-io-13-1:ReadEntryProcessor@87] - Thread name bookie-io-13-1 @ processPacket, fence result
2022-09-08T18:12:27,318 - INFO - [bookie-io-13-1:PacketProcessorBase@145] - Thread name bookie-io-13-1 @ send response and wait | org.apache.bookkeeper.proto.BookieProtocol$ReadResponse
2022-09-08T18:12:27,318 - ERROR - [bookie-io-13-1:ReadEntryProcessor@113] - Unexpected exception reading at 0:-1 : DefaultChannelPromise@ab4113(incomplete)
io.netty.util.concurrent.BlockingOperationException: DefaultChannelPromise@ab4113(incomplete)
at io.netty.util.concurrent.DefaultPromise.checkDeadLock(DefaultPromise.java:462) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.checkDeadLock(DefaultChannelPromise.java:159) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:247) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:131) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:30) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.PacketProcessorBase.sendResponseAndWait(PacketProcessorBase.java:147) ~[classes/:?]
at org.apache.bookkeeper.proto.PacketProcessorBase.sendReadReqResponse(PacketProcessorBase.java:80) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.sendResponse(ReadEntryProcessor.java:140) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.sendFenceResponse(ReadEntryProcessor.java:146) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.handleReadResultForFenceRead(ReadEntryProcessor.java:169) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.processPacket(ReadEntryProcessor.java:88) ~[classes/:?]
at org.apache.bookkeeper.proto.PacketProcessorBase.safeRun(PacketProcessorBase.java:175) ~[classes/:?]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestProcessor.processReadRequest(BookieRequestProcessor.java:665) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestProcessor.processRequest(BookieRequestProcessor.java:372) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestHandler.channelRead(BookieRequestHandler.java:78) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.AuthHandler$ServerSideHandler.channelRead(AuthHandler.java:86) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.BookieProtoEncoding$RequestDecoder.channelRead(BookieProtoEncoding.java:447) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) ~[netty-codec-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) ~[netty-codec-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.channelRead(FlushConsolidationHandler.java:152) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
2022-09-08T18:12:27,318 - INFO - [bookie-io-13-1:ReadEntryProcessor@121] - Thread name bookie-io-13-1 @ processPacket, send response
2022-09-08T18:12:27,765 - INFO - [bookie-io-13-1:PacketProcessorBase@145] - Thread name bookie-io-13-1 @ send response and wait | org.apache.bookkeeper.proto.BookieProtocol$ReadResponse
2022-09-08T18:12:27,765 - ERROR - [bookie-io-13-1:SafeRunnable@38] - Unexpected throwable caught
io.netty.util.concurrent.BlockingOperationException: DefaultChannelPromise@50605c50(incomplete)
at io.netty.util.concurrent.DefaultPromise.checkDeadLock(DefaultPromise.java:462) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.checkDeadLock(DefaultChannelPromise.java:159) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:247) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:131) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:30) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.PacketProcessorBase.sendResponseAndWait(PacketProcessorBase.java:147) ~[classes/:?]
at org.apache.bookkeeper.proto.PacketProcessorBase.sendReadReqResponse(PacketProcessorBase.java:80) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.sendResponse(ReadEntryProcessor.java:140) ~[classes/:?]
at org.apache.bookkeeper.proto.ReadEntryProcessor.processPacket(ReadEntryProcessor.java:122) ~[classes/:?]
at org.apache.bookkeeper.proto.PacketProcessorBase.safeRun(PacketProcessorBase.java:175) ~[classes/:?]
at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestProcessor.processReadRequest(BookieRequestProcessor.java:665) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestProcessor.processRequest(BookieRequestProcessor.java:372) ~[classes/:?]
at org.apache.bookkeeper.proto.BookieRequestHandler.channelRead(BookieRequestHandler.java:78) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.AuthHandler$ServerSideHandler.channelRead(AuthHandler.java:86) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at org.apache.bookkeeper.proto.BookieProtoEncoding$RequestDecoder.channelRead(BookieProtoEncoding.java:447) ~[classes/:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) ~[netty-codec-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) ~[netty-codec-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.channelRead(FlushConsolidationHandler.java:152) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
2022-09-08T18:12:27,766 - ERROR - [bookie-io-13-1:BookieRequestHandler@68] - Unhandled exception occurred in I/O thread or handler on [id: 0xbf0f987a, L:/127.0.0.1:65522 - R:/127.0.0.1:65535]
io.netty.channel.socket.ChannelOutputShutdownException: Channel output shutdown
at io.netty.channel.AbstractChannel$AbstractUnsafe.shutdownOutput(AbstractChannel.java:650) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.handleWriteError(AbstractChannel.java:953) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:933) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:354) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:895) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushNow(FlushConsolidationHandler.java:204) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushIfNeeded(FlushConsolidationHandler.java:197) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.resetReadAndFlushIfNeeded(FlushConsolidationHandler.java:192) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.channelReadComplete(FlushConsolidationHandler.java:145) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:925) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:171) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: io.netty.util.IllegalReferenceCountException: refCnt: 0
at io.netty.buffer.AbstractByteBuf.ensureAccessible(AbstractByteBuf.java:1454) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.UnpooledHeapByteBuf.nioBuffer(UnpooledHeapByteBuf.java:305) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.nioBuffer(AbstractDerivedByteBuf.java:122) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.internalNioBuffer(AbstractDerivedByteBuf.java:117) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelOutboundBuffer.nioBuffers(ChannelOutboundBuffer.java:447) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:399) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:931) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
... 26 more
2022-09-08T18:12:27,767 - INFO - [bookkeeper-io-18-1:PerChannelBookieClient@1245] - Disconnected from bookie channel [id: 0x5b9f1585, L:/127.0.0.1:65535 ! R:/127.0.0.1:65522]
2022-09-08T18:12:27,767 - ERROR - [bookie-io-13-1:BookieRequestHandler@68] - Unhandled exception occurred in I/O thread or handler on [id: 0xbf0f987a, L:/127.0.0.1:65522 ! R:/127.0.0.1:65535]
io.netty.channel.socket.ChannelOutputShutdownException: Channel output shutdown
at io.netty.channel.AbstractChannel$AbstractUnsafe.shutdownOutput(AbstractChannel.java:650) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.handleWriteError(AbstractChannel.java:953) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:933) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:354) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:895) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushNow(FlushConsolidationHandler.java:204) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushIfNeeded(FlushConsolidationHandler.java:197) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.resetReadAndFlushIfNeeded(FlushConsolidationHandler.java:192) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.channelReadComplete(FlushConsolidationHandler.java:145) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:925) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:171) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: io.netty.util.IllegalReferenceCountException: refCnt: 0
at io.netty.buffer.AbstractByteBuf.ensureAccessible(AbstractByteBuf.java:1454) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.UnpooledHeapByteBuf.nioBuffer(UnpooledHeapByteBuf.java:305) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.nioBuffer(AbstractDerivedByteBuf.java:122) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.internalNioBuffer(AbstractDerivedByteBuf.java:117) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelOutboundBuffer.nioBuffers(ChannelOutboundBuffer.java:447) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:399) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:931) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
... 26 more
2022-09-08T18:12:27,768 - WARN - [bookie-io-13-1:ReferenceCountUtil@118] - Failed to release a message: UnpooledDuplicatedByteBuf(freed)
io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.release0(AbstractDerivedByteBuf.java:98) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.buffer.AbstractDerivedByteBuf.release(AbstractDerivedByteBuf.java:94) ~[netty-buffer-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.ReferenceCountUtil.safeRelease(ReferenceCountUtil.java:116) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelOutboundBuffer.remove0(ChannelOutboundBuffer.java:306) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.ChannelOutboundBuffer.failFlushed(ChannelOutboundBuffer.java:660) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.closeOutboundBufferForShutdown(AbstractChannel.java:672) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.shutdownOutput(AbstractChannel.java:666) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.handleWriteError(AbstractChannel.java:953) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:933) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:354) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:895) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushNow(FlushConsolidationHandler.java:204) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.flushIfNeeded(FlushConsolidationHandler.java:197) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.resetReadAndFlushIfNeeded(FlushConsolidationHandler.java:192) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.handler.flush.FlushConsolidationHandler.channelReadComplete(FlushConsolidationHandler.java:145) ~[netty-handler-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:925) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:171) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:722) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[netty-transport-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
2022-09-08T18:12:27,769 - INFO - [bookie-io-13-1:BookieRequestHandler@59] - Channels disconnected: [id: 0xbf0f987a, L:/127.0.0.1:65522 ! R:/127.0.0.1:65535]
2022-09-08T18:12:27,770 - ERROR - [BookKeeperClientWorker-OrderedExecutor-0-0:ReadLastConfirmedOp@151] - While readLastConfirmed ledger: 0 did not hear success responses from all quorums, QuorumCoverage(e:1,w:1,a:1) = [-8]
bk returned code -10 : Error while recovering ledger
error
</details>
I found if `setNumHighPriorityWorkerThreads` > 0, the test will pass. I suspect there has a deadlock but I haven't found other evidence. Do you have some ideas?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@bookkeeper.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org