Diagnostics: Fix ToString() to not grow exponentially with retries (#…

…1539)

Diagnostics: Fix ToString() to not grow exponentially with retries (#1539)

Microsoft.Azure.Cosmos/src/Diagnostics/CosmosClientSideRequestStatistics.cs

@@ -16,6 +16,7 @@ namespace Microsoft.Azure.Cosmos
 
     internal sealed class CosmosClientSideRequestStatistics : CosmosDiagnosticsInternal, IClientSideRequestStatistics
     {
+        public const string DefaultToStringMessage = "Please see CosmosDiagnostics";
         private readonly object lockObject = new object();
 
         public CosmosClientSideRequestStatistics(CosmosDiagnosticsContext diagnosticsContext = null)
@@ -151,20 +152,24 @@ public void RecordAddressResolutionEnd(string identifier)
             }
         }
 
+        /// <summary>
+        /// The new Cosmos Exception always includes the diagnostics and the
+        /// document client exception message. Some of the older document client exceptions
+        /// include the request statistics in the message causing a circle reference.
+        /// This always returns empty string to prevent the circle reference which
+        /// would cause the diagnostic string to grow exponentially.
+        /// </summary>
         public override string ToString()
         {
-            // This is required for the older IClientSideRequestStatistics
-            // Capture the entire diagnostic context in the toString to avoid losing any information
-            // for any APIs using the older interface.
-            return this.DiagnosticsContext.ToString();
+            return DefaultToStringMessage;
         }
 
+        /// <summary>
+        /// Please see ToString() documentation
+        /// </summary>
         public void AppendToBuilder(StringBuilder stringBuilder)
         {
-            // This is required for the older IClientSideRequestStatistics
-            // Capture the entire diagnostic context in the toString to avoid losing any information
-            // for any APIs using the older interface.
-            stringBuilder.Append(this.DiagnosticsContext.ToString());
+            stringBuilder.Append(DefaultToStringMessage);
         }
 
         public override void Accept(CosmosDiagnosticsInternalVisitor visitor)

Microsoft.Azure.Cosmos/src/Resource/CosmosExceptions/CosmosException.cs

@@ -236,6 +236,7 @@ private string ToStringHelper(
 
             if (this.Diagnostics != null)
             {
+                stringBuilder.Append("--- Cosmos Diagnostics ---");
                 stringBuilder.Append(this.Diagnostics);
             }
 

Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/CosmosDiagnosticsTests.cs

@@ -16,6 +16,7 @@ namespace Microsoft.Azure.Cosmos.SDK.EmulatorTests
     using System.Linq;
     using System.Net;
     using System.Runtime.CompilerServices;
+    using System.Text.RegularExpressions;
     using System.Threading;
     using System.Threading.Tasks;
 
@@ -129,6 +130,88 @@ public async Task PointOperationRequestTimeoutDiagnostic(bool disableDiagnostics
             }
         }
 
