[infinispan-issues] [JBoss JIRA] (ISPN-6366) NPE during startup/initialization of cache from other cluster members in a distributed, synchronized cluster

Mehdi Rakhshani (JIRA) issues at jboss.org
Fri Mar 11 11:29:00 EST 2016 

    [ https://issues.jboss.org/browse/ISPN-6366?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13175520#comment-13175520 ] 

Mehdi Rakhshani commented on ISPN-6366:
---------------------------------------

The app servers come up and wait for a REST request to read the data; they do not update the cache as long as the cache is reliable (meaning the "cluster" cache, which is updated by cache managers, contains a count for each data cache). If the cache is not reliable, when they receive a request, they go to the DB to retrieve the record and then they update the cache with the result. Under most circumstances, the cache would be reliable and they would never have to go to the DB. The 4 tomcat instances are recycled one at a time and never simultaneously, therefore, at least one cluster member has the full caches which is used to populate the other cluster member's caches when they come up.

The cache managers perform this:
- Configure the cache (which is seen in the log). They expect the caches to be loaded by Infinispan from other cluster members
- Check to see if the "manager" cache contains any entries. This tells a manager if there is another instance that is managing the cache. If so, it does nothing.
- If "manager" cache is empty then it starts reading records from the DB and updating the cache. The log that I attached has this entry: "Manager cache does not contain a valid timestamp so we must update the caches from the DB." The next few lines show that BU was loaded properly. Then it started to load EDI data into the cache and got an NPE exception.

I have the logs and catalina.out from all 4 instances in case you are interested. 
This is the first time that we have seen this behavior. The other times that these tomcats have been recycled they have come up fine and we have not experienced any issues. 
This application runs in QA (one data center), System Integration Test (one data center), preproduction (two different data centers) and production (two different data centers).

> NPE during startup/initialization of cache from other cluster members in a distributed, synchronized cluster
> ------------------------------------------------------------------------------------------------------------
>
>                 Key: ISPN-6366
>                 URL: https://issues.jboss.org/browse/ISPN-6366
>             Project: Infinispan
>          Issue Type: Bug
>         Environment: RH LINUX
>            Reporter: Mehdi Rakhshani
>         Attachments: btotcrc1.log, jbossDataGridConfiguration.xml, jgroups.xml
>
>
> We have 4 instances of our application that uses Infinispan in a replicated, synchronized cluster. There are multiple independent clusters running in different data centers which share the same DB so the content of the caches is the same everywhere. The instances have been running for weeks with very little activity (the internal client application that comes in via REST API to access these apps has not been brought on live yet). 
> Of the 4 cluster members, 2 (app servers) use the cache for read-only, 2 (cache managers) keep the cache up to date from the DB. The app servers keep 20,000 records in the cache and the rest in a file store. The cache managers keep all records in the cache and do not use a file store. All cluster members are configured to get a copy of the cache from others in the cluster during startup.
> Without any changes, when the two tomcat containers hosting the cache mangers were recycled, they stopped coming up. The following exception is thrown in each cache manager in catalina.out.
> The key for this cache ('EdiCache') is a 39 byte string. It is made up of two left-padded strings concatenated together. The key in the exception contains '+' which should be blank instead. When I dump the caches from a cluster that is running in a different data center, I see that the key is '128738                                 ' not '128738+++++++++++++++++++++++++++++++++'.
> We are using version: 8.1.0.Final
> I can upload catalina.out, my application logs and Infinispan configuration files if needed.
> Any idea what is the cause of this error?
> 2016-03-09 07:29:02,106 [remote-thread--p2-t4] ERROR org.infinispan.interceptors.InvocationContextInterceptor - ISPN000136: Error executing command PutKeyValueCommand, writing keys [128738+++++++++++++++++++++++++++++++++]
> java.lang.NullPointerException
> 	at org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8$LIRSEvictionPolicy.findIfEntriesNeedEvicting(BoundedEquivalentConcurrentHashMapV8.java:1532)
> 	at org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8.compute(BoundedEquivalentConcurrentHashMapV8.java:3658)
> 	at org.infinispan.container.DefaultDataContainer.put(DefaultDataContainer.java:226)
> 	at org.infinispan.container.entries.ReadCommittedEntry.commit(ReadCommittedEntry.java:168)
> 	at org.infinispan.statetransfer.CommitManager.commit(CommitManager.java:98)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$InvalidationLogic.commitSingleEntry(ClusteringDependentLogic.java:377)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$ReplicationLogic.commitSingleEntry(ClusteringDependentLogic.java:421)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.commitEntry(ClusteringDependentLogic.java:114)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntry(EntryWrappingInterceptor.java:478)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitEntryIfNeeded(EntryWrappingInterceptor.java:654)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntries(EntryWrappingInterceptor.java:455)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:529)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:560)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:198)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:93)
> 	at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
> 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:62)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:352)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:290)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:107)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:191)
> 	at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:177)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:76)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:43)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
> 	at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:43)
> 	at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:48)
> 	at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokePerform(BasePerCacheInboundInvocationHandler.java:92)
> 	at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:34)
> 	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)
> 2016-03-09 07:29:02,111 [remote-thread--p2-t4] WARN  org.infinispan.remoting.inboundhandler.NonTotalOrderPerCacheInboundInvocationHandler - ISPN000071: Caught exception when handling command SingleRpcCommand{cacheName='EdiCache', command=PutKeyValueCommand{key=128738+++++++++++++++++++++++++++++++++, value=ImBusinessUnitRootEdi [address=128738, qualifier=null, buId=GC00029665M1], flags=[IGNORE_RETURN_VALUES], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=null}, successful=true}}
> java.lang.NullPointerException
> 	at org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8$LIRSEvictionPolicy.findIfEntriesNeedEvicting(BoundedEquivalentConcurrentHashMapV8.java:1532)
> 	at org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8.compute(BoundedEquivalentConcurrentHashMapV8.java:3658)
> 	at org.infinispan.container.DefaultDataContainer.put(DefaultDataContainer.java:226)
> 	at org.infinispan.container.entries.ReadCommittedEntry.commit(ReadCommittedEntry.java:168)
> 	at org.infinispan.statetransfer.CommitManager.commit(CommitManager.java:98)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$InvalidationLogic.commitSingleEntry(ClusteringDependentLogic.java:377)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$ReplicationLogic.commitSingleEntry(ClusteringDependentLogic.java:421)
> 	at org.infinispan.interceptors.locking.ClusteringDependentLogic$AbstractClusteringDependentLogic.commitEntry(ClusteringDependentLogic.java:114)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntry(EntryWrappingInterceptor.java:478)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitEntryIfNeeded(EntryWrappingInterceptor.java:654)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntries(EntryWrappingInterceptor.java:455)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:529)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:560)
> 	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:198)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:93)
> 	at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
> 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:62)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:352)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:290)
> 	at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:107)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:191)
> 	at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:177)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:76)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:43)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
> 	at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:43)
> 	at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:48)
> 	at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokePerform(BasePerCacheInboundInvocationHandler.java:92)
> 	at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:34)
> 	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)



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)

More information about the infinispan-issues mailing list