Summary

I have a large legacy ASP.NET Web Forms .NET 4.7 Framework application that I would like to instrument. In anticipation of this, I decided to revisit the Autoinstrumentation to see how well it works with the older style apps running on .NET 4.7 under IIS. The Autoinstrumentation works to send metrics, but fails to send traces with a repeated error in the logs.

Test Applications

I created 3 test applications using .NET 4.7.2 framework (net472):

• Hello-world quality with just a single Default.aspx with no codebehind or compiled library, not connecting to anything running on IIS web site 3 port 81
• OOB ASP.NET Web Forms app using VS 2022, with one addition of a page connecting to SQL Server via SqlClient and rendering DataTable in DataGrid via databinding, running on IIS web site 4 port 82
• OOB ASP.NET MVC app using VS 2022, with one additional route connecting to SQL Server via SqlClient and rendering DataTable in table via Razor, running site 5 port 83

I am hosing them in IIS:

Configuration of Autoinjection

I got binaries locally https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/releases/tag/v0.7.0.

I added OTEL_LOG_LEVEL=debug per https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/blob/main/docs/config.md#internal-logs to the variables set up by OpenTelemetry.DotNet.Auto.psm1 before configuring anything.

I then ran the install from the local archive:

PS > Import-Module .\OpenTelemetry.DotNet.Auto.psm1
PS > Install-OpenTelemetryCore -LocalPath ".\opentelemetry-dotnet-instrumentation-windows.zip"

The binaries are properly unpacked to C:\Program Files\OpenTelemetry .NET AutoInstrumentation and I can I can see the variables set up in the W3SVC service:

PS C:\Users\Administrator> (Get-ItemProperty HKLM:\SYSTEM\CurrentControlSet\Services\W3SVC).Environment | Sort
ASPNETCORE_HOSTINGSTARTUPASSEMBLIES=OpenTelemetry.AutoInstrumentation.AspNetCoreBootstrapper
COR_ENABLE_PROFILING=1
COR_PROFILER_PATH_32=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\win-x86\OpenTelemetry.AutoInstrumentation.Native.dll
COR_PROFILER_PATH_64=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\win-x64\OpenTelemetry.AutoInstrumentation.Native.dll
COR_PROFILER={918728DD-259F-4A6A-AC2B-B85E1B658318}
CORECLR_ENABLE_PROFILING=1
CORECLR_PROFILER_PATH_32=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\win-x86\OpenTelemetry.AutoInstrumentation.Native.dll
CORECLR_PROFILER_PATH_64=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\win-x64\OpenTelemetry.AutoInstrumentation.Native.dll
CORECLR_PROFILER={918728DD-259F-4A6A-AC2B-B85E1B658318}
DOTNET_ADDITIONAL_DEPS=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\AdditionalDeps
DOTNET_SHARED_STORE=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\store
DOTNET_STARTUP_HOOKS=C:\Program Files\OpenTelemetry .NET AutoInstrumentation\net\OpenTelemetry.AutoInstrumentation.StartupHook.dll
OTEL_DOTNET_AUTO_HOME=C:\Program Files\OpenTelemetry .NET AutoInstrumentation
OTEL_LOG_LEVEL=debug

OtelCol setup

I got otelcol from https://github.com/open-telemetry/opentelemetry-collector-releases/releases/tag/v0.78.0.

I configured it with this otel-collector-config.yaml:

receivers:
  otlp:
    protocols:
      grpc:
      http:

processors:
  attributes/example:
    actions:
      - key: machine_name
        value: "OBSERVEWS2022"
        action: insert
  batch:

exporters:
  logging:
    #logLevel: debug
  otlphttp:
    endpoint: "https://collect.observe-eng.com/v1/otel"
    headers:
      'Authorization': 'REDACTED'
  prometheusremotewrite:
    endpoint: "https://collect.observe-eng.com/v1/prometheus"
    headers:
      'Authorization': 'REDACTED'

extensions:
  health_check:
  pprof:
  zpages:

