Diagnostics: Adds performance improvement to GetContactedRegions() (A…

…zure#2907) Getting region Contacted information from the diagnostics is very inefficient today. It is affecting Client Telemetry Performance by 2% to 3% . Right now, Overall impact is 5% (Comparing run with Telemetry and Without Telemetry)
juraj-blazek · Jan 12, 2022 · 1d8a2d4 · 1d8a2d4
1 parent ce58fed
commit 1d8a2d4
Show file tree

Hide file tree

Showing 11 changed files with 310 additions and 155 deletions.
diff --git a/Microsoft.Azure.Cosmos/src/Diagnostics/CosmosTraceDiagnostics.cs b/Microsoft.Azure.Cosmos/src/Diagnostics/CosmosTraceDiagnostics.cs
@@ -20,7 +20,7 @@ public CosmosTraceDiagnostics(ITrace trace)
             if (trace == null)
             {
                 throw new ArgumentNullException(nameof(trace));
-            }
+            }
 
             // Need to set to the root trace, since we don't know which layer of the stack the response message was returned from.
             ITrace rootTrace = trace;
@@ -45,11 +45,8 @@ public override TimeSpan GetClientElapsedTime()
         }
 
         public override IReadOnlyList<(string regionName, Uri uri)> GetContactedRegions()
-        {
-            HashSet<(string, Uri)> regionsContacted = new HashSet<(string, Uri)>();
-            ITrace rootTrace = this.Value;
-            this.WalkTraceTreeForRegionsContated(rootTrace, regionsContacted);
-            return regionsContacted.ToList();
+        {
+            return this.Value?.RegionsContacted;
         }
 
         internal bool IsGoneExceptionHit()
@@ -89,23 +86,6 @@ private bool WalkTraceTreeForGoneException(ITrace currentTrace)
             return false;
         }
 
-        private void WalkTraceTreeForRegionsContated(ITrace currentTrace, HashSet<(string, Uri)> regionsContacted)
-        {
-            foreach (object datums in currentTrace.Data.Values)
-            {
-                if (datums is ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
-                {
-                    regionsContacted.UnionWith(clientSideRequestStatisticsTraceDatum.RegionsContacted);
-                    return;
-                }
-            }
-
-            foreach (ITrace childTrace in currentTrace.Children)
-            {
-                this.WalkTraceTreeForRegionsContated(childTrace, regionsContacted);
-            }
-        }
-
         private string ToJsonString()
         {
             ReadOnlyMemory<byte> utf8String = this.WriteTraceToJsonWriter(JsonSerializationFormat.Text);

diff --git a/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs b/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs
@@ -29,9 +29,10 @@ public override async Task<ResponseMessage> SendAsync(
             CancellationToken cancellationToken)
         {
             try
-            {
+            {
                 ResponseMessage response = await this.ProcessMessageAsync(request, cancellationToken);
-                Debug.Assert(System.Diagnostics.Trace.CorrelationManager.ActivityId != Guid.Empty, "Trace activity id is missing");
+                Debug.Assert(System.Diagnostics.Trace.CorrelationManager.ActivityId != Guid.Empty, "Trace activity id is missing");
+
                 return response;
             }
             //catch DocumentClientException and exceptions that inherit it. Other exception types happen before a backend request
@@ -90,7 +91,8 @@ internal async Task<ResponseMessage> ProcessMessageAsync(
                 throw new ArgumentNullException(nameof(request));
             }
 
-            DocumentServiceRequest serviceRequest = request.ToDocumentServiceRequest();
+            DocumentServiceRequest serviceRequest = request.ToDocumentServiceRequest();
+
             ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
             serviceRequest.RequestContext.ClientRequestStatistics = clientSideRequestStatisticsTraceDatum;
 
@@ -103,21 +105,29 @@ internal async Task<ResponseMessage> ProcessMessageAsync(
                 AuthorizationTokenType.PrimaryMasterKey,
                 request.Trace);
 
-            serviceRequest.Headers[HttpConstants.HttpHeaders.Authorization] = authorization;
+            serviceRequest.Headers[HttpConstants.HttpHeaders.Authorization] = authorization;
 
             IStoreModel storeProxy = this.client.DocumentClient.GetStoreProxy(serviceRequest);
             using (ITrace processMessageAsyncTrace = request.Trace.StartChild(
-                name: $"{storeProxy.GetType().FullName} Transport Request",
-                TraceComponent.Transport,
-                Tracing.TraceLevel.Info))
+                            name: $"{storeProxy.GetType().FullName} Transport Request",
+                            component: TraceComponent.Transport,
+                            level: Tracing.TraceLevel.Info))
             {
                 request.Trace = processMessageAsyncTrace;
                 processMessageAsyncTrace.AddDatum("Client Side Request Stats", clientSideRequestStatisticsTraceDatum);
-
-                DocumentServiceResponse response = request.OperationType == OperationType.Upsert
-                        ? await this.ProcessUpsertAsync(storeProxy, serviceRequest, cancellationToken)
-                        : await storeProxy.ProcessMessageAsync(serviceRequest, cancellationToken);
-
+
+                DocumentServiceResponse response = null;
+                try
+                {
+                    response = request.OperationType == OperationType.Upsert
+                       ? await this.ProcessUpsertAsync(storeProxy, serviceRequest, cancellationToken)
+                       : await storeProxy.ProcessMessageAsync(serviceRequest, cancellationToken);
+                }
+                finally
+                {
+                    processMessageAsyncTrace.UpdateRegionContacted(clientSideRequestStatisticsTraceDatum);
+                }
+
                 return response.ToCosmosResponseMessage(
                     request,
                     serviceRequest.RequestContext.RequestChargeTracker);

diff --git a/Microsoft.Azure.Cosmos/src/Telemetry/ClientTelemetryHelper.cs b/Microsoft.Azure.Cosmos/src/Telemetry/ClientTelemetryHelper.cs
@@ -178,6 +178,11 @@ internal static List<OperationInfo> ToListWithMetricsInfo(IDictionary<OperationI
         internal static string GetContactedRegions(CosmosDiagnostics cosmosDiagnostics)
         {
             IReadOnlyList<(string regionName, Uri uri)> regionList = cosmosDiagnostics.GetContactedRegions();
+
+            if (regionList == null || regionList.Count == 0)
+            {
+                return null;
+            }
 
             if (regionList.Count == 1)
             {

diff --git a/Microsoft.Azure.Cosmos/src/Tracing/ITrace.cs b/Microsoft.Azure.Cosmos/src/Tracing/ITrace.cs
@@ -67,6 +67,11 @@ interface ITrace : IDisposable
         /// Gets additional datum associated with this trace.
         /// </summary>
         IReadOnlyDictionary<string, object> Data { get; }
+
+        /// <summary>
+        /// Consolidated Region contacted Information of this and children nodes
+        /// </summary>
+        IReadOnlyList<(string, Uri)> RegionsContacted { get; }
 
         /// <summary>
         /// Starts a Trace and adds it as a child to this instance.
@@ -118,6 +123,12 @@ ITrace StartChild(
         /// Adds a trace children that is already completed.
         /// </summary>
         /// <param name="trace">Existing trace.</param>
-        void AddChild(ITrace trace);
+        void AddChild(ITrace trace);
+
+        /// <summary>
+        /// Update region contacted information to the parent Itrace
+        /// </summary>
+        /// <param name="traceDatum"></param>
+        void UpdateRegionContacted(TraceDatum traceDatum);
     }
 }
diff --git a/Microsoft.Azure.Cosmos/src/Tracing/NoOpTrace.cs b/Microsoft.Azure.Cosmos/src/Tracing/NoOpTrace.cs
@@ -12,6 +12,7 @@ internal sealed class NoOpTrace : ITrace
         public static readonly NoOpTrace Singleton = new NoOpTrace();
 
         private static readonly IReadOnlyList<ITrace> NoOpChildren = new List<ITrace>();
+        private static readonly IReadOnlyList<(string, Uri)> NoOpRegionsContacted = new List<(string, Uri)>();
         private static readonly IReadOnlyDictionary<string, object> NoOpData = new Dictionary<string, object>();
         private static readonly CallerInfo NoOpCallerInfo = new CallerInfo(memberName: "NoOp", filePath: "NoOp", lineNumber: 9001);
 
@@ -39,6 +40,8 @@ private NoOpTrace()
 
         public IReadOnlyDictionary<string, object> Data => NoOpData;
 
+        public IReadOnlyList<(string, Uri)> RegionsContacted => NoOpRegionsContacted;
+
         public void Dispose()
         {
             // NoOp
@@ -81,5 +84,10 @@ public void AddChild(ITrace trace)
         {
             // NoOp
         }
+
+        public void UpdateRegionContacted(TraceDatum traceDatum)
+        {
+            // NoOp
+        }
     }
 }
diff --git a/Microsoft.Azure.Cosmos/src/Tracing/Trace.cs b/Microsoft.Azure.Cosmos/src/Tracing/Trace.cs
@@ -6,21 +6,25 @@ namespace Microsoft.Azure.Cosmos.Tracing
 {
     using System;
     using System.Collections.Generic;
-    using System.Diagnostics;
-    using System.Runtime.CompilerServices;
-
+    using System.Diagnostics;
+    using System.Linq;
+    using System.Runtime.CompilerServices;
+    using Microsoft.Azure.Cosmos.Tracing.TraceData;
+
     internal sealed class Trace : ITrace
     {
         private readonly List<ITrace> children;
         private readonly Dictionary<string, object> data;
         private readonly Stopwatch stopwatch;
+        private readonly ISet<(string, Uri)> regionContactedInternal;
 
         private Trace(
             string name,
             CallerInfo callerInfo,
             TraceLevel level,
             TraceComponent component,
-            Trace parent)
+            Trace parent,
+            ISet<(string, Uri)> regionContactedInternal)
         {
             this.Name = name ?? throw new ArgumentNullException(nameof(name));
             this.Id = Guid.NewGuid();
@@ -31,7 +35,9 @@ private Trace(
             this.Component = component;
             this.Parent = parent;
             this.children = new List<ITrace>();
-            this.data = new Dictionary<string, object>();
+            this.data = new Dictionary<string, object>();
+
+            this.regionContactedInternal = regionContactedInternal;
         }
 
         public string Name { get; }
@@ -52,7 +58,39 @@ private Trace(
 
         public IReadOnlyList<ITrace> Children => this.children;
 
-        public IReadOnlyDictionary<string, object> Data => this.data;
+        public IReadOnlyDictionary<string, object> Data => this.data;
+
+        public IReadOnlyList<(string, Uri)> RegionsContacted 
+        { 
+            get
+            {
+                lock (this.regionContactedInternal)
+                {
+                    return this.regionContactedInternal.ToList();
+                }
+            }
+        }
+
+        /// <summary>
+        /// Update region contacted information to this node
+        /// </summary>
+        /// <param name="traceDatum"></param>
+        public void UpdateRegionContacted(TraceDatum traceDatum)
+        {
+            if (traceDatum is ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
+            {
+                if (clientSideRequestStatisticsTraceDatum.RegionsContacted == null || 
+                            clientSideRequestStatisticsTraceDatum.RegionsContacted.Count == 0)
+                {
+                    return;
+                }
+
+                lock (this.regionContactedInternal)
+                {
+                    this.regionContactedInternal.UnionWith(clientSideRequestStatisticsTraceDatum.RegionsContacted);
+                }
+            }
+        }
 
         public void Dispose()
         {
@@ -87,7 +125,8 @@ public ITrace StartChild(
                 callerInfo: new CallerInfo(memberName, sourceFilePath, sourceLineNumber),
                 level: level,
                 component: component,
-                parent: this);
+                parent: this,
+                regionContactedInternal: this.regionContactedInternal);
 
             this.AddChild(child);
 
@@ -123,12 +162,14 @@ public static Trace GetRootTrace(
                 callerInfo: new CallerInfo(memberName, sourceFilePath, sourceLineNumber),
                 level: level,
                 component: component,
-                parent: null);
+                parent: null,
+                regionContactedInternal: new HashSet<(string, Uri)>());
         }
 
         public void AddDatum(string key, TraceDatum traceDatum)
         {
-            this.data.Add(key, traceDatum);
+            this.data.Add(key, traceDatum);
+            this.UpdateRegionContacted(traceDatum);
         }
 
         public void AddDatum(string key, object value)

diff --git a/...os/tests/Microsoft.Azure.Cosmos.EmulatorTests/Tracing/EndToEndTraceWriterBaselineTests.cs b/...os/tests/Microsoft.Azure.Cosmos.EmulatorTests/Tracing/EndToEndTraceWriterBaselineTests.cs
@@ -1363,8 +1363,10 @@ public TraceForBaselineTesting(
 
             public IReadOnlyList<ITrace> Children => this.children;
 
-            public IReadOnlyDictionary<string, object> Data => this.data;
-
+            public IReadOnlyDictionary<string, object> Data => this.data;
+
+            public IReadOnlyList<(string, Uri)> RegionsContacted => new List<(string, Uri)>();
+
             public void AddDatum(string key, TraceDatum traceDatum)
             {
                 this.data[key] = traceDatum;
@@ -1405,7 +1407,12 @@ public void AddChild(ITrace trace)
             public static TraceForBaselineTesting GetRootTrace()
             {
                 return new TraceForBaselineTesting("Trace For Baseline Testing", TraceLevel.Info, TraceComponent.Unknown, parent: null);
-            }
+            }
+
+            public void UpdateRegionContacted(TraceDatum traceDatum)
+            {
+                //NoImplementation
+            }
         }
 
         private sealed class RequestHandlerSleepHelper : RequestHandler