ISPN000660: Cache org.infinispan.LOCKS start failed, stopping any running components

[manologg]

I have this issue that happens from time to time when I try to deploy Infinispan in our AWS cluster. I get this error at startup:

ISPN000660: Cache org.infinispan.LOCKS start failed, stopping any running components

Caused by:

org.infinispan.commons.CacheConfigurationException: ISPN000659: Component ComponentWrapper{name=org.infinispan.statetransfer.StateTransferManager, instance=StateTransferManagerImpl [org.infinispan.LOCKS@ip-10-0-112-198.eu-central-1.compute.internal(site-id=eu-central-1)], status=FAILED} failed to start
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.startWrapper(BasicComponentRegistryImpl.java:584)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl$ComponentWrapper.running(BasicComponentRegistryImpl.java:807)
	at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:379)
	at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:252)
	at org.infinispan.factories.ComponentRegistry.start(ComponentRegistry.java:222)
	at org.infinispan.cache.impl.CacheImpl.start(CacheImpl.java:1009)
	at org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:504)
	at org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:504)
	at org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:504)
	at org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:504)
	at org.infinispan.security.impl.SecureCacheImpl.start(SecureCacheImpl.java:129)
	at org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:727)
	at org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:673)
	at org.infinispan.manager.DefaultCacheManager.internalGetCache(DefaultCacheManager.java:562)
	at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:525)
	at org.infinispan.security.actions.GetCacheAction.run(GetCacheAction.java:26)
	at org.infinispan.security.actions.GetCacheAction.run(GetCacheAction.java:14)
	at org.infinispan.security.Security.doPrivileged(Security.java:61)
	at org.infinispan.registry.impl.SecurityActions.getCache(SecurityActions.java:49)
	at org.infinispan.registry.impl.InternalCacheRegistryImpl.startInternalCaches(InternalCacheRegistryImpl.java:136)
	at org.infinispan.globalstate.impl.GlobalConfigurationManagerImpl.start(GlobalConfigurationManagerImpl.java:106)
	at org.infinispan.globalstate.impl.CorePackageImpl$2.start(CorePackageImpl.java:61)
	at org.infinispan.globalstate.impl.CorePackageImpl$2.start(CorePackageImpl.java:48)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.invokeStart(BasicComponentRegistryImpl.java:616)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.doStartWrapper(BasicComponentRegistryImpl.java:607)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.startWrapper(BasicComponentRegistryImpl.java:576)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl$ComponentWrapper.running(BasicComponentRegistryImpl.java:807)
	at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:379)
	at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:252)
	at org.infinispan.manager.DefaultCacheManager.internalStart(DefaultCacheManager.java:779)
	at org.infinispan.manager.DefaultCacheManager.start(DefaultCacheManager.java:747)
	at org.infinispan.server.SecurityActions.lambda$startCacheManager$1(SecurityActions.java:68)
	at org.infinispan.security.Security.doPrivileged(Security.java:56)
	at org.infinispan.server.SecurityActions.doPrivileged(SecurityActions.java:40)
	at org.infinispan.server.SecurityActions.startCacheManager(SecurityActions.java:71)
	at org.infinispan.server.Server.run(Server.java:425)
	at org.infinispan.server.Bootstrap.runInternal(Bootstrap.java:173)
	at org.infinispan.server.tool.Main.run(Main.java:98)
	at org.infinispan.server.Bootstrap.main(Bootstrap.java:56)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.infinispan.server.loader.Loader.run(Loader.java:106)
	at org.infinispan.server.loader.Loader.main(Loader.java:51)
Caused by: java.util.concurrent.CompletionException: java.lang.ClassCastException: class java.lang.NullPointerException cannot be cast to class org.infinispan.topology.CacheJoinException (java.lang.NullPointerException is in module java.base of loader 'bootstrap'; org.infinispan.topology.CacheJoinException is in unnamed module of loader java.net.URLClassLoader @3a71f4dd)
	at org.infinispan.util.concurrent.CompletionStages.join(CompletionStages.java:89)
	at org.infinispan.statetransfer.StateTransferManagerImpl.start(StateTransferManagerImpl.java:123)
	at org.infinispan.statetransfer.CorePackageImpl$2.start(CorePackageImpl.java:102)
	at org.infinispan.statetransfer.CorePackageImpl$2.start(CorePackageImpl.java:81)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.invokeStart(BasicComponentRegistryImpl.java:616)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.doStartWrapper(BasicComponentRegistryImpl.java:607)
	at org.infinispan.factories.impl.BasicComponentRegistryImpl.startWrapper(BasicComponentRegistryImpl.java:576)
	... 44 more
