Infinispan ISPN005003 Connection Reset

[ramiseesniblic]

Hello.

I am running infinispan 9 as a separate application on a server and it is connected into by various microservices.  During heavy load I am seeing a failure of infinispan and the following exception on the infinispan log:

2017-10-25 18:16:02,902 ERROR [org.infinispan.server.hotrod.CacheDecodeContext] (HotRod-ServerWorker-5-16) ISPN005003: Exception reported: io.netty.channel.unix.Errors$NativeIoException: syscall:read(..) failed: Connection reset by peer

        at io.netty.channel.unix.FileDescriptor.readAddress(..)(Unknown Source)

2017-10-25 22:10:17,279 WARNING [io.netty.util.concurrent.SingleThreadEventExecutor] (HotRod-ServerMaster-4-1) Unexpected exception from an event executor: : java.lang.OutOfMemoryError: Java heap space

2017-10-25 22:09:34,709 WARNING [io.netty.channel.AbstractChannelHandlerContext] (HotRod-ServerWorker-5-3) An exception 'java.lang.BootstrapMethodError: call site initialization exception' [enable DEBUG level for full stacktrace] was thrown by a user handler's exceptionCaught() method while handling the following exception:: java.lang.OutOfMemoryError: Java heap space

On the microservice logs I am seeing:

17:45:45.431 [DefaultMessageListenerContainer-1] [user="" token=""] ERROR o.i.c.h.i.o.RetryOnFailureOperation - ISPN004007: Exception encountered. Retry 10 out of 10

org.infinispan.client.hotrod.exceptions.TransportException: java.net.SocketTimeoutException

        at org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport.readByte(TcpTransport.java:225)

        at org.infinispan.client.hotrod.impl.protocol.Codec20.readMagic(Codec20.java:325)

        at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:135)

        at org.infinispan.client.hotrod.impl.operations.HotRodOperation.readHeaderAndValidate(HotRodOperation.java:60)

        at org.infinispan.client.hotrod.impl.operations.AbstractKeyValueOperation.sendPutOperation(AbstractKeyValueOperation.java:58)

        at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:34)

        at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:56)

        at org.infinispan.client.hotrod.impl.RemoteCacheImpl.put(RemoteCacheImpl.java:269)

        at org.infinispan.client.hotrod.impl.RemoteCacheSupport.put(RemoteCacheSupport.java:79)

        at sun.reflect.GeneratedMethodAccessor68.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:180)

        at org.springframework.messaging.handler.invocation.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:112)

        at org.springframework.jms.listener.adapter.MessagingMessageListenerAdapter.invokeHandler(MessagingMessageListenerAdapter.java:104)

        at org.springframework.jms.listener.adapter.MessagingMessageListenerAdapter.onMessage(MessagingMessageListenerAdapter.java:69)

        at org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:721)

        at org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:681)

        at org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:651)

        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:317)

        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:255)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1166)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1158)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1055)

        at java.lang.Thread.run(Thread.java:748)

Caused by: java.net.SocketTimeoutException: null

I am at a loss as to why the socket is failing.

I am running Centos 7 with infinispan allocated 2GB (JAVA_OPTS="-Xms64m -Xmx2048m -Djava.net.preferIPv4Stack=true").

The hotrod config in the xml file is:

            <hotrod-connector cache-container="local" socket-binding="hotrod">

                <topology-state-transfer lazy-retrieval="false" lock-timeout="1000" replication-timeout="5000"/>

            </hotrod-connector>

Any ideas if I have this miss-configured?

[gustavonalle]

The server failed to respond due to heap memory exhaustion:

(HotRod-ServerMaster-4-1) Unexpected exception from an event executor: : java.lang.OutOfMemoryError: Java heap space

What is your heap size? By default the server uses 512 Mb, and you should be able to increase it on bin/standalone.conf or via JAVA_OPTS environment variable.

[ramiseesniblic]

Hello.

Thanks for the answer.

As shown, our configuration is : JAVA_OPTS="-Xms64m -Xmx2048m -Djava.net.preferIPv4Stack=true"

[sebastian.laskawiec]

Perhaps you might be interested in checkout our Performance Guide? Infinispan 9.2 Performance Guide

It should give you some hints on configuring JVM as well how to do capacity planning.

[ramiseesniblic]

An update.

I have enabled a more finer level of output and we are also seeing the following:

