We use Micrometer in our Spring Boot applications.
When shutting down our applications we sometimes get WARN log messages with Exceptions that say:
Failed to apply the value function for the gauge (...)
All of these value functions fail because some part of the application is already shut down. For example, we have a metric that's based on a Spring Data Repository, so we get
org.springframework.beans.factory.BeanCreationNotAllowedException: Error creating bean with name 'entityManagerFactory': Singleton bean creation not allowed while singletons of this factory are in destruction (Do not request a bean from a BeanFactory in a destroy method implementation!)
I assume this would be avoidable if publishing of Metrics is stopped by calling MeterRegistry.clear() and PushMeterRegistry.stop() when the shutdown begins.
(We are using Datadog, which apparently implements PushMeterRegistry)
Comment From: mbhave
This was fixed in #12006 but #12121 removed the need to declare the destroy method explicitly. The tests written in #12006 are still green so I would think the stop methods are called when necessary.
@waschmittel Could you provide a small sample with steps on how to reproduce the issue?
Comment From: spring-projects-issues
If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.
Comment From: waschmittel
Tried to reproduce ... the first thing Datadog's PushMeterRegistry does when close() is called, is calling publish().
So this seems to be a Datadog bug after all.
Comment From: waschmittel
Oh wait ... PushMeterRegistry is a part of micrometer (in io.micrometer.core.instrument.push)
So PushMeterRegistry's close() looks like this:
@Override
public void close() {
if (config.enabled()) {
publishSafely();
}
stop();
super.close();
}
And publishSafely looks like this:
private void publishSafely() {
try {
publish();
} catch (Throwable e) {
logger.warn("Unexpected exception thrown while publishing metrics for " + this.getClass().getSimpleName(), e);
}
}
So Micrometer apparently expects metrics to still be extractable when close() is called.
So I guess Spring should handle a PushMeterRegistry differently from a Non-Push MeterRegistry - Although I assume it would be difficult to call close() while the context is still fully available.
So I can can probably my metrics to handle the Exceptions that occur while the context is already being closed, but I would prefer a generic solution for this issue, of course.
Comment From: snicoll
So Micrometer apparently expects metrics to still be extractable when close() is called.
@waschmittel I think the intention is to let the registry publish metrics "safely" (as the method name states) before closing it. The problem is that other parts of the infrastructure may have already been closed when the registry itself is closed. Perhaps the error message is misleading and can be refined (but that would have to be dealt in Micrometer itself).
Paging @shakuzen for insights.
Comment From: waschmittel
Or Spring could do something to make config.enabled() false before calling close() (if possible - I have no idea). Although I think this is surprising behavior by Micrometer to do a last publish when closing.
Comment From: snicoll
Or Spring could do something to make config.enabled() false before calling close()
Why would we do that? I'd rather understand the intention of Micrometer rather than trying to force it to do something different. Doing something different may be the right call after all but there is no reason it should be specific to a spring app.
Comment From: arijitdeb1
Hi team,
Any resolution to this issue as me too having the same concern and need some explanation to put up. Thanks in advance.
Comment From: snicoll
@arijitdeb1 I pinged @shakuzen for feedback and we need to follow-up. Thanks for the nudge, I've flagged this one for team attention.
Comment From: wilkinsona
We might be able to do something with SmartLifecycle and phases so that the meter registries are stopped before other beans. Before investigating that approach, we'd still like to get some feedback from @shakuzen.
Comment From: shakuzen
Sorry for not responding before. The intention of calling publish on close is to do a final publish so any changes in metrics between the previous publish (possibly never for a short-lived application) and the registry being closed are not lost.
We might be able to do something with
SmartLifecycleand phases so that the meter registries are stopped before other beans.
If that is possible, it sounds like the route to go. If that could be achieved, I would expect there won't be any exceptions thrown on the final publish (unless exceptions are being thrown on other publishes for some reason).
Comment From: wilkinsona
Thinking some more about SmartLifecycle, that could only really help with an auto-configured PushMeterRegistry. Once a user has configured their own, I don't think it would then be reasonable for Boot to meddle with its lifecycle.
I think a more natural way to fix this would be via dependency relationships between the various beans that are involved. In this context, it's interesting that Spring Data is apparently triggering bean creation. That suggests that the bean in question isn't being injected and, therefore, that the container probably doesn't have a depends on relationship between the repository and the bean.
@waschmittel I think we're back to needing a sample, please. I'd like to understand exactly what's happening in terms of the bean that are involved in getting the gauge's value and the dependency relationships that are in play when the application context is being closed.
Comment From: spring-projects-issues
If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.
Comment From: waschmittel
I was unpexcedly busy this week, but I will try to set up a sample project that reproduces this next week.
Comment From: waschmittel
Please take a look at https://github.com/waschmittel/spring-boot-19557 that reproduces this @wilkinsona
Comment From: wilkinsona
Thanks for the sample, @waschmittel. I've reproduced the problem. Here's the full stack trace of the failure:
org.springframework.beans.factory.BeanCreationNotAllowedException: Error creating bean with name 'entityManagerFactory': Singleton bean creation not allowed while singletons of this factory are in destruction (Do not request a bean from a BeanFactory in a destroy method implementation!)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:208) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeansOfType(DefaultListableBeanFactory.java:617) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.BeanFactoryUtils.beansOfTypeIncludingAncestors(BeanFactoryUtils.java:378) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.detectPersistenceExceptionTranslators(PersistenceExceptionTranslationInterceptor.java:168) ~[spring-tx-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:150) ~[spring-tx-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:178) ~[spring-data-jpa-2.2.5.RELEASE.jar:2.2.5.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) ~[spring-aop-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at com.sun.proxy.$Proxy101.count(Unknown Source) ~[na:na]
at io.micrometer.core.instrument.Gauge.lambda$builder$0(Gauge.java:58) ~[micrometer-core-1.3.5.jar:1.3.5]
at io.micrometer.core.instrument.StrongReferenceGaugeFunction.applyAsDouble(StrongReferenceGaugeFunction.java:47) ~[micrometer-core-1.3.5.jar:1.3.5]
at io.micrometer.core.instrument.internal.DefaultGauge.value(DefaultGauge.java:54) ~[micrometer-core-1.3.5.jar:1.3.5]
at io.micrometer.core.instrument.Measurement.getValue(Measurement.java:39) ~[micrometer-core-1.3.5.jar:1.3.5]
at io.micrometer.datadog.DatadogMeterRegistry.lambda$writeMeter$12(DatadogMeterRegistry.java:210) ~[micrometer-registry-datadog-1.3.5.jar:1.3.5]
at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195) ~[na:na]
at java.base/java.util.Collections$2.tryAdvance(Collections.java:4745) ~[na:na]
at java.base/java.util.Collections$2.forEachRemaining(Collections.java:4753) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[na:na]
at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[na:na]
at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:na]
at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497) ~[na:na]
at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:274) ~[na:na]
at java.base/java.util.ArrayList$SubList$2.forEachRemaining(ArrayList.java:1510) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[na:na]
at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[na:na]
at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:na]
at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[na:na]
at io.micrometer.datadog.DatadogMeterRegistry.publish(DatadogMeterRegistry.java:134) ~[micrometer-registry-datadog-1.3.5.jar:1.3.5]
at io.micrometer.core.instrument.push.PushMeterRegistry.publishSafely(PushMeterRegistry.java:48) ~[micrometer-core-1.3.5.jar:1.3.5]
at io.micrometer.core.instrument.push.PushMeterRegistry.close(PushMeterRegistry.java:83) ~[micrometer-core-1.3.5.jar:1.3.5]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:339) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:273) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:571) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:543) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:1072) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:504) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:1065) ~[spring-beans-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1060) ~[spring-context-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1029) ~[spring-context-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:978) ~[spring-context-5.2.4.RELEASE.jar:5.2.4.RELEASE]
at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:803) ~[spring-boot-2.2.5.RELEASE.jar:2.2.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:325) ~[spring-boot-2.2.5.RELEASE.jar:2.2.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) ~[spring-boot-2.2.5.RELEASE.jar:2.2.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1215) ~[spring-boot-2.2.5.RELEASE.jar:2.2.5.RELEASE]
at com.example.demo.DemoApplication.main(DemoApplication.java:10) ~[classes/:na]
A bean lookup is being performed to determine the persistence exception translator to use. The exception that has triggered this is due to an attempt to start a transaction when the entity manager factory has been closed.
Comment From: wilkinsona
You can avoid the problem by adding the following @Bean definition to the sample:
@Bean
static AbstractDependsOnBeanFactoryPostProcessor entityManagerFactoryMeterRegistryDependency() {
return new AbstractDependsOnBeanFactoryPostProcessor(DatadogMeterRegistry.class, EntityManagerFactory.class) {};
}
This ensures that the meter registry is closed before the EntityManagerFactory. I'm now investigating if it's possible for us to establish this relationship automatically.
Comment From: wilkinsona
On closer inspection, the lack of dependency relationships between the various beans that are involved is due to how the Gauge is being registered:
@Bean
public Gauge queueSize(MeterRegistry registry, QueueItemRepository repository) {
return Gauge.builder("queueSize", repository::count).register(registry);
}
The registration is being performed as a side-effect of the queueSize bean being created. This happens towards the end of the startup processing, by which time the disposal ordering of the meter registry and the entity manager factory have already been established.
Switching to use a MeterBinder to register the gauge fixes the problem. All MeterBinder beans are created and invoked when the MeterRegistry is being created. This allows the dependency relationship between the MeterBinder and the EntityManagerFactory to be established.
In short, there's no need for the workaround above if the gauge is registered using a MeterBinder instead of relying on a side-effect of bean creation:
diff --git a/src/main/java/com/example/demo/MetricsConfig.java b/src/main/java/com/example/demo/MetricsConfig.java
index d3e77a2..04020ea 100644
--- a/src/main/java/com/example/demo/MetricsConfig.java
+++ b/src/main/java/com/example/demo/MetricsConfig.java
@@ -1,16 +1,20 @@
package com.example.demo;
-import io.micrometer.core.instrument.Gauge;
-import io.micrometer.core.instrument.MeterRegistry;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
+import io.micrometer.core.instrument.Gauge;
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.core.instrument.binder.MeterBinder;
+
@Configuration
public class MetricsConfig {
- @Bean
- public Gauge queueSize(MeterRegistry registry, QueueItemRepository repository) {
- return Gauge.builder("queueSize", repository::count).register(registry);
+ @Bean
+ public MeterBinder queueMeterBinder(QueueItemRepository repository) {
+ return (registry) -> {
+ Gauge.builder("queueSize", repository::count).register(registry);
+ };
}
}
We should update the documentation to recommend broader use of a MeterBinder, particularly when the metric being registered is backed by other beans that are involved in the application context's lifecycle.
Comment From: wojciechkedziora
Hi @wilkinsona - after upgrading to the latest spring-boot 3.1.5 we've spot similar issue. I've reproduced it using the same project from previous comment - you can check it: https://github.com/wojciechkedziora/spring-boot-3-19557 (changes: spring boot version + MeterBinder solution from your previous comment). Applying short-term solution from this post obviously resolves the issue. Could you take a look? Thanks
Comment From: wilkinsona
Thanks, @wojciechkedziora. I've reproduced the problem with your updated sample and can see that things have changed since 2.2. I'm not yet sure of the cause of that, but it may be due to https://github.com/spring-projects/spring-boot/issues/30636. Please open a new issue so that we can investigate further.
Comment From: wojciechkedziora
@wilkinsona Thanks for your answer. I've created new issue - https://github.com/spring-projects/spring-boot/issues/38240.