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.

Sign up for GitHub

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

Modify ASP.NET Core instrumentation to take advantage of sampling decision #1899

Merged
merged 11 commits into from
Mar 18, 2021
Merged

Modify ASP.NET Core instrumentation to take advantage of sampling decision #1899

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
bf0184e
Optimize ASP.NET Core instrumentation for SuppressInstrumentation
utpilla Mar 11, 2021
bb8b094
Updated unit tests
utpilla Mar 11, 2021
63b1a7f
Update src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/Ht…
utpilla Mar 11, 2021
1582a56
Update src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/Ht…
utpilla Mar 11, 2021
1c36600
Addressed PR comments
utpilla Mar 11, 2021
c1955d5
Update TestAspNetCore controller
utpilla Mar 11, 2021
2c062eb
Merge branch 'main' into utpilla/Optimize-AspNetCoreInstrumentation-F…
utpilla Mar 18, 2021
080066e
Merge remote-tracking branch 'origin/main' into utpilla/Optimize-AspN…
utpilla Mar 18, 2021
1463409
Updated CHANGELOG.md
utpilla Mar 18, 2021
0a32504
Merge remote-tracking branch 'fork/utpilla/Optimize-AspNetCoreInstrum…
utpilla Mar 18, 2021
b88ba57
Updated CHANGELOG.md
utpilla Mar 18, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
54 changes: 36 additions & 18 deletions src/OpenTelemetry.Instrumentation.AspNetCore/Implementation/HttpInListener.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -57,29 +57,29 @@ public HttpInListener(string name, AspNetCoreInstrumentationOptions options)
[System.Diagnostics.CodeAnalysis.SuppressMessage("Reliability", "CA2000:Dispose objects before losing scope", Justification = "The objects should not be disposed.")]
public override void OnStartActivity(Activity activity, object payload)
{
_ = this.startContextFetcher.TryFetch(payload, out HttpContext context);
if (context == null)
// The overall flow of what HttpClient library does is as below:
utpilla marked this conversation as resolved.
Show resolved Hide resolved
// Activity.Start()
// DiagnosticSource.WriteEvent("Start", payload)
// DiagnosticSource.WriteEvent("Stop", payload)
// Activity.Stop()

// This method is in the WriteEvent("Start", payload) path.
// By this time, samplers have already run and
// activity.IsAllDataRequested populated accordingly.

if (Sdk.SuppressInstrumentation)
cijothomas marked this conversation as resolved.
Show resolved Hide resolved
{
AspNetCoreInstrumentationEventSource.Log.NullPayload(nameof(HttpInListener), nameof(this.OnStartActivity));
return;
}

try
{
if (this.options.Filter?.Invoke(context) == false)
{
AspNetCoreInstrumentationEventSource.Log.RequestIsFilteredOut(activity.OperationName);
activity.IsAllDataRequested = false;
return;
}
}
catch (Exception ex)
_ = this.startContextFetcher.TryFetch(payload, out HttpContext context);
if (context == null)
{
AspNetCoreInstrumentationEventSource.Log.RequestFilterException(ex);
activity.IsAllDataRequested = false;
AspNetCoreInstrumentationEventSource.Log.NullPayload(nameof(HttpInListener), nameof(this.OnStartActivity));
return;
}

// Enusre context propagation irrespective of sampling decision
utpilla marked this conversation as resolved.
Show resolved Hide resolved
utpilla marked this conversation as resolved.
Show resolved Hide resolved
var request = context.Request;
var textMapPropagator = Propagators.DefaultTextMapPropagator;
if (!this.hostingSupportsW3C || !(textMapPropagator is TraceContextPropagator))
Expand Down Expand Up @@ -110,11 +110,29 @@ public override void OnStartActivity(Activity activity, object payload)
}
}

ActivityInstrumentationHelper.SetActivitySourceProperty(activity, ActivitySource);
ActivityInstrumentationHelper.SetKindProperty(activity, ActivityKind.Server);