2017-10-26 14:51:10,024 ERROR [org.infinispan.server.hotrod.CacheDecodeContext] (HotRod-ServerWorker-5-9) ISPN005003: Exception reported: org.infinispan.server.hotrod.UnknownVersionException: Unknown version:30

        at org.infinispan.server.hotrod.HotRodDecoder.readHeader(HotRodDecoder.java:240)

        at org.infinispan.server.hotrod.HotRodDecoder.decodeHeader(HotRodDecoder.java:152)

        at org.infinispan.server.hotrod.HotRodDecoder.decode(HotRodDecoder.java:93)

        at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)

        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.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:26)

        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:1334)

        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:926)

        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:1017)

        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:394)

        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:299)

        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)

        at java.lang.Thread.run(Thread.java:748)

The new OOM exception is now:

2017-10-26 14:48:29,134 ERROR [org.infinispan.server.hotrod.HotRodEncoder] (HotRod-ServerWorker-5-2) ISPN005023: Exception encoding message GetResponse{version=12, messageId=4756179, cacheName='<CACHENAME>', clientIntel=3, operation=GET, status=KeyDoesNotExist, topologyId=-1, data=null}: java.lang.OutOfMemoryError: GC overhead limit exceeded

        at java.util.Arrays.copyOf(Arrays.java:3332)

        at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124)

        at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:649)

        at java.lang.StringBuilder.append(StringBuilder.java:202)

        at org.jboss.modules.LocalModuleLoader.toString(LocalModuleLoader.java:62)

        at org.jboss.modules.Module.toString(Module.java:933)

        at java.lang.String.valueOf(String.java:2994)

        at java.lang.StringBuilder.append(StringBuilder.java:131)

        at org.jboss.modules.ModuleClassLoader.getClassNotFoundExceptionMessage(ModuleClassLoader.java:210)

        at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:198)

        at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:363)

        at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:351)

        at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:93)

        at java.lang.Class.forName0(Native Method)

        at java.lang.Class.forName(Class.java:348)

        at org.jboss.logging.Logger$1.run(Logger.java:2544)

        at java.security.AccessController.doPrivileged(Native Method)

        at org.jboss.logging.Logger.getMessageLogger(Logger.java:2529)

        at org.jboss.logging.Logger.getMessageLogger(Logger.java:2516)

        at org.infinispan.commons.logging.LogFactory.getLog(LogFactory.java:18)

        at org.infinispan.server.hotrod.AbstractEncoder1x.<init>(AbstractEncoder1x.java:38)

        at org.infinispan.server.hotrod.AbstractTopologyAwareEncoder1x.<init>(AbstractTopologyAwareEncoder1x.java:32)

        at org.infinispan.server.hotrod.HotRodEncoder$2.<init>(HotRodEncoder.java:92)

        at org.infinispan.server.hotrod.HotRodEncoder.getEncoder(HotRodEncoder.java:92)

        at org.infinispan.server.hotrod.HotRodEncoder.encode(HotRodEncoder.java:53)

        at io.netty.handler.codec.MessageToByteEncoder.write(MessageToByteEncoder.java:107)

        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:738)

        at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:801)

        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814)

        at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794)

        at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:831)

        at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1032)

Is the remote cache creating a new Java Object and returning that when requested by a remote client "get()" ?

Just to give some context.  The Infinispan server is v9 and the microservices use v9 hotrod client.  I also have another system (JBoss EAP 6.3) that is accessing the Infinispan server with v5 of the hotrod client.  Could there be some incompatibility with the server and hotrod client version?

[galder.zamarreno]

By default, the v9 hot rod client will use a version that a v9 server understands. What the error is saying is that the v5 server does not understand the v9 version, which makes sense. However, you can configure the v9 client with the Hot Rod protocol version understood by the v5 server. You can configure this via the client configuration, as indicated in the Hot Rod protocol reference guide, you probably want to set the version to 1.2 or earlier depending on which v5 server you use.

[galder.zamarreno]

For the GC error, either give it more memory or set -XX:+HeapDumpOnOutOfMemoryError and then take the heap and inspect it using Eclipse Memory Analyzer or similar tools.

[ramiseesniblic]

Hello.

I think I wasn't too clear about the fact that we have a v9 server and a v5 client.  Is there anyway to make the v9 server accept the v5 client messages?

[nadirx]

Version 30 is very strange, since we haven't reached that yet. Infinispan 5.2 (that is inside EAP 6.x) supports protocol 1.2 (aka 12). Infinispan Server should support all existing versions (going back to 1.0). Maybe try forcing the client version to 1.2.