1 Reply Latest reply on Oct 5, 2011 3:38 AM by galder.zamarreno

    CacheLoader Latency Causes Failure to Persist Data - DB2

    ray.ploski

      The following error is thrown in DIST mode and generates a raise in the average response time and also some data does not get persisted in the database with the Cache Store. The database is a DB2.

       

       

      2011-08-12 11:18:43,602 DEBUG [ar.com.osde.agentedemo.backend.filter.BPFilterStrategy] Se agrego el Consumo con BP= 236099001523727575

      2011-08-12 11:18:43,610 DEBUG [ar.com.osde.agentedemo.backend.filter.ContratoFilterStrategy] Se agrego el Consumo con NumeroContrato= 6025007528944750468

      2011-08-12 11:18:43,611 DEBUG [ar.com.osde.agentedemo.backend.filter.ContratoYOrdenFilterStrategy] Se agrego el Consumo con Id = 3577937037768888757

      2011-08-12 11:18:48,974 DEBUG [ar.com.osde.agentedemo.backend.filter.BPFilterStrategy] Se agrego el Consumo con BP= 6467343532756890789

      2011-08-12 11:18:48,986 DEBUG [ar.com.osde.agentedemo.backend.filter.ContratoFilterStrategy] Se agrego el Consumo con NumeroContrato= 7923713369101594335

      2011-08-12 11:18:48,986 DEBUG [ar.com.osde.agentedemo.backend.filter.ContratoYOrdenFilterStrategy] Se agrego el Consumo con Id = 1006828495934204769

      2011-08-12 11:19:03,289 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] ISPN000136: Execution error

      org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [20 seconds] on key [3644692677981402374.1021409333048166645] for requestor [Thread[OOB-1,dhcp-192-168-0-133-54192,5,Thread Pools]]! Lock held by [DldGlobalTransaction{coinToss=1055335540884825396, isMarkedForRollback=false, lockIntention=null, affectedKeys=[], locksAtOrigin=[]} GlobalTransaction:<dhcp-192-168-0-133-23435>:2:remote]

          at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:240)

          at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:133)

          at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeededAndUpdateStats(CacheLoaderInterceptor.java:218)

          at org.infinispan.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:90)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)

          at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)

          at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)

          at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:201)

          at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:192)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:84)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)

          at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:104)

          at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:64)

          at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)

          at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)

          at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:274)

          at org.infinispan.commands.remote.ClusteredGetCommand.perform(ClusteredGetCommand.java:105)

          at org.infinispan.commands.remote.ClusteredGetCommand.perform(ClusteredGetCommand.java:53)

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:181)

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:195)

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:289)

          at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:167)

          at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:165)

          at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:144)

          at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:577)

          at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:488)

          at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:364)

          at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:770)

          at org.jgroups.JChannel.up(JChannel.java:1484)

          at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1074)

          at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:263)

          at org.jgroups.protocols.FRAG2.up(FRAG2.java:189)

          at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

          at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)

          at org.jgroups.protocols.pbcast.GMS.up(GMS.java:908)

          at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:246)

          at org.jgroups.protocols.UNICAST.handleDataReceived(UNICAST.java:575)

          at org.jgroups.protocols.UNICAST.up(UNICAST.java:294)

          at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:703)

          at org.jgroups.protocols.BARRIER.up(BARRIER.java:99)

          at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:177)

          at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:275)

          at org.jgroups.protocols.MERGE2.up(MERGE2.java:209)

          at org.jgroups.protocols.Discovery.up(Discovery.java:293)

          at org.jgroups.protocols.PING.up(PING.java:69)

          at org.jgroups.protocols.TP.passMessageUp(TP.java:1109)

          at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1665)

          at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1647)

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

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

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

       

      We are controlling the timeout with lockAcquisitionTimeout attribute http://docs.jboss.org/infinispan/5.0/apidocs/config.html#ce_default_locking (Now configured in 20000 ms)

       

       

      In replication mode, with 4 nodes and cache loader in sync mode, this error is not happening.

       

      There is a related reported error  http://community.jboss.org/thread/162158?tstart=0

       

      Could this issue be caused from using jboss-4.3?