+        [TestMethod]
+        public async Task PointOperationForbiddenDiagnostic()
+        {
+            List<int> stringLength = new List<int>();
+            foreach (int maxCount in new int[] { 1, 2, 4 })
+            {
+                int count = 0;
+                List<(string, string)> activityIdAndErrorMessage = new List<(string, string)>(maxCount);
+                Guid transportExceptionActivityId = Guid.NewGuid();
+                string transportErrorMessage = $"TransportErrorMessage{Guid.NewGuid()}";
+
+                Action<Uri, Documents.ResourceOperation, Documents.DocumentServiceRequest> interceptor =
+                    (uri, operation, request) =>
+                {
+                    if (request.ResourceType == Documents.ResourceType.Document)
+                    {
+                        if (count >= maxCount)
+                        {
+                            TransportClientHelper.ThrowTransportExceptionOnItemOperation(
+                                uri,
+                                operation,
+                                request,
+                                transportExceptionActivityId,
+                                transportErrorMessage);
+                        }
+
+                        count++;
+                        string activityId = Guid.NewGuid().ToString();
+                        string errorMessage = $"Error{Guid.NewGuid()}";
+
+                        activityIdAndErrorMessage.Add((activityId, errorMessage));
+                        TransportClientHelper.ThrowForbiddendExceptionOnItemOperation(
+                            uri,
+                            request,
+                            activityId,
+                            errorMessage);
+                    }
+                };
+
+                Container containerWithTransportException = TransportClientHelper.GetContainerWithIntercepter(
+                                        this.database.Id,
+                                        this.Container.Id,
+                                        interceptor);
+                //Checking point operation diagnostics on typed operations
+                ToDoActivity testItem = ToDoActivity.CreateRandomToDoActivity();
+
+                try
+                {
+                    ItemResponse<ToDoActivity> createResponse = await containerWithTransportException.CreateItemAsync<ToDoActivity>(
+                      item: testItem);
+                    Assert.Fail("Should have thrown a request timeout exception");
+                }
+                catch (CosmosException ce) when (ce.StatusCode == System.Net.HttpStatusCode.RequestTimeout)
+                {
+                    string exceptionToString = ce.ToString();
+                    Assert.IsNotNull(exceptionToString);
+                    stringLength.Add(exceptionToString.Length);
+
+                    // Request timeout info will be in the exception message and in the diagnostic info.
+                    Assert.AreEqual(2, Regex.Matches(exceptionToString, transportExceptionActivityId.ToString()).Count);
+                    Assert.AreEqual(2, Regex.Matches(exceptionToString, transportErrorMessage).Count);
+
+                    // Check to make sure the diagnostics does not include duplicate info.
+                    foreach ((string activityId, string errorMessage) in activityIdAndErrorMessage)
+                    {
+                        Assert.AreEqual(1, Regex.Matches(exceptionToString, activityId).Count);
+                        Assert.AreEqual(1, Regex.Matches(exceptionToString, errorMessage).Count);
+                    }
+                }
+            }
+
+            // Check if the exception message is not growing exponentially
+            Assert.IsTrue(stringLength.Count > 2);
+            for (int i = 0; i < stringLength.Count - 1; i++)
+            {
+                int currLength = stringLength[i];
+                int nextLength = stringLength[i + 1];
+                Assert.IsTrue( nextLength < currLength * 2,
+                    $"The diagnostic string is growing faster than linear. Length: {currLength}, Next Length: {nextLength}");
+            }
+        }
+
         [TestMethod]
         [DataRow(true)]
         [DataRow(false)]

Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/CosmosItemTests.cs

@@ -1667,7 +1667,9 @@ public async Task VerifySessionNotFoundStatistics()
                 }
                 catch (CosmosException cosmosException)
                 {
-                    Assert.IsTrue(cosmosException.Message.Contains("StorePhysicalAddress"), cosmosException.Message);
+                    Assert.IsTrue(cosmosException.Message.Contains("The read session is not available for the input session token."), cosmosException.Message);
+                    string exception = cosmosException.ToString();
+                    Assert.IsTrue(exception.Contains("StorePhysicalAddress"), exception);
                 }
             }
             finally

Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/TransportWrapperTests.cs

@@ -125,8 +125,9 @@ private void ValidateTransportException(ResponseMessage responseMessage)
         {
             Assert.AreEqual(HttpStatusCode.ServiceUnavailable, responseMessage.StatusCode);
             string message = responseMessage.ErrorMessage;
-            Assert.AreEqual(responseMessage.ErrorMessage, responseMessage.CosmosException.Message);
-            Assert.IsTrue(message.Contains("TransportException: A client transport error occurred: The connection failed"), "StoreResult Exception is missing");
+            Assert.AreEqual(message, responseMessage.CosmosException.Message);
+            Assert.IsTrue(message.Contains("ServiceUnavailable (503); Substatus: 0; ActivityId:"));
+            Assert.IsTrue(message.Contains("Reason: (Message: Channel is closed"), "Should contain exception message");
             string diagnostics = responseMessage.Diagnostics.ToString();
             Assert.IsNotNull(diagnostics);
             Assert.IsTrue(diagnostics.Contains("TransportException: A client transport error occurred: The connection failed"));

Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/Utils/TransportClientHelper.cs

@@ -7,11 +7,12 @@ namespace Microsoft.Azure.Cosmos.SDK.EmulatorTests
     using System;
     using System.Collections.Generic;
     using System.Diagnostics;
+    using System.Globalization;
     using System.Text;
     using System.Threading.Tasks;
     using Microsoft.Azure.Cosmos.SDK.EmulatorTests;
     using Microsoft.Azure.Documents;
-
+    using Microsoft.Azure.Documents.Collections;
 
     internal static class TransportClientHelper
     {
@@ -20,24 +21,35 @@ internal static Container GetContainerWithItemTransportException(
             string containerId,
             Guid activityId,
             string transportExceptionSourceDescription)
+        {
+            return GetContainerWithIntercepter(
+                databaseId,
+                containerId,
+                (uri, resourceOperation, request) => TransportClientHelper.ThrowTransportExceptionOnItemOperation(
+                    uri,
+                    resourceOperation,
+                    request,
+                    activityId,
+                    transportExceptionSourceDescription));
+        }
+
+        internal static Container GetContainerWithIntercepter(
+            string databaseId,
+            string containerId,
+            Action<Uri, ResourceOperation, DocumentServiceRequest> interceptor)
         {
             CosmosClient clientWithIntercepter = TestCommon.CreateCosmosClient(
                builder =>
                {
                    builder.WithTransportClientHandlerFactory(transportClient => new TransportClientWrapper(
                        transportClient,
-                       (uri, resourceOperation, request) => TransportClientHelper.ThrowTransportExceptionOnItemOperation(
-                           uri,
-                           resourceOperation,
-                           request,
-                           activityId,
-                           transportExceptionSourceDescription)));
+                       interceptor));
                });
 
             return clientWithIntercepter.GetContainer(databaseId, containerId);
         }
 
