Enabling RecordException on ASP.net throws System.AccessViolationException

[vasicvuk]

Bug Report

List of [all OpenTelemetry NuGet

OpenTelemetry.Exporter.Console" Version="1.3.0" />
OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.3.0" />
OpenTelemetry.Exporter.Prometheus.AspNetCore" Version="1.4.0-alpha.2
OpenTelemetry.Extensions.Hosting" Version="1.0.0-rc9.6
OpenTelemetry.Instrumentation.AspNetCore" Version="1.0.0-rc9.6
OpenTelemetry.Instrumentation.GrpcNetClient" Version="1.0.0-rc9.6
OpenTelemetry.Instrumentation.Http" Version="1.0.0-rc9.6
OpenTelemetry.Instrumentation.SqlClient" Version="1.0.0-rc9.6

Runtime version: NET 6.0

Symptom

Get an exception:

Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
   at System.Runtime.CompilerServices.CastHelpers.IsInstanceOfClass(Void*, System.Object)
   at OpenTelemetry.Internal.TagTransformer`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].TryTransformTag(System.Collections.Generic.KeyValuePair`2<System.String,System.Object>, System.__Canon ByRef)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState.ForEach(System.Collections.Generic.KeyValuePair`2<System.String,System.Object>)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityTagsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].ForEachTagValueCallback(TagEnumerationState ByRef, System.Collections.Generic.KeyValuePair`2<System.String,System.Object>)
   at DynamicClass.AllocationFreeForEachDelegate(System.Collections.Generic.IEnumerable`1<System.Collections.Generic.KeyValuePair`2<System.String,System.Object>>, TagEnumerationState ByRef, ForEachDelegate<System.Collections.Generic.IEnumerable`1<System.Collections.Generic.KeyValuePair`2<System.String,System.Object>>,System.Collections.Generic.KeyValuePair`2<System.String,System.Object>,TagEnumerationState>)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityTagsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].Enumerate(System.Diagnostics.ActivityEvent, TagEnumerationState ByRef)
   at OpenTelemetry.Trace.ActivityHelperExtensions.EnumerateTags[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]](System.Diagnostics.ActivityEvent, TagEnumerationState ByRef)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions.ToOtlpEvent(System.Diagnostics.ActivityEvent)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+EventEnumerationState.ForEach(System.Diagnostics.ActivityEvent)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityEventsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+EventEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].ForEachEventCallback(EventEnumerationState ByRef, System.Diagnostics.ActivityEvent)
   at DynamicClass.AllocationFreeForEachDelegate(System.Collections.Generic.IEnumerable`1<System.Diagnostics.ActivityEvent>, EventEnumerationState ByRef, ForEachDelegate<System.Collections.Generic.IEnumerable`1<System.Diagnostics.ActivityEvent>,System.Diagnostics.ActivityEvent,EventEnumerationState>)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions.AddBatch(Opentelemetry.Proto.Collector.Trace.V1.ExportTraceServiceRequest, Opentelemetry.Proto.Resource.V1.Resource, OpenTelemetry.Batch`1<System.Diagnostics.Activity> ByRef)
   at OpenTelemetry.Exporter.OtlpTraceExporter.Export(OpenTelemetry.Batch`1<System.Diagnostics.Activity> ByRef)
   at OpenTelemetry.BatchExportProcessor`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].ExporterProc()
   at System.Threading.Thread.StartCallback()

What is the expected behavior?

The expected behavior would be to have exception details in trace.

If I disable RecordException everything works fine.

[danspark]

Getting this exception on startup after upgrading OpenTelemetry.Extensions.Hosting to 1.0.0-rc9.6

[hankovich]

Getting it after bumping OpenTelemetry.Extensions.Hosting, OpenTelemetry.Instrumentation.AspNetCore, and OpenTelemetry.Instrumentation.Http from 1.0.0-rc9.5 to 1.0.0-rc9.6. I also use RecordException and AccessViolation is thrown during exporting a trace with exception inside.

Reverting just OpenTelemetry.Extensions.Hosting doesn't help, so it looks like a deradation is in the OpenTelemetry package itself (which was bumped from 1.4.0-alpha.1 to 1.4.0-alpha.2).

[austindrenski]

I also encountered this after bumping instrumentation packages from 1.0.0-rc9.5 to 1.0.0-rc9.6, and eventually traced it back to the bump of OpenTelemetry.Api from 1.4.0-alpha.1 to 1.4.0-alpha.2.

See below for a minimal repro that consistently fails for net48 and net6.0, but succeeds for net7.0.

My working theory is that it involves some of the dynamically built IL methods that are used to enumerate tags from activity events. This theory is based on those methods being the last ones my debugger could step to before the app crash.

While trying to reproduce this, I found that the app crash reproduces when an ActivityEvent has 3 or more tags. In my real world scenario, this was triggered by the HTTP instrumentation recording exceptions (i.e. options.RecordException = true) which adds an ActivityEvent named exception with tags for exception.message, exception.type, and exception.stacktrace.

Minimal repro

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

  <PropertyGroup>
    <LangVersion>latest</LangVersion>
    <Nullable>enable</Nullable>
    <OutputType>exe</OutputType>
    <TargetFrameworks>net48;net6.0;net7.0</TargetFrameworks>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="OpenTelemetry.Api" Version="1.4.0-alpha.2" />
    <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.3.0" />
  </ItemGroup>

</Project>

using System;
using System.Collections.Generic;
using System.Diagnostics;
using OpenTelemetry;
using OpenTelemetry.Trace;

