Hmm, yes, looks messed up. Do you have a reliable repro of this? "at io.netty.channel.DefaultChannelPipeline.onUnhandledInboundMessage" <- it seems the message itself wasn't handled. Do you have any more bookie side logs leading up to this event?
-Ivan On Thu, Mar 8, 2018 at 9:18 AM, Enrico Olivelli <[email protected]> wrote: > Hi all, > I am seeing this bad errors in some test environments with 4.6.1 > The errors appear during rolling restart of the application, the test env is > made of 6 machines: > - 3 bookies > - 3 client machines (with several BK clients, of different sub-systems) > - running with 4.6.1 both client and servers > > *I do not have* reports of this errors from production, already running > 4.6.1 for the last month > > But the problem is quite scary > > This is a sample of relevant errors on clients (in this case Majordodo > brokers, with log level = INFO) > > logs/org.apache.bookkeeper.client.PendingAddOp: > 18-03-07-09-51-43 Write of ledger entry to quorum failed: L366634 > E2557 > 18-03-07-09-51-43 Write of ledger entry to quorum failed: L366634 > E2558 > 18-03-07-09-51-43 Write of ledger entry to quorum failed: L366634 > E2559 > 18-03-07-15-59-55 Failed to write entry (366680, 1865): Bookie > operation timeout > 18-03-07-15-59-55 Failed to write entry (366680, 1865): Bookie > operation timeout > 18-03-07-16-00-00 Failed to write entry (366680, 1865): Bookie > operation timeout > 18-03-07-16-00-00 Failed to write entry (366680, 1865): Bookie > operation timeout > 18-03-07-16-00-05 Failed to write entry (366680, 1865): Bookie > operation timeout > > > org.apache.bookkeeper.proto.PerChannelBookieClient: > > 18-03-07-10-06-44 Unexpected exception caught by bookie client channel > handler > 18-03-07-10-06-44 io.netty.handler.codec.DecoderException: > java.lang.IllegalStateException: Received unknown response : op code = 6 > io.netty.handler.codec.DecoderException: java.lang.IllegalStateException: > Received unknown response : op code = 6 > at > io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:98) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) > at > io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) > at > io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413) > at > io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1414) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:945) > at > io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800) > at > io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) > at > io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304) > at > io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) > at java.base/java.lang.Thread.run(Thread.java:844) > Caused by: java.lang.IllegalStateException: Received unknown response : op > code = 6 > at > org.apache.bookkeeper.proto.BookieProtoEncoding$ResponseEnDeCoderPreV3.decode(BookieProtoEncoding.java:294) > at > org.apache.bookkeeper.proto.BookieProtoEncoding$ResponseDecoder.decode(BookieProtoEncoding.java:478) > at > io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88) > > > ... 19 more > > > Errors on Bookie side, with log level = INFO) > > > io.netty.channel.DefaultChannelPipeline: > 8-03-07-09-51-38 An exceptionCaught() event was fired, and it reached > at the tail of the pipeline. It usually means the last handler in the > pipeline did not handle the exception. > 18-03-07-09-51-38 io.netty.util.IllegalReferenceCountException: > refCnt: 0, increment: 1 > io.netty.util.IllegalReferenceCountException: refCnt: 0, increment: 1 > at > io.netty.buffer.AbstractReferenceCountedByteBuf.release0(AbstractReferenceCountedByteBuf.java:100) > at > io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:84) > at > io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:88) > at > io.netty.channel.DefaultChannelPipeline.onUnhandledInboundMessage(DefaultChannelPipeline.java:1202) > at > io.netty.channel.DefaultChannelPipeline$TailContext.channelRead(DefaultChannelPipeline.java:1299) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > org.apache.bookkeeper.proto.BookieRequestHandler.channelRead(BookieRequestHandler.java:78) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) > at > org.apache.bookkeeper.proto.AuthHandler$ServerSideHandler.channelRead(AuthHandler.java:88) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) > at > io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) > at > io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:413) > at > io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) > at > io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1414) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) > at > io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) > at > io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:945) > at > io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800) > at > io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) > at > io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304) > at > io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) > at java.base/java.lang.Thread.run(Thread.java:844) > >
