6 Replies Latest reply on Dec 24, 2010 12:46 AM by Thiyagu V

    org.infinispan.util.concurrent.TimeoutException

    craig bomba Novice

      I believe the exception below may be related to removing the queue between my app thread and the transport.  I recently removed the asyncMarshalling (ie set it explicitly to false) on my replicated cache.  The exception below seems to be created a deadlock. 

       

       

       

      2010-06-15 06:07:04,126 3167845 TRACE [org.jgroups.protocols.TCP] (Incoming-48,infinispan-cluster-EquityTradeServer1-test16,test16a_GCBC-53813:)received [dst: <null>, src: test16a_GCBC-53813 (3 headers), size=750 bytes], headers are RequestCorrelator: id=201, type=REQ, id=482, rsp_expecte

      d=true, NAKACK: [MSG, seqno=611], TCP: [channel_name=infinispan-cluster-EquityTradeServer1-test16]

      2010-06-15 06:07:04,125 3167844 TRACE [org.jgroups.protocols.FC] (Incoming-13,infinispan-cluster-EquityTradeServer1-test16,test16a_GCBC-53813:) s

      ender test16a_GCBC-53813 minus 750 credits, 1887500 remaining

      2010-06-15 06:07:04,184 3167903 TRACE [org.jgroups.protocols.TCP] (Incoming-48,infinispan-cluster-EquityTradeServer1-test16,test16a_GCBC-53813:)

      received [dst: <null>, src: test16a_GCBC-53813 (3 headers), size=750 bytes], headers are RequestCorrelator: id=201, type=REQ, id=480, rsp_expecte

      d=true, NAKACK: [MSG, seqno=609], TCP: [channel_name=infinispan-cluster-EquityTradeServer1-test16]

      2010-06-15 06:07:04,184 3167903 TRACE [org.jgroups.protocols.TCP] (OOB-49,infinispan-cluster-EquityTradeServer1-test16,test16a_GCBC-53813:) recei

      ved [dst: test16a_GCBC-53813, src: test16b_GCBC-48822 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, TCP: [channel_name=in

      finispan-cluster-EquityTradeServer1-test16]

      2010-06-15 06:07:04,185 3167904 TRACE [org.jgroups.protocols.TCP] (Incoming-48,infinispan-cluster-EquityTradeServer1-test16,test16a_GCBC-53813:)

      received [dst: <null>, src: test16a_GCBC-53813 (3 headers), size=750 bytes], headers are RequestCorrelator: id=201, type=REQ, id=481, rsp_expecte

      d=true, NAKACK: [MSG, seqno=610], TCP: [channel_name=infinispan-cluster-EquityTradeServer1-test16]

      2010-06-15 06:07:04,183 3167902 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (CommandProcessorThread.SGEN:) Execution error:
      org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [20 seconds] on key [377553362] for requestor [Thread[CommandProces
      sorThread.SGEN,5,main]]! Lock held by [Thread[CommandProcessorThread.SNHY,5,main]]
              at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:213)
              at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:148)
              at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
              at org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:197)
              at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
              at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
              at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
              at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:183)
              at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:132)
              at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
              at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
              at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
              at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
              at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
              at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
              at org.infinispan.CacheDelegate.put(CacheDelegate.java:414)
              at org.infinispan.CacheSupport.put(CacheSupport.java:30)
              at com.cboe.infrastructureServices.cacheService.JCacheServiceInfinispanImpl.put(JCacheServiceInfinispanImpl.java:84)
              at com.cboe.server.distributedCache.DistributedCacheImpl.put(DistributedCacheImpl.java:122)
              at com.cboe.server.distributedCache.DistributedCacheImpl.put(DistributedCacheImpl.java:17)
              at com.cboe.internalBusinessServices.productStateService.TradingProductSyncImpl.updateProductData(TradingProductSyncImpl.java:140)
              at com.cboe.internalBusinessServices.productStateService.TradingProductSyncImpl.updateToSync(TradingProductSyncImpl.java:240)
              at com.cboe.internalBusinessServices.productStateService.TradingProductImpl.changesCommitted(TradingProductImpl.java:3603)
              at com.objectwave.transactionalSupport.TransactionLog.commit(TransactionLog.java:319)
              at com.objectwave.transactionalSupport.Session.commit(Session.java:51)
              at com.cboe.infrastructureServices.foundationFramework.transactionManagement.BOSession.commit(BOSession.java:99)
              at com.cboe.infrastructureServices.foundationFramework.utilities.TransactionBaseImpl.commit(TransactionBaseImpl.java:122)
              at com.cboe.infrastructureServices.foundationFramework.utilities.Transaction.commit(Transaction.java:22)
              at com.cboe.internalBusinessServices.productStateService.ProductStateChangeByClassCommand.execute(ProductStateChangeByClassCommand.java:8
      2)
              at com.cboe.server.commandProcessing.CommandProcessorImpl.processCommands(CommandProcessorImpl.java:272)
              at com.cboe.server.commandProcessing.CommandProcessorComboQueueImpl.handleCommands(CommandProcessorComboQueueImpl.java:77)
              at com.cboe.server.commandProcessing.CommandProcessorComboQueueImpl.run(CommandProcessorComboQueueImpl.java:275)
              at java.lang.Thread.run(Thread.java:619)

       

       

      Jgroups contents:

       

      <config xmlns="urn:org:jgroups"

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

              xsi:schemaLocation="urn:org:jgroups file:schema/JGroups-2.8.xsd">

         <TCP bind_port="7850"

              loopback="true"

              port_range="30"

              recv_buf_size="20000000"

              send_buf_size="640000"

              discard_incompatible_packets="true"

              max_bundle_size="64000"

              max_bundle_timeout="30"

              enable_bundling="true"

              use_send_queues="true"

              sock_conn_timeout="300"

              enable_diagnostics="false"

       

              thread_pool.enabled="true"

              thread_pool.min_threads="2"

              thread_pool.max_threads="30"

              thread_pool.keep_alive_time="5000"

              thread_pool.queue_enabled="false"

              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="5000"

              oob_thread_pool.queue_enabled="false"

              oob_thread_pool.queue_max_size="100"

              oob_thread_pool.rejection_policy="Discard"

               />

       

         <MPING receive_on_all_interfaces="true"  break_on_coord_rsp="true"

            mcast_addr="${jgroups.udp.mcast_addr:228.6.7.8}" mcast_port="${jgroups.udp.mcast_port:42610}" ip_ttl="${jgroups.udp.ip_ttl:16}"

            num_initial_members="2" num_ping_requests="1"/>

       

         <MERGE2 max_interval="30000"

                 min_interval="10000"/>

         <FD_SOCK/>

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

         <VERIFY_SUSPECT timeout="1500"/>

         <pbcast.NAKACK

               use_mcast_xmit="false" gc_lag="0"

               retransmit_timeout="300,600,1200,2400,4800"

               discard_delivered_msgs="false"/>

         <UNICAST timeout="300,600,1200"/>

         <pbcast.STABLE stability_delay="1000" desired_avg_gossip="50000"

                        max_bytes="400000"/>

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

         <FC max_credits="2000000"

             min_threshold="0.10"/>

         <FRAG2 frag_size="60000"/>

         <pbcast.STREAMING_STATE_TRANSFER/>

         <!-- <pbcast.STATE_TRANSFER/> -->

         <pbcast.FLUSH timeout="0"/>

      </config>