Skip to content

Early ApplicationContext close call may lead to ApplicationEventMulticaster/LifecycleProcessor access exception [SPR-16149] #20697

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
spring-projects-issues opened this issue Nov 2, 2017 · 6 comments
Closed

Early ApplicationContext close call may lead to ApplicationEventMulticaster/LifecycleProcessor access exception [SPR-16149] #20697

spring-projects-issues opened this issue Nov 2, 2017 · 6 comments
Assignees
@jhoeller
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: backported An issue that has been backported to maintenance branches type: bug A general bug
Milestone
5.0.2

Comments

@spring-projects-issues
Copy link
Collaborator

spring-projects-issues commented Nov 2, 2017 •
edited
Loading

Terence Mill opened SPR-16149 and commented

Similar things as in #17501 happened again on spring-cloud dalston ( spring framework 4.3.9.RELEASE). Not sure but maybe the change has been introduced from change
spring-cloud dalston SR3 to SR4 (did not happen fopr me before)

java.lang.IllegalStateException: LifecycleProcessor not initialized - call 'refresh' before invoking lifecycle methods via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@624c96df: startup date [Thu Nov 02 08:27:24 CET 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@1c5ebbc5
	at org.springframework.context.support.AbstractApplicationContext.getLifecycleProcessor(AbstractApplicationContext.java:427)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:999)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:958)
	at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:750)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
	at com.myorg.dvd.core.DvdSpringApplication.run(DvdSpringApplication.java:68)
	at com.myorg.dvd.core.DvdSpringApplication.run(DvdSpringApplication.java:37)
	at com.myorg.dvd.cfg.ConfigServerApplication.main(ConfigServerApplication.java:36)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)
 
2017-11-02 08:27:28.425 ERROR [configserver,,,] 13740 --- [  restartedMain] o.s.b.f.s.DefaultListableBeanFactory     : Destroy method on bean with name 'org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory' threw an exception
 
java.lang.IllegalStateException: ApplicationEventMulticaster not initialized - call 'refresh' before multicasting events via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@624c96df: startup date [Thu Nov 02 08:27:24 CET 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@1c5ebbc5
	at org.springframework.context.support.AbstractApplicationContext.getApplicationEventMulticaster(AbstractApplicationContext.java:414)
	at org.springframework.context.support.ApplicationListenerDetector.postProcessBeforeDestruction(ApplicationListenerDetector.java:97)
	at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:253)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:578)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:554)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:961)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:523)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:968)
	at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1030)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1006)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:958)
	at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:750)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
	at com.myorg.dvd.core.DvdSpringApplication.run(DvdSpringApplication.java:68)
	at com.myorg.dvd.core.DvdSpringApplication.run(DvdSpringApplication.java:37)
	at com.myorg.dvd.cfg.ConfigServerApplication.main(ConfigServerApplication.java:36)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

Affects: 4.3.9

Reference URL: #17501

Issue Links:

Referenced from: commits 519195c, 1611ce7

Backported to: 4.3.13
@spring-projects-issues
Copy link
Collaborator Author

Juergen Hoeller commented

I assume both of those are 'just' log entries? Even as log entries, we should get rid of them... just double-checking whether they ever bubble up as actual exceptions.

@spring-projects-issues
Copy link
Collaborator Author

Juergen Hoeller commented

We're defensively accessing the ApplicationEventMulticaster and LifecycleProcessor delegates on shutdown now, simply skipping the corresponding steps if they are not initialized yet and therefore not logging any IllegalStateExceptions anymore.

@spring-projects-issues
Copy link
Collaborator Author

Terence Mill commented

Its not just logging, currently the config server boot application is even unable to start

Here is a eureka based app not starting

java.lang.IllegalStateException: LifecycleProcessor not initialized - call 'refresh' before invoking lifecycle methods via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@6b8c9974: startup date [Thu Nov 02 15:48:22 CET 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@3450a40b
	at org.springframework.context.support.AbstractApplicationContext.getLifecycleProcessor(AbstractApplicationContext.java:427)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:999)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:958)
	at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:750)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:68)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:37)
	at com.myorg.dvb.reg.RegistryServerApplication.main(RegistryServerApplication.java:20)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

java.lang.IllegalStateException: ApplicationEventMulticaster not initialized - call 'refresh' before multicasting events via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@6b8c9974: startup date [Thu Nov 02 15:48:22 CET 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@3450a40b
	at org.springframework.context.support.AbstractApplicationContext.getApplicationEventMulticaster(AbstractApplicationContext.java:414)
	at org.springframework.context.support.ApplicationListenerDetector.postProcessBeforeDestruction(ApplicationListenerDetector.java:97)
	at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:253)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:578)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:554)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:961)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:523)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:968)
	at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1030)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1006)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:958)
	at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:750)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:68)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:37)
	at com.myorg.dvb.reg.RegistryServerApplication.main(RegistryServerApplication.java:20)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

java.lang.IllegalStateException: ApplicationEventMulticaster not initialized - call 'refresh' before multicasting events via the context: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@6b8c9974: startup date [Thu Nov 02 15:48:22 CET 2017]; parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@3450a40b
	at org.springframework.context.support.AbstractApplicationContext.getApplicationEventMulticaster(AbstractApplicationContext.java:414)
	at org.springframework.context.support.ApplicationListenerDetector.postProcessBeforeDestruction(ApplicationListenerDetector.java:97)
	at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:253)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:578)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:554)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:961)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:523)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:968)
	at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1030)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1006)
	at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:958)
	at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:750)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:68)
	at com.myorg.dvb.core.DvbSpringApplication.run(DvbSpringApplication.java:37)
	at com.myorg.dvb.reg.RegistryServerApplication.main(RegistryServerApplication.java:20)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

@spring-projects-issues
Copy link
Collaborator Author

Juergen Hoeller commented

So is it the LifecycleProcessor exception bubbling up? I wonder how that can happen since doClose() had a try-catch block around that part, logging an exception. If the config server doesn't start up anymore, it might be for some other reason, with the core shutdown logging just getting in the way there.

In any case, I'll commit my revision along with a few other changes in a few minutes: If for any reason we shut down against a half-initialized context, we are not going to log any spurious IllegalStateExceptions anymore - and as far as I can tell, there is no chance for them to reach user-level code either.

That's all we can do at this level. If the real issue is that a context shutdown is triggered so early in Spring Cloud to begin with, you'll need to raise it with them.

@spring-projects-issues
Copy link
Collaborator Author

Terence Mill commented

Ye, i also think there is some other issue (in best case hidden) behind this one.

@spring-projects-issues
Copy link
Collaborator Author

Juergen Hoeller commented

The current 5.0.2.BUILD-SNAPSHOT contains this revision in the meantime. I'll backport it to 4.3.13 by Monday.

@spring-projects-issues spring-projects-issues added type: bug A general bug status: backported An issue that has been backported to maintenance branches in: core Issues in core modules (aop, beans, core, context, expression) labels Jan 11, 2019
@spring-projects-issues spring-projects-issues added this to the 5.0.2 milestone Jan 11, 2019
This was referenced Jan 11, 2019
Closed
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jhoeller jhoeller

Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: backported An issue that has been backported to maintenance branches type: bug A general bug
Projects
None yet
Milestone
5.0.2
Development

No branches or pull requests
2 participants
@jhoeller @spring-projects-issues