Uploaded image for project: 'Spring Framework'
  1. Spring Framework
  2. SPR-7718

Deadlock between DefaultListableBeanFactory and DefaultSingletonBeanRegistry, perhaps due to lazily-instantiated aspect

    Details

    • Last commented by a User:
      false

      Description

      Deploying EAR on Weblogic 10.0. Root XmlWebApplicationContext ends up w/ about 300 bean definitions from 3 WARs, which takes long enough to instantiate to see this behavior. Each WAR publishes web services specified in Spring contexts as Apache CXF endpoints. Service implementations are annotated so that an aspect can monitor traffic to all services. The traffic is reported to a monitoring process (deployed separately, but also a CXF webservice) at set intervals by Quartz jobs. The Quartz jobs are not wired via Spring integration; the Spring context just declares an org.quartz.Scheduler which gets injected into "updater" classes that add associated jobs right after instantiation (@PostConstruct).

      This architecture has worked well for over a year, but we recently added a JAX-WS Handler to the traffic reporting, and this seemed to affect the timing of the context initialization enough that this deadlock started appearing (and it happens everytime without fail, usually for the same bean names as viewed in debugger, although the same EAR deployed on JBoss 4.2 works fine; different classloader architecture).

      What it looks like is that one of the Quartz jobs triggers while Spring is in the process of pre-instantiating singletons, and an aspect on the traffic reporting client (picked up via <component-scan/> and annotated w/ AspectJ @Aspect and Spring @Component, pointcuts defined AspectJ-style) required for the Quartz job is lazily instantiated for some reason (a guess, from the LazySingletonAspectInstanceFactoryDecorator.getAspectInstance call in the stack trace), leading to the deadlock. Tweaking the triggers so that the start date is some time after instantiation, e.g. 30 sec., is my current workaround, but I thought that if this is a bug in Spring (didn't see any other reports of this scenario in the forums or in general web search), it's worth fixing.

      The last thing written to the log is:

      [many other services being bound to endpoints...]

      16:09:24,496 INFO ReflectionServiceFactoryBean:437 - Creating Service

      {http://services.mycompany.com/diagnostics}

      Diagnostics from class com.mycompany.services.Diagnostics
      16:09:26,275 INFO QuartzScheduler:461 - Scheduler QuartzScheduler_$_NON_CLUSTERED started.
      16:09:26,275 INFO PeriodicalUpdater:73 - ConfigurationManagerUpdater scheduled with interval 5000 ms.
      16:09:29,268 INFO ServerImpl:91 - Setting the server's publish address to be /Diagnostics

      Here's the thread dump:

      Found one Java-level deadlock:
      =============================
      "QuartzScheduler_Worker-2":
      waiting to lock monitor 0x001b702c (object 0x0a7e7e80, a java.util.concurrent.
      ConcurrentHashMap),
      which is held by "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Defa
      ult (self-tuning)'"
      "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'"
      :
      waiting to lock monitor 0x001b6d4c (object 0x0a7e7be0, a java.util.concurrent.
      ConcurrentHashMap),
      which is held by "QuartzScheduler_Worker-2"

      Java stack information for the threads listed above:
      ===================================================
      "QuartzScheduler_Worker-2":
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.
      getBeanDefinitionNames(DefaultListableBeanFactory.java:192)

      • waiting to lock <0x0a7e7e80> (a java.util.concurrent.ConcurrentHashMap
        )
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.
        getBeanNamesForType(DefaultListableBeanFactory.java:209)
        at org.springframework.beans.factory.BeanFactoryUtils.beanNamesForTypeIn
        cludingAncestors(BeanFactoryUtils.java:187)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.
        findAutowireCandidates(DefaultListableBeanFactory.java:652)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.
        resolveDependency(DefaultListableBeanFactory.java:610)
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanP
        ostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.j
        ava:412)
        at org.springframework.beans.factory.annotation.InjectionMetadata.inject
        Fields(InjectionMetadata.java:105)
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanP
        ostProcessor.postProcessAfterInstantiation(AutowiredAnnotationBeanPostProcessor.
        java:240)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBean
        Factory.populateBean(AbstractAutowireCapableBeanFactory.java:959)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBean
        Factory.doCreateBean(AbstractAutowireCapableBeanFactory.java:472)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBean
        Factory$1.run(AbstractAutowireCapableBeanFactory.java:409)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBean
        Factory.createBean(AbstractAutowireCapableBeanFactory.java:380)
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getOb
        ject(AbstractBeanFactory.java:264)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistr
        y.getSingleton(DefaultSingletonBeanRegistry.java:222)
      • locked <0x0a7e7be0> (a java.util.concurrent.ConcurrentHashMap)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBe
        an(AbstractBeanFactory.java:261)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean
        (AbstractBeanFactory.java:185)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean
        (AbstractBeanFactory.java:164)
        at org.springframework.aop.aspectj.annotation.BeanFactoryAspectInstanceF
        actory.getAspectInstance(BeanFactoryAspectInstanceFactory.java:76)
        at org.springframework.aop.aspectj.annotation.LazySingletonAspectInstanc
        eFactoryDecorator.getAspectInstance(LazySingletonAspectInstanceFactoryDecorator.
        java:47)
      • locked <0x0ab1eb00> (a org.springframework.aop.aspectj.annotation.Lazy
        SingletonAspectInstanceFactoryDecorator)
        at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMet
        hodWithGivenArgs(AbstractAspectJAdvice.java:627)
        at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMet
        hod(AbstractAspectJAdvice.java:609)
        at org.springframework.aop.aspectj.AspectJMethodBeforeAdvice.before(Aspe
        ctJMethodBeforeAdvice.java:39)
        at org.springframework.aop.framework.adapter.MethodBeforeAdviceIntercept
        or.invoke(MethodBeforeAdviceInterceptor.java:49)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
        ReflectiveMethodInvocation.java:160)
        at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.p
        roceed(MethodInvocationProceedingJoinPoint.java:77)
        at com.mycompany.services.commons.aspects.ClientProxyAspect.fillRequ
        estInfo(ClientProxyAspect.java:68)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
        java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
        sorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMet
        hodWithGivenArgs(AbstractAspectJAdvice.java:627)
        at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMet
        hod(AbstractAspectJAdvice.java:616)
        at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAro
        undAdvice.java:64)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
        ReflectiveMethodInvocation.java:160)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invok
        e(ExposeInvocationInterceptor.java:89)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
        ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterc
        eptor.intercept(Cglib2AopProxy.java:635)
        at com.mycompany.services.bindings.trafficreporter.client.ws.ConfigurationW
        SClient$$EnhancerByCGLIB$$b4564aa2.getConfiguration(<generated>)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.
        java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
        sorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at com.mycompany.services.trafficreporter.client.Clie
        ntProxy.executeMethod(ClientProxy.java:159)
        at com.mycompany.services.trafficreporter.client.Clie
        ntProxy.getConfiguration(ClientProxy.java:95)
        at com.mycompany.services.trafficreporter.manager.updater.Configurat
        ionManagerJob.updateAction(ConfigurationManagerJob.java:63)
        at com.mycompany.services.trafficreporter.manager.updater.UpdateJob.
        execute(UpdateJob.java:83)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.j
        ava:534)
        "[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'"
        :
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistr
        y.getSingleton(DefaultSingletonBeanRegistry.java:180)
      • waiting to lock <0x0a7e7be0> (a java.util.concurrent.ConcurrentHashMap
        )
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistr
        y.getSingleton(DefaultSingletonBeanRegistry.java:166)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBe
        an(AbstractBeanFactory.java:206)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean
        (AbstractBeanFactory.java:185)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean
        (AbstractBeanFactory.java:164)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.
        preInstantiateSingletons(DefaultListableBeanFactory.java:429)
      • locked <0x0a7e7e80> (a java.util.concurrent.ConcurrentHashMap)
        at org.springframework.context.support.AbstractApplicationContext.finish
        BeanFactoryInitialization(AbstractApplicationContext.java:728)
        at org.springframework.context.support.AbstractApplicationContext.refres
        h(AbstractApplicationContext.java:380)
      • locked <0x0a7e7610> (a java.lang.Object)
        at org.springframework.web.context.ContextLoader.createWebApplicationCon
        text(ContextLoader.java:255)
        at org.springframework.web.context.ContextLoader.initWebApplicationConte
        xt(ContextLoader.java:199)
        at org.springframework.web.context.ContextLoaderListener.contextInitiali
        zed(ContextLoaderListener.java:45)
        at weblogic.servlet.internal.EventsManager$FireContextListenerAction.run
        (EventsManager.java:458)
        at weblogic.security.acl.internal.AuthenticatedSubject.doAs(Authenticate
        dSubject.java:321)
        at weblogic.security.service.SecurityManager.runAs(Unknown Source)
        at weblogic.servlet.internal.EventsManager.notifyContextCreatedEvent(Eve
        ntsManager.java:168)
        at weblogic.servlet.internal.WebAppServletContext.preloadResources(WebAp
        pServletContext.java:1721)
      • locked <0x0a5f7d50> (a weblogic.servlet.internal.WebAppServletContext)

      at weblogic.servlet.internal.WebAppServletContext.start(WebAppServletCon
      text.java:2890)
      at weblogic.servlet.internal.WebAppModule.startContexts(WebAppModule.jav
      a:948)
      at weblogic.servlet.internal.WebAppModule.start(WebAppModule.java:353)
      at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleSta
      teDriver.java:204)
      at weblogic.application.utils.StateMachineDriver.nextState(StateMachineD
      river.java:26)
      at weblogic.application.internal.flow.ModuleStateDriver.start(ModuleStat
      eDriver.java:60)
      at weblogic.application.internal.flow.ScopedModuleDriver.start(ScopedMod
      uleDriver.java:200)
      at weblogic.application.internal.flow.ModuleListenerInvoker.start(Module
      ListenerInvoker.java:117)
      at weblogic.application.internal.flow.ModuleStateDriver$3.next(ModuleSta
      teDriver.java:204)
      at weblogic.application.utils.StateMachineDriver.nextState(StateMachineD
      river.java:26)
      at weblogic.application.internal.flow.ModuleStateDriver.start(ModuleStat
      eDriver.java:60)
      at weblogic.application.internal.flow.StartModulesFlow.activate(StartMod
      ulesFlow.java:26)
      at weblogic.application.internal.BaseDeployment$2.next(BaseDeployment.ja
      va:635)
      at weblogic.application.utils.StateMachineDriver.nextState(StateMachineD
      river.java:26)
      at weblogic.application.internal.BaseDeployment.activate(BaseDeployment.
      java:212)
      at weblogic.application.internal.DeploymentStateChecker.activate(Deploym
      entStateChecker.java:154)
      at weblogic.deploy.internal.targetserver.AppContainerInvoker.activate(Ap
      pContainerInvoker.java:80)
      at weblogic.deploy.internal.targetserver.BasicDeployment.activate(BasicD
      eployment.java:182)
      at weblogic.deploy.internal.targetserver.BasicDeployment.activateFromSer
      verLifecycle(BasicDeployment.java:359)
      at weblogic.management.deploy.internal.DeploymentAdapter$1.doActivate(De
      ploymentAdapter.java:51)
      at weblogic.management.deploy.internal.DeploymentAdapter.activate(Deploy
      mentAdapter.java:196)
      at weblogic.management.deploy.internal.AppTransition$2.transitionApp(App
      Transition.java:30)
      at weblogic.management.deploy.internal.ConfiguredDeployments.transitionA
      pps(ConfiguredDeployments.java:233)
      at weblogic.management.deploy.internal.ConfiguredDeployments.activate(Co
      nfiguredDeployments.java:169)
      at weblogic.management.deploy.internal.ConfiguredDeployments.deploy(Conf
      iguredDeployments.java:123)
      at weblogic.management.deploy.internal.DeploymentServerService.resume(De
      ploymentServerService.java:173)
      at weblogic.management.deploy.internal.DeploymentServerService.start(Dep
      loymentServerService.java:89)
      at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      Found 1 deadlock.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                juergen.hoeller Juergen Hoeller
                Reporter:
                sowberry John Lee
                Last updater:
                Chris Beams
              • Votes:
                11 Vote for this issue
                Watchers:
                14 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Days since last comment:
                  5 years, 26 weeks ago