Use W3C trace Id format for Activities that do not have parents

CHANGELOG.md

@@ -1,5 +1,8 @@
 # Changelog
 
+## Version 2.7.0-beta4
+- [When there is no parent operation, generate W3C compatible operation Id](https://github.com/Microsoft/ApplicationInsights-dotnet-server/pull/952)
+
 ## Version 2.7.0-beta3
 - [Fix: SerializationException resolving Activity in cross app-domain calls](https://github.com/Microsoft/ApplicationInsights-dotnet-server/issues/613)
 - [Fix: Race condition in generic diagnostic source listener](https://github.com/Microsoft/ApplicationInsights-dotnet-server/pull/948)

Src/Common/ActivityExtensions.cs

@@ -0,0 +1,31 @@
+namespace Microsoft.ApplicationInsights.Common
+{
+    using System.Diagnostics;
+
+    internal static class ActivityExtensions
+    {
+        public static Activity UpdateParent(this Activity original, string newParentId)
+        {
+            if (original == null || original.Parent != null)
+            {
+                return original;
+            }
+
+            var auxActivity = new Activity(original.OperationName)
+                .SetParentId(newParentId)
+                .SetStartTime(original.StartTimeUtc);
+
+            foreach (var baggageItem in original.Baggage)
+            {
+                auxActivity.AddBaggage(baggageItem.Key, baggageItem.Value);
+            }
+
+            foreach (var tag in original.Tags)
+            {
+                auxActivity.AddTag(tag.Key, tag.Value);
+            }
+
+            return auxActivity.Start();
+        }
+    }
+}

Src/Common/Common.projitems

@@ -9,6 +9,7 @@
     <Import_RootNamespace>Microsoft.ApplicationInsights.Common</Import_RootNamespace>
   </PropertyGroup>
   <ItemGroup>
+    <Compile Include="$(MSBuildThisFileDirectory)ActivityExtensions.cs" />
     <Compile Include="$(MSBuildThisFileDirectory)AppMapCorrelationEventSource.cs" />
     <Compile Include="$(MSBuildThisFileDirectory)ConditionalWeakTableExtensions.cs" />
     <Compile Include="$(MSBuildThisFileDirectory)ExceptionUtilities.cs" />

Src/Common/StringUtilities.cs

@@ -1,5 +1,6 @@
 namespace Microsoft.ApplicationInsights.Common
 {
+    using System;
     using System.Diagnostics;
     using System.Globalization;
 
@@ -8,6 +9,8 @@
     /// </summary>
     public static class StringUtilities
     {
+        private static readonly uint[] Lookup32 = CreateLookup32();
+
         /// <summary>
         /// Check a strings length and trim to a max length if needed.
         /// </summary>
@@ -24,5 +27,39 @@ public static string EnforceMaxLength(string input, int maxLength)
 
             return input;
         }
+
+        /// <summary>
+        /// Generates random trace Id as per W3C Distributed tracing specification.
+        /// https://github.com/w3c/distributed-tracing/blob/master/trace_context/HTTP_HEADER_FORMAT.md#trace-id
+        /// </summary>
+        /// <returns>Random 16 bytes array encoded as hex string</returns>
+        public static string GenerateTraceId()
+        {
+            // See https://stackoverflow.com/questions/311165/how-do-you-convert-a-byte-array-to-a-hexadecimal-string-and-vice-versa/24343727#24343727
+            var bytes = Guid.NewGuid().ToByteArray();
+
+            var result = new char[32];
+            for (int i = 0; i < 16; i++)
+            {
+                var val = Lookup32[bytes[i]];
+                result[2 * i] = (char)val;
+                result[(2 * i) + 1] = (char)(val >> 16);
+            }
+
+            return new string(result);
+        }
+
+        private static uint[] CreateLookup32()
+        {
+            // See https://stackoverflow.com/questions/311165/how-do-you-convert-a-byte-array-to-a-hexadecimal-string-and-vice-versa/24343727#24343727
+            var result = new uint[256];
+            for (int i = 0; i < 256; i++)
+            {
+                string s = i.ToString("x2", CultureInfo.InvariantCulture);
+                result[i] = ((uint)s[0]) + ((uint)s[1] << 16);
+            }
+
+            return result;
+        }
     }
 }

Src/DependencyCollector/NetCore.Tests/DependencyTrackingTelemetryModuleTestNetCore.cs

@@ -5,6 +5,7 @@
     using System.Diagnostics;
     using System.Linq;
     using System.Net.Http;
+    using System.Text.RegularExpressions;
     using System.Threading;
     using System.Threading.Tasks;
     using Microsoft.ApplicationInsights.Common;
@@ -167,7 +168,7 @@ public async Task TestDependencyCollectionWithParentActivity()
 
                 parent.Stop();
 
-                this.ValidateTelemetryForDiagnosticSource(this.sentTelemetry.Single(), url, request, true, "200", false);
+                this.ValidateTelemetryForDiagnosticSource(this.sentTelemetry.Single(), url, request, true, "200", false, parent);
 
                 Assert.AreEqual("k=v", request.Headers.GetValues(RequestResponseHeaders.CorrelationContextHeader).Single());
             }
@@ -193,7 +194,7 @@ public async Task TestDependencyCollectionDnsIssue()
             }
         }
 
