Activity.DisplayName is overwritten by instrumentation libraries

[johncrim]

Component

OpenTelemetry.Instrumentation.AspNetCore
OpenTelemetry.Instrumentation.Http

Package Version

Package Name	Version
OpenTelemetry	1.9.0
OpenTelemetry.Instrumentation.AspNetCore	1.9.0
OpenTelemetry.Instrumentation.Http	1.9.0

Runtime Version

net8.0

Description

It should be possible to set the Activity.DisplayName in application code to provide a more useful span name than the default auto-instrumented value. For both OpenTelemetry.Instrumentation.AspNetCore and OpenTelemetry.Instrumentation.Http any value stored in .DisplayName before the Activity is stopped is subsequently overwritten by the instrumentation library.

Steps to Reproduce

Here's a test that should pass IMO:

using System.Collections.Generic;
using System.Diagnostics;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Microsoft.AspNetCore.Http.Features;
using Microsoft.AspNetCore.Routing;
using Microsoft.AspNetCore.TestHost;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using OpenTelemetry.Trace;
using Xunit;

public class DisplayNameOverwrittenTest
{

    [Fact]
    public async Task ActivityDisplayName_CanBeSetInHandler()
    {
        var recordedActivities = new List<Activity>();

        var builder = new HostBuilder()
           .ConfigureWebHost(webBuilder =>
                             {
                                 webBuilder
                                    .UseTestServer()
                                    .ConfigureServices(services =>
                                                       {
                                                           services.AddOpenTelemetry()
                                                                   .WithTracing(builder =>
                                                                                {
                                                                                    builder.AddAspNetCoreInstrumentation();
                                                                                    builder.AddInMemoryExporter(recordedActivities);
                                                                                });
                                                           services.AddRouting();
                                                       })
                                    .Configure(app =>
                                               {
                                                   app.UseRouting();
                                                   app.UseEndpoints(SetupEndpoints);
                                               });
                             });

        void SetupEndpoints(IEndpointRouteBuilder routeBuilder)
        {
            routeBuilder.Map("{**path}",
                             context =>
                             {
                                 // Here I'm setting the Activity.DisplayName to something more useful for this specific route
                                 var activity = context.Features.Get<IHttpActivityFeature>()?.Activity;
                                 if (activity?.IsAllDataRequested == true)
                                 {
                                     var request = context.Request;
                                     activity.DisplayName = $"{request.Method.ToUpperInvariant()} {request.Path}";
                                 }

                                 context.Response.StatusCode = 200;
                                 return Task.CompletedTask;
                             });
        }

        using var host = await builder.StartAsync();
        using var client = host.GetTestClient();
        var response = await client.GetAsync("/foo/bar");

        var requestActivity = Assert.Single(recordedActivities);
        Assert.Equal("GET /foo/bar", requestActivity.DisplayName);
    }

}

Expected Result

Passing test

Actual Result

The test fails because Activity.DisplayName is overwritten when the Activity is stopped.

DisplayNameOverwrittenTest.ActivityDisplayName_CanBeSetInHandler
  Source: DisplayNameOverwrittenTest.cs line 22
  Duration: 87 ms

 Message: 
   Assert.Equal() Failure: Strings differ
                  ↓ (pos 4)
   Expected: "GET /foo/bar"
   Actual:   "GET {**path}"
                  ↑ (pos 4)

Additional Context

A workaround is to store the .DisplayName value you want in Activity.SetCustomProperty(), then add a processor that reads that value and if present sets the Activity.DisplayName after it has stopped.

The same logic is present in OpenTelemetry.Instrumentation.Http. I haven't checked the other instrumentation libraries, but I wouldn't be surprised in this pattern is pervasive.

Related to #1744 and possibly #1792

[vishweshbankwar]

@johncrim - DisplayName is set by instrumentation as per the specification. You can use Enrich callback to change it. Specifically EnrichWithHttpResponse.

similar example - open-telemetry/opentelemetry-dotnet#3977 (comment)

[cijothomas]

@vishweshbankwar Given the fact this is commonly asked, its best to document the SpanName in the doc : https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.AspNetCore

along with the correct way for users who wish to change it.

[johncrim]

Hi @vishweshbankwar - thank you for the response. My point with this issue is that it's problematic to only allow modifying it in the EnrichResponse. If I modify it in application code (for example, say I have a specific path where the routePattern isn't helpful, eg the {**path} I have in the test case), so it makes sense to update Activity.Current.DisplayName there. If I do so, it is later overwritten by the autoinstrumentation. Requiring adding an EnrichResponse handler as the only way to "fix" this is onerous - it turns what should be a 1 line change into a multi-class and more fragile change.

