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.

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

Update HttpInListener to add gRPC tags - By creating a new activity with the OperationName used by the framework #1879

Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
27 commits
Select commit Hold shift + click to select a range
db21758
Update HttpInListener to add gRPC tags
utpilla Mar 8, 2021
6a679cf
Update ASP.NET Core instrumnetation to use the OperationName used by …
utpilla Mar 8, 2021
84e61b1
Merge remote-tracking branch 'origin/main' into utpilla/Fix-gRPC-Inst…
utpilla Mar 8, 2021
2b0271f
Address PR comments
utpilla Mar 8, 2021
de2d299
Merged with origin/main
utpilla Mar 9, 2021
8f026fc
Correct merge with origin/main
utpilla Mar 10, 2021
bcc6ea8
Merge remote-tracking branch 'fork/utpilla/Fix-gRPC-Instrumentation-F…
utpilla Mar 10, 2021
8b32725
Fix merge error
utpilla Mar 10, 2021
aef69cd
Merge remote-tracking branch 'origin/main' into utpilla/Fix-gRPC-Inst…
utpilla Mar 10, 2021
b5765c4
Merge branch 'main' into utpilla/Fix-gRPC-Instrumentation-For-Sibling…
utpilla Mar 18, 2021
aabfc8d
Resolve merge conflict
utpilla Mar 19, 2021
a53199f
Merge remote-tracking branch 'fork/utpilla/Fix-gRPC-Instrumentation-F…
utpilla Mar 19, 2021
91e52c6
Fix formatting
utpilla Mar 19, 2021
642842e
Merge branch 'main' into utpilla/Fix-gRPC-Instrumentation-For-Sibling…
utpilla Apr 12, 2021
a1b58d1
Merge with origin/main
utpilla Apr 26, 2021
214c4f9
Merge branch 'utpilla/Fix-gRPC-Instrumentation-For-Sibling-Activity-U…
utpilla Apr 26, 2021
b872349
Use tag instead of custom property in the HttpListener; Added CheckFi…
utpilla Apr 27, 2021
6e5da33
Set tag value as True instead of boolean true
utpilla Apr 27, 2021
3a068ea
Use bool.TrueString instead of True
utpilla Apr 27, 2021
a03f7d1
Merge branch 'main' into utpilla/Fix-gRPC-Instrumentation-For-Sibling…
cijothomas May 3, 2021
963f930
Merge remote-tracking branch 'origin/main' into utpilla/Fix-gRPC-Inst…
utpilla May 3, 2021
12222e4
Address PR comments
utpilla May 3, 2021
39f60a4
Trigger CI Run
utpilla May 3, 2021
44383ad
Merge remote-tracking branch 'origin/main' into utpilla/Fix-gRPC-Inst…
utpilla May 3, 2021
33fd687
Merge branch 'main' into utpilla/Fix-gRPC-Instrumentation-For-Sibling…
cijothomas May 3, 2021
6405fbd
Update CHANGELOG.md
utpilla May 3, 2021
58a062d
Merge branch 'utpilla/Fix-gRPC-Instrumentation-For-Sibling-Activity-U…
utpilla May 3, 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
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,6 @@ namespace OpenTelemetry.Instrumentation.AspNetCore.Implementation
internal class HttpInListener : ListenerHandler
{
internal const string ActivityOperationName = "Microsoft.AspNetCore.Hosting.HttpRequestIn";
internal const string ActivityNameByHttpInListener = "ActivityCreatedByHttpInListener";
internal static readonly AssemblyName AssemblyName = typeof(HttpInListener).Assembly.GetName();
internal static readonly string ActivitySourceName = AssemblyName.Name;
internal static readonly Version Version = AssemblyName.Version;
Expand Down Expand Up @@ -92,13 +91,15 @@ public override void OnStartActivity(Activity activity, object payload)
// Create a new activity with its parent set from the extracted context.
// This makes the new activity as a "sibling" of the activity created by
// Asp.Net Core.
Activity newOne = new Activity(ActivityNameByHttpInListener);
Activity newOne = new Activity(ActivityOperationName);
newOne.SetParentId(ctx.ActivityContext.TraceId, ctx.ActivityContext.SpanId, ctx.ActivityContext.TraceFlags);
newOne.TraceStateString = ctx.ActivityContext.TraceState;

// Starting the new activity make it the Activity.Current one.
newOne.Start();

newOne.SetCustomProperty("IsCreatedByInstrumentation", true);
Copy link
Member

Choose a reason for hiding this comment

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

It is super expensive to do this if we're the first caller to add a custom property. We used to add resource as one, and did a bunch of work to avoid that allocation. Can we add as a TagObject instead and then remove after we check it? Adding tag is also not ideal because you have to loop over tags to find one, but if we add immediately after creation, it will be first!

Copy link
Contributor Author

Choose a reason for hiding this comment

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

This is not a common scenario. If we use a tag to keep track of this, we will have to remove this tag before activity.Stop so that this tag does not get exported. This would mean that we will have to look through the TagObjects for this tag for all scenarios. The most commonly occurring scenario would be where there is no new activity created and this tag does not get added. We will have to iterate through all the TagObjects to confirm that no new activity was created which might be a little more expensive than looking up a custom property.

I feel the customProperty approach is good to unblock and fix this issue. We need to run benchmark tests for customProperties vs TagObjects approach to find the most performant one. I have created an issue #1887 to track this

Copy link
Member

Choose a reason for hiding this comment

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

If the user is using some form of propagation other than W3C will it fire 100% of the time? Rare I think would be like it only happens for connection failures.

Some other (maybe crazy) ideas I came up with trying to think outside the box:

