6 Replies Latest reply on Oct 14, 2019 3:16 AM by galder.zamarreno

    Infinispan on Openshift: Hotrod Exception

    sameer.kaikini

      Hello,

       

      1. Infinispan 9.4.11 has been deployed on Openshift 3.11.43 using Infinispan operator using minimal configuration yaml. Practically, default configuration.
      2. Two deployments available, one has a 2-node cluster and the other is a single-node cluster
      3. The hotrod ports are exposed as routes in addition to the REST ports
      4. Clusters have been secured with a user (‘developer’) and password (random string) by default
      5. Wrote very basic PoC/sample client applications to access the remote cache, just to make sure it works.
      6. The client apps are running outside the OpenShift cluster
      7. netstat shows connection in ESTABLISHED state
      8. REST client app works as expected
      9. Hotrod client app does not work. It takes a min (~61 secs) for the RemoteCacheManager constructor to return. RemoteCacheManager.getCache() (or any other call) does not return. We see the below exception repeatedly on the console.
      10. No logs are available on the server side for the requests.

       

      org.infinispan.client.hotrod.exceptions.TransportException:: java.net.SocketTimeoutException: AuthMechListOperation{(default), flags=0} timed out after 60000 ms

             at org.infinispan.client.hotrod.impl.transport.netty.ActivationHandler.exceptionCaught(ActivationHandler.java:53)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:285)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:264)

             at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:256)

             at io.netty.channel.DefaultChannelPipeline$HeadContext.exceptionCaught(DefaultChannelPipeline.java:1401)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:285)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:264)

             at io.netty.channel.DefaultChannelPipeline.fireExceptionCaught(DefaultChannelPipeline.java:953)

             at org.infinispan.client.hotrod.impl.transport.netty.AuthHandler.lambda$channelActive$2(AuthHandler.java:86)

             at java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:870)

             at java.util.concurrent.CompletableFuture$UniExceptionally.tryFire(CompletableFuture.java:852)

             at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

             at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)

             at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:172)

             at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38)

             at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:127)

             at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)

             at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404)

             at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:464)

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

             at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

             at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

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

       

      The code:

      public class CacheClient {

                    @SuppressWarnings("deprecation")

                    public static void main( String[] args) throws InterruptedException {

                  

                      System.out.println( "Start" );

                      // Create a configuration for a remote server

                      ConfigurationBuilder builder = new ConfigurationBuilder();

                      builder.addServer().host("dev-infinispan-hotrod")

                      .port(ConfigurationProperties.DEFAULT_HOTROD_PORT).security() .authentication() .saslMechanism("PLAIN")

                           .username("developer") .password("epXZ,unWL@CIy\\,V");

                      System.out.println("Builder configured");

                      // Connect to the server

                      RemoteCacheManager cacheManager = new RemoteCacheManager(builder.build());

                      System.out.println("CacheManager created::"+cacheManager);

                      System.out.println("Cache Connection Count::"+cacheManager.getConnectionCount()+"--IsStarted::"+cacheManager.isStarted());

       

                      // Obtain the remote cache

                      RemoteCache<String, String> cache = cacheManager.getCache();

                      System.out.println("Cache created");

       

                      cache.put("key1", "value1");

                     System.out.println("cache.put() executed");

                      cache.put("key2", "value2");

                      System.out.println("cache.put() executed");

                      cache.put("key1","newValue");

                      System.out.println("cache.put() executed");

       

          }

       

      Output:

      Start

      Builder configured

      Sep 18, 2019 2:03:21 PM org.infinispan.client.hotrod.RemoteCacheManager actualStart

      INFO: ISPN004021: Infinispan version: 9.4.11.Final

      CacheManager created::org.infinispan.client.hotrod.RemoteCacheManager@2ff5659e

      Cache Connection Count::0--IsStarted::true

      org.infinispan.client.hotrod.exceptions.TransportException:: java.net.SocketTimeoutException: AuthMechListOperation{(default), flags=0} timed out after 60000 ms

             at org.infinispan.client.hotrod.impl.transport.netty.ActivationHandler.exceptionCaught(ActivationHandler.java:53)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:285)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:264)

             at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:256)

             at io.netty.channel.DefaultChannelPipeline$HeadContext.exceptionCaught(DefaultChannelPipeline.java:1401)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:285)

             at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:264)

             at io.netty.channel.DefaultChannelPipeline.fireExceptionCaught(DefaultChannelPipeline.java:953)

             at org.infinispan.client.hotrod.impl.transport.netty.AuthHandler.lambda$channelActive$2(AuthHandler.java:86)

             at java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:870)

             at java.util.concurrent.CompletableFuture$UniExceptionally.tryFire(CompletableFuture.java:852)

             at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

             at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)

             at org.infinispan.client.hotrod.impl.operations.HotRodOperation.run(HotRodOperation.java:172)

             at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38)

             at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:127)

             at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)

             at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404)

             at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:464)

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

             at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

             at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

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

       

      Any idea what could be going wrong?