Skip to content

Commit

Permalink
CosmosException: Adds diagnostics to message for 408, 500, 503, 404/1…
Browse files Browse the repository at this point in the history 
…002 scenarios (#2719)

This change is being done because most users are not capturing the diagnostics for these exceptions. It is not possible to root cause or trouble shoot these issues without the diagnostics. This requires the customer to make code changes to get the additional info which causes the issue to persist for a long time.
  • Loading branch information
@j82w
j82w authored Sep 10, 2021
1 parent 2b2988e commit 33f3ec5
Show file tree
Hide file tree
Showing 7 changed files with 188 additions and 31 deletions.
60 changes: 49 additions & 11 deletions Microsoft.Azure.Cosmos/src/Resource/CosmosExceptions/CosmosException.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ namespace Microsoft.Azure.Cosmos
public class CosmosException : Exception
{
private readonly string stackTrace;
private readonly Lazy<string> lazyMessage;

internal CosmosException(
HttpStatusCode statusCode,
Expand All @@ -26,17 +27,21 @@ internal CosmosException(
ITrace trace,
Error error,
Exception innerException)
: base(CosmosException.GetMessageHelper(
statusCode,
headers,
message), innerException)
// The message is overridden. Base exception does not have CTOR for just innerException and the property is not virtual
: base(string.Empty, innerException)
{
this.ResponseBody = message;
this.stackTrace = stackTrace;
this.StatusCode = statusCode;
this.Headers = headers ?? new Headers();
this.Error = error;
this.Trace = trace;
this.Diagnostics = new CosmosTraceDiagnostics(this.Trace ?? NoOpTrace.Singleton);
this.lazyMessage = new Lazy<string>(() => CosmosException.GetMessageHelper(
statusCode,
this.Headers,
this.ResponseBody,
this.Diagnostics));
}

/// <summary>
Expand All @@ -59,6 +64,7 @@ public CosmosException(
this.StatusCode = statusCode;
this.ResponseBody = message;
this.Trace = NoOpTrace.Singleton;
this.lazyMessage = new Lazy<string>(() => message);
this.Headers = new Headers()
{
SubStatusCode = (SubStatusCodes)subStatusCode,
Expand All @@ -71,6 +77,9 @@ public CosmosException(
}
}

/// <inheritdoc/>
public override string Message => this.lazyMessage.Value;

/// <summary>
/// The body of the cosmos response message as a string
/// </summary>
Expand Down Expand Up @@ -117,7 +126,7 @@ public CosmosException(
/// <summary>
/// Gets the diagnostics for the request
/// </summary>
public virtual CosmosDiagnostics Diagnostics => new CosmosTraceDiagnostics(this.Trace ?? NoOpTrace.Singleton);
public virtual CosmosDiagnostics Diagnostics { get; }

/// <inheritdoc/>
public override string StackTrace
Expand Down Expand Up @@ -189,32 +198,61 @@ internal ResponseMessage ToCosmosResponseMessage(RequestMessage request)
private static string GetMessageHelper(
HttpStatusCode statusCode,
Headers headers,
string responseBody)
string responseBody,
CosmosDiagnostics diagnostics)
{
StringBuilder stringBuilder = new StringBuilder();

CosmosException.AppendMessageWithoutDiagnostics(
stringBuilder,
statusCode,
headers,
responseBody);

// Include the diagnostics for exceptions where it is critical
// to root cause failures.
if (statusCode == HttpStatusCode.RequestTimeout
|| statusCode == HttpStatusCode.InternalServerError
|| statusCode == HttpStatusCode.ServiceUnavailable
|| (statusCode == HttpStatusCode.NotFound && headers.SubStatusCode == SubStatusCodes.ReadSessionNotAvailable))
{
stringBuilder.Append("; Diagnostics:");
stringBuilder.Append(diagnostics.ToString());
}

return stringBuilder.ToString();
}

private static void AppendMessageWithoutDiagnostics(
StringBuilder stringBuilder,
HttpStatusCode statusCode,
Headers headers,
string responseBody)
{
stringBuilder.Append($"Response status code does not indicate success: ");
stringBuilder.Append($"{statusCode} ({(int)statusCode})");
stringBuilder.Append("; Substatus: ");
stringBuilder.Append(headers?.SubStatusCodeLiteral ?? "0" );
stringBuilder.Append(headers?.SubStatusCodeLiteral ?? "0");
stringBuilder.Append("; ActivityId: ");
stringBuilder.Append(headers?.ActivityId ?? string.Empty);
stringBuilder.Append("; Reason: (");
stringBuilder.Append(responseBody ?? string.Empty);
stringBuilder.Append(");");

return stringBuilder.ToString();
}

private string ToStringHelper(
StringBuilder stringBuilder)
StringBuilder stringBuilder)
{
if (stringBuilder == null)
{
throw new ArgumentNullException(nameof(stringBuilder));
}

stringBuilder.Append(this.Message);
CosmosException.AppendMessageWithoutDiagnostics(
stringBuilder,
this.StatusCode,
this.Headers,
this.ResponseBody);
stringBuilder.AppendLine();

if (this.InnerException != null)
Expand Down
10 changes: 9 additions & 1 deletion Microsoft.Azure.Cosmos/src/Resource/CosmosExceptions/CosmosOperationCanceledException.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ namespace Microsoft.Azure.Cosmos
public class CosmosOperationCanceledException : OperationCanceledException
{
private readonly OperationCanceledException originalException;
private readonly Lazy<string> lazyMessage;

/// <summary>
/// Create an instance of CosmosOperationCanceledException
Expand All @@ -30,6 +31,7 @@ public CosmosOperationCanceledException(
{
this.originalException = originalException ?? throw new ArgumentNullException(nameof(originalException));
this.Diagnostics = diagnostics ?? throw new ArgumentNullException(nameof(diagnostics));
this.lazyMessage = this.CreateLazyMessage();
}

internal CosmosOperationCanceledException(
Expand All @@ -45,6 +47,7 @@ internal CosmosOperationCanceledException(

trace.AddDatum("Operation Cancelled Exception", originalException);
this.Diagnostics = new CosmosTraceDiagnostics(trace);
this.lazyMessage = this.CreateLazyMessage();
}

/// <inheritdoc/>
Expand All @@ -55,7 +58,7 @@ public override string Source
}

/// <inheritdoc/>
public override string Message => this.originalException.Message;
public override string Message => this.lazyMessage.Value;

/// <inheritdoc/>
public override string StackTrace => this.originalException.StackTrace;
Expand Down Expand Up @@ -86,5 +89,10 @@ public override string ToString()
{
return $"{this.originalException} {Environment.NewLine}CosmosDiagnostics: {this.Diagnostics}";
}

private Lazy<string> CreateLazyMessage()
{
return new Lazy<string>(() => $"{this.originalException.Message} {Environment.NewLine}CosmosDiagnostics: {this.Diagnostics}");
}
}
}
26 changes: 25 additions & 1 deletion Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/CosmosItemTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ namespace Microsoft.Azure.Cosmos.SDK.EmulatorTests
using PartitionKey = Documents.PartitionKey;
using static Microsoft.Azure.Cosmos.SDK.EmulatorTests.TransportClientHelper;
using System.Reflection;
using System.Text.RegularExpressions;

[TestClass]
public class CosmosItemTests : BaseCosmosClientHelper
Expand Down Expand Up @@ -88,6 +89,7 @@ public async Task CreateDropItemWithInvalidIdCharactersTest()
{
string message = ce.ToString();
Assert.IsNotNull(message);
CosmosItemTests.ValidateCosmosException(ce);
}

// Get a container reference that use RID values
Expand Down Expand Up @@ -216,6 +218,7 @@ public async Task NegativeCreateItemTest()
Assert.IsTrue(exception.StartsWith("Microsoft.Azure.Cosmos.CosmosException : Response status code does not indicate success: Forbidden (403); Substatus: 999999; "));
string diagnostics = ce.Diagnostics.ToString();
Assert.IsTrue(diagnostics.Contains("999999"));
CosmosItemTests.ValidateCosmosException(ce);
}
}

Expand Down Expand Up @@ -351,6 +354,7 @@ public async Task CreateDropItemPartitionKeyNotInTypeTest()
catch (CosmosException ex)
{
Assert.AreEqual(HttpStatusCode.NotFound, ex.StatusCode);
CosmosItemTests.ValidateCosmosException(ex);
}
}

Expand Down Expand Up @@ -391,6 +395,7 @@ public async Task CreateDropItemMultiPartPartitionKeyTest()
catch (CosmosException ex)
{
Assert.AreEqual(HttpStatusCode.NotFound, ex.StatusCode);
CosmosItemTests.ValidateCosmosException(ex);
}
}

