Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ending an activity will not restore the previously active one for explicit parents #46721

Closed
cijothomas opened this issue Jan 8, 2021 · 6 comments · Fixed by #48034
Closed

Comments

@cijothomas
Copy link
Contributor

Copied from open-telemetry/opentelemetry-dotnet#1677

Symptom

Activity.Current becomes null whenever any Activity with explicit parent is ended. I would instead have expected that the previously active activity would be restored, independent of whether it was the parent or not.

Following shows how to repro this with OpenTelemetry, but this can be reproed by setting up any Activitylistener.

Reproduce

using System;
using System.Diagnostics;
using OpenTelemetry;
using OpenTelemetry.Trace;

public class Program
{
    private static readonly ActivitySource MyActivitySource = new ActivitySource(
        "MyCompany.MyProduct.MyLibrary");

    public static void Main()
    {
        using var tracerProvider = Sdk.CreateTracerProviderBuilder()
            .SetSampler(new AlwaysOnSampler())
            .AddSource("MyCompany.MyProduct.MyLibrary")
            .Build();

        using (var activity = MyActivitySource.StartActivity("SayHello"))
        {
            Console.WriteLine("Current before: {0}", Activity.Current?.DisplayName);
            using (var child = MyActivitySource.StartActivity("SayWorld", ActivityKind.Internal, activity.Context))
            {
                Console.WriteLine("Current child: {0}", Activity.Current?.DisplayName);
            }

            Console.WriteLine("Current after: {0}", Activity.Current?.DisplayName ?? "(null)");
        }
    }
}

Actual Output:

Current before: SayHello
Current child: SayWorld
Current after: (null)

Expected output would be that the last line is Current after: SayHello.

Additional context

Responsible line in Activity.Stop:

https://github.com/dotnet/runtime/blob/v5.0.1/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs#L629

I think the Activity should capture a "previous" Activity independently of the Parent Activity and then always set that as active when stopping it.

@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added area-System.Diagnostics.Tracing untriaged New issue has not been triaged by the area owner labels Jan 8, 2021
@ghost
Copy link

ghost commented Jan 8, 2021

Tagging subscribers to this area: @tarekgh, @tommcdon, @pjanotti
See info in area-owners.md if you want to be subscribed.

Issue Details

Copied from open-telemetry/opentelemetry-dotnet#1677

Symptom

Activity.Current becomes null whenever any Activity with explicit parent is ended. I would instead have expected that the previously active activity would be restored, independent of whether it was the parent or not.

Following shows how to repro this with OpenTelemetry, but this can be reproed by setting up any Activitylistener.

Reproduce

using System;
using System.Diagnostics;
using OpenTelemetry;
using OpenTelemetry.Trace;

public class Program
{
    private static readonly ActivitySource MyActivitySource = new ActivitySource(
        "MyCompany.MyProduct.MyLibrary");

    public static void Main()
    {
        using var tracerProvider = Sdk.CreateTracerProviderBuilder()
            .SetSampler(new AlwaysOnSampler())
            .AddSource("MyCompany.MyProduct.MyLibrary")
            .Build();

        using (var activity = MyActivitySource.StartActivity("SayHello"))
        {
            Console.WriteLine("Current before: {0}", Activity.Current?.DisplayName);
            using (var child = MyActivitySource.StartActivity("SayWorld", ActivityKind.Internal, activity.Context))
            {
                Console.WriteLine("Current child: {0}", Activity.Current?.DisplayName);
            }

            Console.WriteLine("Current after: {0}", Activity.Current?.DisplayName ?? "(null)");
        }
    }
}

Actual Output:

Current before: SayHello
Current child: SayWorld
Current after: (null)

Expected output would be that the last line is Current after: SayHello.

Additional context

Responsible line in Activity.Stop:

https://github.com/dotnet/runtime/blob/v5.0.1/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs#L629

I think the Activity should capture a "previous" Activity independently of the Parent Activity and then always set that as active when stopping it.

Author: cijothomas
Assignees: -
Labels:

area-System.Diagnostics.Tracing, untriaged

Milestone: -

@tarekgh
Copy link
Member

tarekgh commented Jan 8, 2021

@cijothomas I am wondering how this suppose to work from the OTel specification point of view? I mean:

  • Create a Span and set its customized parent SpanContext. note that current Tracer.Context is different than the parent context we set to the Span.
  • Set Tracer.Context to the created span.
  • Then dispose the created span
  • request the current Tracer.Context.

what value you'll get?

CC @noahfalk

@tarekgh tarekgh removed the untriaged New issue has not been triaged by the area owner label Jan 8, 2021
@tarekgh tarekgh added this to the 6.0.0 milestone Jan 8, 2021
@Oberon00
Copy link

Oberon00 commented Jan 8, 2021

The Activity API is not conformant to the spec at all, see https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/api.md#span-creation:

Span creation MUST NOT set the newly created Span as the currently active Span by default, but this functionality MAY be offered additionally as a separate operation.

Which the activity API violates. It also says in https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/api.md#end:

End MUST NOT inactivate the Span in any Context it is active in. It MUST still be possible to use an ended span as parent via a Context it is contained in. Also, any mechanisms for putting the Span into a Context MUST still work after the Span was ended.

Which the activity API also does not conform to.

As per the spec for End, Tracer.Context would be the "disposed" span, if I understand you correctly.

@Oberon00
Copy link

Oberon00 commented Jan 8, 2021

Also note that the spec requires a concept of a "wrapped" SpanContext, i.e. a SpanContext can be wrapped in a non-recording Span so that it can be active in a context: https://github.com/open-telemetry/opentelemetry-specification/blob/master/specification/trace/api.md#wrapping-a-spancontext-in-a-span

The API MUST provide an operation for wrapping a SpanContext with an object implementing the Span interface. This is done in order to expose a SpanContext as a Span in operations such as in-process Span propagation.

@noahfalk
Copy link
Member

noahfalk commented Jan 8, 2021

I'm happy to explore what we can do to improve things, but I do want to be up-front that spec conformance is not the only consideration which drives .NET's design in this space. The Activity API long pre-dated OpenTelemetry's spec and there is a huge ecosystem of .NET apps that our customers depend on us not to break when they upgrade. Re-defining the behavior of existing APIs is always an area we are going to proceed cautiously.

@Oberon00
Copy link

Oberon00 commented Jan 8, 2021

I understand. That's why I suggested in open-telemetry/opentelemetry-dotnet#1677 (and copied here) that

I think the Activity should capture a "previous" Activity independently of the Parent Activity and then always set that as active when stopping it.

This may also break any use cases that rely on the activity being null when it is not after that change, but that would be a much smaller change.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Feb 9, 2021
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Feb 10, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Mar 12, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants