Generate W3C-compatible operation id if there is no request-id header (…

…#722)

CHANGELOG.md

@@ -1,6 +1,7 @@
 # Changelog
 
 ## Version 2.4.0-beta4
+- [Generate W3C compatible operation Id when there is no parent operation](https://github.com/Microsoft/ApplicationInsights-dotnet-server/pull/952)
 - Updated Web/Base SDK version dependency to 2.7.0-beta4
 
 ## Version 2.4.0-beta3

src/Microsoft.ApplicationInsights.AspNetCore/Common/StringUtilities.cs

@@ -1,4 +1,7 @@
-namespace Microsoft.ApplicationInsights.AspNetCore.Common
+using System;
+using System.Globalization;
+
+namespace Microsoft.ApplicationInsights.AspNetCore.Common
 {
     using System.Diagnostics;
 
@@ -7,11 +10,14 @@
     /// </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>
         public static string EnforceMaxLength(string input, int maxLength)
         {
+            // TODO: remove/obsolete and use StringUtilities from Web SDK
             Debug.Assert(input != null, $"{nameof(input)} must not be null");
             Debug.Assert(maxLength > 0, $"{nameof(maxLength)} must be greater than 0");
 
@@ -22,5 +28,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>
+        internal 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/Microsoft.ApplicationInsights.AspNetCore/DiagnosticListeners/Implementation/HostingDiagnosticListener.cs

@@ -79,18 +79,38 @@ public void OnHttpRequestInStart(HttpContext httpContext)
                 var currentActivity = Activity.Current;
                 var isActivityCreatedFromRequestIdHeader = false;
 
-                StringValues xmsRequestRootId;
                 if (currentActivity.ParentId != null)
                 {
                     isActivityCreatedFromRequestIdHeader = true;
                 }
-                else if (httpContext.Request.Headers.TryGetValue(RequestResponseHeaders.StandardRootIdHeader, out xmsRequestRootId))
+                else if (httpContext.Request.Headers.TryGetValue(RequestResponseHeaders.StandardRootIdHeader, out var xmsRequestRootId))
                 {
                     xmsRequestRootId = StringUtilities.EnforceMaxLength(xmsRequestRootId, InjectionGuardConstants.RequestHeaderMaxLength);
                     var activity = new Activity(ActivityCreatedByHostingDiagnosticListener);
                     activity.SetParentId(xmsRequestRootId);
                     activity.Start();
                     httpContext.Features.Set(activity);
+
+                    currentActivity = activity;
+                }
+                else
+                {
+                    // 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 current Activity (i.e. there were no Request-Id header in the incoming request), we'll override ParentId on 
+                    // the current Activity by the properly formatted one. This workaround should go away
+                    // with W3C support on .NET https://github.com/dotnet/corefx/issues/30331
+
+                    var activity = new Activity(ActivityCreatedByHostingDiagnosticListener);
+
+                    activity.SetParentId(StringUtilities.GenerateTraceId());
+                    activity.Start();
+                    httpContext.Features.Set(activity);
+                    currentActivity = activity;
+
+                    // end of workaround
                 }
 
                 var requestTelemetry = InitializeRequestTelemetry(httpContext, currentActivity, isActivityCreatedFromRequestIdHeader, Stopwatch.GetTimestamp());
@@ -147,6 +167,20 @@ public void OnBeginRequest(HttpContext httpContext, long timestamp)
                     standardRootId = StringUtilities.EnforceMaxLength(standardRootId, InjectionGuardConstants.RequestHeaderMaxLength);
                     activity.SetParentId(standardRootId);
                 }
+                else
+                {
+                    // 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 current Activity (i.e. there were no Request-Id header in the incoming request), we'll override ParentId on 
+                    // the current Activity by the properly formatted one. This workaround should go away
+                    // with W3C support on .NET https://github.com/dotnet/corefx/issues/30331
+
+                    activity.SetParentId(StringUtilities.GenerateTraceId());
+
+                    // end of workaround
+                }
 
                 activity.Start();
                 httpContext.Features.Set(activity);

test/FunctionalTestUtils20/TelemetryTestsBase.cs

@@ -7,6 +7,7 @@
     using System.Reflection;
     using System.Runtime.CompilerServices;
     using System.Text;
+    using System.Text.RegularExpressions;
     using System.Threading;
     using System.Threading.Tasks;
     using AI;
@@ -32,7 +33,7 @@ public TelemetryTestsBase(ITestOutputHelper output)
         }
 
         [MethodImpl(MethodImplOptions.NoOptimization)]
-        public void ValidateBasicRequest(InProcessServer server, string requestPath, RequestTelemetry expected, bool expectRequestContextInResponse = true)
+        public TelemetryItem<RequestData> ValidateBasicRequest(InProcessServer server, string requestPath, RequestTelemetry expected, bool expectRequestContextInResponse = true)
         {
             // Subtract 50 milliseconds to hack around strange behavior on build server where the RequestTelemetry.Timestamp is somehow sometimes earlier than now by a few milliseconds.
             expected.Timestamp = DateTimeOffset.Now.Subtract(TimeSpan.FromMilliseconds(50));
@@ -58,6 +59,8 @@ public void ValidateBasicRequest(InProcessServer server, string requestPath, Req
             output.WriteLine("actual.Duration: " + data.duration);
             output.WriteLine("timer.Elapsed: " + timer.Elapsed);
             Assert.True(TimeSpan.Parse(data.duration) < timer.Elapsed.Add(TimeSpan.FromMilliseconds(20)), "duration");
+
+            return item;
         }
 
         public void ValidateBasicException(InProcessServer server, string requestPath, ExceptionTelemetry expected)

test/Microsoft.ApplicationInsights.AspNetCore.Tests/RequestTrackingMiddlewareTest.cs

@@ -5,6 +5,7 @@
     using System.Diagnostics;
     using System.Globalization;
     using System.Linq;
+    using System.Text.RegularExpressions;
     using System.Threading.Tasks;
     using Microsoft.ApplicationInsights.AspNetCore.DiagnosticListeners;
     using Microsoft.ApplicationInsights.AspNetCore.Tests.Helpers;
@@ -173,6 +174,11 @@ public void OnBeginRequestCreateNewActivityAndInitializeRequestTelemetry()
             Assert.Equal(requestTelemetry.Context.Operation.Id, Activity.Current.RootId);
             Assert.Equal(requestTelemetry.Context.Operation.ParentId, Activity.Current.ParentId);
             Assert.Null(requestTelemetry.Context.Operation.ParentId);
+
+            // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+            Assert.Equal(32, requestTelemetry.Context.Operation.Id.Length);
+            Assert.True(Regex.Match(requestTelemetry.Context.Operation.Id, @"[a-z][0-9]").Success);
+            // end of workaround test
         }
 
         [Fact]
@@ -220,8 +226,8 @@ public void OnBeginRequestCreateNewActivityAndInitializeRequestTelemetryFromRequ
             middleware.OnBeginRequest(context, 0);
 
             Assert.NotNull(Activity.Current);
-            Assert.NotNull(Activity.Current.Baggage.FirstOrDefault(b => b.Key == "prop1" && b.Value == "value1"));
-            Assert.NotNull(Activity.Current.Baggage.FirstOrDefault(b => b.Key == "prop2" && b.Value == "value2"));
+            Assert.Single(Activity.Current.Baggage.Where(b => b.Key == "prop1" && b.Value == "value1"));
+            Assert.Single(Activity.Current.Baggage.Where(b => b.Key == "prop2" && b.Value == "value2"));
 
             var requestTelemetry = context.Features.Get<RequestTelemetry>();
             Assert.NotNull(requestTelemetry);
@@ -230,8 +236,8 @@ public void OnBeginRequestCreateNewActivityAndInitializeRequestTelemetryFromRequ
             Assert.NotEqual(requestTelemetry.Context.Operation.Id, standardRequestRootId);
             Assert.Equal(requestTelemetry.Context.Operation.ParentId, requestId);
             Assert.NotEqual(requestTelemetry.Context.Operation.ParentId, standardRequestId);
-            Assert.Equal(requestTelemetry.Context.Properties["prop1"], "value1");
-            Assert.Equal(requestTelemetry.Context.Properties["prop2"], "value2");
+            Assert.Equal("value1", requestTelemetry.Context.Properties["prop1"]);
+            Assert.Equal("value2", requestTelemetry.Context.Properties["prop2"]);
         }
 
         [Fact]
@@ -253,7 +259,7 @@ public void OnHttpRequestInStartInitializeTelemetryIfActivityParentIdIsNotNull()
             middleware.OnHttpRequestInStart(context);
             middleware.OnHttpRequestInStop(context);
 
-            Assert.Equal(1, sentTelemetry.Count);
+            Assert.Single(sentTelemetry);
             var requestTelemetry = this.sentTelemetry.First() as RequestTelemetry;
 
             Assert.Equal(requestTelemetry.Id, activity.Id);
@@ -293,7 +299,7 @@ public void OnHttpRequestInStartCreateNewActivityIfParentIdIsNullAndHasStandardH
 
             middleware.OnHttpRequestInStop(context);
 
-            Assert.Equal(1, sentTelemetry.Count);
+            Assert.Single(sentTelemetry);
             var requestTelemetry = this.sentTelemetry.First() as RequestTelemetry;
 
             Assert.Equal(requestTelemetry.Id, activityInitializedByStandardHeader.Id);
@@ -315,7 +321,7 @@ public void OnEndRequestSetsRequestNameToMethodAndPathForPostRequest()
 
             Assert.Single(sentTelemetry);
             Assert.IsType<RequestTelemetry>(this.sentTelemetry.First());
-            RequestTelemetry requestTelemetry = this.sentTelemetry.First() as RequestTelemetry;
+            RequestTelemetry requestTelemetry = this.sentTelemetry.Single() as RequestTelemetry;
             Assert.True(requestTelemetry.Duration.TotalMilliseconds >= 0);
             Assert.True(requestTelemetry.Success);
             Assert.Equal(CommonMocks.InstrumentationKey, requestTelemetry.Context.InstrumentationKey);

test/WebApi20.FunctionalTests/FunctionalTest/RequestTelemetryWebApiTests.cs

@@ -1,14 +1,13 @@
-using System;
-using System.Collections.Generic;
-using Microsoft.ApplicationInsights.Extensibility;
-using Microsoft.ApplicationInsights.Extensibility.Implementation.ApplicationId;
-using Microsoft.AspNetCore.Hosting;
-using Microsoft.Extensions.DependencyInjection;
-
-namespace WebApi20.FunctionalTests.FunctionalTest
+namespace WebApi20.FunctionalTests.FunctionalTest
 {
+    using System.Linq;
+    using System.Text.RegularExpressions;
+
     using FunctionalTestUtils;
     using Microsoft.ApplicationInsights.DataContracts;
+    using Microsoft.ApplicationInsights.DependencyCollector;
+    using Microsoft.AspNetCore.Hosting;
+    using Microsoft.Extensions.DependencyInjection;
     using Xunit;
     using Xunit.Abstractions;
 
@@ -94,6 +93,39 @@ IWebHostBuilder Config(IWebHostBuilder builder)
                 this.ValidateBasicRequest(server, RequestPath, expectedRequestTelemetry, false);
             }
         }
