2 Replies Latest reply: Oct 11, 2012 12:03 PM by 785631 RSS

    Spring Coherence deadlock issue

    785631
      So we have a coherence-app that we're trying to fire up using jetty in a development environment. Meaning, it's just a standalone jvm that is not going to cluster with anything else. In particular, with -Dtangosol.coherence.distributed.localstorage=true.

      When the app starts up, it hangs. This is the logging prior to the hang:
      2012-10-09 17:05:53.320/9.886 Oracle Coherence GE 3.5.3/465 <Info> (thread=Cluster, member=n/a): Created a new cluster "my-coherence" with Member(Id=1, Timestamp=2012-10-09 17:05:50.063, Address=10.200.251.71:8088, MachineId=14663, Location=site:myhcompany.com,machine:machine-3,process:11320, Role=CodehausPlexusLauncher, Edition=Grid Edition, Mode=Development, CpuCount=6, SocketCount=6) UID=0x0AC8FB470000013A47FDDB6F39471F98
      2012-10-09 17:05:53.337/9.903 Oracle Coherence GE 3.5.3/465 <D5> (thread=Invocation:Management, member=1): Service Management joined the cluster with senior service member 1
      2012-10-09 17:05:53.446/10.012 Oracle Coherence GE 3.5.3/465 <D5> (thread=DistributedCache:DistributedWriteThrough, member=1): Service DistributedWriteThrough joined the cluster with senior service member 1
      2012-10-09 17:05:53.488/10.054 Oracle Coherence GE 3.5.3/465 <Info> (thread=DistributedCache:DistributedWriteThrough, member=1): Loading POF configuration from resource "jar:file:/C:/repo/com/mycompany/2.0-SNAPSHOT/common-2.0-SNAPSHOT.jar!/com/mycompany/common-pof-config.xml"
      2012-10-09 17:05:53.490/10.056 Oracle Coherence GE 3.5.3/465 <Info> (thread=DistributedCache:DistributedWriteThrough, member=1): Loading POF configuration from resource "jar:file:/C:/repo/com/oracle/tangosol/coherence/3.5.3/coherence-3.5.3.jar!/coherence-pof-config.xml"
      # Hangs for about 30 seconds, then we get this logging, followed by a thread dump.
      2012-10-09 17:06:24.946/41.512 Oracle Coherence GE 3.5.3/465 <Error> (thread=Cluster, member=1): Attempting recovery (due to soft timeout) of Guard{Daemon=DistributedCache:DistributedWriteThrough}
      2012-10-09 17:06:28.447/45.014 Oracle Coherence GE 3.5.3/465 <Error> (thread=Cluster, member=1): Terminating guarded execution (due to hard timeout) of Guard{Daemon=DistributedCache:DistributedWriteThrough}
      Coherence <Error>: Halting this cluster node due to unrecoverable service failure
      Now, the main thread is just stuck doing this:
      Thread[main,5,main]
           java.lang.Object.wait(Native Method)
           java.lang.Object.wait(Object.java:485)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.Grid.poll(Grid.CDB:31)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.Grid.poll(Grid.CDB:11)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache.ensureCache(DistributedCache.CDB:29)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache.ensureCache(DistributedCache.CDB:39)
           com.tangosol.coherence.component.util.safeService.SafeCacheService.ensureCache$Router(SafeCacheService.CDB:1)
           com.tangosol.coherence.component.util.safeService.SafeCacheService.ensureCache(SafeCacheService.CDB:46)
           com.tangosol.net.DefaultConfigurableCacheFactory.ensureCache(DefaultConfigurableCacheFactory.java:878)
           com.tangosol.net.DefaultConfigurableCacheFactory.configureCache(DefaultConfigurableCacheFactory.java:1088)
           com.tangosol.net.DefaultConfigurableCacheFactory.ensureCache(DefaultConfigurableCacheFactory.java:304)
           com.tangosol.net.CacheFactory.getCache(CacheFactory.java:735)
           com.tangosol.net.CacheFactory.getCache(CacheFactory.java:712)
           com.mycompany.coherence.MyCacheFactory.getCache(MyCacheFactory.java:25)
           com.mycompany.coherence.Caches.getCache(Caches.java:32)
           sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
           sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
           sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
           java.lang.reflect.Method.invoke(Method.java:597)
           org.springframework.expression.spel.support.ReflectivePropertyAccessor$OptimalPropertyAccessor.read(ReflectivePropertyAccessor.java:501)
           org.springframework.expression.spel.ast.PropertyOrFieldReference.readProperty(PropertyOrFieldReference.java:196)
           org.springframework.expression.spel.ast.PropertyOrFieldReference.getValueInternal(PropertyOrFieldReference.java:72)
           org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:57)
           org.springframework.expression.spel.ast.SpelNodeImpl.getValue(SpelNodeImpl.java:93)
           org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:89)
           org.springframework.context.expression.StandardBeanExpressionResolver.evaluate(StandardBeanExpressionResolver.java:139)
           org.springframework.beans.factory.support.AbstractBeanFactory.evaluateBeanDefinitionString(AbstractBeanFactory.java:1299)
           org.springframework.beans.factory.support.BeanDefinitionValueResolver.evaluate(BeanDefinitionValueResolver.java:211)
           org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:183)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1372)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1130)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
           org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
           org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
           org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:874)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:816)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:731)
           org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:485)
           org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:92)
           org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:284)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
           org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
           org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
           org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:874)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:816)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:731)
           org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:485)
           org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:92)
           org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:284)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
           org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
           org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
           org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
           org.springframework.context.annotation.CommonAnnotationBeanPostProcessor.autowireResource(CommonAnnotationBeanPostProcessor.java:442)
           org.springframework.context.annotation.CommonAnnotationBeanPostProcessor.getResource(CommonAnnotationBeanPostProcessor.java:416)
           org.springframework.context.annotation.CommonAnnotationBeanPostProcessor$ResourceElement.getResourceToInject(CommonAnnotationBeanPostProcessor.java:549)
           org.springframework.beans.factory.annotation.InjectionMetadata$InjectedElement.inject(InjectionMetadata.java:155)
           org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:92)
           org.springframework.context.annotation.CommonAnnotationBeanPostProcessor.postProcessPropertyValues(CommonAnnotationBeanPostProcessor.java:303)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
           org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
           org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
           org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
           org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
           org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:605)
           org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:913)
           org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:464)
           org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:384)
           org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
           org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
           org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548)
           org.mortbay.jetty.servlet.Context.startContext(Context.java:136)
           org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1239)
           org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517)
           org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:466)
           org.mortbay.jetty.plugin.Jetty6PluginWebAppContext.doStart(Jetty6PluginWebAppContext.java:124)
           org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
           org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:152)
           org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:156)
           org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
           org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:152)
           org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
           org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
           org.mortbay.jetty.Server.doStart(Server.java:224)
           org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
           org.mortbay.jetty.plugin.Jetty6PluginServer.start(Jetty6PluginServer.java:132)
           org.mortbay.jetty.plugin.AbstractJettyMojo.startJetty(AbstractJettyMojo.java:441)
           org.mortbay.jetty.plugin.AbstractJettyMojo.execute(AbstractJettyMojo.java:383)
           org.mortbay.jetty.plugin.AbstractJettyRunMojo.execute(AbstractJettyRunMojo.java:210)
           org.mortbay.jetty.plugin.Jetty6RunMojo.execute(Jetty6RunMojo.java:184)
           org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:101)
           org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:209)
           org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
           org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
           org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:84)
           org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:59)
           org.apache.maven.lifecycle.internal.LifecycleStarter.singleThreadedBuild(LifecycleStarter.java:183)
           org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:161)
           org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:319)
           org.apache.maven.DefaultMaven.execute(DefaultMaven.java:156)
           org.apache.maven.cli.MavenCli.execute(MavenCli.java:537)
           org.apache.maven.cli.MavenCli.doMain(MavenCli.java:196)
           org.apache.maven.cli.MavenCli.main(MavenCli.java:141)
           sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
           sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
           sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
           java.lang.reflect.Method.invoke(Method.java:597)
           org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:290)
           org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:230)
           org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:409)
           org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:352)
      I know (from looking at spring source code) that the above thread is grabbing a lock, that the thread below wants, so the thread below just hangs.
      Thread[DistributedCache:DistributedWriteThrough,5,Cluster]
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:184)
           org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:169)
           org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:237)
           org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
           com.tangosol.coherence.spring.SpringAwareCacheFactory.instantiateAny(SpringAwareCacheFactory.java:188)
           com.tangosol.net.DefaultConfigurableCacheFactory.instantiateCacheStore(DefaultConfigurableCacheFactory.java:2857)
           com.tangosol.net.DefaultConfigurableCacheFactory.instantiateReadWriteBackingMap(DefaultConfigurableCacheFactory.java:1493)
           com.tangosol.net.DefaultConfigurableCacheFactory.configureBackingMap(DefaultConfigurableCacheFactory.java:1258)
           com.tangosol.net.DefaultConfigurableCacheFactory$Manager.instantiateBackingMap(DefaultConfigurableCacheFactory.java:3492)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache$Storage.instantiateResourceMap(DistributedCache.CDB:22)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache$Storage.setCacheName(DistributedCache.CDB:27)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache$ConfigListener.entryInserted(DistributedCache.CDB:15)
           com.tangosol.util.MapEvent.dispatch(MapEvent.java:266)
           com.tangosol.util.MapEvent.dispatch(MapEvent.java:226)
           com.tangosol.util.MapListenerSupport.fireEvent(MapListenerSupport.java:556)
           com.tangosol.util.ObservableHashMap.dispatchEvent(ObservableHashMap.java:229)
           com.tangosol.util.ObservableHashMap$Entry.onAdd(ObservableHashMap.java:270)
           com.tangosol.util.SafeHashMap.put(SafeHashMap.java:244)
           com.tangosol.coherence.component.util.collections.WrapperMap.put(WrapperMap.CDB:1)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.Grid$ServiceConfigMap.put(Grid.CDB:31)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache$StorageIdRequest.onReceived(DistributedCache.CDB:45)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.Grid.onMessage(Grid.CDB:9)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.Grid.onNotify(Grid.CDB:136)
           com.tangosol.coherence.component.util.daemon.queueProcessor.service.grid.DistributedCache.onNotify(DistributedCache.CDB:3)
           com.tangosol.coherence.component.util.Daemon.run(Daemon.CDB:42)
           java.lang.Thread.run(Thread.java:662)
      So the questions are:

      1) It looks like there's some sort of A/B, B/A deadlock, is that the case? I can't look at coherence source, but i can look at spring source, and i know that in the above the "main" thread has grabbed a lock in spring, and the "DistributedWriteThrough" thread is waiting to grab this lock.
      2) What is the main thread waiting for? It's doing a grid.poll and just hanging.
      2) What is the DistributedWriteThrough thread doing? In particular why is it even doing anything? At this point the application is just starting up, and isn't trying to read/write from the caches, simply initialize them.

      Thanks.
        • 1. Re: Spring Coherence deadlock issue
          Jonathan.Knight
          Hi,

          The DistributedCache:DistributedWriteThrough thread is trying to create an instance of the CacheStore, which from the stack trace I assume you have configured as a Spring bean, so the thread is trying to get the CacheStore instance from Spring, which is currently locked. The DistributedCache:DistributedWriteThrough thread is running in response to something doing a put into a cache (com.tangosol.util.SafeHashMap.put(SafeHashMap.java:244) in the stack).

          Obviously without knowing anything about your system it is impossible to say what is doing the put at the same time as something in the main thread is calling getCache here:
          com.tangosol.net.CacheFactory.getCache(CacheFactory.java:712)
          com.mycompany.coherence.MyCacheFactory.getCache(MyCacheFactory.java:25)

          JK
          • 2. Re: Spring Coherence deadlock issue
            785631
            Ok, i don't really know where the put was coming from; but the problem was the spring init was calling into the CacheFactory.getCache() to retrieve a NamedCache, simply to assign to a property of some spring bean. Once i removed any access to any cache during spring-init, everything was fine.