Console.WriteLine("Starting");

using (Sdk.CreateTracerProviderBuilder().AddOtlpExporter().AddSource("some_activity_source").Build())
{
    using var activitySource = new ActivitySource("some_activity_source");

    using var activity = activitySource.StartActivity("some_activity");

    activity?.AddEvent(new ActivityEvent(
        "some_activity_event",
        DateTimeOffset.UtcNow,
        new ActivityTagsCollection(new KeyValuePair<string, object?>[]
        {
            new("some_activity_event_tag_0", "some_activity_event_tag_value_0"),
            new("some_activity_event_tag_1", "some_activity_event_tag_value_1"),
            new("some_activity_event_tag_2", "some_activity_event_tag_value_2")
        })));
}

Console.WriteLine("Complete");

net48

This crashes silently, so Windows Event Viewer details included below:

$ dotnet run -f net48
Starting

Application: otel-dotnet-activity-event-crash.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an internal error in the .NET Runtime at IP 00007FFD0E493CA0 (00007FFD0E490000) with exit code 80131506.

Faulting application name: otel-dotnet-activity-event-crash.exe, version: 1.0.0.0, time stamp: 0xf17b8757
Faulting module name: clr.dll, version: 4.8.4515.0, time stamp: 0x624ce98e
Exception code: 0xc0000005
Fault offset: 0x0000000000003ca0
Faulting process id: 0x15fd8
Faulting application start time: 0x01d8b7bd2edc47e7
Faulting application path: C:\Users\adren\rider\otel-dotnet-activity-event-crash\bin\Debug\net48\otel-dotnet-activity-event-crash.exe
Faulting module path: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Report Id: 9d748c8f-68e0-4837-a4d4-cdfc08adca06
Faulting package full name: 
Faulting package-relative application ID: 

net6.0

$ dotnet run -f net6.0
Starting
Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
   at System.Runtime.CompilerServices.CastHelpers.IsInstanceOfClass(Void*, System.Object)
   at OpenTelemetry.Internal.TagTransformer`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].TryTransformTag(System.Collections.Generic.KeyValuePair`2<System.String,System.Object>, System.__Canon ByRef)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState.ForEach(System.Collections.Generic.KeyValuePair`2<System.String,System.Object>)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityTagsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].ForEachTagValueCallback(TagEnumerationState ByRef, System.Collections.Generic.KeyValuePair`2<System.String,System.Object>)
   at DynamicClass.AllocationFreeForEachDelegate(System.Collections.Generic.IEnumerable`1<System.Collections.Generic.KeyValuePair`2<System.String,System.Object>>, TagEnumerationState ByRef, ForEachDelegate<System.Collections.Generic.IEnumerable`1<System.Collections.Generic.KeyValuePair`2<System.String,System.Object>>,System.Collections.Generic.KeyValuePair`2<System.String,System.Object>,TagEnumerationState>)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityTagsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].Enumerate(System.Diagnostics.ActivityEvent, TagEnumerationState ByRef)
   at OpenTelemetry.Trace.ActivityHelperExtensions.EnumerateTags[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+TagEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]](System.Diagnostics.ActivityEvent, TagEnumerationState ByRef)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions.ToOtlpEvent(System.Diagnostics.ActivityEvent)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+EventEnumerationState.ForEach(System.Diagnostics.ActivityEvent)
   at OpenTelemetry.Trace.ActivityHelperExtensions+ActivityEventsEnumeratorFactory`1[[OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions+EventEnumerationState, OpenTelemetry.Exporter.OpenTelemetryProtocol, Version=1.0.0.0, Culture=neutral, PublicKeyToken=7bd6737fe5b67e3c]].ForEachEventCallback(EventEnumerationState ByRef, System.Diagnostics.ActivityEvent)
   at DynamicClass.AllocationFreeForEachDelegate(System.Collections.Generic.IEnumerable`1<System.Diagnostics.ActivityEvent>, EventEnumerationState ByRef, ForEachDelegate<System.Collections.Generic.IEnumerable`1<System.Diagnostics.ActivityEvent>,System.Diagnostics.ActivityEvent,EventEnumerationState>)
   at OpenTelemetry.Exporter.OpenTelemetryProtocol.Implementation.ActivityExtensions.AddBatch(Opentelemetry.Proto.Collector.Trace.V1.ExportTraceServiceRequest, Opentelemetry.Proto.Resource.V1.Resource, OpenTelemetry.Batch`1<System.Diagnostics.Activity> ByRef)
   at OpenTelemetry.Exporter.OtlpTraceExporter.Export(OpenTelemetry.Batch`1<System.Diagnostics.Activity> ByRef)
   at OpenTelemetry.BatchExportProcessor`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].ExporterProc()
   at System.Threading.Thread.StartCallback()

net7.0

$ dotnet run -f net7.0
Starting
Complete

[CodeBlanch]

@austindrenski Hey I'm still looking into why this is happening, but FYI if you do this...

  <ItemGroup>
    <PackageReference Include="OpenTelemetry.Api" Version="1.4.0-alpha.2" />
-   <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.3.0" />
+   <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.4.0-alpha.2" />
  </ItemGroup>

...then the sample project above starts to works fine.

[litan1106]

<PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.4.0-alpha.2" />

thanks for the workaround. I got the same error this morning

[cijothomas]

We are treating this error as P0, and will be releasing 1.3.1 hotfix. Please expect the details and patch release by next Tuesday.

[cijothomas]

Closing as the hotfix has been released. See #3629