+
+        [Fact]
+        public void TestW3COperationIdFormatGeneration()
+        {
+            IWebHostBuilder Config(IWebHostBuilder builder)
+            {
+                // disable Dependency tracking (i.e. header injection)
+                return builder.ConfigureServices(services =>
+                {
+                    services.AddApplicationInsightsTelemetry();
+                    services.Remove(services.Single(sd =>
+                        sd.ImplementationType == typeof(DependencyTrackingTelemetryModule)));
+                });
+            }
+
+            using (var server = new InProcessServer(assemblyName, this.output, Config))
+            {
+                const string RequestPath = "/api/values/1";
+
+                var expectedRequestTelemetry = new RequestTelemetry();
+                expectedRequestTelemetry.Name = "GET Values/Get [id]";
+                expectedRequestTelemetry.ResponseCode = "200";
+                expectedRequestTelemetry.Success = true;
+                expectedRequestTelemetry.Url = new System.Uri(server.BaseHost + RequestPath);
+
+                var item = this.ValidateBasicRequest(server, RequestPath, expectedRequestTelemetry, true);
+
+                // W3C compatible-Id ( should go away when W3C is implemented in .NET https://github.com/dotnet/corefx/issues/30331)
+                Assert.Equal(32, item.tags["ai.operation.id"].Length);
+                Assert.True(Regex.Match(item.tags["ai.operation.id"], @"[a-z][0-9]").Success);
+                // end of workaround test
+            }
+        }
     }
 }