open-telemetry / opentelemetry-dotnet

The OpenTelemetry .NET Client
https://opentelemetry.io
Apache License 2.0
3.27k stars 769 forks source link

Start Root Span Collects Current Active Span as Parent #2803

Closed omamoo closed 1 year ago

omamoo commented 2 years ago

Bug Report

List of NuGet packages and version that you are using (e.g. OpenTelemetry 1.0.2):

Runtime version (e.g. net461, net48, netcoreapp3.1, net5.0 etc. You can find this information from the *.csproj file):

Symptom

I defined simple Api endpoint with the following code:

[HttpGet]
public async Task TestOtel()
{
    using (TracerProvider.Default.
               GetTracer(ActivitySourceProvider.ActivitySourceName, ActivitySourceProvider.Version).
               StartActiveSpan("FirstSpan"))
    {
        await Task.Delay(5.Seconds());
        var rootSpan = 
            TracerProvider.Default.
                GetTracer(ActivitySourceProvider.ActivitySourceName, ActivitySourceProvider.Version).
                StartRootSpan("MyRootSpan"); 
        using (Tracer.WithSpan(rootSpan))
        {
            Task.Delay(5.Seconds());
        }
    }
}

What is the expected behavior?

I'm expecting to see two different traces:

What is the actual behavior?

One trace with all span see attached image.

Additional Context

Image with trace at Jaeger: image

Thanks for the help.

omamoo commented 2 years ago

Anyone?

alanwest commented 2 years ago

Yes, this might be a bug. I created a test #2878 that I think models your situation.

omamoo commented 2 years ago

@alanwest Yes this is the exact case, thanks. How can I know if the test passes?

alanwest commented 2 years ago

We'll leave this issue open as I'm not yet sure what the best fix will be.

In my opinion, the problem is due in part to the behavior of the StartActivity method when it is passed an empty parent context (i.e., starting a root span). StartActivity is called from StartRootSpan and is not part of the OpenTelemetry .NET project - it is part of .NET's System.Diagnostics library.

I'll raise this issue for discussion in the .NET SIG meeting agenda next week.

In the meantime, a work around for you may be to set Activity.Current = null prior to calling StartRootSpan. It is the fact that Activity.Current is not null which is causing MyRootSpan to be a child of FirstSpan in your case.


Turns out there's another issue already tracking the underlying issue #984. Looks like there was discussion to follow up with the runtime team, but not sure if that happened or not.

omamoo commented 2 years ago

@alanwest Thanks for the update.

Thanks.

Oberon00 commented 2 years ago

I don't think this is exactly the same as #984. While #984 is about the Activity API missing required basic functionality, this is about the OTel-specific StartRootSpan not doing what it says in its name.

alanwest commented 2 years ago

I don't think this is exactly the same as #984. While #984 is about the Activity API missing required basic functionality, this is about the OTel-specific StartRootSpan not doing what it says in its name.

We discussed in this week's SIG meeting fixing this for the StartRootSpan API since we control that in this project, so I agree we should keep this bug open for that.

Separately, I just opened https://github.com/dotnet/runtime/issues/65528 to address #984.