Micrometer @Timed in Spring Boot REST method and Prometheus Error

Question

I am attempting to send data to Prometheus from my Spring Boot app using Micrometer's @Timed annotation and am seeing strange behavior. I see my method's data in prometheus, but I'm also seeing it fail in some instances with the exception below. I am including the necessary libraries and have followed Spring Boot configuration instructions for adding Micrometer @Timed annotation. Feels like a Spring Boot / Micrometer bug when constructing the keys for the metric. My timed annotation is very simple:

    @GetMapping(value = {"/pageable"}, produces = MediaType.APPLICATION_JSON_VALUE)
    @Timed("employees.get.pageable")
    public Page<Employee> all(@SortDefault(sort = "id", direction = Sort.Direction.ASC) Pageable p) {
        return (Page<Employee>) employeeRepository.findAll(p);
    }

Any ideas what I might be doing wrong? I'll be glad to respond with additional config, but didn't want to paste my entire project here. The stacktrace:

2020-01-21 18:53:40.559 ERROR 1 --- [nio-8080-exec-8] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception
java.lang.IllegalArgumentException: Prometheus requires that all meters with the same name have the same set of tag keys. There is already an existing meter named 'companies_get_single_seconds' containing tag keys [class, exception, method]. The meter you are attempting to register has keys [exception, method, outcome, status, uri].
    at io.micrometer.prometheus.PrometheusMeterRegistry.lambda$collectorByName$9(PrometheusMeterRegistry.java:382) ~[micrometer-registry-prometheus-1.3.2.jar!/:1.3.2]
    at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1932) ~[na:na]
    at io.micrometer.prometheus.PrometheusMeterRegistry.collectorByName(PrometheusMeterRegistry.java:369) ~[micrometer-registry-prometheus-1.3.2.jar!/:1.3.2]
    at io.micrometer.prometheus.PrometheusMeterRegistry.newTimer(PrometheusMeterRegistry.java:175) ~[micrometer-registry-prometheus-1.3.2.jar!/:1.3.2]
    at io.micrometer.core.instrument.MeterRegistry.lambda$timer$2(MeterRegistry.java:270) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:575) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:528) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.timer(MeterRegistry.java:268) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.Timer$Builder.register(Timer.java:464) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.composite.CompositeTimer.registerNewMeter(CompositeTimer.java:140) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.composite.CompositeTimer.registerNewMeter(CompositeTimer.java:31) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.composite.AbstractCompositeMeter.add(AbstractCompositeMeter.java:66) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[na:na]
    at java.base/java.util.Collections$SetFromMap.forEach(Collections.java:5581) ~[na:na]
    at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$null$0(CompositeMeterRegistry.java:65) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lock(CompositeMeterRegistry.java:184) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.composite.CompositeMeterRegistry.lambda$new$1(CompositeMeterRegistry.java:65) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.getOrCreateMeter(MeterRegistry.java:585) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.registerMeterIfNecessary(MeterRegistry.java:528) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.MeterRegistry.timer(MeterRegistry.java:268) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at io.micrometer.core.instrument.Timer$Builder.register(Timer.java:464) ~[micrometer-core-1.1.7.jar!/:1.1.7]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.stop(WebMvcMetricsFilter.java:180) ~[spring-boot-actuator-2.1.9.RELEASE.jar!/:2.1.9.RELEASE]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.record(WebMvcMetricsFilter.java:174) ~[spring-boot-actuator-2.1.9.RELEASE.jar!/:2.1.9.RELEASE]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:130) ~[spring-boot-actuator-2.1.9.RELEASE.jar!/:2.1.9.RELEASE]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104) ~[spring-boot-actuator-2.1.9.RELEASE.jar!/:2.1.9.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar!/:5.1.10.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar!/:9.0.26]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar!/:9.0.26]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.1.10.RELEASE.jar!/:5.1.10.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar!/:5.1.10.RELEASE]

score 6 · Answer 1 · answered Jan 24 '20 at 21:25

6

Most of the posts concerning Spring Boot Actuator timer metrics with micrometer show add the spring boot aop libs and using TimedAspect bean in the config. I removed the TimedAspect from config and removed spring-boot-starter-aop from my dependencies, but retained my @Timed annotations and the issue went away. I'm assuming (not sure) that both Spring and Micrometer where registering same metric with different tag keys. With this setup I am getting my custom metrics in prometheus with no more exceptions.

Flagging this as answered but would like some info as to why this works.

answered Jan 24 '20 at 21:25

Bill Pfeiffer

926
8
20

4

By default Spring Boot Actuator adds to every controller endpoints a metric. So you get this error when adding @Timed("...") on controller method (you were right about the double registration). If you annotate a service method for example, you should not have the error. I'm still looking for the right conf to avoid this. – Benjamin Caure May 25 '20 at 11:43
2

I encountered same error when added "@Timed" to one of the endpoint in the controller (springboot2). That it is because I have a bean of type TimedAspect in my code. Normally you don't need to define a TimedAspect bean if you are only adding the "@Timed" to your RestController but in my case I wanted to be able to use a timer in other parts of my application and "@Timed" were not being considered when it was outside of controller. Creating a TimedAspect bean resolved that problem but then it causes this issue when annotating controller methods. Thinking to move the "@Timed" to service layer – Navid H Jul 14 '20 at 05:14
1

Having the same problem. I believe if you remove the @Timed for the controller, tags such as outcome, status, etc are lost. Which in my case are really important. Any idea how to solve this problem? – jflroes Aug 12 '20 at 15:16
2

I went the other way around and disabled `WebMvcMetricsAutoConfiguration`. That way all `@Timed` annotations are picked up by the TimedAspect only. Downside is that you lose the tags handling that the auto configuration provides – geld0r Jan 14 '21 at 14:54

score -2 · Answer 2 · answered May 13 '20 at 18:11

-2

Had the same issue, using spring boot 2.0.2.RELEASE. Followed answer from Bill Pfeiffer and added this in my pom, solved the issue.

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

answered May 13 '20 at 18:11

user3595094

1

1

Since this is just reaffirming an existing answer, it shouldn’t be posted as a new answer. That said, I do appreciate you including the configuration example. – Jeremy Caney May 14 '20 at 00:25
@JeremyCaney agree, should have just replied Bill Pfeiffer's post – user3595094 May 18 '20 at 20:29
add this conf IS causing the error mentionned! Bill told that this dependency should be REMOVED not added, I have the same behavior than him! – Benjamin Caure May 25 '20 at 11:43

Micrometer @Timed in Spring Boot REST method and Prometheus Error

2 Answers2