In general, I think it's reasonable to expect that any telemetry values or attributes added throughout the request lifecycle will not be overwritten by the autoinstrumentation (unless there's a good reason for it).Otherwise, I have to debug this issue (which I did), and then in my app code set a value to use later, and then add an EnrichResponse handler to overwrite the value that the autoinstrumentation overwrote.

Also, without stepping through the library code to figure out why and where it's being overwritten, a normal developer wouldn't figure out that for DisplayName specifically, you have to use the EnrichResponse handler, and not the EnrichRequest handler. It's not intuitive, because the name EnrichResponse is in no way related to the DisplayName. So I'd have to analyze all the different changes by all the different participants to find the right extension point where setting DisplayName works (which I did).

@cijothomas - Thanks for the reply. I'll add that the span name in the Azure Monitor exporter also effectively overwrites the value a second time, so even if I add an EnrichResponse callback (or Processor) to overwrite the DisplayName value after it's been overwritten by the AspNetCore instrumentation, the Azure Monitor exporter doesn't use that DisplayName for the Request name or OperationName. I'm working on a separate issue for that right now.

[johncrim]

Also: using EnrichWithHttpResponse to set the DisplayName is only applicable for RequestIn telemetry. This is also an issue for HttpClient / dependency telemetry.

[vishweshbankwar]

In general, I think it's reasonable to expect that any telemetry values or attributes added throughout the request lifecycle will not be overwritten by the autoinstrumentation (unless there's a good reason for it)

@johncrim - Its actually the other way. If you are relying on auto-instrumentation, then in general you would not need to modify the tags or display name set by the instrumentation. However, there are valid scenarios as you shared in example where the modification is needed and for such scenarios Enrich callbacks are provided to override that behavior.

using EnrichWithHttpResponse to set the DisplayName is only applicable for RequestIn telemetry. This is also an issue for HttpClient / dependency telemetry.

Http instrumentation provides the Enrich callbacks as well. https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.Http#enrich-httpclient-api

[johncrim]

@johncrim - Its actually the other way. If you are relying on auto-instrumentation, then in general you would not need to modify the tags or display name set by the instrumentation. However, there are valid scenarios as you shared in example where the modification is needed and for such scenarios Enrich callbacks are provided to override that behavior.

This seems like the wrong approach to me. Are you trying to make it more difficult to use? Giving the developer the ability to add to the default telemetry is important. I think it's unrealistic to think that the autoinstrumentation provides the right answer all of the time. Escape hatches / allowing intuitive overrides is important.

Http instrumentation provides the Enrich callbacks as well. https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.Http#enrich-httpclient-api

I'm aware of that. However that means 2 places to make the same change, and 2 places to document DisplayName and support developers when they can't figure out why it's being overwritten.

[cijothomas]

@johncrim Would it be better to offer an option in the instrumentation library SetSpanName (or SetActivityDisplay) defaulting to true? When it is set to false, the instrumentation won't attempt to set DisplayName, so it'll remain whatever was the default or user-overrridden one.

(By next year, we expect Asp.Net Core to natively produce span with right names. So at that point, we should make sure they also allow such flexibility (or provide more useful name by default) )

[johncrim]

@cijothomas - I think it's desirable for the instrumentation library to provide a good default (which it does), but not overwrite a value that the developer (or another instrumentation library) set. I think it's very desirable for the value to be settable during request processing (it's likely only for certain code paths that I would want to change from the default), and not have it overwritten later.

I think adding an option to not set the DisplayName at all (if I'm understanding you right) would do more harm than good, because most of the time I want the default value. And any new config option has the potential for adding complexity and thus adding to support load.

Since the final default DisplayName can't be computed when the Activity is started (the route hasn't been determined yet), I understand why the DisplayName is set when the Activity is stopped. I think a fix could be as simple as:

1. Don't set the DisplayName when the Activity is started (thus leaving it with the default value of Microsoft.AspNetCore.Hosting.HttpRequestIn set by the runtime). This value isn't used anyway, currently it's always set a 2nd time when the activity is stopped.
2. When the Activity is stopped or on error, if DisplayName is still Microsoft.AspNetCore.Hosting.HttpRequestIn, set the default DisplayName.

Then do the same for the HttpClient activity (I think the same logic would work, but I haven't stepped through it as much).

This should work for only setting a default value when the developer or any other instrumentation library has not set it. I agree that it's not pretty, but seems reasonable.