3 Replies Latest reply on Jan 29, 2014 4:17 PM by William Burns

    Hanging threads in distribute cache ISPN 6.0.0.Final

    Mikolaj Gierulski Newbie

      We are running a distributed cluster using ISPN 6.0.0.Final.

      We have 10 cluster nodes - infinispan is embedded in our web application, deployed on 8 tomcat and 2 glassfish (v3) servers.

      These are running on two machines - 10 nodes let us keep heaps relatively small to avoid long gc pauses.

      All requests to the system come to two glassfish servers, which perform operations on the cluster.

      The standard load is about 140-200 qps, with up to 20 writes per second.

      We are using async distribute cache with numOwners=1. The transport is tcp.

      On regular basis we observe glassfish threads receiving InterruptedException in L1WriteSynchronizer.

      Further investigation shows, that InterruptedExceptions come from a Glassfish mechanism, which interrupts threads that show no activity for 15 minutes while handling single http request. This means, threads are sometimes hanging on infinispan operations for at least 15 minutes.

      I was able to reproduce this situation in our test environment and get a thread dump where there are two threads stuck in L1WriteSynchronizer for several hours.

      Below is a stacktrace of such thread. I also attach my ispn and jgroups config.

      What can be causing this and how to avoid this problem?

      Best regards,

      Mikolaj

       

      "http-thread-pool-5280(3)" daemon prio=10 tid=0x00007fbd30095000 nid=0x2efd waiting on condition [0x00007fbd489be000]
         java.lang.Thread.State: WAITING (parking)
           at sun.misc.Unsafe.park(Native Method)
           - parking to wait for   (a org.infinispan.interceptors.distribution.L1WriteSynchronizer$L1WriteSync)
           at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
           at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
           at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
           at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
           at org.infinispan.interceptors.distribution.L1WriteSynchronizer$L1WriteSync.innerGet(L1WriteSynchronizer.java:89)
           at org.infinispan.interceptors.distribution.L1WriteSynchronizer.get(L1WriteSynchronizer.java:138)
           at org.infinispan.interceptors.distribution.L1NonTxInterceptor.performL1Lookup(L1NonTxInterceptor.java:164)
           at org.infinispan.interceptors.distribution.L1NonTxInterceptor.performCommandWithL1WriteIfAble(L1NonTxInterceptor.java:116)
           at org.infinispan.interceptors.distribution.L1NonTxInterceptor.visitGetKeyValueCommand(L1NonTxInterceptor.java:104)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.EntryWrappingInterceptor.visitGetKeyValueCommand(EntryWrappingInterceptor.java:115)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112)
           at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:74)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitGetKeyValueCommand(NonTransactionalLockingInterceptor.java:34)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112)
           at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:74)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112)
           at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:74)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:258)
           at org.infinispan.statetransfer.StateTransferInterceptor.handleDefault(StateTransferInterceptor.java:242)
           at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:74)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:92)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
           at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:106)
           at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:70)
           at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:74)
           at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
           at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:321)
           at org.infinispan.CacheImpl.get(CacheImpl.java:368)
           at org.infinispan.CacheImpl.get(CacheImpl.java:360)
           at pl.com.agora.forum.backend.opinions.service.impl.IspnDistOpinionsServiceImpl.getEntityData(IspnDistOpinionsServiceImpl.java:426)
           at pl.com.agora.forum.backend.opinions.service.impl.IspnDistOpinionsServiceImpl.getOpinions(IspnDistOpinionsServiceImpl.java:92)
           at pl.com.agora.forum.backend.opinions.service.impl.StatisticsCollectingOpinionsService.getOpinions(StatisticsCollectingOpinionsService.java:48)
           at pl.com.agora.forum.backend.dist.rest.opinions.OpinionsDistController.doGetOpinions(OpinionsDistController.java:125)
           at pl.com.agora.forum.backend.dist.rest.opinions.OpinionsDistController.getOpinions(OpinionsDistController.java:115)
           at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
           at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
           at java.lang.reflect.Method.invoke(Method.java:601)
           at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213)
           at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126)
           at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96)
           at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617)
           at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578)
           at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
           at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
           at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
           at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
           at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
           at javax.servlet.http.HttpServlet.service(HttpServlet.java:668)
           at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
           at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
           at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
           at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
           at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
           at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
           at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
           at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:331)
           at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
           at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
           at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
           at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:860)
           at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
           at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
           at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
           at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
           at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
           at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
           at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
           at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
           at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
           at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
           at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
           at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
           at java.lang.Thread.run(Thread.java:722) 

       

      infinispan config

      <?xml version="1.0" encoding="UTF-8"?>

      <infinispan xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:infinispan:config:6.0 http://www.infinispan.org/schemas/infinispan-config-6.0.xsd" xmlns="urn:infinispan:config:6.0">

        <global>

        <globalJmxStatistics enabled="true" jmxDomain="org.infinispan.fb.dist"/>

        <transport clusterName="opinionsDist" machineId="${ispn.machineId}" nodeName="${ispn.nodeId}">

        <properties>

        <property name="configurationFile" value="jgroups-tcp.xml" />

        </properties>

        </transport>

        </global>

        <default>

        <jmxStatistics enabled="true"/>

        </default>

       

        <namedCache name="entityCache">

        <clustering mode="dist">

        <async/>

        <hash numOwners="1" numSegments="512" capacityFactor="0" factory="org.infinispan.distribution.ch.SyncConsistentHashFactory"/>

        <l1 enabled="true"/>

        </clustering>

        <eviction strategy="LIRS" maxEntries="1024" />

        <expiration lifespan="-1" maxIdle="-1" reaperEnabled="true" wakeUpInterval="10000" />

        <locking concurrencyLevel="256" isolationLevel="REPEATABLE_READ" useLockStriping="true"  />

        <transaction transactionMode="NON_TRANSACTIONAL" />

        <storeAsBinary enabled="false" />

        </namedCache>

      </infinispan>

      jgroups:

        
      

      <config xmlns="urn:org:jgroups"

              xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

              xsi:schemaLocation="urn:org:jgroups http://www.jgroups.org/schema/JGroups-3.4.xsd">

         <TCP

              bind_addr="${jgroups.tcp.address}"

              bind_port="${jgroups.tcp.port}"

              loopback="true"

              port_range="30"

              recv_buf_size="20m"

              send_buf_size="640k"

              max_bundle_size="31k"

              use_send_queues="true"

              enable_diagnostics="false"

              bundler_type="old"

       

       

              thread_naming_pattern="pl"

       

       

              thread_pool.enabled="true"

              thread_pool.min_threads="2"

              thread_pool.max_threads="30"

              thread_pool.keep_alive_time="60000"

              thread_pool.queue_enabled="true"

              thread_pool.queue_max_size="100"

              thread_pool.rejection_policy="Discard"

       

       

              oob_thread_pool.enabled="true"

              oob_thread_pool.min_threads="2"

              oob_thread_pool.max_threads="30"

              oob_thread_pool.keep_alive_time="60000"

              oob_thread_pool.queue_enabled="false"

              oob_thread_pool.queue_max_size="100"

              oob_thread_pool.rejection_policy="Discard"

       

       

              internal_thread_pool.enabled="true"

              internal_thread_pool.min_threads="1"

              internal_thread_pool.max_threads="10"

              internal_thread_pool.keep_alive_time="60000"

              internal_thread_pool.queue_enabled="true"

              internal_thread_pool.queue_max_size="100"

              internal_thread_pool.rejection_policy="Discard"

              />

       

       

         <FILE_PING timeout="3000" num_initial_members="1" location="${jgroups.fileping.location}"/>  

       

       

         <MERGE2 max_interval="30000" min_interval="10000"/>

       

       

         <FD_SOCK/>

         <FD timeout="3000" max_tries="5"/>

         <VERIFY_SUSPECT timeout="1500"/>

       

       

         <pbcast.NAKACK2 use_mcast_xmit="false"

                         xmit_interval="1000"

                         xmit_table_num_rows="100"

                         xmit_table_msgs_per_row="10000"

                         xmit_table_max_compaction_time="10000"

                         max_msg_batch_size="100"/>

         <UNICAST3 xmit_interval="500"

                   xmit_table_num_rows="20"

                   xmit_table_msgs_per_row="10000"

                   xmit_table_max_compaction_time="10000"

                   max_msg_batch_size="100"

                   conn_expiry_timeout="0"

                   conn_close_timeout="3000"/>

       

       

         <pbcast.STABLE stability_delay="500" desired_avg_gossip="5000" max_bytes="1m"/>

         <pbcast.GMS print_local_addr="false" join_timeout="3000" view_bundling="true"/>

         <tom.TOA/> <!-- the TOA is only needed for total order transactions-->

       

       

         <UFC max_credits="2m" min_threshold="0.40"/>

         <MFC max_credits="2m" min_threshold="0.40"/>

         <FRAG2 frag_size="30k"/>

         <RSVP timeout="60000" resend_interval="500" ack_on_delivery="false" />

      </config>