[infinispan-issues] [JBoss JIRA] (HRJS-24) "Unknown version:-96" appears sometimes on the server while put/get operation
Galder Zamarreño (JIRA)
issues at jboss.org
Thu Jan 12 12:02:00 EST 2017
[ https://issues.jboss.org/browse/HRJS-24?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13347461#comment-13347461 ]
Galder Zamarreño commented on HRJS-24:
--------------------------------------
I've not been able to run this Radargun combo locally :( , but I've run some smaller tests which give some clues to what is going on.
I suspect what is happening here is that the integration layer in Radargun might be over stressing the JS client. I think the radargun Node.js client might be sending multiple operations in parallel (either implicitly or explicitly) over a single client instance.
Currently the Node.js client does not have connection pooling, so creating a a node.js client will keep at most, one connection for each server there is in the topology. With that in mind, a well behaving client should execute an operation, and when that completes, send the next one...etc.
If you take a client, and send 100 put operations without waiting for them to complete (e.g. execute [this script|https://gist.github.com/galderz/c6390bb2bb2e7a2a2106856aeebb798d]), I see exceptions such as the ones above appearing in the logs:
{code}
[Server:server-local] 17:26:53,768 ERROR [org.infinispan.server.hotrod.CacheDecodeContext] (HotRodServerWorker-7-6) ISPN005003: Exception reported: org.infinispan.server.hotrod.UnknownVersionException: Unknown version:-96
[Server:server-local] at org.infinispan.server.hotrod.HotRodDecoder.readHeader(HotRodDecoder.java:202)
{code}
This is not a problem specific to the Node.js. You'd have the same issue if for example, you take the Java Hot Rod client, and given an iterator, you try to iterate over it in parallel (see [this test|https://github.com/galderz/infinispan/blob/15053b36ee05db886cf859210911ac3f92006df1/client/hotrod-client/src/test/java/org/infinispan/client/hotrod/impl/iteration/SingleServerParallelRemoteIteratorTest.java]).
What's different Node.js is that because all operations are async, you can implicitly get such problems if you send operations and don't wait for them to complete, like in the sample script above.
Even if you have a connection pool per node, you could put so much load on a single client instance without waiting that you might have such issues too. However, I don't think implicit parallelism is the problem with Radargun since the nodejs-http-client.js script stored in the svn repo (why is that not part of Radargun?) seems to respond when the operation completes.
Apart from implicit parallelism, similar issue could be encountered with explicit parallelism. Here, you take a single client instance and you share it between different threads. This is more likely what is happening here because the http server in nodejs-http-client.js uses a single client, and since there are several threads sending http requests, maybe there's some overlapping between the different requests...
In essence, I think we need to find a way to avoid such overlapping. Connection pooling might be the way to go but I need to look further into it...
> "Unknown version:-96" appears sometimes on the server while put/get operation
> -----------------------------------------------------------------------------
>
> Key: HRJS-24
> URL: https://issues.jboss.org/browse/HRJS-24
> Project: Infinispan Javascript client
> Issue Type: Bug
> Affects Versions: 0.3.0
> Reporter: Anna Manukyan
> Assignee: Galder Zamarreño
>
> I have extended the radargun with nodejs plugin so that later it is possible to test the xsite failover.
> The issue is that sometimes under the load while performing a put/get request over nodejs client, I am getting the following exception on the server:
> {code}
> 14:02:56,885 ERROR [org.infinispan.server.hotrod.CacheDecodeContext] (HotRodServerWorker-7-1) ISPN005003: Exception reported: org.infinispan.server.hotrod.UnknownVersionException: Unknown version:-96
> at org.infinispan.server.hotrod.HotRodDecoder.readHeader(HotRodDecoder.java:199)
> at org.infinispan.server.hotrod.HotRodDecoder.decodeHeader(HotRodDecoder.java:129)
> at org.infinispan.server.hotrod.HotRodDecoder.decode(HotRodDecoder.java:87)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:387)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:245)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeChannelReadNow(ChannelHandlerInvokerUtil.java:83)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeChannelRead(DefaultChannelHandlerInvoker.java:154)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:354)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:145)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:28)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeChannelReadNow(ChannelHandlerInvokerUtil.java:83)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeChannelRead(DefaultChannelHandlerInvoker.java:154)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:354)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:145)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:1078)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:872)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:359)
> at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:275)
> at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:742)
> at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
> at java.lang.Thread.run(Thread.java:745)
> 14:02:56,888 ERROR [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-7-1) ISPN005023: Exception encoding message ErrorResponse{version=-96, messageId=-9223372036854775808, operation=ErrorResponse, status=UnknownVersion, msg=org.infinispan.server.hotrod.UnknownVersionException: Unknown version:-96}: scala.MatchError: -96 (of class java.lang.Byte)
> at org.infinispan.server.hotrod.HotRodEncoder.getEncoder(HotRodEncoder.scala:79)
> at org.infinispan.server.hotrod.HotRodEncoder.encode(HotRodEncoder.scala:38)
> at io.netty.handler.codec.MessageToByteEncoder.write(MessageToByteEncoder.java:107)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeWriteNow(ChannelHandlerInvokerUtil.java:157)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeWrite(DefaultChannelHandlerInvoker.java:372)
> at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:400)
> at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:266)
> at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:272)
> at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1186)
> at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:286)
> at org.infinispan.server.hotrod.HotRodExceptionHandler.exceptionCaught(HotRodExceptionHandler.java:31)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.ChannelHandlerAdapter.exceptionCaught(ChannelHandlerAdapter.java:78)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeExceptionCaughtNow(ChannelHandlerInvokerUtil.java:64)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeExceptionCaught(DefaultChannelHandlerInvoker.java:111)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:346)
> at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:131)
> at io.netty.channel.DefaultChannelPipeline.fireExceptionCaught(DefaultChannelPipeline.java:1066)
> at org.infinispan.server.hotrod.HotRodDecoder.decode(HotRodDecoder.java:124)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:387)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:245)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeChannelReadNow(ChannelHandlerInvokerUtil.java:83)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeChannelRead(DefaultChannelHandlerInvoker.java:154)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:354)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:145)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:28)
> at io.netty.channel.ChannelHandlerInvokerUtil.invokeChannelReadNow(ChannelHandlerInvokerUtil.java:83)
> at io.netty.channel.DefaultChannelHandlerInvoker.invokeChannelRead(DefaultChannelHandlerInvoker.java:154)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:354)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:145)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:1078)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:872)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:359)
> at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:275)
> at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:742)
> at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
> at java.lang.Thread.run(Thread.java:745)
> {code}
> I am using the infinispan-js-client 0.3.0. For server different versions are tried - 8.4.2.Final, 9.0.0.Alpha4 - the issue still appears. For 20000 requests I am getting this error for about 3-4 times (maybe more, because after the error appears I am getting an exception on Java side).
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)
More information about the infinispan-issues
mailing list