Skip to content

Deadlock between DefaultListableBeanFactory and DefaultSingletonBeanRegistry, perhaps due to lazily-instantiated aspect [SPR-7718] #12374

Closed
@spring-projects-issues

Description

@spring-projects-issues

John Lee opened SPR-7718 and commented

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.


Affects: 2.5.6

Issue Links:

11 votes, 14 watchers

Metadata

Metadata

Assignees

Labels

has: votes-jiraIssues migrated from JIRA with more than 10 votes at the time of importin: coreIssues in core modules (aop, beans, core, context, expression)type: bugA general bug

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions