Using TracerShim results in ConditionalWeakTable ArgumentException: "An item with the same key has already been added."

[tvandenheuvel]

Bug Report

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

AspNetCore app

• Npgsql.OpenTelemetry 8.0.2
• OpenTelemetry 1.7.0
• OpenTelemetry.Exporter.Console 1.7.0
• OpenTelemetry.Extensions.Hosting 1.7.0
• OpenTelemetry.Instrumentation.AspNetCore 1.7.1
• OpenTelemetry.Instrumentation.Http 1.7.1
• OpenTelemetry.Instrumentation.Runtime 1.7.0
• OpenTelemetry.Shims.OpenTracing 1.7.0-beta.1

Library

• OpenTracing 0.12.1

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

• net8.0 aspnetcore webapp
• net6.0 library

Symptom

When building and starting child spans using the TracerShim injected as OpenTracer ITracer, the ScopeManagerShim throws a ArgumentException

What is the expected behavior?

That a span is created and activated

What is the actual behavior?

System.ArgumentException: An item with the same key has already been added.
   at System.Runtime.CompilerServices.ConditionalWeakTable`2.Add(TKey key, TValue value)
   at OpenTelemetry.Shims.OpenTracing.ScopeManagerShim.Activate(ISpan span, Boolean finishSpanOnDispose)
   at OpenTelemetry.Shims.OpenTracing.SpanBuilderShim.StartActive(Boolean finishSpanOnDispose)
   at SubLibrary.SubClassWithOpenTracing.RecursiveChildSpan(String input, Int32 recursiveDepth) in .\OpenTelemetryTesting\SubLibrary\SubClassWithOpenTracing.cs:line 24
   at SubLibrary.SubClassWithOpenTracing.ParentSpan(String input) in.\OpenTelemetryTesting\SubLibrary\SubClassWithOpenTracing.cs:line 18
   at OpenTelemetryTesting.Program.<>c__DisplayClass0_0.<Main>b__0() in .\OpenTelemetryTesting\OpenTelemetryTesting\Program.cs:line 28
   at lambda_method2(Closure, Object, HttpContext)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddlewareImpl.Invoke(HttpContext context)

Reproduce

https://github.com/tvandenheuvel/OpenTelemetryTesting

We will close this issue if:

• The repro project you share with us is complex. We can't investigate custom
  projects, so don't point us to such, please.
• If we can not reproduce the behavior you're reporting.

[meganaut]

I am getting the same issue in an .net6 app with

<PackageReference Include="OpenTelemetry" Version="1.9.0"/> <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.9.0"/> <PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.9.0"/> <PackageReference Include="OpenTelemetry.Instrumentation.AspNetCore" Version="1.9.0"/> <PackageReference Include="OpenTelemetry.Instrumentation.Http" Version="1.9.0"/> <PackageReference Include="OpenTelemetry.Shims.OpenTracing" Version="1.9.0-beta.2"/>

Also referencing old libraries using OpenTracing 0.12.1 although it is also targeting .net6

[Kielek]

Guys, could you please provide Minimal, Reproducible Example?

In this case, I mean small portion of code (whole project) where we can observe problems. It should reduce time to response.

[lucasoares]

Same in our applications. We updated from

    <PackageReference Include="OpenTelemetry.Shims.OpenTracing" Version="1.0.0-rc9.9" />

to

    <PackageReference Include="OpenTelemetry.Shims.OpenTracing" Version="1.9.0-beta.2" />

And this issue started to throw errors throughout our codebase.

[lucasoares]

I did a little debugging on this, and it looks like the problem is happening in this line:

opentelemetry-dotnet/src/OpenTelemetry.Shims.OpenTracing/ScopeManagerShim.cs

Line 62 in a871f0f

SpanScopeTable.Add(shim.Span, instrumentation);

The issue occurs because the same TelemetrySpan is activated more than once.
When Activate is called multiple times for the same span, the code tries to insert it again into the ConditionalWeakTable. Since ConditionalWeakTable.Add does not allow duplicate keys, this results in an ArgumentException.

I haven’t figured out yet why it is being activated multiple times. The Activate code in ScopeManagerShim hasn’t changed between 1.0.0-rc9.9 and 1.9.0-beta.2, so it seems like something else upstream is triggering the duplicate activations.