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: Adds Summary for Diagnostic message #2732

Merged
merged 15 commits into from
Sep 23, 2021
Merged
Show file tree
Hide file tree
Changes from 3 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
1 change: 1 addition & 0 deletions Microsoft.Azure.Cosmos/src/Tracing/ITraceDatumVisitor.cs
Original file line number Diff line number Diff line change
Expand Up @@ -16,5 +16,6 @@ internal interface ITraceDatumVisitor
void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum);
void Visit(CpuHistoryTraceDatum cpuHistoryTraceDatum);
void Visit(ClientConfigurationTraceDatum clientConfigurationTraceDatum);
void Visit(SummaryDiagnosticsTraceDatum summaryDiagnosticsTraceDatum);
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,164 @@
// ------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
// ------------------------------------------------------------

namespace Microsoft.Azure.Cosmos.Tracing.TraceData
{
using System;
using System.Collections.Generic;
using System.Linq;
using System.Net;
using System.Net.Http;
using Microsoft.Azure.Documents;

internal sealed class SummaryDiagnosticsTraceDatum : TraceDatum
asketagarwal marked this conversation as resolved.
Show resolved Hide resolved
{
private const string TransitTimeEventName = "Transit Time";

public SummaryDiagnosticsTraceDatum(ITrace trace)
{
this.DirectRequestsSummary = new RequestSummary();
this.GatewayRequestsSummary = new GatewayRequestSummary();
this.TotalTimeInMs = trace.Duration.TotalMilliseconds;
this.CollectSummaryFromTraceTree(trace);
}

public double TotalTimeInMs { get; }
public double MaxServiceProcessingTimeInMs { get; private set; }
public double MaxGatewayRequestTimeInMs { get; private set; }
public RequestSummary DirectRequestsSummary { get; }
public GatewayRequestSummary GatewayRequestsSummary { get; }

private void CollectSummaryFromTraceTree(ITrace currentTrace)
{
foreach (object datums in currentTrace.Data.Values)
{
// TODO: Add MaxCpuUsage using CpuHistoryTraceDatum
if (datums is ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
this.AggregateStatsFromStoreResults(clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList);
this.AggregateGatewayStatistics(clientSideRequestStatisticsTraceDatum.HttpResponseStatisticsList);
}
}

foreach (ITrace childTrace in currentTrace.Children)
{
this.CollectSummaryFromTraceTree(childTrace);
}
}

private void AggregateGatewayStatistics(IReadOnlyList<ClientSideRequestStatisticsTraceDatum.HttpResponseStatistics> httpResponseStatisticsList)
{
foreach (ClientSideRequestStatisticsTraceDatum.HttpResponseStatistics httpResponseStatistics in httpResponseStatisticsList)
{
this.GatewayRequestsSummary.RecordHttpResponse(httpResponseStatistics);

if (httpResponseStatistics.Duration.TotalMilliseconds > this.MaxGatewayRequestTimeInMs)
{
this.MaxGatewayRequestTimeInMs = httpResponseStatistics.Duration.TotalMilliseconds;
}
}
}

private void AggregateStatsFromStoreResults(IReadOnlyList<ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics> storeResponseStatisticsList)
{
foreach (ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics storeResponseStatistics in storeResponseStatisticsList)
{
StatusCodes statusCode = storeResponseStatistics.StoreResult.StatusCode;
this.DirectRequestsSummary.RecordStatusCode((int)statusCode);

if (double.TryParse(storeResponseStatistics.StoreResult.BackendRequestDurationInMs, out double backendLatency))
{
if (backendLatency > this.MaxServiceProcessingTimeInMs)
{
this.MaxServiceProcessingTimeInMs = backendLatency;
}
}
}
}

internal override void Accept(ITraceDatumVisitor traceDatumVisitor)
{
traceDatumVisitor.Visit(this);
}

public class RequestSummary
{
public int TotalCalls { get; protected set; }
public int NumberOf429s { get; private set; }
public int NumberOf410s { get; private set; }
public int NumberOf408s { get; private set; }
public int NumberOf449s { get; private set; }
public int NumberOf404s { get; private set; }
public int OtherErrors { get; private set; }
public int SuccessfullCalls { get; private set; }

public void RecordStatusCode(int statusCode)
{
this.TotalCalls++;
if (statusCode >= 200 && statusCode <= 299)
{
this.SuccessfullCalls++;
return;
}

switch ((int)statusCode)
{
case 429:
this.NumberOf429s++;
break;
case 410:
this.NumberOf410s++;
break;
case 408:
this.NumberOf408s++;
break;
case 449:
this.NumberOf449s++;
break;
case 404:
this.NumberOf404s++;
break;
default:
this.OtherErrors++;
break;
}
}
}

public class GatewayRequestSummary : RequestSummary
{
public int NumberOfOperationCancelledExceptions { get; private set; }
public int NumberOfWebExceptions { get; private set; }
public int NumberOfHttpRequestExceptions { get; private set; }
public int OtherExceptions { get; private set; }

public void RecordHttpResponse(ClientSideRequestStatisticsTraceDatum.HttpResponseStatistics httpResponseStatistics)
{
this.TotalCalls++;
if (httpResponseStatistics.Exception != null)
{
switch (httpResponseStatistics.Exception)
{
case OperationCanceledException operationCanceledException:
this.NumberOfOperationCancelledExceptions++;
break;
case WebException webException:
this.NumberOfWebExceptions++;
break;
case HttpRequestException httpRequestException:
this.NumberOfHttpRequestExceptions++;
break;
default:
this.OtherExceptions++;
break;
}
}
else if (httpResponseStatistics.HttpResponseMessage != null)
{
base.RecordStatusCode((int)httpResponseStatistics.HttpResponseMessage.StatusCode);
}
}
}
}
}
118 changes: 116 additions & 2 deletions Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,8 @@ private static class TraceJsonWriter
{
public static void WriteTrace(
IJsonWriter writer,
ITrace trace)
ITrace trace,
bool isRootTrace)
{
if (writer == null)
{
Expand All @@ -34,6 +35,12 @@ public static void WriteTrace(

writer.WriteObjectStart();

if (isRootTrace)
{
writer.WriteFieldName("Summary");
WriteTraceDatum(writer, new SummaryDiagnosticsTraceDatum(trace));
}

writer.WriteFieldName("name");
writer.WriteStringValue(trace.Name);

Expand Down Expand Up @@ -90,7 +97,9 @@ public static void WriteTrace(

foreach (ITrace child in trace.Children)
{
WriteTrace(writer, child);
WriteTrace(writer,
child,
isRootTrace: false);
}

writer.WriteArrayEnd();
Expand Down Expand Up @@ -376,6 +385,111 @@ public void Visit(ClientConfigurationTraceDatum clientConfigurationTraceDatum)
}
}

public void Visit(SummaryDiagnosticsTraceDatum summaryDiagnosticsTraceDatum)
{
this.jsonWriter.WriteObjectStart();

this.jsonWriter.WriteFieldName("TotalTimeMs");
this.jsonWriter.WriteNumber64Value(summaryDiagnosticsTraceDatum.TotalTimeInMs);

if (summaryDiagnosticsTraceDatum.DirectRequestsSummary.TotalCalls > 0)
{
this.jsonWriter.WriteFieldName("Direct");
this.jsonWriter.WriteObjectStart();
this.WriteRequestSummaryObject(summaryDiagnosticsTraceDatum.DirectRequestsSummary);
this.jsonWriter.WriteObjectEnd();

this.jsonWriter.WriteFieldName("MaxBELatencyMs");
this.jsonWriter.WriteNumber64Value(summaryDiagnosticsTraceDatum.MaxServiceProcessingTimeInMs);
}

if (summaryDiagnosticsTraceDatum.GatewayRequestsSummary.TotalCalls > 0)
{
this.jsonWriter.WriteFieldName("Gateway");
this.jsonWriter.WriteObjectStart();
this.WriteGatewayRequestSummaryObject(summaryDiagnosticsTraceDatum.GatewayRequestsSummary);
this.jsonWriter.WriteObjectEnd();

this.jsonWriter.WriteFieldName("MaxGatewayRequestTimeInMs");
this.jsonWriter.WriteNumber64Value(summaryDiagnosticsTraceDatum.MaxGatewayRequestTimeInMs);
}

this.jsonWriter.WriteObjectEnd();
}

private void WriteGatewayRequestSummaryObject(SummaryDiagnosticsTraceDatum.GatewayRequestSummary gatewayRequestSummary)
{
this.WriteRequestSummaryObject(gatewayRequestSummary);
if (gatewayRequestSummary.NumberOfOperationCancelledExceptions > 0)
{
this.jsonWriter.WriteFieldName("OperationCancelledException");
this.jsonWriter.WriteNumber64Value(gatewayRequestSummary.NumberOfOperationCancelledExceptions);
}

if (gatewayRequestSummary.NumberOfWebExceptions > 0)
{
this.jsonWriter.WriteFieldName("WebExceptions");
this.jsonWriter.WriteNumber64Value(gatewayRequestSummary.NumberOfWebExceptions);
}

if (gatewayRequestSummary.NumberOfHttpRequestExceptions > 0)
{
this.jsonWriter.WriteFieldName("HttpRequestExceptions");
this.jsonWriter.WriteNumber64Value(gatewayRequestSummary.NumberOfHttpRequestExceptions);
}

if (gatewayRequestSummary.OtherExceptions > 0)
{
this.jsonWriter.WriteFieldName("Other Exceptions");
this.jsonWriter.WriteNumber64Value(gatewayRequestSummary.OtherExceptions);
}
}

private void WriteRequestSummaryObject(SummaryDiagnosticsTraceDatum.RequestSummary requestSummary)
{
if (requestSummary.SuccessfullCalls > 0)
{
this.jsonWriter.WriteFieldName("SuccessfullCalls");
this.jsonWriter.WriteNumber64Value(requestSummary.SuccessfullCalls);
}

if (requestSummary.NumberOf404s > 0)
{
this.jsonWriter.WriteFieldName("404");
this.jsonWriter.WriteNumber64Value(requestSummary.NumberOf404s);
}

if (requestSummary.NumberOf408s > 0)
{
this.jsonWriter.WriteFieldName("408");
this.jsonWriter.WriteNumber64Value(requestSummary.NumberOf408s);
}

if (requestSummary.NumberOf410s > 0)
{
this.jsonWriter.WriteFieldName("410");
this.jsonWriter.WriteNumber64Value(requestSummary.NumberOf410s);
}

if (requestSummary.NumberOf429s > 0)
{
this.jsonWriter.WriteFieldName("429");
this.jsonWriter.WriteNumber64Value(requestSummary.NumberOf429s);
}

if (requestSummary.NumberOf449s > 0)
{
this.jsonWriter.WriteFieldName("449");
this.jsonWriter.WriteNumber64Value(requestSummary.NumberOf449s);
}

if (requestSummary.OtherErrors > 0)
{
this.jsonWriter.WriteFieldName("OtherStatusCodes");
this.jsonWriter.WriteNumber64Value(requestSummary.OtherErrors);
}
}

public void Visit(StoreResult storeResult)
{
this.jsonWriter.WriteObjectStart();
Expand Down
14 changes: 14 additions & 0 deletions Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceTextWriter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -497,6 +497,20 @@ public void Visit(ClientConfigurationTraceDatum clientConfigurationTraceDatum)
this.toStringValue = stringBuilder.ToString();
}

public void Visit(SummaryDiagnosticsTraceDatum summaryDiagnosticsTraceDatum)
{
StringBuilder stringBuilder = new StringBuilder();
stringBuilder.AppendLine("Summary Diagnostics");
stringBuilder.AppendLine("Direct Requests:");
stringBuilder.AppendLine($"TotalTimeInMs: {summaryDiagnosticsTraceDatum.TotalTimeInMs}");
stringBuilder.AppendLine($"MaxBELatencyInMs: {summaryDiagnosticsTraceDatum.MaxServiceProcessingTimeInMs}");

stringBuilder.AppendLine("Gateway Requests:");
stringBuilder.AppendLine($"MaxGatewayRequestTimeInMs: {summaryDiagnosticsTraceDatum.MaxGatewayRequestTimeInMs}");

this.toStringValue = stringBuilder.ToString();
}

public override string ToString()
{
return this.toStringValue;
Expand Down
4 changes: 3 additions & 1 deletion Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,9 @@ public static void WriteTrace(
IJsonWriter writer,
ITrace trace)
{
TraceJsonWriter.WriteTrace(writer, trace);
TraceJsonWriter.WriteTrace(writer,
trace,
isRootTrace: true);
}

public static string TraceToText(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,9 @@
└── Create Trace(00000000-0000-0000-0000-000000000000) Batch-Component MemberName@FilePath:42 12:00:00:000 0.00 milliseconds
]]></Text>
<Json><![CDATA[{
"Summary": {
"TotalTimeMs": 0
},
"name": "ExecuteAsync",
"id": "00000000-0000-0000-0000-000000000000",
"caller info": {
Expand Down
Loading