We have observed a behaviour that seems to be incorrect with respect to the generation of the http.client.requests metric of the http clients (webClient and restTemplate) via the Observation API.

What we have observed is that making a single request with the client generates duplicate metrics, since the KeyValues status and outcome have different values in the start and stop of the Observation API.

For example, we show the generated metrics exposed in the Prometheus endpoint after making a single request with a restTemplate:

# HELP http_client_requests_active_seconds  
# TYPE http_client_requests_active_seconds summary
http_client_requests_active_seconds_active_count{client_name="localhost",exception="none",method="GET",outcome="UNKNOWN",status="CLIENT_ERROR",uri="/app-rest/client-invoked",} 0.0
http_client_requests_active_seconds_duration_sum{client_name="localhost",exception="none",method="GET",outcome="UNKNOWN",status="CLIENT_ERROR",uri="/app-rest/client-invoked",} 0.0
# HELP http_client_requests_active_seconds_max  
# TYPE http_client_requests_active_seconds_max gauge
http_client_requests_active_seconds_max{client_name="localhost",exception="none",method="GET",outcome="UNKNOWN",status="CLIENT_ERROR",uri="/app-rest/client-invoked",} 0.0

# HELP http_client_requests_seconds  
# TYPE http_client_requests_seconds summary
http_client_requests_seconds_count{client_name="localhost",error="none",exception="none",method="GET",outcome="SUCCESS",status="200",uri="/app-rest/client-invoked",} 1.0
http_client_requests_seconds_sum{client_name="localhost",error="none",exception="none",method="GET",outcome="SUCCESS",status="200",uri="/app-rest/client-invoked",} 0.020930106
# HELP http_client_requests_seconds_max  
# TYPE http_client_requests_seconds_max gauge
http_client_requests_seconds_max{client_name="localhost",error="none",exception="none",method="GET",outcome="SUCCESS",status="200",uri="/app-rest/client-invoked",} 0.020930106

We have added a simple demo that reproduces this behavior by following the steps below: 1. Start the application. 2. Invoke the endpoint http://localhost:8080/app-rest/invoke 3. Display the metrics generated by the Prometheus endpoint http://localhost:8080/actuator/prometheus

The versions used are Spring Boot 3.0.5.

Comment From: bclozel

I believe this is the expected behavior from a Spring Framework perspective, as the observation is handled by the DefaultMeterObservationHandler which converts the observation into timers.

During onStart, a timer and a long task timer are created; at this point, we don't have all the information about observation as it's barely started. Tags are collected at this point for the "http.client.requests.active" metric (the long task timer variant). During onStop, both are recorded and tags are collected for the regular "http.client.requests" observation.

@marcingrzejszczak is this the expected behavior for Micrometer?

Comment From: marcingrzejszczak

Yup, that is the expected behaviour

Comment From: bclozel

Thanks for the confirmation Marcin. @ferblaca please create a Micrometer issue if you believe long tasks should not be instrumented. Thanks!

Comment From: hkecho

Hi @bclozel @marcingrzejszczak Just wondering will it cause some disaster for Service, or just lose some metrics?

Comment From: bclozel

@hkecho it won't cause either of those.

Comment From: hkecho

Thanks @bclozel