-        private void ValidateTelemetryForDiagnosticSource(DependencyTelemetry item, Uri url, HttpRequestMessage request, bool success, string resultCode, bool expectLegacyHeaders)
+        private void ValidateTelemetryForDiagnosticSource(DependencyTelemetry item, Uri url, HttpRequestMessage request, bool success, string resultCode, bool expectLegacyHeaders, Activity parent = null)
         {
             Assert.AreEqual(url, item.Data);
             Assert.AreEqual(url.Host, item.Target);
@@ -215,6 +216,19 @@ private void ValidateTelemetryForDiagnosticSource(DependencyTelemetry item, Uri
 
             var requestId = item.Id;
             Assert.IsTrue(requestId.StartsWith('|' + item.Context.Operation.Id + '.'));
+
+            if (parent == null)
+            {
+                // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+                Assert.AreEqual(32, item.Context.Operation.Id.Length);
+                Assert.IsTrue(Regex.Match(item.Context.Operation.Id, @"[a-z][0-9]").Success);
+                // end of workaround test
+            }
+            else
+            {
+                Assert.AreEqual(parent.RootId, item.Context.Operation.Id);
+            }
+
             if (request != null)
             {
                 Assert.AreEqual(requestId, request.Headers.GetValues(RequestResponseHeaders.RequestIdHeader).Single());

Src/DependencyCollector/Shared.Tests/Implementation/DependencyCollectorDiagnosticListenerTests.Netstandard20.cs

@@ -62,8 +62,8 @@ public void OnActivityStartInjectsLegacyHeaders()
 
             // Request-Id and Correlation-Context are injected by HttpClient
             // check only legacy headers here
-            Assert.AreEqual(activity.RootId, request.Headers.GetValues(RequestResponseHeaders.StandardRootIdHeader).Single());
-            Assert.AreEqual(activity.Id, request.Headers.GetValues(RequestResponseHeaders.StandardParentIdHeader).Single());
+            Assert.AreEqual(Activity.Current.RootId, request.Headers.GetValues(RequestResponseHeaders.StandardRootIdHeader).Single());
+            Assert.AreEqual(Activity.Current.Id, request.Headers.GetValues(RequestResponseHeaders.StandardParentIdHeader).Single());
             Assert.AreEqual(this.testApplicationId1, GetRequestContextKeyValue(request, RequestResponseHeaders.RequestContextCorrelationSourceKey));
         }
 
@@ -82,8 +82,8 @@ public void OnActivityStopTracksTelemetry()
             HttpRequestMessage request = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
             this.listener.OnActivityStart(request);
 
+            activity = Activity.Current;
             HttpResponseMessage response = new HttpResponseMessage(HttpStatusCode.OK);
-            activity.SetEndTime(startTime.AddSeconds(1));
             this.listener.OnActivityStop(response, request, TaskStatus.RanToCompletion);
 
             var telemetry = this.sentTelemetry.Single() as DependencyTelemetry;
@@ -96,7 +96,8 @@ public void OnActivityStopTracksTelemetry()
             Assert.AreEqual(true, telemetry.Success);
 
             Assert.AreEqual(activity.StartTimeUtc, telemetry.Timestamp);
-            Assert.AreEqual(1, telemetry.Duration.TotalSeconds);
+            Assert.IsTrue(1 <= telemetry.Duration.TotalSeconds);
+            Assert.IsTrue(2 > telemetry.Duration.TotalSeconds);
 
             Assert.AreEqual(activity.RootId, telemetry.Context.Operation.Id);
             Assert.AreEqual(activity.ParentId, telemetry.Context.Operation.ParentId);
@@ -111,6 +112,39 @@ public void OnActivityStopTracksTelemetry()
             this.ValidateOperationDetails(telemetry);
         }
 
+        /// <summary>
+        /// Tests that OnStopActivity tracks telemetry.
+        /// </summary>
+        [TestMethod]
+        public void OnActivityStopWithParentTracksTelemetry()
+        {
+            var parent = new Activity("parent")
+                .AddBaggage("k", "v")
+                .Start();
+
+            var activity = new Activity("System.Net.Http.HttpRequestOut").Start();
+
+            HttpRequestMessage request = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
+            this.listener.OnActivityStart(request);
+
+            HttpResponseMessage response = new HttpResponseMessage(HttpStatusCode.OK);
+            this.listener.OnActivityStop(response, request, TaskStatus.RanToCompletion);
+
+            var telemetry = this.sentTelemetry.Single() as DependencyTelemetry;
+
+            Assert.AreEqual(parent.RootId, telemetry.Context.Operation.Id);
+            Assert.AreEqual(parent.Id, telemetry.Context.Operation.ParentId);
+            Assert.AreEqual(activity.Id, telemetry.Id);
+            Assert.AreEqual("v", telemetry.Context.Properties["k"]);
+
+            string expectedVersion =
+                SdkVersionHelper.GetExpectedSdkVersion(typeof(DependencyTrackingTelemetryModule), prefix: "rdddsc:");
+            Assert.AreEqual(expectedVersion, telemetry.Context.GetInternalContext().SdkVersion);
+
+            // Check the operation details
+            this.ValidateOperationDetails(telemetry);
+        }
+
         /// <summary>
         /// Tests that OnStopActivity tracks cancelled request.
         /// </summary>

Src/DependencyCollector/Shared.Tests/Implementation/EventHubsDiagnosticListenerTests.cs

@@ -4,6 +4,7 @@
     using System.Collections.Generic;
     using System.Diagnostics;
     using System.Linq;
+    using System.Text.RegularExpressions;
     using System.Threading.Tasks;
     using Microsoft.ApplicationInsights.Channel;
     using Microsoft.ApplicationInsights.DataContracts;
@@ -94,6 +95,36 @@ public void EventHubsSuccessfulSendIsHandled()
             }
         }
 
