Tracing not registered automatically when using `WebApplication.CreateBuilder` with `UseRouting`

[madmox]

Tracing not registered automatically when using `WebApplication.CreateBuilder` with `UseRouting`

[jamescrosswell]

@madmox for the time being (until we can work out how to do this automatically), you'll need to add the following after the call to UseRouting (and before either your own middleware or any endpoints that you map):

app.UseRouting();
app.UseSentryTracing();

[madmox]

Yeah we tried to "magic" that away since it's a bit complex for people who are new to Sentry. The call to UseSentryTracing has to come after the call to UseRouting and before the call to UseEndpoints... which is a bit fragile.

If people are using WebApplicationBuilder (which most will be these days), either they shouldn't call UseRouting or, if they do, they should call UseSentryTracing immediately afterwards.

Not sure if this is possible, but maybe the middleware could throw at startup with an explicit error message about middleware registration order when it's not registered properly?

Additionally, I found out why this logic isn't working in the sample code you provided. With the introduction of WebApplicationBuilder and WebAppliction Microsoft also added a bit of trickery to "magic" away some of those complexities.

Talking about implicit behavior reducing code readability...

If you remove the call to UserRouting from the example code you provided, you'll see the SentryTracing middleware gets registered correctly and GetSpan returns a non-null value for any other middleware that you register.

Yes, I mentionned that in my previous posts, but for the reasons given above, I prefer registering routing explicitly.

I also mentionned that the behavior is different when targeting .NET 8, tracing always works, even if the middleware is registered before UseRouting(), so there's something else to dig here too.

[madmox]

Oh, I did not know that. It works as suggested then, thank you. Although it would probably be better to add this information on the UseSentryTracing() method documentation comment, or detect redundant instances in the auto-registration process!

[jamescrosswell]

@madmox yes that's essentially what we're doing in the SentryTracingBuilder:

sentry-dotnet/src/Sentry.AspNetCore/SentryTracingBuilder.cs

Line 47 in 24c159f

if (Properties.ContainsKey(EndpointRouteBuilder) && this.ShouldRegisterSentryTracing())