  • The AspNetCore created Activity never has a parent? What if we set a parent on the one we create and use that as the signal?

  • AspNetCore created Activity doesn't have an ActivitySource set? What if we set one to use as the signal? It is a private set so we would need a bit of magic for that.

Copy link
Member

@alanwest alanwest Apr 16, 2021

Choose a reason for hiding this comment

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

If the user is using some form of propagation other than W3C will it fire 100% of the time?

Yes, this is true. Also, B3 is pretty common case, so yea if there are perf concerns here then it makes sense to me to consider this.

The AspNetCore created Activity never has a parent?

I do not think this is always true. AspNetCore created activity will have a parent if the calling service included W3C context headers in the request. Though not sure how common it would be to have both W3C and B3 headers.

AspNetCore created Activity doesn't have an ActivitySource set? What if we set one to use as the signal? It is a private set so we would need a bit of magic for that.

This seems like a legit solution. AspNetCore may eventually get instrumented with ActivitySource, but then I guess this instrumentation would not be invoked, so we're probably good.


// Set IsAllDataRequested to false for the activity created by the framework to only export the sibling activity and not the framework activity
activity.IsAllDataRequested = false;
activity = newOne;
Expand Down Expand Up @@ -194,7 +195,7 @@ public override void OnStopActivity(Activity activity, object payload)
}
}

if (activity.OperationName.Equals(ActivityNameByHttpInListener, StringComparison.Ordinal))
if (activity.GetCustomProperty("IsCreatedByInstrumentation") is bool isCreatedByInstrumentation && isCreatedByInstrumentation)
{
// If instrumentation started a new Activity, it must
// be stopped here.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -44,8 +44,7 @@ public static TracerProviderBuilder AddAspNetCoreInstrumentation(
configureAspNetCoreInstrumentationOptions?.Invoke(aspnetCoreOptions);
builder.AddInstrumentation(() => new AspNetCoreInstrumentation(aspnetCoreOptions));
builder.AddSource(HttpInListener.ActivitySourceName);
builder.AddLegacyActivity(HttpInListener.ActivityOperationName); // for the activities created by AspNetCore
builder.AddLegacyActivity(HttpInListener.ActivityNameByHttpInListener); // for the sibling activities created by the instrumentation library
builder.AddLegacyActivity(HttpInListener.ActivityOperationName); // for the activities created by AspNetCore framework and instrumentation

return builder;
}
Expand Down
24 changes: 12 additions & 12 deletions test/OpenTelemetry.Instrumentation.AspNetCore.Tests/BasicTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -174,10 +174,10 @@ public async Task SuccessfulTemplateControllerCallUsesParentContext()
// List of invocations
// 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
// 3. OnStart for the sibling activity created by the instrumentation library with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn and the customProperty IsCreatedByInstrumentation set to true
// 4. OnEnd for the sibling activity created by the instrumentation library with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn and the customProperty IsCreatedByInstrumentation set to true

