Timeout initializing cache
acorbellini Nov 15, 2012 9:52 AMHi!,
I've been struggling with these issue for several weeks and couldn't find a workaround or a fix for it.
The thing is that, I succesfully load my data (about 40gb) into a 6-node infinispan cluster and persist them using a jdbm loader.
Now, when I try to restart infinispan (by shutting it down and restarting), it seems to get in a deadlock, and finally throws the following Exception:
2012-11-14 10:00:52,130 WARN [LegacyStoreConfigurationBuilder] (InfinispanServer-Main) ISPN000149: Fetch persistent state and purge on startup are both disabled, cache may contain stale entries on startup 2012-11-14 10:00:52,861 WARN [Configurator] (InfinispanServer-Main) [JGRP00013] TP.discard_incompatible_packets has been deprecated: incompatible packets are discarded anyway 2012-11-14 10:00:52,898 WARN [Configurator] (InfinispanServer-Main) [JGRP00013] UNICAST2.setTimeout has been deprecated: not used anymore Failed to boot JBoss: org.infinispan.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.InterruptedException on object of type StateTransferManagerImpl at org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:205) at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:883) at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:654) at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:643) at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:546) at org.infinispan.factories.ComponentRegistry.start(ComponentRegistry.java:199) at org.infinispan.CacheImpl.start(CacheImpl.java:520) at org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:690) at org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:653) at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:549) at org.infinispan.server.hotrod.HotRodServer$$anonfun$preStartCaches$1.apply(HotRodServer.scala:127) at org.infinispan.server.hotrod.HotRodServer$$anonfun$preStartCaches$1.apply(HotRodServer.scala:125) at scala.collection.Iterator$class.foreach(Iterator.scala:772) at scala.collection.JavaConversions$JIteratorWrapper.foreach(JavaConversions.scala:573) at org.infinispan.server.hotrod.HotRodServer.preStartCaches(HotRodServer.scala:125) at org.infinispan.server.hotrod.HotRodServer.startTransport(HotRodServer.scala:114) at org.infinispan.server.core.AbstractProtocolServer.start(AbstractProtocolServer.scala:99) at org.infinispan.server.hotrod.HotRodServer.start(HotRodServer.scala:93) at org.infinispan.server.core.Main$.boot(Main.scala:140) at org.infinispan.server.core.Main$$anon$1.call(Main.scala:94) at org.infinispan.server.core.Main$$anon$1.call(Main.scala:91) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: org.infinispan.CacheException: Initial state transfer timed out for cache mycache on GridCluster1-60905 at org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete(StateTransferManagerImpl.java:209) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:203) ... 27 more Exception in thread "main" java.util.concurrent.ExecutionException: org.infinispan.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.InterruptedException on object of type StateTransferManagerImpl at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222) at java.util.concurrent.FutureTask.get(FutureTask.java:83) at org.infinispan.server.core.Main$.main(Main.scala:112) at org.infinispan.server.core.Main.main(Main.scala) Caused by: org.infinispan.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.InterruptedException on object of type StateTransferManagerImpl at org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:205) at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:883) at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:654) at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:643) at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:546) at org.infinispan.factories.ComponentRegistry.start(ComponentRegistry.java:199) at org.infinispan.CacheImpl.start(CacheImpl.java:520) at org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:690) at org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:653) at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:549) at org.infinispan.server.hotrod.HotRodServer$$anonfun$preStartCaches$1.apply(HotRodServer.scala:127) at org.infinispan.server.hotrod.HotRodServer$$anonfun$preStartCaches$1.apply(HotRodServer.scala:125) at scala.collection.Iterator$class.foreach(Iterator.scala:772) at scala.collection.JavaConversions$JIteratorWrapper.foreach(JavaConversions.scala:573) at org.infinispan.server.hotrod.HotRodServer.preStartCaches(HotRodServer.scala:125) at org.infinispan.server.hotrod.HotRodServer.startTransport(HotRodServer.scala:114) at org.infinispan.server.core.AbstractProtocolServer.start(AbstractProtocolServer.scala:99) at org.infinispan.server.hotrod.HotRodServer.start(HotRodServer.scala:93) at org.infinispan.server.core.Main$.boot(Main.scala:140) at org.infinispan.server.core.Main$$anon$1.call(Main.scala:94) at org.infinispan.server.core.Main$$anon$1.call(Main.scala:91) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: org.infinispan.CacheException: Initial state transfer timed out for cache mycache on GridCluster1-60905 at org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete(StateTransferManagerImpl.java:209) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:203) ... 27 more 2012-11-14 13:10:50,718 WARN [GMS] (Incoming-2,GridCluster1-60905) GridCluster1-60905: not member of view [GridCluster5-57770|9]; discarding it 2012-11-14 13:10:53,128 WARN [GMS] (ViewHandler,GridCluster1-60905) GridCluster1-60905: failed to collect all ACKs (expected=3) for view [GridCluster1-60905|10] after 2000ms, missing ACKs from [GridCluster4-28055, GridCluster2-32147] 2012-11-14 13:11:08,746 WARN [NAKACK] (OOB-97,GridCluster1-60905) [JGRP00011] GridCluster1-60905: dropped message 21 from non-member GridCluster5-57770 (view=[GridCluster1-60905|10] [GridCluster1-60905, GridCluster4-28055, GridCluster2-32147]) 2012-11-14 13:11:51,670 ERROR [ClusterTopologyManagerImpl] (notification-thread-0) ISPN000196: Failed to recover cluster state after the current node became the coordinator java.util.concurrent.ExecutionException: org.infinispan.CacheException: org.jgroups.TimeoutException: TimeoutException at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:232) at java.util.concurrent.FutureTask.get(FutureTask.java:91) at org.infinispan.topology.ClusterTopologyManagerImpl.executeOnClusterSync(ClusterTopologyManagerImpl.java:563) at org.infinispan.topology.ClusterTopologyManagerImpl.recoverClusterStatus(ClusterTopologyManagerImpl.java:427) at org.infinispan.topology.ClusterTopologyManagerImpl.handleNewView(ClusterTopologyManagerImpl.java:231) at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.handleViewChange(ClusterTopologyManagerImpl.java:593) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:200) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: org.infinispan.CacheException: org.jgroups.TimeoutException: TimeoutException at org.infinispan.util.Util.rewrapAsCacheException(Util.java:532) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:152) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.broadcastRemoteCommands(CommandAwareRpcDispatcher.java:196) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:498) at org.infinispan.topology.ClusterTopologyManagerImpl$2.call(ClusterTopologyManagerImpl.java:545) at org.infinispan.topology.ClusterTopologyManagerImpl$2.call(ClusterTopologyManagerImpl.java:542) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) ... 3 more Caused by: org.jgroups.TimeoutException: TimeoutException at org.jgroups.util.Promise._getResultWithTimeout(Promise.java:145) at org.jgroups.util.Promise.getResultWithTimeout(Promise.java:40) at org.jgroups.util.AckCollector.waitForAllAcks(AckCollector.java:93) at org.jgroups.protocols.RSVP$Entry.block(RSVP.java:287) at org.jgroups.protocols.RSVP.down(RSVP.java:118) at org.jgroups.stack.ProtocolStack.down(ProtocolStack.java:1025) at org.jgroups.JChannel.down(JChannel.java:700) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.down(MessageDispatcher.java:622) at org.jgroups.blocks.RequestCorrelator.sendRequest(RequestCorrelator.java:173) at org.jgroups.blocks.GroupRequest.sendRequest(GroupRequest.java:360) at org.jgroups.blocks.GroupRequest.sendRequest(GroupRequest.java:103) at org.jgroups.blocks.Request.execute(Request.java:83) at org.jgroups.blocks.MessageDispatcher.cast(MessageDispatcher.java:335) at org.jgroups.blocks.MessageDispatcher.castMessage(MessageDispatcher.java:249) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processCalls(CommandAwareRpcDispatcher.java:330) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:145) ... 9 more
My infinispan.xml looks like this:
<infinispan xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:infinispan:config:5.0 http://www.infinispan.org/schemas/infinispan-config-5.1.xsd " xmlns="urn:infinispan:config:5.0"> <global> <globalJmxStatistics cacheManagerName="mycache" enabled="true" jmxDomain="org.infinispan" /> <transport clusterName="infinispan"> <properties> <property name="configurationFile" value="/home/user/infinispan/jgroups-udp.xml" /> </properties> </transport> <asyncTransportExecutor> <properties> <property name="maxThreads" value="1000" /> </properties> </asyncTransportExecutor> </global> <default> <expiration lifespan="100"/> </default> <namedCache name="mycache"> <locking useLockStriping="false" concurrencyLevel="100" lockAcquisitionTimeout="10000"/> <clustering mode="dist"> <async /> <hash numOwners="1" /> <stateTransfer fetchInMemoryState="false"/> </clustering> <eviction maxEntries="100000" strategy="LRU" /> <loaders passivation="false" preload="false"> <loader purgeOnStartup="false" ignoreModifications="false" class="org.infinispan.loaders.jdbm.JdbmCacheStore"> <async enabled="true" threadPoolSize="10" /> <properties> <property name="location" value="/home/user/jdbm-db/lists" /> </properties> </loader> </loaders> </namedCache> </infinispan>
I'm currently using a version of infinispan built by myself using the source code from github (built using just "mvn package"). I've already tried using version 5.0.1, 5.2.0-Beta3, 5.1.6-Final, with no luck. I've already seen https://issues.jboss.org/browse/ISPN-2373 , which is why I'm using the source build.
I've already tried using TCP, with the same result.
Any idea of what is wrong with my configuration?
Thanks in advance!!
Ale