// enrich Activity from payload only if sampling decision
// is favorable.
if (activity.IsAllDataRequested)
{
try
{
if (this.options.Filter?.Invoke(context) == false)
utpilla marked this conversation as resolved.
Show resolved Hide resolved
{
AspNetCoreInstrumentationEventSource.Log.RequestIsFilteredOut(activity.OperationName);
activity.IsAllDataRequested = false;
return;
}
}
catch (Exception ex)
{
AspNetCoreInstrumentationEventSource.Log.RequestFilterException(ex);
activity.IsAllDataRequested = false;
return;
}

ActivityInstrumentationHelper.SetActivitySourceProperty(activity, ActivitySource);
ActivityInstrumentationHelper.SetKindProperty(activity, ActivityKind.Server);

var path = (request.PathBase.HasValue || request.Path.HasValue) ? (request.PathBase + request.Path).ToString() : "/";
activity.DisplayName = path;

Expand Down
212 changes: 138 additions & 74 deletions test/OpenTelemetry.Instrumentation.AspNetCore.Tests/BasicTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@
using Microsoft.AspNetCore.TestHost;
using Microsoft.Extensions.DependencyInjection;
using Moq;
using Newtonsoft.Json;
using OpenTelemetry.Context.Propagation;
using OpenTelemetry.Instrumentation.AspNetCore.Implementation;
using OpenTelemetry.Tests;
Expand Down Expand Up @@ -97,6 +98,8 @@ void ConfigureTestServices(IServiceCollection services)

var status = activity.GetStatus();
Assert.Equal(status, Status.Unset);

ValidateAspNetCoreActivity(activity, "/api/values");
}

[Theory]
Expand Down Expand Up @@ -190,95 +193,101 @@ public async Task SuccessfulTemplateControllerCallUsesParentContext()
// is always ignored and new one is created by the Instrumentation
Assert.Equal("ActivityCreatedByHttpInListener", activity.OperationName);
#endif
Assert.Equal(ActivityKind.Server, activity.Kind);
Assert.Equal("api/Values/{id}", activity.DisplayName);
Assert.Equal("/api/values/2", activity.GetTagValue(SpanAttributeConstants.HttpPathKey) as string);

Assert.Equal(expectedTraceId, activity.Context.TraceId);
Assert.Equal(expectedSpanId, activity.ParentSpanId);

ValidateAspNetCoreActivity(activity, "/api/values/2");
}

