Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 4 commits into from
May 19, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -236,6 +236,7 @@ private string ToStringHelper(

if (this.Diagnostics != null)
{
stringBuilder.Append("--- Cosmos Diagnostics ---");
j82w marked this conversation as resolved.
Show resolved Hide resolved
stringBuilder.Append(this.Diagnostics);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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,
j82w marked this conversation as resolved.
Show resolved Hide resolved
$"The diagnostic string is growing faster than linear. Length: {currLength}, Next Length: {nextLength}");
}
}

[TestMethod]
[DataRow(true)]
[DataRow(false)]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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"));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
{
Expand All @@ -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,
Expand All @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down Expand Up @@ -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);
}


Expand Down