Runtime: Root Activity has non default parent span id, when ActivityCreationOptions.TraceId is accessed.

Created on 18 Sep 2020  路  16Comments  路  Source: dotnet/runtime

Description

When creating an activity using ActivitySource, the activity's parentSpanId is expected to be default (when there was no active Activity at the time) But if the ActivityCreationOptions.TraceId is accessed in the Sample callback, then parentSpanId becomes non default.

Sharing the full repro below.

csproj:

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

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net5.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="System.Diagnostics.DiagnosticSource" Version="5.0.0-rc.1.20451.14" />
  </ItemGroup>

</Project>

Program

```C#
using System;
using System.Collections.Generic;
using System.Diagnostics;

namespace ActivitySourceTest
{
class Program
{
static void Main(string[] args)
{
Console.WriteLine("Hello World!");
ActivityListener listener = new ActivityListener();
listener.ShouldListenTo = (source) => true;
listener.Sample = (ref ActivityCreationOptions options) =>
{
var traceIdOfParent = options.Parent.TraceId;

            // Accessing the ToBeCreated TraceId causes the activity's parent
            // spanid to be non-default.
            // var traceIdOfActivityToBeCreated = options.TraceId;
            // Uncomment above line, and see that parentspanid is not default.
            return ActivitySamplingResult.AllDataAndRecorded;
        };

        ActivitySource.AddActivityListener(listener);

        var source = new ActivitySource("TestActivitySource");
        using (var rootActivity = source.StartActivity("RootOperation", ActivityKind.Server))
        {
            if (rootActivity.ParentSpanId == default)
            {
                Console.WriteLine("ParentSpanId is default"); // Expected behavior
            }
            else
            {
                Console.WriteLine("ParentSpanId is *NOT* default"); // Not expected behavior
            }
        }
    }
}

}

```

Configuration

Regression?


This must be a regression since Preview8. But the feature of "generate traceid of to be created Activity" existed in a different way earlier, so not easy to validate that.

Other information

area-System.Diagnostics.Tracing bug

All 16 comments

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

adding @noahfalk too

Although you are getting Activity.ParentSpanId != default but still you have same value of the default. I mean you still get Activity.ParentSpanId.ToString() == default.ToString() or it is "0000000000000000".

How blocking this issue for your scenario? The workaround is change your check to do something like

```C#

public bool IsDefaultSpanId(ActivitySpanId spanId) => spanId == default || spanId.ToHexString() == default.ToHexString();

```

Please get back to me quickly if this workaround is not enough for your scenario.

Yes. I believe this can be worked around.
If its too late for 5.0, is this something which could be fixed in a servicing release like 5.0.1 or something?

(I am on the move/driving, so may not be able to respond back immeditely.)

  • @reyang too.

If its too late for 5.0, is this something which could be fixed in a servicing release like 5.0.1 or something?

If this is really a blocker and will need to be fixed in the servicing release, then we should fix it now. servicing bar is same as current 5.0 release bar.

we can fix it in the next release 6.0 if this is not blocking for you.

@tarekgh have you had any chance to investigate why the value no longer compares equal to default yet? I don't know enough to say we should be fixing it or not, but it at least sounds worrisome. Understanding the underlying issue and how complicated it would be to make a fix would be very helpful.

@noahfalk yes I understand what is going on and the fix will be simple. basically it is in the line

https://github.com/tarekgh/runtime/blob/527f9ae88a0ee216b44d556f9bdc84037fe0ebda/src/libraries/System.Diagnostics.DiagnosticSource/src/System/Diagnostics/Activity.cs#L952

should be changed to something like
C# if (parentContext.SpanId != default) activity._parentSpanId = parentContext.SpanId.ToString();

I put this issue to 6.0 release. please advise if you think this is blocking for OTel and we should have it in 5.0.

I have created a PR https://github.com/dotnet/runtime/pull/42483 for the fix in our master branch (6.0 release). please have a look.

@cijothomas what is the impact of using the workaround instead of having the good fix for OpenTelemetry? I'm guessing it hurts performance a bit but not sure if there are other problems it creates?

I think the perf hit could be negligible or none.

  1. The workaround itself is easy to apply in OpenTelemetry .NET. (specifically in the repo https://github.com/open-telemetry/opentelemetry-dotnet where the SDK and a bunch of standard exporters/samplers are hosted)

  2. It is not clear how will vendors who write OpenTelemetry Exporters/Samplers/other components will know about this issue. They could be incorrectly determining if a given activity is root or not. And depending on the particular backend, this can cause issues. (eg: https://github.com/open-telemetry/opentelemetry-dotnet/issues/1288)
    The fact that this issue is only triggered when someone accesses the ActivityCreationOptions.TraceId makes it even hard to isolate and investigate.

Considering that the impact can be bad if one hits this issue, and it could be non-trivial to track it back to this issue and workaround, I'd propose to make this available in 5.0.1 service release, rather than 6.0. Will leave it upto .NET team to make the final call.

(The OpenTelemetry .NET SDK repo (where I am one of the maintainers) can apply this workaround, and are not blocked)

Just to be clear, this could impact users not using OpenTelemetry at all. A library author would have to have some logic inspecting Activity.ParentSpanId and relying on default to trigger some parent-based logic. If something else in the process registers an ActivityListener which happens to inspect TraceId during Sample callback, then that Activity.ParentSpanId behavior will change for the library author. Totally out of their control. We might want to fix in 5.0, if possible, just because of the potential for confusion.

A library author would have to have some logic inspecting Activity.ParentSpanId and relying on default to trigger some parent-based logi

Did we publish anywhere they should check against default value? or you are just speculating they will do that?

Purely speculative. The comment in there...

        /// <summary>
        /// If the parent Activity ID has the W3C format, this returns the ID for the SpanId part of the ParentId.
        /// Otherwise it returns a zero SpanId.
        /// </summary>

...actually leads in the right direction. If you code using that rule, like this...

if (activity.ParentSpanId.ToHexString() == "0000000000000000")

...you would be fine. It's only if you do...

if (activity.ParentSpanId == default)

...you potentially run into dragons.

Very easy workaround once you figure out what's going on. Just figuring out what's going on is the real trick 馃槃

I am currently checking if we can including it in 5.0 release.

We'll include the fix in the 5.0 release. It will be part of our RC2 release. Thanks all for your feedback.

Was this page helpful?
0 / 5 - 0 ratings

Related issues

iCodeWebApps picture iCodeWebApps  路  3Comments

omariom picture omariom  路  3Comments

bencz picture bencz  路  3Comments

sahithreddyk picture sahithreddyk  路  3Comments

matty-hall picture matty-hall  路  3Comments