Expand Down Expand Up @@ -1710,7 +1715,7 @@ await containerInternal.PatchItemAsync<ToDoActivity>(
Assert.AreEqual(HttpStatusCode.NotFound, ex.StatusCode);
Assert.IsTrue(ex.Message.Contains("Resource Not Found"));
Assert.IsTrue(ex.Message.Contains("https://aka.ms/cosmosdb-tsg-not-found"));

CosmosItemTests.ValidateCosmosException(ex);
}

// adding a child when parent / ancestor does not exist - 400 BadRequest response
Expand All @@ -1727,6 +1732,7 @@ await containerInternal.PatchItemAsync<ToDoActivity>(
{
Assert.AreEqual(HttpStatusCode.BadRequest, ex.StatusCode);
Assert.IsTrue(ex.Message.Contains("Add Operation only support adding a leaf node of an existing node(array or object), no path found beyond: 'nonExistentParent'"), ex.Message);
CosmosItemTests.ValidateCosmosException(ex);
}

// precondition failure - 412 response
Expand All @@ -1749,6 +1755,7 @@ await containerInternal.PatchItemAsync<ToDoActivity>(
{
Assert.AreEqual(HttpStatusCode.PreconditionFailed, ex.StatusCode);
Assert.IsTrue(ex.Message.Contains("One of the specified pre-condition is not met"));
CosmosItemTests.ValidateCosmosException(ex);
}
}

Expand Down Expand Up @@ -2925,6 +2932,23 @@ private static async Task VerifyQueryToManyExceptionAsync(
}
}

