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

Fix StartOperation(Activity) for legacy ids #1213

Merged
merged 5 commits into from
Sep 19, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,9 @@

This changelog will be used to generate documentation on [release notes page](http://azure.microsoft.com/documentation/articles/app-insights-release-notes-dotnet/).

## Version 2.11.0
- [Fix: StartOperation(Activity) does not check for Ids compatibility](https://github.com/microsoft/ApplicationInsights-dotnet/pull/1213)

## Version 2.11.0-beta2
- [Fix: Emit warning if user sets both Sampling IncludedTypes and ExcludedTypes. Excluded will take precedence.](https://github.com/microsoft/ApplicationInsights-dotnet/issues/1166)
- [Minor perf improvement by reading Actity.Tag only if required.](https://github.com/microsoft/ApplicationInsights-dotnet/pull/1170)
Expand Down
4 changes: 4 additions & 0 deletions Common.props
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,10 @@
<ChecksumAlgorithm>SHA256</ChecksumAlgorithm>
</PropertyGroup>

<PropertyGroup>
<LangVersion>7.1</LangVersion>
</PropertyGroup>

<PropertyGroup Condition="'$(Configuration)' == 'Debug'">
<DebugSymbols>true</DebugSymbols>
<DebugType>full</DebugType>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ public void TestCleanup()
[TestMethod]
public void BasicStartOperationWithActivity()
{
var activity = new Activity("name").SetParentId("parentId").AddBaggage("b1", "v1").AddTag("t1", "v1");
var activity = new Activity("name").AddBaggage("b1", "v1").AddTag("t1", "v1");

RequestTelemetry telemetry;
using (var operation = this.telemetryClient.StartOperation<RequestTelemetry>(activity))
Expand All @@ -64,6 +64,87 @@ public void BasicStartOperationWithActivity()
Assert.AreEqual(telemetry, this.sendItems.Single());
}

[TestMethod]
public void StartOperationWithActivity_LegacyId1()
{
var activity = new Activity("name")
.SetParentId("parentId")
.AddBaggage("b1", "v1")
.AddTag("t1", "v1");

activity.ActivityTraceFlags = ActivityTraceFlags.Recorded;
activity.TraceStateString = "state=some";

RequestTelemetry telemetry;
using (var operation = this.telemetryClient.StartOperation<RequestTelemetry>(activity))
{
telemetry = operation.Telemetry;
Assert.AreEqual(activity, Activity.Current);
Assert.IsNotNull(activity.Id);
}

this.ValidateTelemetry(telemetry, activity, true, "parentId");
Assert.IsTrue(telemetry.Properties.TryGetValue("ai_legacyRootId", out var legacyRoot));
Assert.AreEqual("parentId", legacyRoot);

Assert.AreEqual(telemetry, this.sendItems.Single());
}

[TestMethod]
public void StartOperationWithActivity_LegacyId2()
{
var activity = new Activity("name")
.SetParentId("|parentId.123.")
.AddBaggage("b1", "v1")
.AddTag("t1", "v1");

activity.ActivityTraceFlags = ActivityTraceFlags.Recorded;
activity.TraceStateString = "state=some";

RequestTelemetry telemetry;
using (var operation = this.telemetryClient.StartOperation<RequestTelemetry>(activity))
{
telemetry = operation.Telemetry;
Assert.AreEqual(activity, Activity.Current);
Assert.IsNotNull(activity.Id);
}

this.ValidateTelemetry(telemetry, activity, true, "|parentId.123.");

Assert.IsTrue(telemetry.Properties.TryGetValue("ai_legacyRootId", out var legacyRoot));
Assert.AreEqual("parentId", legacyRoot);
Assert.AreEqual(telemetry, this.sendItems.Single());
}

[TestMethod]
public void StartOperationWithActivity_LegacyIdCompatible()
{
var activity = new Activity("name")
.SetParentId("|00112233445566778899aabbccddeeff.123.")
.AddBaggage("b1", "v1")
.AddTag("t1", "v1");

activity.ActivityTraceFlags = ActivityTraceFlags.Recorded;
activity.TraceStateString = "state=some";

RequestTelemetry telemetry;
Activity newActivity = null;
using (var operation = this.telemetryClient.StartOperation<RequestTelemetry>(activity))
{
telemetry = operation.Telemetry;
newActivity = Activity.Current;
Assert.AreNotEqual(activity, newActivity);
Assert.IsNotNull(newActivity?.Id);
}

this.ValidateTelemetry(telemetry, newActivity, true, "|00112233445566778899aabbccddeeff.123.");
Assert.AreEqual("00112233445566778899aabbccddeeff", telemetry.Context.Operation.Id);

Assert.IsFalse(telemetry.Properties.ContainsKey("ai_legacyRootId"));

Assert.AreEqual(telemetry, this.sendItems.Single());
}

[TestMethod]
public void BasicStartOperationWithActivityInScopeOfUnrelatedActivity()
{
Expand All @@ -80,7 +161,7 @@ public void BasicStartOperationWithActivityInScopeOfUnrelatedActivity()
Assert.IsNotNull(activity.Id);
}

this.ValidateTelemetry(telemetry, activity);
this.ValidateTelemetry(telemetry, activity, true, "parentId");

Assert.AreEqual(telemetry, this.sendItems.Single());
Assert.AreEqual(outerActivity, Activity.Current);
Expand All @@ -99,7 +180,11 @@ public void BasicStartOperationWithStartedActivityInScopeOfUnrelatedActivity()

// this is not right to give started Activity to StartOperation, but nothing terrible should happen
// except it won't be possible to restore original context after StartOperation completes
var activity = new Activity("name").SetParentId("parentId").AddBaggage("b1", "v1").AddTag("t1", "v1").Start();
var activity = new Activity("name")
.SetParentId(ActivityTraceId.CreateRandom(), ActivitySpanId.CreateRandom())
.AddBaggage("b1", "v1")
.AddTag("t1", "v1")
.Start();

RequestTelemetry telemetry;
using (var operation = this.telemetryClient.StartOperation<RequestTelemetry>(activity))
Expand All @@ -119,7 +204,6 @@ public void BasicStartOperationWithStartedActivityInScopeOfUnrelatedActivity()
Assert.IsNotNull(request);
Assert.AreEqual(activity.TraceId.ToHexString(), request.Context.Operation.Id);
Assert.AreEqual($"|{activity.TraceId.ToHexString()}.{activity.SpanId.ToHexString()}.", request.Id);
Assert.AreEqual("parentId", request.Context.Operation.ParentId);
}

/// <summary>
Expand All @@ -128,7 +212,7 @@ public void BasicStartOperationWithStartedActivityInScopeOfUnrelatedActivity()
[TestMethod]
public void InvalidStartOperationWithStartedActivity()
{
var activity = new Activity("name").SetParentId("parentId").AddBaggage("b1", "v1").AddTag("t1", "v1").Start();
var activity = new Activity("name").AddBaggage("b1", "v1").AddTag("t1", "v1").Start();

DependencyTelemetry telemetry;
using (var operation = this.telemetryClient.StartOperation<DependencyTelemetry>(activity))
Expand All @@ -150,12 +234,12 @@ public void StartOperationSynchronousInScopeOfOtherUnrelatedActivity()
// nested operation processing.
// E.g. Background Activity is tracking high-level operation "get 5 messages from the queue and process them all"
// In this case, each message processing has it's own correlation scope, passed in the message (i.e. Parent Activity is external)
// The requirement is that backgorund Activity must survive each message processing.
// The requirement is that background Activity must survive each message processing.

var backgroundActivity = new Activity("background").Start();

//since ParentId is set on the activity, it won't be child of the parentActivity
var activity = new Activity("name").SetParentId("parentId");
var activity = new Activity("name").SetParentId(ActivityTraceId.CreateRandom(), ActivitySpanId.CreateRandom());

// in order to keep parentActivity, StartOperation and StopOperation(or dispose)
// must be called
Expand Down Expand Up @@ -184,7 +268,7 @@ public async Task StartOperationAsyncInScopeOfOtherUnrelatedActivity()
var activity = new Activity("name").SetParentId("parentId");
RequestTelemetry telemetry = await ProcessWithStartOperationAsync<RequestTelemetry>(activity, null);

this.ValidateTelemetry(telemetry, activity);
this.ValidateTelemetry(telemetry, activity, true, "parentId");
Assert.AreEqual(telemetry, this.sendItems.Single());

// after processing is done and chile activity is finished,
Expand Down Expand Up @@ -332,20 +416,34 @@ private async Task ProcessAsync(Activity activity, Activity parentActivity)
return telemetry;
}

private void ValidateTelemetry<T>(T telemetry, Activity activity, bool isW3C = true) where T : OperationTelemetry
private void ValidateTelemetry<T>(T telemetry, Activity activity, bool isW3C = true, string legacyParentId = null) where T : OperationTelemetry
{
Assert.AreEqual(activity.OperationName, telemetry.Name);
Assert.AreEqual(
isW3C
? W3CUtilities.FormatTelemetryId(activity.TraceId.ToHexString(), activity.SpanId.ToHexString())
: activity.Id, telemetry.Id);

if (isW3C)
{
Assert.AreEqual(W3CUtilities.FormatTelemetryId(activity.TraceId.ToHexString(), activity.SpanId.ToHexString()), telemetry.Id);
if (activity.ParentSpanId != default && activity.ParentSpanId.ToHexString() != "0000000000000000")
{
Assert.AreEqual(
W3CUtilities.FormatTelemetryId(activity.TraceId.ToHexString(),
activity.ParentSpanId.ToHexString()), telemetry.Context.Operation.ParentId);
}
else
{
Assert.AreEqual(legacyParentId, telemetry.Context.Operation.ParentId);
}

Assert.AreEqual(activity.TraceId.ToHexString(), telemetry.Context.Operation.Id);
}
else
{
Assert.AreEqual(activity.Id, telemetry.Id);
Assert.AreEqual(activity.ParentId, telemetry.Context.Operation.ParentId);
Assert.AreEqual(activity.RootId, telemetry.Context.Operation.Id);
}

Assert.AreEqual(activity.ParentId, telemetry.Context.Operation.ParentId);
Assert.AreEqual(activity.RootId, telemetry.Context.Operation.Id);

foreach (var baggage in activity.Baggage)
{
Expand All @@ -358,6 +456,18 @@ private void ValidateTelemetry<T>(T telemetry, Activity activity, bool isW3C = t
Assert.IsTrue(telemetry.Properties.ContainsKey(tag.Key));
Assert.AreEqual(tag.Value, telemetry.Properties[tag.Key]);
}

if (activity.TraceStateString != null)
{
Assert.IsTrue(telemetry.Properties.TryGetValue("tracestate", out var tracestate));
Assert.AreEqual(activity.TraceStateString, tracestate);
}
else
{
Assert.IsFalse(telemetry.Properties.ContainsKey("tracestate"));
}

Assert.AreEqual(activity.Recorded ? SamplingDecision.SampledIn : SamplingDecision.None, (telemetry as ISupportAdvancedSampling).ProactiveSamplingDecision);
}
}
}
66 changes: 64 additions & 2 deletions src/Microsoft.ApplicationInsights/TelemetryClientExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -305,9 +305,43 @@ public static void StopOperation<T>(this TelemetryClient telemetryClient, IOpera
originalActivity = Activity.Current;
}

string legacyRoot = null;
string legacyParent = null;
if (Activity.DefaultIdFormat == ActivityIdFormat.W3C)
{
// if parent is not W3C
if (activity.ParentId != null &&
!activity.ParentId.StartsWith("00-", StringComparison.Ordinal))
{
// save parent
legacyParent = activity.ParentId;

if (W3CUtilities.IsCompatibleW3CTraceId(activity.RootId))
{
// reuse root id when compatible with trace ID
activity = CopyFromCompatibleRoot(activity);
}
else
{
// or store legacy root in custom property
legacyRoot = activity.RootId;
}
}
}

activity.Start();
T operationTelemetry = ActivityToTelemetry<T>(activity);

if (legacyRoot != null)
{
operationTelemetry.Properties.Add(W3CConstants.LegacyRootIdProperty, legacyRoot);
}

if (legacyParent != null)
{
operationTelemetry.Context.Operation.ParentId = legacyParent;
}

// We initialize telemetry here AND in Track method because of RichPayloadEventSource.
// It sends Start and Stop events for OperationTelemetry. During Start event telemetry
// has to contain essential telemetry properties such as correlations ids and ikey.
Expand All @@ -332,15 +366,22 @@ public static void StopOperation<T>(this TelemetryClient telemetryClient, IOpera

OperationContext operationContext = telemetry.Context.Operation;
operationContext.Name = activity.GetOperationName();
operationContext.ParentId = activity.ParentId;

if (activity.IdFormat == ActivityIdFormat.W3C)
{
operationContext.Id = activity.TraceId.ToHexString();
operationContext.Id = activity.TraceId.ToHexString();
telemetry.Id = W3CUtilities.FormatTelemetryId(operationContext.Id, activity.SpanId.ToHexString());

if (string.IsNullOrEmpty(operationContext.ParentId) && activity.ParentSpanId != default)
{
operationContext.ParentId =
W3CUtilities.FormatTelemetryId(operationContext.Id, activity.ParentSpanId.ToHexString());
}
}
else
{
operationContext.Id = activity.RootId;
operationContext.ParentId = activity.ParentId;
telemetry.Id = activity.Id;
}

Expand All @@ -362,5 +403,26 @@ public static void StopOperation<T>(this TelemetryClient telemetryClient, IOpera

return telemetry;
}

private static Activity CopyFromCompatibleRoot(Activity from)
{
var copy = new Activity(from.OperationName);
copy.SetParentId(ActivityTraceId.CreateFromString(from.RootId.AsSpan()),
default(ActivitySpanId), from.ActivityTraceFlags);

foreach (var tag in from.Tags)
{
copy.AddTag(tag.Key, tag.Value);
}

foreach (var baggage in from.Baggage)
{
copy.AddBaggage(baggage.Key, baggage.Value);
}

copy.TraceStateString = from.TraceStateString;

return copy;
}
}
}