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 GetStartTimeUtc and GetFailedRequestCount #3268

Merged
merged 31 commits into from
Jul 13, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
31 commits
Select commit Hold shift + click to select a range
32f9e94
Get Failed count and GetStartTime and TraceSummary implemented
SchintaMicrosoft Jun 14, 2022
649919b
Trace summary null check added
SchintaMicrosoft Jun 14, 2022
2eb430f
Merge branch 'master' into users/schinta/2848FailedRequestCount
ealsur Jun 14, 2022
82e6aaf
Changed new me,bers from abstract to virutal
SchintaMicrosoft Jun 17, 2022
014276c
Merge branch 'users/schinta/2848FailedRequestCount' of https://github…
SchintaMicrosoft Jun 17, 2022
b6b1a38
Contracts Updated
SchintaMicrosoft Jun 17, 2022
0058ec0
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jun 20, 2022
217659f
Revert "Contracts Updated"
SchintaMicrosoft Jun 21, 2022
c462108
Merge branch 'users/schinta/2848FailedRequestCount' of https://github…
SchintaMicrosoft Jun 21, 2022
c2bdeb0
ContractsUpdated
SchintaMicrosoft Jun 22, 2022
24cc62e
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jun 22, 2022
1ad3919
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jun 23, 2022
96402d6
Contracts updated.
SchintaMicrosoft Jun 23, 2022
ad01380
Merge branch 'master' into users/schinta/2848FailedRequestCount
ealsur Jun 27, 2022
cc22234
Merge branch 'master' into users/schinta/2848FailedRequestCount
ealsur Jun 27, 2022
3e510ad
Merge branch 'master' into users/schinta/2848FailedRequestCount
ealsur Jun 28, 2022
7c3cd70
Comments Resolved
SchintaMicrosoft Jun 29, 2022
f0b899b
Merge branch 'users/schinta/2848FailedRequestCount' of https://github…
SchintaMicrosoft Jun 29, 2022
bcbadf9
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jun 29, 2022
64224b3
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jun 30, 2022
11d65a0
Comments Resolved for getstarttime and failedcount
SchintaMicrosoft Jul 6, 2022
7d8ee61
Merge branch 'users/schinta/2848FailedRequestCount' of https://github…
SchintaMicrosoft Jul 6, 2022
e6e6327
Comments Resolved for GetStartTime
SchintaMicrosoft Jul 6, 2022
1acab56
TraceSummary changed as Internal
SchintaMicrosoft Jul 7, 2022
a7edfe9
Trace Summary condition added
SchintaMicrosoft Jul 7, 2022
2a3c819
Updated Contracts
SchintaMicrosoft Jul 8, 2022
402a6e4
Merge branch 'master' into users/schinta/2848FailedRequestCount
SchintaMicrosoft Jul 8, 2022
974565e
Merge branch 'master' into users/schinta/2848FailedRequestCount
FabianMeiswinkel Jul 11, 2022
1b537c9
Exttra Space removed
SchintaMicrosoft Jul 12, 2022
ffe99bd
Merge branch 'users/schinta/2848FailedRequestCount' of https://github…
SchintaMicrosoft Jul 12, 2022
87828fb
Merge branch 'master' into users/schinta/2848FailedRequestCount
ealsur Jul 13, 2022
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 @@ -86,5 +86,17 @@ public override string ToString()

return stringWriter.ToString();
}

#if SDKPROJECTREF
public override DateTime? GetStartTimeUtc()
{
return this.coreDiagnostics.GetStartTimeUtc();
}
public override int GetFailedRequestCount()
{
return this.coreDiagnostics.GetFailedRequestCount();
ealsur marked this conversation as resolved.
Show resolved Hide resolved
}
#endif

}
}
}
20 changes: 20 additions & 0 deletions Microsoft.Azure.Cosmos/src/Diagnostics/CosmosDiagnostics.cs
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,26 @@ public virtual TimeSpan GetClientElapsedTime()
throw new NotImplementedException($"CosmosDiagnostics.GetElapsedTime");
}

/// <summary>
SchintaMicrosoft marked this conversation as resolved.
Show resolved Hide resolved
/// This represents the start time of the request.
/// </summary>
/// <returns>This returns the start time of the request.</returns>
public virtual DateTime? GetStartTimeUtc()
{
// Default implementation avoids breaking change for users upgrading.
throw new NotImplementedException($"{nameof(CosmosDiagnostics)}.{nameof(GetStartTimeUtc)})");
}