+        [TestMethod]
+        public void EventHubsSuccessfulSendIsHandledWithoutParent()
+        {
+            using (var module = new DependencyTrackingTelemetryModule())
+            {
+                module.IncludeDiagnosticSourceActivities.Add("Microsoft.Azure.EventHubs");
+                module.Initialize(this.configuration);
+
+                DiagnosticListener listener = new DiagnosticListener("Microsoft.Azure.EventHubs");
+
+                var telemetry = this.TrackOperation<DependencyTelemetry>(listener, "Microsoft.Azure.EventHubs.Send", TaskStatus.RanToCompletion);
+
+                Assert.IsNotNull(telemetry);
+                Assert.AreEqual("Send", telemetry.Name);
+                Assert.AreEqual(RemoteDependencyConstants.AzureEventHubs, telemetry.Type);
+                Assert.AreEqual("sb://eventhubname.servicebus.windows.net/ | ehname", telemetry.Target);
+                Assert.IsTrue(telemetry.Success.Value);
+
+                // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+                Assert.AreEqual(32, telemetry.Context.Operation.Id.Length);
+                Assert.IsTrue(Regex.Match(telemetry.Context.Operation.Id, @"[a-z][0-9]").Success);
+                // end of workaround test
+
+                Assert.AreEqual("eventhubname.servicebus.windows.net", telemetry.Properties["peer.hostname"]);
+                Assert.AreEqual("ehname", telemetry.Properties["eh.event_hub_name"]);
+                Assert.AreEqual("SomePartitionKeyHere", telemetry.Properties["eh.partition_key"]);
+                Assert.AreEqual("EventHubClient1(ehname)", telemetry.Properties["eh.client_id"]);
+            }
+        }
+
         [TestMethod]
         public void EventHubsFailedSendIsHandled()
         {

Src/DependencyCollector/Shared.Tests/Implementation/ServiceBusDiagnosticListenerTests.cs

@@ -4,6 +4,7 @@
     using System.Collections.Generic;
     using System.Diagnostics;
     using System.Linq;
+    using System.Text.RegularExpressions;
     using System.Threading.Tasks;
     using Microsoft.ApplicationInsights.Channel;
     using Microsoft.ApplicationInsights.DataContracts;
@@ -85,6 +86,33 @@ public void ServiceBusSendHanding()
             }
         }
 
