`HttpMetricsEnrichmentContext.AddCallback` seems to sometimes add duplicate tags

[lindeberg]

Description

When using HttpMetricsEnrichmentContext.AddCallback, it sometimes seems to add duplicate tags to a metric.

For a metric, I got multiple amount of different amount of duplicates. For example, with prometheus exposed metrics, notice the custom label gateway_api:

http_client_request_duration_seconds_bucket{gateway_api="crm",http_request_method="GET",http_response_status_code="200",network_protocol_version="1.1",server_address="whatever.com",url_scheme="https",le="0.1"} 4234 1727271043861

http_client_request_duration_seconds_bucket{gateway_api="crm",gateway_api="crm",http_request_method="GET",http_response_status_code="200",network_protocol_version="1.1",server_address="whatever.com",url_scheme="https",le="0.1"} 108 1727271043861

http_client_request_duration_seconds_bucket{gateway_api="crm",gateway_api="crm",gateway_api="crm",http_request_method="GET",http_response_status_code="200",network_protocol_version="1.1",server_address="whatever.com",url_scheme="https",le="0.1"} 8 1727271043861

http_client_request_duration_seconds_bucket{gateway_api="crm",gateway_api="crm",gateway_api="crm",gateway_api="crm",http_request_method="GET",http_response_status_code="200",network_protocol_version="1.1",server_address="whatever.com",url_scheme="https",le="0.1"} 1 1727271043861

Which causes Prometheus scraper to stop working with error message label name "gateway_api" is not unique: invalid sample.

Reproduction Steps

I'm unable to reproduce it locally, but it happened in the production environment which has a high request rate.

public sealed class HttpClientMetricsEnrichmentHandler : DelegatingHandler
{
    protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        HttpMetricsEnrichmentContext.AddCallback(request, context => context.AddCustomTag("gateway-api", "crm"););

        return base.SendAsync(request, cancellationToken);
    }
}

// While writing this, I realized the scope may be the problem somehow? 🦆
services.AddScoped<HttpClientMetricsEnrichmentHandler>();

services.AddHttpClient<ICrmClient, CrmClient>().AddHttpMessageHandler<HttpClientMetricsEnrichmentHandler>(); //Etc.

Followed by usage of the ICrmClient in the API.

Expected behavior

The custom tag should only be added once, I don't know how exactly. But maybe a duplicate check should be included?

Actual behavior

The custom tag is added multiple times, creating duplicate tags, which causes an error in Prometheus.

Regression?

No response

Known Workarounds

No response

Configuration

mcr.microsoft.com/dotnet/aspnet:8.0.8-alpine

Other information

No response

[CarnaViire]

// While writing this, I realized the scope may be the problem somehow? 🦆

I can't yet comment on whether this could be the cause of the duplication, but note that the handler used in AddHttpMessageHandler<THandler> must be registered as a Transient, see the Type Parameters section in the API docs.

[antonfirsov]

Without a repro or some other source of actionable data, it is not possible to determine if the bug lives in System.Net.Http, the application code, or some library your app is using.

// While writing this, I realized the scope may be the problem somehow? 🦆

This looks suspicious, can you please share more context and all the relevant code, including service registration CrmClient etc.

Edit: Natalia replied faster 😄

[lindeberg]

Thank you! We can start by trying out registering the Message Handler correctly as transient.

[antonfirsov]

@lindeberg did the registration change help?

[CarnaViire]

@lindeberg also couple of additional thoughts/things to check:

1. Whether it is possible that the message handler gets added to the same client twice
2. Whether there is any resilience handler/pipeline set up before the HttpClientMetricsEnrichmentHandler, so if retry happens, the enrichment handler might end up executing twice over the same request message.

You can check (1) over the registration time by calling ConfigureAdditionalHttpMessageHandlers and checking the list of all the handlers (you can even create an extension method to use instead of AddHttpMessageHandler), e.g.:

public static IHttpClientBuilder AddMetricsEnrichmentHandler(this IHttpClientBuilder builder)
    => builder.ConfigureAdditionalHttpMessageHandlers((additionalHandlers, serviceProvider) =>
    {
        if (additionalHandlers.Any(h => h is HttpClientMetricsEnrichmentHandler))
        {
            throw new Exception("MetricsEnrichmentHandler added twice");
        }

        additionalHandlers.Add(serviceProvider.GetRequiredService<HttpClientMetricsEnrichmentHandler>());
    });

// -------------

services.AddHttpClient<ICrmClient, CrmClient>()
    .AddMetricsEnrichmentHandler(); // instead of AddHttpMessageHandler<HttpClientMetricsEnrichmentHandler>()

You can check (2) in runtime by either collecting existing HttpClient logs, or by adding some tracking to the handler/message, e.g.:

public sealed class HttpClientMetricsEnrichmentHandler : DelegatingHandler
{
    private static readonly HttpRequestOptionsKey<bool> HandlerAddedKey = new("MetricsEnrichmentHandlerAdded");

    protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        if (request.Options.TryGetValue<bool>(HandlerAddedKey, out var _))
        {
            throw new Exception("MetricsEnrichmentHandler called twice");
        }
        request.Options.Set(HandlerAddedKey, true);

        HttpMetricsEnrichmentContext.AddCallback(request, context => context.AddCustomTag("gateway-api", "crm"));

        return base.SendAsync(request, cancellationToken);
    }
}

[lindeberg]

@lindeberg did the registration change help?

@CarnaViire

I haven't had the time to try it out yet, but spot on about the resilience handler being registered before the HttpClientMetricsEnrichmentHandler. I didn't consider that, now it makes sense.

Full registration:

  services
            .AddHttpClient<ISalesClient, SalesClient>()
            .AddCompanyDefaultResilienceHandler()
            .AddHttpMessageHandler<HttpClientMetricsEnrichmentHandler>()
            .ConfigureHttpClient((serviceProvider, httpClient) =>
            {
                var settings = serviceProvider.GetRequiredService<IOptions<SalesClientSettings>>().Value;
                httpClient.BaseAddress = new Uri(settings.BaseAddress);
            });

So I should make sure to have the HttpClientMetricsEnrichmentHandler after the resilience handler?

[antonfirsov]

@lindeberg how is the resilience handler implemented? Does it reuse the HttpRequestMessage instance? If yes and the HttpClientMetricsEnrichmentHandler is being run after the resilience handler, that would explain double additions on retries.

[lindeberg]

@antonfirsov

    private static Action<ResiliencePipelineBuilder<HttpResponseMessage>> Configure()
    {
        return resilience =>
        {
            resilience.AddRetry(new HttpRetryStrategyOptions
            {
                ShouldRetryAfterHeader = true,
                MaxRetryAttempts = 3,
                Delay = TimeSpan.FromSeconds(.2),
                UseJitter = true,
                BackoffType = DelayBackoffType.Exponential,
            });
            resilience.AddTimeout(TimeSpan.FromSeconds(10));
        };
    }

[antonfirsov]

Based on the code, I assume you are using Microsoft.Extensions.Resilience which AFAIK relies on Polly. Polly may reuse the request object between retries which can lead to the attribute duplication described.

@lindeberg can you confirm if changing the handler order fixes the issue?

We should document in API and conceptual docs that enrichment callbacks should be registered before running handlers that may retry the request.