We use the presence of that property to detect when UseRouting has been called and then use that to trigger the registration of the Sentry tracing middleware. That bit is working fine. We also have some logic that uses a very similar technique (added a property to the builder) to record when the Sentry tracing middleware has been added so that we know not to add this again. That's the bit that's not working since seemingly there are multiple builders involved in net6.0 and later. So we set that property on one builder (the one that's used when you call UseRouting explicitly) but the other builder (the one that gets passed to the SentryTracingStartupFilter) sees different properties entirely. At first I thought it might be that one of the builders was the inner/wrapped builder and the other was the outer/wrapping builder but this does not appear to be the case.

It may be possible to fix this - I'm not sure. It would require a more detailed inspection of the ASP.NET Core codebase or that we use some alternative mechanism to record/detect when the sentry tracing middleware has already been added to the builder.

[jamescrosswell]

Hi @madmox ,

To create traces manually you'll need to start by creating a transaction and set this on the scope (see docs). SentrySdk.GetSpan() will always return null if Scope.Transaction has not been set.

You can see how this is done internally here:

sentry-dotnet/src/Sentry/Internal/Hub.cs

Lines 538 to 545 in 37eb4a5

	public ISpan StartSpan(string operation, string description)
	{
	ITransactionTracer? currentTransaction = null;
	ConfigureScope(s => currentTransaction = s.Transaction);
	return currentTransaction is { } transaction
	? transaction.StartChild(operation, description)
	: this.StartTransaction(operation, description);
	}

Arguably, that functionality could be surfaced in the Public API.

[madmox]

@jamescrosswell: I don't want to create a new transaction. I want to use the "request transaction" Sentry automatically creates somewhere in the pipeline when I use builder.WebHost.UseSentry(); to trace operations in my middelware. Those operations (spans) should be included in the same transaction as operations performed in my controller.

More specifically, I have a middleware that creates an ambiant SQL transaction when the request starts, and commits/rolls back when the HTTP request completes (when the response starts). I want to trace the commit/rollback statement in the same transaction as the other SQL statements.

Maybe your suggestion does that, I should look more into it. But from what I can see, if SentrySdk.GetSpan() returns null when I commit my SQL transaction, then your code will open a new "Sentry" transaction, not add a span to the one the SDK created for the request (which is presumably already finished).

[bitsandfoxes]

Hey @madmox,

I want to use the "request transaction" Sentry automatically creates somewhere in the pipeline when I use builder.WebHost.UseSentry(); to trace operations in my middelware.

I gave this a try locally because this is how I expected it to work and now I'm in a "it works on my machine" situation.
The SentryTracingMiddleware runs before app.Use so there should definitely be a transaction available for you to add a childspan to. Do you have tracing enabled? I.e. options.TracesSampleRate = 1.0f?

[madmox]

According to the doc, I should be able to retrieve the current transaction by using ISpan span = SentrySdk.GetSpan();. Simple repro sample I came up with:

// Program.cs
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.DependencyInjection;
using Sentry;

WebApplicationBuilder builder = WebApplication.CreateBuilder(args);
builder.WebHost.UseSentry("xxx");
builder.Services.AddControllers();

WebApplication app = builder.Build();
app.Use(async (context, next) =>
{
    ISpan span1 = SentrySdk.GetSpan(); // null
    await next();
    ISpan span2 = SentrySdk.GetSpan(); // null
});
app.UseRouting();
app.MapControllers();

app.Run();

[ApiController]
public class TestController
{
    [HttpGet]
    [Route("")]
    public IActionResult Get()
    {
        ISpan span = SentrySdk.GetSpan(); // not null
        return new StatusCodeResult(StatusCodes.Status204NoContent);
    }
}

<Project Sdk="Microsoft.NET.Sdk.Web">

  <PropertyGroup>
    <TargetFramework>net6.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Sentry.AspNetCore" Version="4.7.0" />
  </ItemGroup>

</Project>

After investigating, I found out that it works when using .NET 8 (TargetFramework=net8.0 in the .csproj) OR if I use .NET 6 but remove the line app.UseRouting(); (doesn't work if I move this line before my middleware though) 🤔

[bitsandfoxes]

This reminds me of something @jamescrosswell came across a while back! Didn't we make some changes to the initialization and setup to take care of the order internally?

[jamescrosswell]

@madmox sorry I didn't read your original post carefully enough. Sentry's tracing module is registered automatically after the call to app.UseRouting (see #2602).

So I tweaked the AspNetCoreBasic sample to do this:

                app.Use(async (_, next) =>
                {
                    var s1 = SentrySdk.GetSpan(); // null
                    Console.WriteLine($"Active span before first middleware: {s1?.SpanId ?? "null"}");
                    await next();
                    var s2 = SentrySdk.GetSpan(); // null
                    Console.WriteLine($"Active span after first middleware: {s2?.SpanId ?? "null"}");
                });
                app.UseRouting();
                app.Use(async (_, next) =>
                {
                    var s1 = SentrySdk.GetSpan(); // null
                    Console.WriteLine($"Active span before second middleware: {s1?.SpanId ?? "null"}");
                    await next();
                    var s2 = SentrySdk.GetSpan(); // null
                    Console.WriteLine($"Active span after second middleware: {s2?.SpanId ?? "null"}");
                });

                app.UseEndpoints(endpoints =>
                {
                    // Reported events will be grouped by route pattern
                    endpoints.MapGet("/", context => context.Response.WriteAsync("Hello World!"));
               }

And making a request to the root / route gives the following console output:

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:59740/echo - -
info: Sentry.ISentryClient[0]
      Sentry trace header is null. Creating new Sentry Propagation Context.
Active span before first middleware: null
info: Sentry.ISentryClient[0]
      Started transaction with span ID '492d591e96dfcc00' and trace ID '349164adf0f348e0901b66ad6c8a941b'.
Active span before second middleware: 492d591e96dfcc00
Active span after second middleware: 492d591e96dfcc00
info: Sentry.ISentryClient[0]
      Capturing transaction.
info: Sentry.ISentryClient[0]
      Envelope queued up: '9f6734da40144c2b822d5368994f0b3a'
Active span after first middleware: null
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 GET http://localhost:59740/echo - - - 404 0 - 15.5105ms
info: Sentry.ISentryClient[0]
      HttpTransport: Envelope '9f6734da40144c2b822d5368994f0b3a' successfully sent.

If you really want/need to, you could theoretically enable Sentry's tracing before the UseRouting middleware so that it was available earlier in the request pipeline. However things like the names of routes won't work property if you do that and we can't guarantee the behaviour of the auto-instrumentation in this case though. Ideally you can register your own middleware after the call to UseRouting.

[madmox]

Your example doesn't work for me. As I wrote in my previous message:

• With .NET 6, the current span is always null in my middleware if I explicitly call app.UseRouting() and always not null if I let the framework register routing implicitly (by not calling app.UseRouting()). The position of my middleware relative to routing does not matter.
• With .NET 8, the current span is never null, regardless of any explicit or implicit call to app.UseRouting().

using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Sentry;
using System;

WebApplicationBuilder builder = WebApplication.CreateBuilder(args);
builder.WebHost.UseSentry("<your DSN here>");

WebApplication app = builder.Build();
app.Use(async (_, next) =>
{
    Console.WriteLine($"Active span before first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
});
app.UseRouting();
app.Use(async (_, next) =>
{
    Console.WriteLine($"Active span before second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
});
app.MapGet("/", () => "Hello World!");

app.Run();

With .NET 6:

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET https://localhost:5100/ - -
Active span before first middleware: null
Active span before second middleware: null
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'HTTP: GET /'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'HTTP: GET /'
Active span after second middleware: null
Active span after first middleware: null
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 GET https://localhost:5100/ - - - 200 - text/plain;+charset=utf-8 101.6752ms

With .NET 8 (also with .NET 6 when I comment out the line app.UseRouting();):

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET https://localhost:5100/ - - -
Active span before first middleware: bd9a3db9ac2df702
Active span before second middleware: bd9a3db9ac2df702
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'HTTP: GET /'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'HTTP: GET /'
Active span after second middleware: bd9a3db9ac2df702
Active span after first middleware: bd9a3db9ac2df702
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 GET https://localhost:5100/ - 200 - text/plain;+charset=utf-8 63.8173ms

[bitsandfoxes]

Thanks @madmox, for being so persistent. I can reproduce this locally with our own samples as well. Looks like a bug to me. This behaviour should not change based on the TFM.

[jamescrosswell]

I can reproduce this locally with our own samples as well.

I can't reproduce this locally, targeting net6.0 on macOS using our AspNetCore.Basic sample... I'm not sure what you guys are doing differently (or conversely, what I'm doing differently).

Could one of you push a repro up to a github repo that I could clone?

[madmox]

Not sure about your AspNetCore.Basic sample, but can you reproduce using these 2 files?

Program.cs:

using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Sentry;
using System;

WebApplicationBuilder builder = WebApplication.CreateBuilder(args);
builder.WebHost.UseSentry("https://[email protected]/1");

WebApplication app = builder.Build();
app.Use(async (_, next) =>
{
    Console.WriteLine($"Active span before first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
});
app.UseRouting();
app.Use(async (_, next) =>
{
    Console.WriteLine($"Active span before second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
});
app.MapGet("/", () => "Hello World!");

app.Run();

Application.csproj:

<Project Sdk="Microsoft.NET.Sdk.Web">

  <PropertyGroup>
    <TargetFramework>net6.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Sentry.AspNetCore" Version="4.7.0" />
  </ItemGroup>

</Project>

Copy both files in a new directory (no change needed), cd into it, and execute dotnet run, and access your kestrel server using your web browser (usually at http://localhost:5000/).

Then kill the server, change the target framework to net8.0, execute again, and refresh your browser.

[bitsandfoxes]

I can't reproduce this locally, targeting net6.0 on macOS using our AspNetCore.Basic sample...

I was using the MVC sample.

[jamescrosswell]

but can you reproduce using these 2 files

OK yeah, interesting. The code you supplied is missing something to enable tracing:

builder.WebHost.UseSentry(o =>
{
    o.Dsn = "https://[email protected]/5428537";
    o.TracesSampleRate = 1.0;
});

But even after adding that, I'm seeing GetSpan() returns null before and after both middleware.

Which is curious. If I instead initialise everything using the generic host builder, as follows, it all works as expected:

var builder = WebHost.CreateDefaultBuilder(args);
builder.UseSentry(o =>
{
    o.Dsn = "https://[email protected]/5428537";
    o.TracesSampleRate = 1.0;
});
builder.Configure(app =>
{
    app.Use(async (_, next) =>
    {
        Console.WriteLine($"Active span before first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
        await next();
        Console.WriteLine($"Active span after first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    });
    app.UseRouting();
    app.Use(async (_, next) =>
    {
        Console.WriteLine($"Active span before second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
        await next();
        Console.WriteLine($"Active span after second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    });
    app.UseEndpoints(endpoints =>
    {
        endpoints.MapGet("/", () => "Hello World!");
    });
});
builder.Build().Run();

Now we just have to understand why it's working with the IWebHostBuilder but not with the WebApplicationBuilder... under the hood, both of them are using the same IWebHostBuilder extension method to register Sentry but clearly that's working with different concrete classes that each have different behaviour... not very Liskovy, I must say.

[madmox]

Oh I did not know it was possible to register the tracing middleware explicitly, thanks. I tend to always prefer explicit code even if that's more verbose, this way you have a better understanding of what's going on by looking at your own code. So that's a workaround, as well as migrating to .NET 8, which we are currently up to.

[jamescrosswell]

Oh I did not know it was possible to register the tracing middleware explicitly, thanks.

Yeah we tried to "magic" that away since it's a bit complex for people who are new to Sentry. The call to UseSentryTracing has to come after the call to UseRouting and before the call to UseEndpoints... which is a bit fragile. In the PR I linked to way up top of this discussion, we built some logic to automatically register the Sentry tracing middleware immediately after the routing middleware gets registered.

Additionally, I found out why this logic isn't working in the sample code you provided. With the introduction of WebApplicationBuilder and WebAppliction Microsoft also added a bit of trickery to "magic" away some of those complexities. Generally speaking, you don't have to call UseRouting anymore and, in fact, it's best if you don't. If you don't, then the WebApplicationBuilder will automatically add the RoutingMiddleware and EndpointMiddleware before and after (respectively) the ApplicationBuilder middleware pipeline... meaning you can't stuff up the order in which all the other middleware like SentryTracing gets registered.

If you remove the call to UserRouting from the example code you provided, you'll see the SentryTracing middleware gets registered correctly and GetSpan returns a non-null value for any other middleware that you register.

So this basically (noting that UseRouting and UseSentryTracing are both commented out):

var builder = WebApplication.CreateBuilder(args);
builder.WebHost.UseSentry(o =>
{
    o.Dsn = "https://[email protected]/5428537";
    o.TracesSampleRate = 1.0;
});
var app = builder.Build();
Func<HttpContext,Func<Task>,Task> middleware1 = async (_, next) =>
{
    Console.WriteLine($"Active span before first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after first middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
};
app.Use(middleware1);
// app.UseRouting();
Func<HttpContext,Func<Task>,Task> middleware2 = async (_, next) =>
{
    Console.WriteLine($"Active span before second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after second middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
};
app.Use(middleware2);
// app.UseSentryTracing();
app.MapGet("/", () => "Hello World!");

app.Run();

If you do call UseRouting explicitly, effectively you're changing the order in which this middleware gets called (it won't get called before the ApplicationBuilder middleware pipeline anymore). Andrew Lock has a fairly detailed set of articles that explains all of this but here are the main points relevant to this discussion.

@bitsandfoxes I'm not sure what we want to do about this. At the very least, I think we should document this potential pitfall. If people are using WebApplicationBuilder (which most will be these days), either they shouldn't call UseRouting or, if they do, they should call UseSentryTracing immediately afterwards.

[madmox]

I'm not sure why, but the behavior has changed since my last test. I'm confident I did not change anything in the code, so I don't know what's going on.

Now I get consistent behaviors in both .NET 6 and .NET 8 (current span is always null in the middlewares when using UseRouting() without UseSentryTracing()), although I previously confirmed at least 10 times that they were different (it was only behaving this way with .NET 6, with .NET 8 the current span was always defined). It's crazy.

I also get a valid transaction in both middlewares if I don't use UseRouting(). If I do, I can only get a valid transaction in the middleware after UseSentryTracing(), but only before calling the next() delegate, which is a problem because I need to add a transaction span after the request has been processed. SentrySdk.GetSpan() returns null after the call to next() in both middlewares.

So basically, the workarounds (migrating to .NET 8 or using UseSentryTracing()) don't work anymore for me, and I have to stop using UseRouting() explicitly. I'm lost.

[jamescrosswell]

I need to add a transaction span after the request has been processed.

@madmox the simplest way to do that might be something like:

var span = SentrySdk.GetSpan();
if (span == null) {
  span = SentrySdk.StartTransaction("transaction.name", "operation.name");
  SentrySdk.ConfigureScope(s => s.Transaction = (ITransactionTracer)span);
}

Sentry's tracing middleware will automatically create a transaction for you and set this on the scope before every request (and finish the transaction after every request). If no transaction has yet been created though (because you're instrumenting some code before the tracing middleware kicks in in the middleware pipeline) there's no reason why you can't create your own transaction.

If you do this before calling UseRouting, you're not going to have access to all of the information required to set the transaction and operation name to nice readable values reflecting the route info (which is why we delay the middleware until after UseRouting is called) but you can still instrument code with transactions/spans at this point.

[madmox]

I moved UseRouting() and UseSentryTracing() before my middleware, that's not the problem here. I want to reuse the transaction Sentry creates with every request (supposedly in the UseSentryTracing() middleware) and not create a new one.

What I'm saying is that Sentry's request transaction should not be finished after the call to the next() delegate in my middleware, because it's declared after in the pipeline. It is definitely possible because it works when I don't call UseRounting() and let the framework place the routing middleware at the start of the pipeline. It should behave the same way when I explicitly register the routing and tracing middlewares.

WebApplication app = builder.Build();
app.UseRouting();
app.UseSentryTracing();
app.Use(async (_, next) =>
{
    Console.WriteLine($"Active span before middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
    await next();
    Console.WriteLine($"Active span after middleware: {SentrySdk.GetSpan()?.SpanId ?? "null"}");
});
app.MapGet("/", () => "Hello World!");
app.Run();

This produces:

Active span before middleware: 350a6a855c0a95d0
Active span after middleware: null

But when I comment out both UseRouting() and UseSentrytracing(), both spans are not null. For the time being, that's what I'm going to do, but I think it denotes a bug in the way the middleware handles the closure of the transaction.

[jamescrosswell]

What I'm saying is that Sentry's request transaction should not be finished after the call to the next() delegate in my middleware, because it's declared after in the pipeline.

Ah, OK... I see what you're saying @madmox. Apologies, I think I only gave you a partial solution before. If you call UseSentryTracing manually, then you also need to disable automatic registration of the SentryTracing middleware via the Sentry Options (otherwise you'll end up with multiple instances of the tracing middleware and the "inner" instance will finish transactions that the outer instance starts).

In any event, it you set this to false, the span will not be null before or after your middleware executes:

sentry-dotnet/src/Sentry.AspNetCore/SentryAspNetCoreOptions.cs

Lines 76 to 89 in d1e5efc

	/// <summary>
	/// <para>
	/// When true (by default) Sentry automatically registers its tracing middleware immediately after
	/// `EndpointRoutingApplicationBuilderExtensions.UseRouting`.
	/// </para>
	/// <para>
	/// If you need to control when Sentry's tracing middleware is registered, you can set
	/// <see cref="AutoRegisterTracing"/> to false and call
	/// <see cref="SentryTracingMiddlewareExtensions.UseSentryTracing"/> yourself, sometime after calling
	/// `EndpointRoutingApplicationBuilderExtensions.UseRouting` and before calling
	/// `EndpointRoutingApplicationBuilderExtensions.UseEndpoints`.
	/// </para>
	/// </summary>
	public bool AutoRegisterTracing { get; set; } = true;

[jamescrosswell]

it would probably be better to add this information on the UseSentryTracing() method documentation comment, or detect redundant instances in the auto-registration process!

Agreed. We should definitely document this at the very least.

I had an initial look at trying to detect this automatically and it's unfortunately not trivial. Normally this logic should prevent the double registration of the tracing middleware:

sentry-dotnet/src/Sentry.AspNetCore/SentryTracingMiddlewareExtensions.cs

Lines 40 to 44 in 24c159f

	// Don't register twice
	if (builder.IsSentryTracingRegistered())
	{
	return builder;
	}

But in the case of the WebApplicationBuilder, the builder that is used when you call UseSentryTracing explicitly is not the same builder as the one that is used to initialise tracing via the SentryTracingStartupFilter (and nor is it the inner builder that gets wrapped by SentryTracingBuilder)... so ASP.NET Core 6+ is doing something more convoluted that I don't yet understand.

@bitsandfoxes it might be possible to find a workaround for this (e.g. to record when/whether tracing has been registered somewhere other than on the Builder.Properties - we could store this as an internal variable in the SentryOptions themselves, for example, or as a static variable somewhere).

[madmox]

The link you posted above describes 2 built-in middleware that handle duplicate registration differently.

On one hand, UseRouting() is able to detect an existing registration in the WebApplication.ApplicationBuilder pipeline and avoid the "automatic" registration in the "main" pipeline in this case. I'm not sure but I think the detection logic is implemented here, so maybe you could use the same approach.

On the other hand, UseEndpoints() is not able to apply the same logic, and I'm not sure why.