Caused by: java.lang.ClassCastException: class java.lang.NullPointerException cannot be cast to class org.infinispan.topology.CacheJoinException (java.lang.NullPointerException is in module java.base of loader 'bootstrap'; org.infinispan.topology.CacheJoinException is in unnamed module of loader java.net.URLClassLoader @3a71f4dd)
	at org.infinispan.topology.LocalTopologyManagerImpl.lambda$sendJoinRequest$5(LocalTopologyManagerImpl.java:230)
	at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
	at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
	at org.infinispan.remoting.transport.AbstractRequest.completeExceptionally(AbstractRequest.java:75)
	at org.infinispan.remoting.transport.impl.SingleTargetRequest.onResponse(SingleTargetRequest.java:50)
	at org.infinispan.remoting.transport.impl.RequestRepository.addResponse(RequestRepository.java:51)
	at org.infinispan.remoting.transport.jgroups.JGroupsTransport.processResponse(JGroupsTransport.java:1570)
	at org.infinispan.remoting.transport.jgroups.JGroupsTransport.processMessage(JGroupsTransport.java:1471)
	at org.infinispan.remoting.transport.jgroups.JGroupsTransport$ChannelCallbacks.up(JGroupsTransport.java:1663)
	at org.jgroups.JChannel.up(JChannel.java:733)
	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:936)
	at org.jgroups.protocols.FRAG2.up(FRAG2.java:139)
	at org.jgroups.protocols.FlowControl.up(FlowControl.java:245)
	at org.jgroups.protocols.FlowControl.up(FlowControl.java:245)
	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:845)
	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:226)
	at org.jgroups.protocols.UNICAST3.deliverMessage(UNICAST3.java:1083)
	at org.jgroups.protocols.UNICAST3.addMessage(UNICAST3.java:822)
	at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:804)
	at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:453)
	at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:680)
	at org.jgroups.protocols.VERIFY_SUSPECT2.up(VERIFY_SUSPECT2.java:105)
	at org.jgroups.protocols.FailureDetection.up(FailureDetection.java:180)
	at org.jgroups.protocols.FD_SOCK2.up(FD_SOCK2.java:188)
	at org.jgroups.protocols.MERGE3.up(MERGE3.java:274)
	at org.jgroups.protocols.Discovery.up(Discovery.java:294)
	at org.jgroups.stack.Protocol.up(Protocol.java:340)
	at org.jgroups.protocols.TP.passMessageUp(TP.java:1184)
	at org.jgroups.util.SubmitToThreadPool$SingleMessageHandler.run(SubmitToThreadPool.java:107)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:840)

Any ideas of what might be happening?

I'm using the Infinispan image quay.io/infinispan/server:14.0.22.Final

and this is my JGROUPS configuration:

<jgroups>
        <stack name="tcp-dns-ping" extends="tcp">
            <dns.DNS_PING dns_query="${env.ISPN_DNS_PING_QUERY}"
                          num_discovery_runs="10"
                          max_members_in_discovery_request="32"
                          dns_record_type="A"
                          stack.combine="REPLACE"
                          stack.position="MPING"/>
        </stack>
    </jgroups>

[jabolina]

Hey, @manologg. Does this still happen with more recent versions? I've added a few changes that landed on the last release (14.0.25.Final).

Including other nodes, did you notice other exceptions before this one? The node receives an exception from the remote node during the start-up process, so it should have the real exception from the remote around the same time in the logs.

If this still happens, could you provide the logs with debug enabled on the org.infinispan.topology package?

[jabolina]

I came across this issue with a reproducer running on 14.0.21.Final.

The issue is fixed by https://issues.redhat.com/browse/ISPN-15351, which has the workaround on the comments. The fix landed on 14.0.22.Final.

[manologg]

I started using 14.0.25.Final a couple of days ago and we haven't seen any issue since 👍