[Fact]
public async Task CustomPropagator()
{
var activityProcessor = new Mock<BaseProcessor<Activity>>();

var expectedTraceId = ActivityTraceId.CreateRandom();
var expectedSpanId = ActivitySpanId.CreateRandom();

var propagator = new Mock<TextMapPropagator>();
propagator.Setup(m => m.Extract(It.IsAny<PropagationContext>(), It.IsAny<HttpRequest>(), It.IsAny<Func<HttpRequest, string, IEnumerable<string>>>())).Returns(
new PropagationContext(
new ActivityContext(
expectedTraceId,
expectedSpanId,
ActivityTraceFlags.Recorded),
default));

// Arrange
using (var testFactory = this.factory
.WithWebHostBuilder(builder =>
builder.ConfigureTestServices(services =>
{
Sdk.SetDefaultTextMapPropagator(propagator.Object);
this.openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.AddAspNetCoreInstrumentation()
.AddProcessor(activityProcessor.Object)
.Build();
})))
try
{
using var client = testFactory.CreateClient();
var response = await client.GetAsync("/api/values/2");
response.EnsureSuccessStatusCode(); // Status Code 200-299
var activityProcessor = new Mock<BaseProcessor<Activity>>();

var expectedTraceId = ActivityTraceId.CreateRandom();
var expectedSpanId = ActivitySpanId.CreateRandom();

var propagator = new Mock<TextMapPropagator>();
propagator.Setup(m => m.Extract(It.IsAny<PropagationContext>(), It.IsAny<HttpRequest>(), It.IsAny<Func<HttpRequest, string, IEnumerable<string>>>())).Returns(
new PropagationContext(
new ActivityContext(
expectedTraceId,
expectedSpanId,
ActivityTraceFlags.Recorded),
default));

// Arrange
using (var testFactory = this.factory
.WithWebHostBuilder(builder =>
builder.ConfigureTestServices(services =>
{
Sdk.SetDefaultTextMapPropagator(propagator.Object);
this.openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.AddAspNetCoreInstrumentation()
.AddProcessor(activityProcessor.Object)
.Build();
})))
{
using var client = testFactory.CreateClient();
var response = await client.GetAsync("/api/values/2");
response.EnsureSuccessStatusCode(); // Status Code 200-299

WaitForProcessorInvocations(activityProcessor, 4);
}
WaitForProcessorInvocations(activityProcessor, 4);
}

// List of invocations on the processor
// 1. SetParentProvider for TracerProviderSdk
// 2. OnStart for the activity created by AspNetCore with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn
// 3. OnStart for the sibling activity created by the instrumentation library with the OperationName: ActivityCreatedByHttpInListener
// 4. OnEnd for the sibling activity created by the instrumentation library with the OperationName: ActivityCreatedByHttpInListener
Assert.Equal(4, activityProcessor.Invocations.Count);
// List of invocations on the processor
// 1. SetParentProvider for TracerProviderSdk
// 2. OnStart for the activity created by AspNetCore with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn
// 3. OnStart for the sibling activity created by the instrumentation library with the OperationName: ActivityCreatedByHttpInListener
// 4. OnEnd for the sibling activity created by the instrumentation library with the OperationName: ActivityCreatedByHttpInListener
Assert.Equal(4, activityProcessor.Invocations.Count);

var startedActivities = activityProcessor.Invocations.Where(invo => invo.Method.Name == "OnStart");
var stoppedActivities = activityProcessor.Invocations.Where(invo => invo.Method.Name == "OnEnd");
Assert.Equal(2, startedActivities.Count());
Assert.Single(stoppedActivities);
var startedActivities = activityProcessor.Invocations.Where(invo => invo.Method.Name == "OnStart");
var stoppedActivities = activityProcessor.Invocations.Where(invo => invo.Method.Name == "OnEnd");
Assert.Equal(2, startedActivities.Count());
Assert.Single(stoppedActivities);

// The activity created by the framework and the sibling activity are both sent to Processor.OnStart
Assert.Contains(startedActivities, item =>
{
var startedActivity = item.Arguments[0] as Activity;
return startedActivity.OperationName == HttpInListener.ActivityOperationName;
});
// The activity created by the framework and the sibling activity are both sent to Processor.OnStart
Assert.Contains(startedActivities, item =>
{
var startedActivity = item.Arguments[0] as Activity;
return startedActivity.OperationName == HttpInListener.ActivityOperationName;
});

Assert.Contains(startedActivities, item =>
{
var startedActivity = item.Arguments[0] as Activity;
return startedActivity.OperationName == HttpInListener.ActivityNameByHttpInListener;
});
Assert.Contains(startedActivities, item =>
{
var startedActivity = item.Arguments[0] as Activity;
return startedActivity.OperationName == HttpInListener.ActivityNameByHttpInListener;
});

// Only the sibling activity is sent to Processor.OnEnd
Assert.Contains(stoppedActivities, item =>
{
var stoppedActivity = item.Arguments[0] as Activity;
return stoppedActivity.OperationName == HttpInListener.ActivityNameByHttpInListener;
});
// Only the sibling activity is sent to Processor.OnEnd
Assert.Contains(stoppedActivities, item =>
{
var stoppedActivity = item.Arguments[0] as Activity;
return stoppedActivity.OperationName == HttpInListener.ActivityNameByHttpInListener;
});

var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;
Assert.Equal(ActivityKind.Server, activity.Kind);
Assert.True(activity.Duration != TimeSpan.Zero);
Assert.Equal("api/Values/{id}", activity.DisplayName);
Assert.Equal("/api/values/2", activity.GetTagValue(SpanAttributeConstants.HttpPathKey) as string);
var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;
Assert.True(activity.Duration != TimeSpan.Zero);
Assert.Equal("api/Values/{id}", activity.DisplayName);

Assert.Equal(expectedTraceId, activity.Context.TraceId);
Assert.Equal(expectedSpanId, activity.ParentSpanId);
Sdk.SetDefaultTextMapPropagator(new CompositeTextMapPropagator(new TextMapPropagator[]
Assert.Equal(expectedTraceId, activity.Context.TraceId);
Assert.Equal(expectedSpanId, activity.ParentSpanId);

ValidateAspNetCoreActivity(activity, "/api/values/2");
}
finally
{
new TraceContextPropagator(),
new BaggagePropagator(),
}));
Sdk.SetDefaultTextMapPropagator(new CompositeTextMapPropagator(new TextMapPropagator[]
{
new TraceContextPropagator(),
new BaggagePropagator(),
}));
}
}

[Fact]
Expand Down Expand Up @@ -322,8 +331,7 @@ void ConfigureTestServices(IServiceCollection services)
Assert.Single(activityProcessor.Invocations, invo => invo.Method.Name == "OnEnd");
var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;

Assert.Equal(ActivityKind.Server, activity.Kind);
Assert.Equal("/api/values", activity.GetTagValue(SpanAttributeConstants.HttpPathKey) as string);
ValidateAspNetCoreActivity(activity, "/api/values");
}

[Fact]
Expand Down Expand Up @@ -383,8 +391,62 @@ void ConfigureTestServices(IServiceCollection services)
Assert.Single(activityProcessor.Invocations, invo => invo.Method.Name == "OnEnd");
var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;

Assert.Equal(ActivityKind.Server, activity.Kind);
Assert.Equal("/api/values", activity.GetTagValue(SpanAttributeConstants.HttpPathKey) as string);
ValidateAspNetCoreActivity(activity, "/api/values");
}