-        private static void ThrowTransportExceptionOnItemOperation(
+        public static void ThrowTransportExceptionOnItemOperation(
                 Uri physicalAddress,
                 ResourceOperation resourceOperation,
                 DocumentServiceRequest request,
@@ -60,6 +72,27 @@ private static void ThrowTransportExceptionOnItemOperation(
             }
         }
 
+        public static void ThrowForbiddendExceptionOnItemOperation(
+                Uri physicalAddress,
+                DocumentServiceRequest request,
+                string activityId,
+                string errorMessage)
+        {
+            if (request.ResourceType == ResourceType.Document)
+            {
+                DictionaryNameValueCollection headers = new DictionaryNameValueCollection();
+                headers.Add(HttpConstants.HttpHeaders.ActivityId, activityId.ToString());
+                headers.Add(WFConstants.BackendHeaders.SubStatus, ((int)SubStatusCodes.WriteForbidden).ToString(CultureInfo.InvariantCulture));
+
+                ForbiddenException forbiddenException = new ForbiddenException(
+                    errorMessage,
+                    headers,
+                    physicalAddress);
+
+                throw forbiddenException;
+            }
+        }
+
         private sealed class TransportClientWrapper : TransportClient
         {
             private readonly TransportClient baseClient;

Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/CosmosDiagnosticsUnitTests.cs

@@ -126,14 +126,12 @@ public void ValidateClientSideRequestStatisticsToString()
 
             CosmosClientSideRequestStatistics clientSideRequestStatistics = new CosmosClientSideRequestStatistics(diagnosticsContext);
             string noInfo = clientSideRequestStatistics.ToString();
-            Assert.IsNotNull(noInfo);
+            Assert.AreEqual("Please see CosmosDiagnostics", noInfo);
 
             StringBuilder stringBuilder = new StringBuilder();
             clientSideRequestStatistics.AppendToBuilder(stringBuilder);
             string noInfoStringBuilder = stringBuilder.ToString();
-            Assert.IsNotNull(noInfoStringBuilder);
-
-            Assert.AreEqual(noInfo, noInfoStringBuilder);
+            Assert.AreEqual("Please see CosmosDiagnostics", noInfo);
 
             string id = clientSideRequestStatistics.RecordAddressResolutionStart(new Uri("https://testuri"));
             clientSideRequestStatistics.RecordAddressResolutionEnd(id);
@@ -168,9 +166,7 @@ public void ValidateClientSideRequestStatisticsToString()
                     usingLocalLSN: true));
 
             string statistics = clientSideRequestStatistics.ToString();
-            Assert.IsTrue(statistics.Contains("\"UserAgent\":\"cosmos-netstandard-sdk"));
-            Assert.IsTrue(statistics.Contains("UsingLocalLSN: True, TransportException: null"));
-            Assert.IsTrue(statistics.Contains("AddressResolutionStatistics\",\"StartTimeUtc"));
+            Assert.AreEqual("Please see CosmosDiagnostics", statistics);
         }