Duplicated spans using ASP.NET controllers

[matteopey]

Describe the bug I'm not sure if this is a bug or is by design, so I'm opening this issue to have some guidance on how to solve this. I have an application that is using .NET Core 6. The controllers in this applications are implemented using the ControllerBase class from ASP.NET. The result on Datadog is that inside the trace two spans are shown, even though the controller path and the request made is only one. The service entry is of type aspnet_core.request the inner one is of type aspnet_core_mvc.request. Instead, using the new routing like this app.MapGet("/api/mapget", () => "Hello!"); only one trace is shown.

To Reproduce I setup Datadog with an agent running on the host machine on Docker with APM enabled and the application is running on the same host, integrating the .NET tracer as explained in the /apm/intro guide on Datadog.

Expected behavior One span is shown given the single request and the single controller.

Screenshots Controllers

MapGet

Runtime environment (please complete the following information):

• Automatic instrumentation
• Tracer version: 2.29.0
• OS: Windows 10 on WSL2. Happening in production on K8S cluster.
• CLR: >= .NET Core 3.1

Additional context Noticed this issue in our production systems, but is easily reproducible with a simple application locally.

[andrewlock]

Hi @matteopey, the behaviour you're seeing is expected when you use minimal APIs. There is no controller/Razor Page with minimal APIs so the MVC request aspect doesn't apply here, and there's no additional span to create. The root span contains details about the selected endpoint.

Can I take it from this issue that you would like there to be an additional span for the endpoint execution? If so, what information is it that you'd like to obtain? Is it the duration of the endpoint relative to the whole request? Or is there some additional information you would hope to see?

We've had some feedback that having two spans per request is problematic for some people, so it would be good to know if you prefer the two-span setup we have. Thanks!

[matteopey]

Hi @andrewlock I probably explained myself badly. The behavior of the minimal API is the one that I think is correct. What I would prefer is to have for the controllers only one span per request instead of the two currently, so exactly the same behavior as the minimal APIs. I'm therefore aligned with the feedback you received from the other people. For us having two span is creating too much overhead in some places of our applications, where we see on Datadog hundreds of spans while instead they are half of that.

[lpodolak]

I have also mixed feelings about these duplicated spans. I think they are the source of problems that I observe:

I discovered that it matters at which stage of processing we enhance spans with custom metadata using the span.SetTag() method: 1) If we do it in middleware, before request is processed, the metadata lands on the first span. These custom data are indexed and I can search/filter by them on the Datadog UI 2) If I do it later however, e.g. by attaching from middlware to context.Response.OnStarting() or even earlier - in asp.net core Filters, then these metadata land on the 2nd span. Unfortunately it is also not indexed, which means I can't filter/search for these data.

Recently we migrated our old Datadog.Tracer & the Datadog.Trace from version 1.27 to latest: 2.30. We don't have older data, but we're sure that we could filter/search by our custom fields added in a way #2 before the upgrade.

@andrewlock Do you have any idea how we could make these fields from the span #2 be indexed so that we can filter/search for them? Or maybe you could get back to an idea of single-span per controller action processing?

[lpodolak]

Here's a screenshot with our custom metadata landing on the 2nd span and so - being not searchable anymore.

[rjune]

Describe the bug I'm not sure if this is a bug or is by design, so I'm opening this issue to have some guidance on how to solve this. I have an application that is using .NET Core 6. The controllers in this applications are implemented using the ControllerBase class from ASP.NET. The result on Datadog is that inside the trace two spans are shown, even though the controller path and the request made is only one. The service entry is of type aspnet_core.request the inner one is of type aspnet_core_mvc.request. Instead, using the new routing like this app.MapGet("/api/mapget", () => "Hello!"); only one trace is shown.

To Reproduce I setup Datadog with an agent running on the host machine on Docker with APM enabled and the application is running on the same host, integrating the .NET tracer as explained in the /apm/intro guide on Datadog.

Expected behavior One span is shown given the single request and the single controller.

Screenshots Controllers

MapGet

Runtime environment (please complete the following information):

• Automatic instrumentation
• Tracer version: 2.29.0
• OS: Windows 10 on WSL2. Happening in production on K8S cluster.
• CLR: >= .NET Core 3.1

Additional context Noticed this issue in our production systems, but is easily reproducible with a simple application locally.

I don't know if you're still having this issue but, if you set DD_TRACE_ROUTE_TEMPLATE_RESOURCE_NAMES_ENABLED=false then the "duplicate" span goes away. https://ddtrace.readthedocs.io/en/stable/configuration.html

[andrewlock]

I don't know if you're still having this issue but, if you set DD_TRACE_ROUTE_TEMPLATE_RESOURCE_NAMES_ENABLED=false then the "duplicate" span goes away.

It's true that this goes away, but you also lose rich template names, the resource names become inconsistent, and you're using an old, deprecated mode.

I took another look at our options here recently, and the big trouble with offering a single-span mode is you lose a bunch of information related to how your app is behaving.

For example, looking at the screen shots above, the mvc span gives you interesting extra information, mostly around timings and the source of any child spans. We can still preserve the tags that are recorded, i.e. information about the controller/action, but we lose all the timing information. There doesn't seem to be a great solution to that either.

Another issue is when the middleware pipeline is re-executed, for example when an error occurs, and the pipeline redirects to an error controller. Currently, both of those MVC executions show up as separate spans nested in the root span, each with their own tags (and timings). If we switch to a single root span, there's a question about how we can preserve that information - we can tag an array of controller+action pairs that were invoked, but it's all a bit of a mess.

Which is all to say that we're still well aware of the difficulty here, we're considering our options, but haven't worked out the fine details yet I'm afraid.

[rjune]

I don't know if you're still having this issue but, if you set DD_TRACE_ROUTE_TEMPLATE_RESOURCE_NAMES_ENABLED=false then the "duplicate" span goes away.

It's true that this goes away, but you also lose rich template names, the resource names become inconsistent, and you're using an old, deprecated mode.

I took another look at our options here recently, and the big trouble with offering a single-span mode is you lose a bunch of information related to how your app is behaving.

For example, looking at the screen shots above, the mvc span gives you interesting extra information, mostly around timings and the source of any child spans. We can still preserve the tags that are recorded, i.e. information about the controller/action, but we lose all the timing information. There doesn't seem to be a great solution to that either.

Another issue is when the middleware pipeline is re-executed, for example when an error occurs, and the pipeline redirects to an error controller. Currently, both of those MVC executions show up as separate spans nested in the root span, each with their own tags (and timings). If we switch to a single root span, there's a question about how we can preserve that information - we can tag an array of controller+action pairs that were invoked, but it's all a bit of a mess.

Which is all to say that we're still well aware of the difficulty here, we're considering our options, but haven't worked out the fine details yet I'm afraid.

I totally get it, that isn't going to work for everybody. We don't use a lot of middleware and so the extra span that refers to just the endpoint method as opposed to the actual entry point into the API it's pretty useless for us. But if you've got a lot of middleware classes then you will lose some information about what's happening there. I didn't see it mentioned anywhere and wanted to make sure you at least aware of it so you had the option

[matteopey]

Hi @rjune I missed your comment. I'm trying now and it looks like is working as expected. We are also not using much the middleware part so is fine for now.

Thank you very much.