// we should only call Processor.OnEnd once for the sibling activity with the OperationName ActivityCreatedByHttpInListener
// we should only call Processor.OnEnd once for the sibling activity
Assert.Single(activityProcessor.Invocations, invo => invo.Method.Name == "OnEnd");
var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;

Expand All @@ -188,7 +188,7 @@ public async Task SuccessfulTemplateControllerCallUsesParentContext()
#else
// ASP.NET Core before 3.x is not W3C aware and hence Activity created by it
// is always ignored and new one is created by the Instrumentation
Assert.Equal("ActivityCreatedByHttpInListener", activity.OperationName);
Assert.True(activity.GetCustomProperty("IsCreatedByInstrumentation") is bool isCreatedByInstrumentation && isCreatedByInstrumentation);
#endif
Assert.Equal(ActivityKind.Server, activity.Kind);
Assert.Equal("api/Values/{id}", activity.DisplayName);
Expand Down Expand Up @@ -237,8 +237,8 @@ public async Task CustomPropagator()
// 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
// 3. OnStart for the sibling activity created by the instrumentation library with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn and the customProperty IsCreatedByInstrumentation set to true
// 4. OnEnd for the sibling activity created by the instrumentation library with the OperationName: Microsoft.AspNetCore.Hosting.HttpRequestIn and the customProperty IsCreatedByInstrumentation set to true
Assert.Equal(4, activityProcessor.Invocations.Count);

var startedActivities = activityProcessor.Invocations.Where(invo => invo.Method.Name == "OnStart");
Expand All @@ -247,23 +247,23 @@ public async Task CustomPropagator()
Assert.Single(stoppedActivities);

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