/// <summary>
/// This represents the count of failed requests.
/// </summary>
/// <returns>The count of failed requests with cosmos service.</returns>
public virtual int GetFailedRequestCount()
{
// Default implementation avoids breaking change for users upgrading.
throw new NotImplementedException($"{nameof(CosmosDiagnostics)}.{nameof(GetFailedRequestCount)}");
}

/// <summary>
/// Gets the string field <see cref="CosmosDiagnostics"/> instance in the Azure CosmosDB database service.
/// </summary>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -98,5 +98,25 @@ private ReadOnlyMemory<byte> WriteTraceToJsonWriter(JsonSerializationFormat json
TraceWriter.WriteTrace(jsonTextWriter, this.Value);
return jsonTextWriter.GetResult();
}

public override DateTime? GetStartTimeUtc()
{
if (this.Value == null || this.Value.StartTime == null)
{
return null;
}

return this.Value.StartTime;
}

public override int GetFailedRequestCount()
{
if (this.Value == null || this.Value.Summary == null)
{
return 0;
}

return this.Value.Summary.GetFailedCount();
ealsur marked this conversation as resolved.
Show resolved Hide resolved
}
}
}
}
38 changes: 17 additions & 21 deletions Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
//------------------------------------------------------------
//------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
//------------------------------------------------------------

Expand Down Expand Up @@ -47,33 +47,29 @@ await this.cosmosAuthorization.AddAuthorizationHeaderAsync(
HttpConstants.HttpMethods.Get,
AuthorizationTokenType.PrimaryMasterKey);

IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
SchintaMicrosoft marked this conversation as resolved.
Show resolved Hide resolved
try
using (ITrace trace = Trace.GetRootTrace("Account Read", TraceComponent.Transport, TraceLevel.Info))
{
using (HttpResponseMessage responseMessage = await this.httpClient.GetAsync(
uri: serviceEndpoint,
additionalHeaders: headers,
resourceType: ResourceType.DatabaseAccount,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRead.Instance,
clientSideRequestStatistics: stats,
cancellationToken: this.cancellationToken))
IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace.Summary);