private static void ValidateCosmosException(CosmosException exception)
{
if(exception.StatusCode == HttpStatusCode.RequestTimeout ||
exception.StatusCode == HttpStatusCode.InternalServerError ||
exception.StatusCode == HttpStatusCode.ServiceUnavailable)
{
Assert.IsTrue(exception.Message.Contains("Diagnostics"));
}
else
{
Assert.IsFalse(exception.Message.Contains("Diagnostics"));
}

string toString = exception.ToString();
Assert.AreEqual(1, Regex.Matches(toString, "Client Configuration").Count, $"The Cosmos Diagnostics does not exists or multiple instance are in the ToString(). {toString}");
}

private static async Task ExecuteQueryAsync(Container container, HttpStatusCode expected)
{
FeedIterator iterator = container.GetItemQueryStreamIterator("select * from r");
Expand Down
10 changes: 6 additions & 4 deletions ...osmos/tests/Microsoft.Azure.Cosmos.EmulatorTests/CosmosOperationCanceledExceptionTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -101,7 +101,9 @@ await container.CreateItemAsync<ToDoActivity>(
string diagnostics = ce.Diagnostics.ToString();
string toString = ce.ToString();
Assert.IsTrue(toString.Contains(diagnostics));
Assert.IsTrue(toString.Contains(message));
Assert.IsTrue(message.Contains(diagnostics));
string messageWithoutDiagnostics = message.Substring(0, message.IndexOf(Environment.NewLine)).Trim();
Assert.IsTrue(toString.Contains(messageWithoutDiagnostics));
}

try
Expand All @@ -115,13 +117,13 @@ await container.CreateItemAsync<ToDoActivity>(
}
catch (CosmosOperationCanceledException ce)
{
Assert.IsNotNull(ce);
string message = ce.Message;
string diagnostics = ce.Diagnostics.ToString();
Assert.IsTrue(diagnostics.Contains("The operation was canceled."));
string toString = ce.ToString();
Assert.IsTrue(toString.Contains(diagnostics));
Assert.IsTrue(toString.Contains(message));
Assert.IsTrue(message.Contains(diagnostics));
string messageWithoutDiagnostics = message.Substring(0, message.IndexOf(Environment.NewLine)).Trim();
Assert.IsTrue(toString.Contains(messageWithoutDiagnostics));
}
}
}
Expand Down
20 changes: 10 additions & 10 deletions ...ure.Cosmos/tests/Microsoft.Azure.Cosmos.Performance.Tests/Contracts/BenchmarkResults.json
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,11 +11,11 @@
"MockedItemBenchmark.DeleteItemExists;[Type=OfTWithClientTelemetryEnabled]": 39840.0,
"MockedItemBenchmark.DeleteItemExists;[Type=OfTWithDiagnosticsToString]": 70924.0,
"MockedItemBenchmark.DeleteItemExists;[Type=Stream]": 29872.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfT]": 48270.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTCustom]": 48264.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTWithClientTelemetryEnabled]": 51146.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTWithDiagnosticsToString]": 82144.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=Stream]": 43180.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfT]": 42786.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTCustom]": "43144.0",
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTWithClientTelemetryEnabled]": 44694.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=OfTWithDiagnosticsToString]": 77632.0,
"MockedItemBenchmark.DeleteItemNotExists;[Type=Stream]": 37610.0,
"MockedItemBenchmark.ReadFeed;[Type=OfT]": 560692.0,
"MockedItemBenchmark.ReadFeed;[Type=OfTCustom]": 571334.0,
"MockedItemBenchmark.ReadFeed;[Type=OfTWithClientTelemetryEnabled]": 565196.0,
Expand All @@ -26,11 +26,11 @@
"MockedItemBenchmark.ReadItemExists;[Type=OfTWithClientTelemetryEnabled]": 44440.0,
"MockedItemBenchmark.ReadItemExists;[Type=OfTWithDiagnosticsToString]": 76298.0,
"MockedItemBenchmark.ReadItemExists;[Type=Stream]": 34464.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfT]": 52826.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTCustom]": 52864.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTWithClientTelemetryEnabled]": 55754.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTWithDiagnosticsToString]": 87640.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=Stream]": 47994.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfT]": 47408.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTCustom]": 47406.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTWithClientTelemetryEnabled]": 49298.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=OfTWithDiagnosticsToString]": 81450.0,
"MockedItemBenchmark.ReadItemNotExists;[Type=Stream]": 42246.0,
"MockedItemBenchmark.UpdateItem;[Type=OfT]": 45542.0,
"MockedItemBenchmark.UpdateItem;[Type=OfTCustom]": 45532.0,
"MockedItemBenchmark.UpdateItem;[Type=OfTWithClientTelemetryEnabled]": 48372.0,
Expand Down
16 changes: 14 additions & 2 deletions Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Contracts/DotNetSDKAPI.json
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2446,9 +2446,11 @@
"Attributes": [],
"MethodInfo": "Microsoft.Azure.Cosmos.CosmosDiagnostics Diagnostics;CanRead:True;CanWrite:False;Microsoft.Azure.Cosmos.CosmosDiagnostics get_Diagnostics();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"Microsoft.Azure.Cosmos.CosmosDiagnostics get_Diagnostics()": {
"Microsoft.Azure.Cosmos.CosmosDiagnostics get_Diagnostics()[System.Runtime.CompilerServices.CompilerGeneratedAttribute()]": {
"Type": "Method",
"Attributes": [],
"Attributes": [
"CompilerGeneratedAttribute"
],
"MethodInfo": "Microsoft.Azure.Cosmos.CosmosDiagnostics get_Diagnostics();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"Microsoft.Azure.Cosmos.Headers get_Headers()[System.Runtime.CompilerServices.CompilerGeneratedAttribute()]": {
Expand Down Expand Up @@ -2495,6 +2497,11 @@
"Attributes": [],
"MethodInfo": "System.String get_ActivityId();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"System.String get_Message()": {
"Type": "Method",
"Attributes": [],
"MethodInfo": "System.String get_Message();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"System.String get_ResponseBody()[System.Runtime.CompilerServices.CompilerGeneratedAttribute()]": {
"Type": "Method",
"Attributes": [
Expand All @@ -2507,6 +2514,11 @@
"Attributes": [],
"MethodInfo": "System.String get_StackTrace();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"System.String Message": {
"Type": "Property",
"Attributes": [],
"MethodInfo": "System.String Message;CanRead:True;CanWrite:False;System.String get_Message();IsAbstract:False;IsStatic:False;IsVirtual:True;IsGenericMethod:False;IsConstructor:False;IsFinal:False;"
},
"System.String ResponseBody": {
"Type": "Property",
"Attributes": [],
Expand Down
Loading

0 comments on commit 33f3ec5

Please sign in to comment.