Skip to content

Commit

Permalink
Fix StartOperation(Activity) for legacy ids (#1213)
Browse files Browse the repository at this point in the history
* Fix StartOperation(Activity) for legacy ids

* changelog

* lang version 7.3

* fxcop!

* fix lang version: linux doesn't like 7.3
  • Loading branch information
Liudmila Molkova authored Sep 19, 2019
1 parent 78dc7e3 commit 0c87e3a
Show file tree
Hide file tree
Showing 4 changed files with 195 additions and 16 deletions.
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;
}
}
}

0 comments on commit 0c87e3a

Please sign in to comment.