+        [TestMethod]
+        public void ServiceBusSendHandingWithoutParent()
+        {
+            using (var module = new DependencyTrackingTelemetryModule())
+            {
+                module.IncludeDiagnosticSourceActivities.Add("Microsoft.Azure.ServiceBus");
+                module.Initialize(this.configuration);
+
+                DiagnosticListener listener = new DiagnosticListener("Microsoft.Azure.ServiceBus");
+
+                var telemetry = this.TrackOperation<DependencyTelemetry>(listener, "Microsoft.Azure.ServiceBus.Send", TaskStatus.RanToCompletion);
+
+                Assert.IsNotNull(telemetry);
+                Assert.AreEqual("Send", telemetry.Name);
+                Assert.AreEqual(RemoteDependencyConstants.AzureServiceBus, telemetry.Type);
+                Assert.AreEqual("sb://queuename.myservicebus.com/ | queueName", telemetry.Target);
+                Assert.IsTrue(telemetry.Success.Value);
+
+                // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+                Assert.AreEqual(32, telemetry.Context.Operation.Id.Length);
+                Assert.IsTrue(Regex.Match(telemetry.Context.Operation.Id, @"[a-z][0-9]").Success);
+                // end of workaround test
+
+                Assert.AreEqual("messageId", telemetry.Properties["MessageId"]);
+            }
+        }
+
         [TestMethod]
         public void ServiceBusBadStatusHanding()
         {
@@ -136,6 +164,32 @@ public void ServiceBusProcessHanding()
             }
         }
 
