Spring-boot: Controller annotated with @Timed and active TimedAspect clashes with WebMvcMetricsFilter

[AndreasKl]

tl;dr
A demo can be found here:

https://github.com/AndreasKl/micrometerunexpectedbehaviour

When the controller is called an unhandled exception is raised, by WebMvcMetricsFilter as org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter#stop tries to register the same meter with different tags as already registered by the TimedAspect. There is afais no way to disable the behaviour of WebMvcMetricsFilter for this aspect.

To generate prometheus percentiles via micrometer for my controllers I added @Timed("some_name") to a few methods. Unluckily this caused issues in WebMvcMetricsFilter which we use to monitor our status codes.

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 containing tag keys [class, exception, method]. The meter you are attempting to register has keys [exception, method, outcome, status, uri].

[wilkinsona]

Thanks for the sample. I've reproduced the problem.

I think the tags added by WebMvcMetricsFilter are more useful than those created by TimedAspect so, ideally, we'd like WebMvcMetricsFilter to win. That would require TimedAspect to realise that something else is already handling the @Timed annotation and it should ignore it. That would require a change in Micrometer.

@jkschneider what would you recommend here?

[AndreasKl]

@wilkinsona a way to disable this behaviour in WebMvcMetricsFilter would help us, I could provide a PR if you think this could be helpful for others.

Maybe you could also propose a name for the config setting.

[wilkinsona]

That sounds like a good fallback, but I don't want to add such an option until we know that it's needed. In the meantime, you can disable WebMvcMetricsFilter entirely by excluding org.springframework.boot.actuate.autoconfigure.metrics.web.servlet.WebMvcMetricsAutoConfiguration. It's broader than just disabling its support for @Timed but it will avoid the problem described here.

[AndreasKl]

@wilkinsona Unfortunately I use the metrics generated by WebMvcMetricsFilter (http_server_requests et. al). I currently mitigate this by creating my own WebMvcMetricsFilter implementation that does not scan for @Timed.

[wilkinsona]

@jkschneider Please see my comment above. Do you have any recommendations?

[wilkinsona]

Ping @jkschneider. We're a bit stuck here. Do you have any suggestions please?

[jkschneider]

@wilkinsona Only thing I can think of is to have a variant of TimedAspect that specifically excludes WebMvc/WebFlux annotated methods as well. Any other ideas?

[sycz]

I found the same problem. When using

@Timed(value = "metric_name", longTask = true)

WebMvcMetricsFilterand LongTaskTimingHandlerInterceptor will all take effect.
They conflict with each other.

Fortunately, io.micrometer.core.aop.TimedAspect is not enabled by default, unless manually enabled.
My understanding is that this means belonging to a user-defined operation.

LongTaskTimingHandlerInterceptor default tag keys specified is [method, uri]
TimedAspect default tag keys specified is[class, exception, method]
WebMvcMetricsFilter default tag keys specified is [exception, method, outcome, status, uri]

Thanks.

[abracadv8]

I also noticed if you have a REST response with an object being returned in the response, you get two distinct JSON bodies: https://github.com/abracadv8/micrometerunexpectedbehaviour

The below method should simply return {"response":"test"} but it returns that along with the Micrometer/Prometheus exception message in separate sets of JSON.

$ curl -i -X GET  -H "Content-Type: application/json" 'http://localhost:8080/response'
HTTP/1.1 200
Content-Type: application/json;charset=UTF-8
Transfer-Encoding: chunked
Date: Mon, 28 Oct 2019 14:10:19 GMT

{"response":"test"}{"timestamp":"2019-10-28T14:10:19.181+0000","status":200,"error":"OK","message":"Prometheus requires that all meters with the same name have the same set of tag keys. There is already an existing meter containing tag keys [class, exception, method]. The meter you are attempting to register has keys [exception, method, outcome, status, uri].","path":"/response"}

[Sancher17]

That sounds like a good fallback, but I don't want to add such an option until we know that it's needed. In the meantime, you can disable WebMvcMetricsFilter entirely by excluding org.springframework.boot.actuate.autoconfigure.metrics.web.servlet.WebMvcMetricsAutoConfiguration. It's broader than just disabling its support for @Timed but it will avoid the problem described here.

Ok, as I understand the problem is not resolved, I updated version of micrometer to new, but no result.
How to disable this one org.springframework.boot.actuate.autoconfigure.metrics.web.servlet.WebMvcMetricsAutoConfiguration. ?
OK, I found the right way:

@SpringBootApplication(exclude = WebMvcMetricsAutoConfiguration.class)

[jkschneider]

FYI in Micrometer 1.6.0 we will no longer hard fail on these tag clashes, though the problem still exists. Just leaving it up to the user to determine how they want to deal with it. See https://github.com/micrometer-metrics/micrometer/issues/2068