service:
  telemetry:
    logs:
      level: "debug"
  extensions: [health_check,pprof,zpages]
  pipelines:
    traces:
      receivers: [otlp]
      processors: [attributes/example,batch]
      exporters: [otlphttp]
    metrics:
      receivers: [otlp]
      processors: [attributes/example,batch]
      exporters: [prometheusremotewrite]
    logs:
      receivers: [otlp]
      processors: [batch]
      exporters: [logging]

I started otelcol:

.".\otelcol.exe" --config ".\otel-collector-config.yaml"

Running the test Applications

When I invoke the applications, I can see the OpenTelemetry Autoingestion kick in (the agent asseblies show up in in the list of loaded dlls in the w3wp) and the logs in C:\ProgramData\OpenTelemetry .NET AutoInstrumentation\logs begin populating.

Metrics are Flowing great

I see this in logs and immediately start seeing metrics sent to my service by otelcol:

[2023-05-30T00:05:10.9921335Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'OpenTelemetry.Exporter.OtlpMetricExporter.Export succeeded.' 
[2023-05-30T00:05:10.9971338Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'ProcessMetrics succeeded.' 
[2023-05-30T00:05:10.9991872Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'MetricReader.Collect succeeded.' 
[2023-05-30T00:06:10.6523332Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'PeriodicExportingMetricReader calling MetricReader.Collect because the export interval has elapsed.' 
[2023-05-30T00:06:10.6573355Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'MetricReader.Collect method called.' 
[2023-05-30T00:06:10.6603280Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'MetricReader.OnCollect called.' 
[2023-05-30T00:06:10.6683465Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'Observable instruments collected.' 
[2023-05-30T00:06:10.6723030Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'ProcessMetrics called.' 
[2023-05-30T00:06:10.6753149Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'BaseExportingMetricReader calling OpenTelemetry.Exporter.OtlpMetricExporter.Export method.' 
[2023-05-30T00:06:10.6852373Z] [Debug] EventSource=OpenTelemetry-Sdk, Message=MetricReader event: 'OpenTelemetry.Exporter.OtlpMetricExporter.Export succeeded.' 

Traces are Not working

However, I am not seeing any traces. Instead, each of my applications is showing this message in the logs every 60 seconds:

  C:\ProgramData\OpenTelemetry .NET AutoInstrumentation\logs\otel-dotnet-auto-\LM\W3SVC\3\ROOT-1-133298786487107275-3556-20230529.log (20 hits)
	Line 110: [2023-05-30T00:05:10.8783479Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 120: [2023-05-30T00:06:10.6803450Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 130: [2023-05-30T00:07:10.6755857Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 140: [2023-05-30T00:08:10.6777436Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 150: [2023-05-30T00:09:10.6755576Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 160: [2023-05-30T00:10:10.6799468Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
	Line 170: [2023-05-30T00:11:10.6826194Z] [Warning] EventSource=OpenTelemetry-Api, Message=Failed to inject activity context in format: 'TraceContextPropagator', context: 'Invalid context'. 
... 

OtelCol zpages

In the http://localhost:55679/debug/tracez, I am seeing only /v1/metrics and exporter/prometheusremotewrite/metrics. I am not seeing the exporter/otlphttp/traces or opentelemetry.proto.collector.trace.v1.TraceService/Export which I see from some other autoinstrumentation of a Python app elsewhere in another environment.

Logs

The logs are otel-dotnet-auto-logs.zip

• Hello World is “otel-dotnet-auto-native-w3wp-3556.log” and otel-dotnet-auto-\LM\W3SVC\3*
• ASP.NET Web Forms is "otel-dotnet-auto-native-w3wp-15904.log and otel-dotnet-auto-\LM\W3SVC\4*
• ASP.NET MVC is otel-dotnet-auto-native-w3wp-7352.log and otel-dotnet-auto-\LM\W3SVC\5*

Apps

HelloWorld.zip WebApplicationForOTEL.zip WebApplicationForOTEL2.zip

Expected Behavior

I’d really like Traces to automagically appear, like they are expected to.