CacheLoader Latency Causes Failure to Persist Data - DB2
ray.ploski Sep 20, 2011 11:52 AMThe 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?