try
{
using (HttpResponseMessage responseMessage = await this.httpClient.GetAsync(
uri: serviceEndpoint,
additionalHeaders: headers,
resourceType: ResourceType.DatabaseAccount,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRead.Instance,
clientSideRequestStatistics: stats,
cancellationToken: default))
using (DocumentServiceResponse documentServiceResponse = await ClientExtensions.ParseResponseAsync(responseMessage))
{
SchintaMicrosoft marked this conversation as resolved.
Show resolved Hide resolved
return CosmosResource.FromStream<AccountProperties>(documentServiceResponse);
}
}
}
catch (ObjectDisposedException) when (this.cancellationToken.IsCancellationRequested)
{
throw new OperationCanceledException($"Client is being disposed for {serviceEndpoint} at {DateTime.UtcNow}, cancelling further operations.");
}
catch (OperationCanceledException ex)
// this is the DocumentClient token, which only gets cancelled upon disposal
when (!this.cancellationToken.IsCancellationRequested)
{
// Catch Operation Cancelled Exception and convert to Timeout 408 if the user did not cancel it.
using (ITrace trace = Trace.GetRootTrace("Account Read Exception", TraceComponent.Transport, TraceLevel.Info))
catch (ObjectDisposedException) when (this.cancellationToken.IsCancellationRequested)
{
throw new OperationCanceledException($"Client is being disposed for {serviceEndpoint} at {DateTime.UtcNow}, cancelling further operations.");
}
catch (OperationCanceledException ex)
{
trace.AddDatum("Client Side Request Stats", stats);
throw CosmosExceptionFactory.CreateRequestTimeoutException(
Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ internal async Task<ResponseMessage> ProcessMessageAsync(

DocumentServiceRequest serviceRequest = request.ToDocumentServiceRequest();

ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, request.Trace.Summary);
serviceRequest.RequestContext.ClientRequestStatistics = clientSideRequestStatisticsTraceDatum;

//TODO: extrace auth into a separate handler
Expand Down
23 changes: 11 additions & 12 deletions Microsoft.Azure.Cosmos/src/Routing/ClientCollectionCache.cs
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ internal class ClientCollectionCache : CollectionCache
public ClientCollectionCache(
ISessionContainer sessionContainer,
IStoreModel storeModel,
ICosmosAuthorizationTokenProvider tokenProvider,
SchintaMicrosoft marked this conversation as resolved.
Show resolved Hide resolved
ICosmosAuthorizationTokenProvider tokenProvider,
IRetryPolicyFactory retryPolicy)
{
this.storeModel = storeModel ?? throw new ArgumentNullException("storeModel");
Expand All @@ -35,8 +35,8 @@ public ClientCollectionCache(
this.sessionContainer = sessionContainer;
}

protected override Task<ContainerProperties> GetByRidAsync(string apiVersion,
string collectionRid,
protected override Task<ContainerProperties> GetByRidAsync(string apiVersion,
string collectionRid,
ITrace trace,
IClientSideRequestStatistics clientSideRequestStatistics,
CancellationToken cancellationToken)
Expand All @@ -46,16 +46,16 @@ protected override Task<ContainerProperties> GetByRidAsync(string apiVersion,
this.sessionContainer, this.retryPolicy.GetRequestPolicy());
return TaskHelper.InlineIfPossible(
() => this.ReadCollectionAsync(
PathsHelper.GeneratePath(ResourceType.Collection, collectionRid, false),
retryPolicyInstance,
PathsHelper.GeneratePath(ResourceType.Collection, collectionRid, false),
retryPolicyInstance,
trace,
clientSideRequestStatistics,
clientSideRequestStatistics,
cancellationToken),
retryPolicyInstance,
cancellationToken);
}

protected override Task<ContainerProperties> GetByNameAsync(string apiVersion,
protected override Task<ContainerProperties> GetByNameAsync(string apiVersion,
string resourceAddress,
ITrace trace,
IClientSideRequestStatistics clientSideRequestStatistics,
Expand Down Expand Up @@ -150,7 +150,7 @@ private async Task<ContainerProperties> ResolveCollectionWithSessionContainerCle
ContainerProperties properties = await resolveContainerProvider();

if (this.sessionContainer != null &&
previouslyResolvedCollectionRid != null &&
previouslyResolvedCollectionRid != null &&
previouslyResolvedCollectionRid != properties.ResourceId)
{
this.sessionContainer.ClearTokenByResourceId(previouslyResolvedCollectionRid);
Expand All @@ -167,7 +167,7 @@ private async Task<ContainerProperties> ReadCollectionAsync(
CancellationToken cancellationToken)
{
using (ITrace childTrace = trace.StartChild("Read Collection", TraceComponent.Transport, TraceLevel.Info))
{
{
cancellationToken.ThrowIfCancellationRequested();

RequestNameValueCollection headers = new RequestNameValueCollection();
Expand All @@ -180,8 +180,7 @@ private async Task<ContainerProperties> ReadCollectionAsync(
{
headers.XDate = Rfc1123DateTimeCache.UtcNow();

request.RequestContext.ClientRequestStatistics =
clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace.Summary);
if (clientSideRequestStatistics == null)
{
childTrace.AddDatum(
Expand Down Expand Up @@ -221,4 +220,4 @@ await this.storeModel.ProcessMessageAsync(request))
}
}
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -316,7 +316,7 @@ private async Task<DocumentServiceResponse> ExecutePartitionKeyRangeReadChangeFe
}

request.Headers[HttpConstants.HttpHeaders.Authorization] = authorizationToken;
request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace.Summary);
if (clientSideRequestStatistics == null)
{
childTrace.AddDatum("Client Side Request Stats", request.RequestContext.ClientRequestStatistics);
Expand Down
5 changes: 5 additions & 0 deletions Microsoft.Azure.Cosmos/src/Tracing/ITrace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,11 @@ interface ITrace : IDisposable
/// Gets the component that governs this trace.
/// </summary>
TraceComponent Component { get; }

/// <summary>
/// Gets the summary of this trace.
/// </summary>
TraceSummary Summary { get; }

/// <summary>
/// Gets the parent node of this trace.
Expand Down
2 changes: 2 additions & 0 deletions Microsoft.Azure.Cosmos/src/Tracing/NoOpTrace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,8 @@ private NoOpTrace()

public TraceLevel Level => default;

public TraceSummary Summary => default;

public TraceComponent Component => default;

public ITrace Parent => null;
Expand Down
14 changes: 10 additions & 4 deletions Microsoft.Azure.Cosmos/src/Tracing/Trace.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,8 @@ private Trace(
TraceLevel level,
TraceComponent component,
Trace parent,
ISet<(string, Uri)> regionContactedInternal)
ISet<(string, Uri)> regionContactedInternal,
TraceSummary summary)
{
this.Name = name ?? throw new ArgumentNullException(nameof(name));
this.Id = Guid.NewGuid();
Expand All @@ -38,6 +39,7 @@ private Trace(
this.data = new Lazy<Dictionary<string, object>>();

this.regionContactedInternal = regionContactedInternal;
this.Summary = summary ?? throw new ArgumentNullException(nameof(summary));
}

public string Name { get; }
Expand All @@ -52,6 +54,8 @@ private Trace(

public TraceComponent Component { get; }

public TraceSummary Summary { get; }

public ITrace Parent { get; }

public IReadOnlyList<ITrace> Children => this.children;
Expand Down Expand Up @@ -119,8 +123,9 @@ public ITrace StartChild(
level: level,
component: component,
parent: this,
regionContactedInternal: this.regionContactedInternal);

regionContactedInternal: this.regionContactedInternal,
summary: this.Summary);

this.AddChild(child);
return child;
}
Expand Down Expand Up @@ -151,7 +156,8 @@ public static Trace GetRootTrace(
level: level,
component: component,
parent: null,
regionContactedInternal: new HashSet<(string, Uri)>());
regionContactedInternal: new HashSet<(string, Uri)>(),
summary: new TraceSummary());
}

public void AddDatum(string key, TraceDatum traceDatum)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ namespace Microsoft.Azure.Cosmos.Tracing.TraceData
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Net;
using System.Net.Http;
using System.Text;
using Microsoft.Azure.Cosmos.Handler;
Expand All @@ -32,8 +33,9 @@ internal sealed class ClientSideRequestStatisticsTraceDatum : TraceDatum, IClien
private IReadOnlyList<StoreResponseStatistics> shallowCopyOfStoreResponseStatistics = null;
private IReadOnlyList<HttpResponseStatistics> shallowCopyOfHttpResponseStatistics = null;
private SystemUsageHistory systemUsageHistory = null;
public TraceSummary TraceSummary = null;

public ClientSideRequestStatisticsTraceDatum(DateTime startTime)
public ClientSideRequestStatisticsTraceDatum(DateTime startTime, TraceSummary summary)
{
this.RequestStartTimeUtc = startTime;
this.RequestEndTimeUtc = null;
Expand All @@ -43,6 +45,7 @@ public ClientSideRequestStatisticsTraceDatum(DateTime startTime)
this.FailedReplicas = new HashSet<TransportAddressUri>();
this.RegionsContacted = new HashSet<(string, Uri)>();
this.httpResponseStatistics = new List<HttpResponseStatistics>();
this.TraceSummary = summary;
}

public DateTime RequestStartTimeUtc { get; }
Expand Down Expand Up @@ -263,6 +266,17 @@ public void RecordResponse(
this.RegionsContacted.Add((regionName, locationEndpoint));
}

if (responseStatistics.StoreResult != null && !((HttpStatusCode)responseStatistics.StoreResult.StatusCode).IsSuccess()
&& !(responseStatistics.StoreResult.StatusCode == StatusCodes.NotFound && responseStatistics.StoreResult.SubStatusCode == SubStatusCodes.Unknown)
&& !(responseStatistics.StoreResult.StatusCode == StatusCodes.Conflict && responseStatistics.StoreResult.SubStatusCode == SubStatusCodes.Unknown)
&& !(responseStatistics.StoreResult.StatusCode == StatusCodes.PreconditionFailed && responseStatistics.StoreResult.SubStatusCode == SubStatusCodes.Unknown))
{
if (this.TraceSummary != null)
{
this.TraceSummary.IncrementFailedCount();
}
}

// Reset the shallow copy
this.shallowCopyOfStoreResponseStatistics = null;
this.storeResponseStatistics.Add(responseStatistics);
Expand Down
45 changes: 45 additions & 0 deletions Microsoft.Azure.Cosmos/src/Tracing/TraceSummary.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
// ------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
// ------------------------------------------------------------

namespace Microsoft.Azure.Cosmos.Tracing
{
using System;
using System.Collections.Generic;
using System.Text;
using System.Threading;

/// <summary>
/// The total count of failed requests for an <see cref="ITrace"/>.
/// </summary>
#if INTERNAL
SchintaMicrosoft marked this conversation as resolved.
Show resolved Hide resolved
public
#else
internal
#endif
class TraceSummary
{
/// <summary>
/// The total count of failed requests for an <see cref="ITrace"/>
/// </summary>
private int failedRequestCount = 0;

/// <summary>
/// The increment of failed requests with thread safe for an <see cref="ITrace"/>
/// </summary>
public void IncrementFailedCount()
{
Interlocked.Increment(ref this.failedRequestCount);
}

/// <summary>
/// The return the count of failed requests for an <see cref="ITrace"/>
/// </summary>
/// <returns>The value of failed requests count</returns>
public int GetFailedCount()
{
return this.failedRequestCount;
}

}
}
Loading