[
https://issues.jboss.org/browse/ISPN-1384?page=com.atlassian.jira.plugin....
]
Michal Linhard commented on ISPN-1384:
--------------------------------------
The NPE in is thrown by Thread2 (pool-5-thread-44), extracting bigger context from the
(pretty big) log:
{code}
16:13:15,749 TRACE [org.infinispan.factories.ComponentRegistry] (MSC service thread 1-2)
Invoking start method protected void
org.infinispan.interceptors.CacheLoaderInterceptor.startInterceptor() on component
org.infinispan.interceptors.CacheLoaderInterceptor
16:13:15,750 TRACE [org.infinispan.factories.ComponentRegistry] (MSC service thread 1-2)
Invoking start method public void org.infinispan.eviction.EvictionManagerImpl.start() on
component org.infinispan.eviction.EvictionManager
16:13:15,750 TRACE [org.infinispan.factories.ComponentRegistry] (MSC service thread 1-2)
Invoking start method public void
org.infinispan.statetransfer.StateTransferManagerImpl.start() throws
org.infinispan.statetransfer.StateTransferException on component
org.infinispan.statetransfer.StateTransferManager
16:13:15,750 TRACE [org.infinispan.statetransfer.StateTransferManagerImpl] (MSC service
thread 1-2) Data container is 1efb0be
16:13:15,750 TRACE [org.infinispan.factories.ComponentRegistry] (MSC service thread 1-2)
Invoking start method public void org.infinispan.loaders.CacheLoaderManagerImpl.preload()
on component org.infinispan.loaders.CacheLoaderManager
16:13:15,750 INFO [org.infinispan.factories.ComponentRegistry] (MSC service thread 1-2)
ISPN000128: Infinispan version: Infinispan 'Brahma' 5.1.0-SNAPSHOT
16:13:15,750 INFO [org.jboss.as.clustering.infinispan.subsystem] (MSC service thread 1-2)
Started ___hotRodTopologyCache cache from default container
16:13:15,751 DEBUG [org.infinispan.CacheImpl] (MSC service thread 1-2) Started cache
___hotRodTopologyCache on michal-linhard-31403
16:13:15,723 TRACE [org.infinispan.distribution.ch.DefaultConsistentHash] (MSC service
thread 1-3) Positions are: {1540079=michal-linhard-43824, 2223212=michal-linhard-31403,
2345974=michal-linhard-9737, 3763968=michal-linhard-31403, 3851237=michal-linhard-9737,
4539514=michal-linhard-43824, 4951724=michal-linhard-41579, 5436692=michal-linhard-43824,
7395847=michal-linhard-9737, 7719857=michal-linhard-9737, 8202189=michal-linhard-9737,
9101869=michal-linhard-31403, 9741262=michal-linhard-31403, 11268960=mi..
16:13:15,731 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(pool-5-thread-44) ISPN000136: Execution error: java.lang.NullPointerException
at
org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:149)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeededAndUpdateStats(CacheLoaderInterceptor.java:218)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:90)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:133)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:201)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:192)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:84)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:119)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:104)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:64)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:90)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:61)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:274)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.remote.ClusteredGetCommand.perform(ClusteredGetCommand.java:105)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.commands.remote.ClusteredGetCommand.perform(ClusteredGetCommand.java:53)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:180)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:194)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:291)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:166)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:165)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:144)
[infinispan-core-5.1.0-SNAPSHOT.jar:5.1.0-SNAPSHOT]
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:577)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:488)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:364)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:770)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.JChannel.up(JChannel.java:1484)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1074)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:477)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at
org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:263)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:189)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.FC.up(FC.java:499) [jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:908)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.VIEW_SYNC.up(VIEW_SYNC.java:170)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:246)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.UNICAST.up(UNICAST.java:309)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:838)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:667)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:123)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:133)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.FD.up(FD.java:275) [jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:275)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:209)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:293)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.PING.up(PING.java:69)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1109)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1665)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1647)
[jgroups-2.12.1.3.Final.jar:2.12.1.3.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[:1.6.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[:1.6.0_25]
at java.lang.Thread.run(Thread.java:662) [:1.6.0_25]
at org.jboss.threads.JBossThread.run(JBossThread.java:122)
[jboss-threads-2.0.0.GA.jar:2.0.0.GA]
{code}
note that the Thread1 (MSC service thread 1-2) called
CacheLoaderInterceptor.startInterceptor() after the NPE even though it's logged
before.
Remote processes can access cache before it's started
-----------------------------------------------------
Key: ISPN-1384
URL:
https://issues.jboss.org/browse/ISPN-1384
Project: Infinispan
Issue Type: Bug
Affects Versions: 5.0.1.FINAL
Reporter: Michal Linhard
Assignee: Galder ZamarreƱo
Fix For: 5.1.0.ALPHA2 , 5.1.0.FINAL
Attachments: edg-thread-problem.zip
version:
Infinispan 5.1.0-SNAPSHOT last commit fc94449eec33469057614a13cbfe59e4f4e855fd Author:
Michal Linhard <michal(a)linhard.sk> Date: Wed Sep 7 13:42:32 2011 +0200
The mechanism that locks cache while it is being created and started is not in effect
when accessing the cache remotely.
The problem happens in this scenario:
1. Thread1 does DefaultCacheManager.getCache and starts the cache to the point where
ComponentRegistry for that cache exists, but the cache is not yet started
2. Thread2 (originating in JGroups layer) does call via InboundInvocationHandlerImpl and
gets hold of the ComponentRegistry for the cache and calls perform() on the command
(note that the Thread2 doesn't obtain the cache via DefaultCacheManager.getCache and
therefore it doesn't have to wait on the cacheCreateLock or CacheWrapper lock)
the problem manifests itself in JBPAPP-7173 where using unstarted CacheLoaderInterceptor
leads to NPE.
--
This message is automatically generated by JIRA.
For more information on JIRA, see:
http://www.atlassian.com/software/jira