+        [TestMethod]
+        public void ServiceBusProcessHandingWithoutParent()
+        {
+            using (var module = new DependencyTrackingTelemetryModule())
+            {
+                module.IncludeDiagnosticSourceActivities.Add("Microsoft.Azure.ServiceBus");
+                module.Initialize(this.configuration);
+
+                DiagnosticListener listener = new DiagnosticListener("Microsoft.Azure.ServiceBus");
+
+                var telemetry = this.TrackOperation<RequestTelemetry>(listener, "Microsoft.Azure.ServiceBus.Process", TaskStatus.RanToCompletion);
+
+                Assert.IsNotNull(telemetry);
+                Assert.AreEqual("Process", telemetry.Name);
+                Assert.AreEqual($"type:{RemoteDependencyConstants.AzureServiceBus} | name:queueName | endpoint:sb://queuename.myservicebus.com/", telemetry.Source);
+                Assert.IsTrue(telemetry.Success.Value);
+
+                // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+                Assert.AreEqual(32, telemetry.Context.Operation.Id.Length);
+                Assert.IsTrue(Regex.Match(telemetry.Context.Operation.Id, @"[a-z][0-9]").Success);
+                // end of workaround test
+
+                Assert.AreEqual("messageId", telemetry.Properties["MessageId"]);
+            }
+        }
+
         [TestMethod]
         public void ServiceBusExceptionsAreIgnored()
         {

Src/DependencyCollector/Shared/HttpCoreDiagnosticSourceListener.cs

@@ -268,7 +268,7 @@ internal void OnException(Exception exception, HttpRequestMessage request)
                 DependencyCollectorEventSource.Log.CurrentActivityIsNull(HttpExceptionEventName);
                 return;
             }
-
+            
             DependencyCollectorEventSource.Log.HttpCoreDiagnosticSourceListenerException(currentActivity.Id);
 
             this.pendingExceptions.TryAdd(currentActivity.Id, exception);
@@ -296,6 +296,20 @@ internal void OnActivityStart(HttpRequestMessage request)
                 return;
             }
 
+            // As a first step in supporting W3C protocol in ApplicationInsights,
+            // we want to generate Activity Ids in the W3C compatible format.
+            // While .NET changes to Activity are pending, we want to ensure trace starts with W3C compatible Id
+            // as early as possible, so that everyone has a chance to upgrade and have compatibility with W3C systems once they arrive.
+            // So if there is no parent Activity (i.e. this request has happened in the background, without parent scope), we'll override 
+            // the current Activity with the one with properly formatted Id. This workaround should go away
+            // with W3C support on .NET https://github.com/dotnet/corefx/issues/30331
+            if (currentActivity.Parent == null)
+            {
+                currentActivity.UpdateParent(StringUtilities.GenerateTraceId());
+            }
+
+            // end of workaround
+
             DependencyCollectorEventSource.Log.HttpCoreDiagnosticSourceListenerStart(currentActivity.Id);
 
             this.InjectRequestHeaders(request, this.configuration.InstrumentationKey);
@@ -322,6 +336,12 @@ internal void OnActivityStop(HttpResponseMessage response, HttpRequestMessage re
                 return;
             }
 
+            // If we started auxiliary Activity before to override the Id with W3C compatible one, now it's time to stop it
+            if (currentActivity.Duration == TimeSpan.Zero)
+            {
+                currentActivity.Stop();
+            }
+
             DependencyCollectorEventSource.Log.HttpCoreDiagnosticSourceListenerStop(currentActivity.Id);
 
             Uri requestUri = request.RequestUri;
@@ -384,7 +404,10 @@ internal void OnRequest(HttpRequestMessage request, Guid loggingRequestId)
                 Uri requestUri = request.RequestUri;
                 var resourceName = request.Method.Method + " " + requestUri.AbsolutePath;
 
-                var dependency = this.client.StartOperation<DependencyTelemetry>(resourceName);
+                var dependency = Activity.Current != null ?
+                    this.client.StartOperation<DependencyTelemetry>(resourceName) :
+                    this.client.StartOperation<DependencyTelemetry>(resourceName, StringUtilities.GenerateTraceId());
+
                 dependency.Telemetry.Target = requestUri.Host;
                 dependency.Telemetry.Type = RemoteDependencyConstants.HTTP;
                 dependency.Telemetry.Data = requestUri.OriginalString;