[Fact]
public async Task PropagateContextIrrespectiveOfSamplingDecision()
{
var activityProcessor = new Mock<BaseProcessor<Activity>>();

var expectedTraceId = ActivityTraceId.CreateRandom();
var expectedParentSpanId = ActivitySpanId.CreateRandom();

// Arrange
using (var testFactory = this.factory
.WithWebHostBuilder(builder =>
builder.ConfigureTestServices(services =>
{
this.openTelemetrySdk = Sdk.CreateTracerProviderBuilder()
.SetSampler(new AlwaysOffSampler())
.AddAspNetCoreInstrumentation()
.AddProcessor(activityProcessor.Object)
.Build();
})))
{
using var client = testFactory.CreateClient();

// Test TraceContext Propagation
var expectedTraceState = "rojo=1,congo=2";
var request = new HttpRequestMessage(HttpMethod.Get, "/api/GetChildActivityTraceContext");
request.Headers.Add("traceparent", $"00-{expectedTraceId}-{expectedParentSpanId}-01");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

portions of this test would pass by default, as asp.net creates activity from traceparent always, irrespective of sampling in Otel.
To ensure thorough test, use a custom propagator (with some header like Foo), and validate the scenarios. Also add cases where sending traceparent with "00" and "01" as sampling flags

request.Headers.Add("tracestate", expectedTraceState);

var response = await client.SendAsync(request);
var childActivityTraceContext = JsonConvert.DeserializeObject<Dictionary<string, string>>(response.Content.ReadAsStringAsync().Result);

response.EnsureSuccessStatusCode();

Assert.Equal(expectedTraceId.ToString(), childActivityTraceContext["TraceId"]);
Assert.Equal(expectedTraceState, childActivityTraceContext["TraceState"]);
Assert.NotEqual(expectedParentSpanId.ToString(), childActivityTraceContext["ParentSpanId"]); // there is a new activity created in instrumentation therefore the ParentSpanId is different that what is provided in the headers

// Test Baggage Context Propagation
request = new HttpRequestMessage(HttpMethod.Get, "/api/GetChildActivityBaggageContext");
request.Headers.Add("Baggage", "key1=value1,key2=value2");
response = await client.SendAsync(request);
var childActivityBaggageContext = JsonConvert.DeserializeObject<IReadOnlyDictionary<string, string>>(response.Content.ReadAsStringAsync().Result);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

you can avoid the additional json parsing, by making the test app return 2 strings contaning traceparent and tracestate (activity.Id, activity.TraceState) respectively.


response.EnsureSuccessStatusCode();

Assert.Single(childActivityBaggageContext, item => item.Key == "key1" && item.Value == "value1");
Assert.Single(childActivityBaggageContext, item => item.Key == "key2" && item.Value == "value2");

WaitForProcessorInvocations(activityProcessor, 1);
}

// Processor.OnStart and Processor.OnEnd are not called as activity.IsAllDataRequested is set to false
Assert.Equal(1, activityProcessor.Invocations.Count); // Only Processor.SetParentProvider is called
}

public void Dispose()
Expand All @@ -409,6 +471,8 @@ private static void WaitForProcessorInvocations(Mock<BaseProcessor<Activity>> ac
private static void ValidateAspNetCoreActivity(Activity activityToValidate, string expectedHttpPath)
{
Assert.Equal(ActivityKind.Server, activityToValidate.Kind);
Assert.Equal(HttpInListener.ActivitySourceName, activityToValidate.Source.Name);
Assert.Equal(HttpInListener.Version.ToString(), activityToValidate.Source.Version);
Assert.Equal(expectedHttpPath, activityToValidate.GetTagValue(SpanAttributeConstants.HttpPathKey) as string);
}

Expand Down
1 change: 1 addition & 0 deletions ...ry.Instrumentation.AspNetCore.Tests/OpenTelemetry.Instrumentation.AspNetCore.Tests.csproj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
<ItemGroup>
<PackageReference Include="Microsoft.NET.Test.Sdk" Version="$(MicrosoftNETTestSdkPkgVer)" />
<PackageReference Include="Moq" Version="$(MoqPkgVer)" />
<PackageReference Include="Newtonsoft.Json" Version="12.0.3" />
<PackageReference Include="xunit" Version="$(XUnitPkgVer)" />
<PackageReference Include="xunit.runner.visualstudio" Version="$(XUnitRunnerVisualStudioPkgVer)">
<PrivateAssets>all</PrivateAssets>
Expand Down
Loading