Assert.Contains(startedActivities, item =>
Assert.Single(startedActivities, item =>
{
var startedActivity = item.Arguments[0] as Activity;
return startedActivity.OperationName == HttpInListener.ActivityNameByHttpInListener;
return startedActivity.GetCustomProperty("IsCreatedByInstrumentation") is bool isCreatedByInstrumentation && isCreatedByInstrumentation;
});

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

var activity = activityProcessor.Invocations.FirstOrDefault(invo => invo.Method.Name == "OnEnd").Arguments[0] as Activity;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,12 +20,15 @@
using System.Net;
using System.Threading;
using Greet;
using Grpc.Core;
using Grpc.Net.Client;
using Moq;
using OpenTelemetry.Context.Propagation;
using OpenTelemetry.Instrumentation.Grpc.Tests.Services;
using OpenTelemetry.Instrumentation.GrpcNetClient;
using OpenTelemetry.Trace;
using Xunit;
using Status = OpenTelemetry.Trace.Status;

namespace OpenTelemetry.Instrumentation.Grpc.Tests
{
Expand Down Expand Up @@ -108,6 +111,86 @@ public void GrpcAspNetCoreInstrumentationAddsCorrectAttributes(bool? enableGrpcA
Assert.StartsWith("grpc-dotnet", activity.GetTagValue(SemanticConventions.AttributeHttpUserAgent) as string);
}

[Theory]
[InlineData(null)]
[InlineData(true)]
[InlineData(false)]
public void GrpcAspNetCoreInstrumentationAddsCorrectAttributesWhenItCreatesNewActivity(bool? enableGrpcAspNetCoreSupport)
{
// B3Propagator along with the headers passed to the client.SayHello ensure that the instrumentation creates a sibling activity
Sdk.SetDefaultTextMapPropagator(new B3Propagator());
var processor = new Mock<BaseProcessor<Activity>>();
var tracerProviderBuilder = Sdk.CreateTracerProviderBuilder();

if (enableGrpcAspNetCoreSupport.HasValue)
{
tracerProviderBuilder.AddAspNetCoreInstrumentation(options =>
{
options.EnableGrpcAspNetCoreSupport = enableGrpcAspNetCoreSupport.Value;
});
}
else
{
tracerProviderBuilder.AddAspNetCoreInstrumentation();
}

using var tracerProvider = tracerProviderBuilder
.AddProcessor(processor.Object)
.Build();

var clientLoopbackAddresses = new[] { IPAddress.Loopback.ToString(), IPAddress.IPv6Loopback.ToString() };
var uri = new Uri($"http://localhost:{this.server.Port}");

using var channel = GrpcChannel.ForAddress(uri);
var client = new Greeter.GreeterClient(channel);
var headers = new Metadata();
headers.Add("traceparent", "00-120dc44db5b736468afb112197b0dbd3-5dfbdf27ec544544-01");
headers.Add("x-b3-traceid", "120dc44db5b736468afb112197b0dbd3");
headers.Add("x-b3-spanid", "b0966f651b9e0126");
headers.Add("x-b3-sampled", "1");
client.SayHello(new HelloRequest(), headers);

WaitForProcessorInvocations(processor, 4);

Assert.Equal(4, processor.Invocations.Count); // SetParentProvider, OnStart (framework activity), OnStart (instrumentation activity), OnStop (instrumentation activity)
var activity = GetActivityFromProcessorInvocation(processor, nameof(processor.Object.OnEnd), OperationNameHttpRequestIn);

Assert.Equal(ActivityKind.Server, activity.Kind);

if (!enableGrpcAspNetCoreSupport.HasValue || enableGrpcAspNetCoreSupport.Value)
{
Assert.Equal("grpc", activity.GetTagValue(SemanticConventions.AttributeRpcSystem));
Assert.Equal("greet.Greeter", activity.GetTagValue(SemanticConventions.AttributeRpcService));
Assert.Equal("SayHello", activity.GetTagValue(SemanticConventions.AttributeRpcMethod));
Assert.Contains(activity.GetTagValue(SemanticConventions.AttributeNetPeerIp), clientLoopbackAddresses);
Assert.NotEqual(0, activity.GetTagValue(SemanticConventions.AttributeNetPeerPort));
Assert.Null(activity.GetTagValue(GrpcTagHelper.GrpcMethodTagName));
Assert.Null(activity.GetTagValue(GrpcTagHelper.GrpcStatusCodeTagName));
Assert.Equal(0, activity.GetTagValue(SemanticConventions.AttributeRpcGrpcStatusCode));
}
else
{
Assert.NotNull(activity.GetTagValue(GrpcTagHelper.GrpcMethodTagName));
Assert.NotNull(activity.GetTagValue(GrpcTagHelper.GrpcStatusCodeTagName));
}

Assert.Equal(Status.Unset, activity.GetStatus());

// The following are http.* attributes that are also included on the span for the gRPC invocation.
Assert.Equal($"localhost:{this.server.Port}", activity.GetTagValue(SemanticConventions.AttributeHttpHost));
Assert.Equal("POST", activity.GetTagValue(SemanticConventions.AttributeHttpMethod));
Assert.Equal("/greet.Greeter/SayHello", activity.GetTagValue(SpanAttributeConstants.HttpPathKey));
Assert.Equal($"http://localhost:{this.server.Port}/greet.Greeter/SayHello", activity.GetTagValue(SemanticConventions.AttributeHttpUrl));
Assert.StartsWith("grpc-dotnet", activity.GetTagValue(SemanticConventions.AttributeHttpUserAgent) as string);

// Set the SDK to use the default propagator for other unit tests
Sdk.SetDefaultTextMapPropagator(new CompositeTextMapPropagator(new TextMapPropagator[]
utpilla marked this conversation as resolved.
Show resolved Hide resolved
{
new TraceContextPropagator(),
new BaggagePropagator(),
}));
}

public void Dispose()
{
this.server.Dispose();
Expand Down