Actuator "http.server.requests" metric has wrong "status" tag for error responses

[i-kaplin]

Actuator reports a metric with status = 200, but controller actually responds with bad request.

MetricsWebFilter.error(ServerWebExchange exchange, long start, Throwable cause) is called with cause:

org.springframework.web.server.ServerWebInputException: Response status 400 with reason "Type mismatch."; nested exception is org.springframework.beans.TypeMismatchException: Failed to convert value of type 'java.lang.String' to required type 'java.util.List'; nested exception is java.lang.NumberFormatException: For input string: "invalidSkuId"

However DefaultWebFluxTagsProvider resolves status tag with 200 because of it gets status from exchange (which is null in this case) and doesn't take exception cause into consideration.

public static Tag status(ServerWebExchange exchange) {
	HttpStatus status = exchange.getResponse().getStatusCode();
	if (status == null) {
		status = HttpStatus.OK;
	}
	return Tag.of("status", status.toString());
}

Actual metric name
httpServerRequests.exception.ServerWebInputException.method.POST.status.200.uri./GoodsService/getActiveGoods.do

Expected metric name
httpServerRequests.exception.ServerWebInputException.method.POST.status.400.uri./GoodsService/getActiveGoods.do

[wilkinsona]

Thanks for the bug report.

IMO, the tag provider is correct in not taking the exception cause into consideration. For it to do so would require it to have knowledge of WebFlux's exception to status mapping logic. Instead, it would be preferable for the tag provider to be called after ExceptionHandlingWebHandler has been called and has set the response status on the exchange. However, I'm not sure that is possible as, currently, WebHttpHandlerBuilder decorates FilteringWebHandler with ExceptionHandlerWebHandler so exception handling is performed after filtering.

@rstoyanchev @sdeleuze Is there a way for us to hook into the web handling pipeline so that we can reliably get the status that will be returned to the client?

/cc @jkschneider

[jkschneider]

There was a related issue on the servlet side a while back micrometer-metrics/micrometer#264. We wound up having to do this rather ugly hack because ultimately the servlet container winds up being the thing that sets the response code, well after it leaves Spring Boot's control.

I checked with @adriancole, and we do the same thing in openzipkin/brave.

There's been some discussion about us (i.e. tracing and metrics) moving further up the stack for instrumentation, hooking into particular container implementations. This is primarily driven by timing accuracy, but also has ramifications for this sort of problem.

[rstoyanchev]

@wilkinsona the only thing that comes to mind is decorating the HttpHandler itself to check the response status after all handling is complete.

Keep in mind though that there is a small number of remaining cases, specifically when ServerHttpResponse#isCommitted returns true at the time of exception handling, where the status may yet change to 500 deeper in server adapter code (Servet containers, Undertow) or in the server itself (Reactor Netty). In those cases the HttpHandler will be returning an error signal, so at least you can recognize them, and at that point it's safe to assume a 500 response will result.

[rstoyanchev]

@jkschneider I had no idea you were using the HandlerMappingIntrospector. It seems a little wasteful to do the entire request mapping to get the handler ahead of time. Intuitively it would make sense to start the metrics and fill in the handler later once it's actually been chosen. Have you considered using WebMvcConfigurer to install a global interceptor?

[jkschneider]

It seems a little wasteful to do the entire request mapping to get the handler ahead of time

I don't quite understand this. Are you saying that matchableHandlerMapping.getHandler(request) is wasteful?

[rstoyanchev]

You're essentially performing an extra run of the complete handler matching algorithm -- go through every HandlerMapping, check every @RequestMapping, look for static resources, and so on.

[jkschneider]

IIRC spring-security and Sleuth are doing much the same. Seems like if this a wasteful operation we would be better served with a cache in the matching algorithm, if nothing else for subsequent requests to the same URI?

[jkschneider]

Also, it is crucial that observability code (metrics/tracing) gets a chance to intercept the request before spring-security which is using a servlet filter. Not sure if the WebMvcConfigurer-based interceptors are ordered ahead of all servlet filters.

It's kind of a me-first arms race over here.

[dsyer]

WebMvcConfigurer-based interceptors are (by definition) ordered after all servlet filters (they are applied by a servlet).

[bclozel]

I've created SPR-16693 as the right abstraction level for that is a WebHandlerDecorator. This issue would be now about turning the MetricsWebFilter into a MetricsWebHandlerDecorator once SPR-16693 is fixed.