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

Add GetClientElapsedTime to CosmosDiagnostics #1268

Merged
merged 25 commits into from
Mar 16, 2020
Merged
Show file tree
Hide file tree
Changes from 14 commits
Commits
Show all changes
25 commits
Select commit Hold shift + click to select a range
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 @@ -134,7 +134,11 @@ internal virtual async Task ValidateOperationAsync(
throw new InvalidOperationException(ClientResources.UnsupportedBulkRequestOptions);
}

Debug.Assert(itemRequestOptions.DiagnosticContext == null, "Disable Diagnostics is not supported on Bulk operations");
if (itemRequestOptions.DiagnosticContext != null)
{
throw new ArgumentException("DiagnosticContext is not allowed when AllowBulkExecution is set to true");
}

Debug.Assert(BatchAsyncContainerExecutor.ValidateOperationEPK(operation, itemRequestOptions));
}

Expand Down Expand Up @@ -242,7 +246,7 @@ private async Task<PartitionKeyRangeBatchExecutionResult> ExecuteAsync(
partitionKey: null,
streamPayload: serverRequestPayload,
requestEnricher: requestMessage => BatchAsyncContainerExecutor.AddHeadersToRequestMessage(requestMessage, serverRequest.PartitionKeyRangeId),
diagnosticsScope: diagnosticsContext,
diagnosticsContext: diagnosticsContext,
cancellationToken: cancellationToken).ConfigureAwait(false);

using (diagnosticsContext.CreateScope("BatchAsyncContainerExecutor.ToResponse"))
Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/Batch/BatchExecutor.cs
Original file line number Diff line number Diff line change
Expand Up @@ -95,7 +95,7 @@ private async Task<TransactionalBatchResponse> ExecuteServerRequestAsync(
requestMessage.Headers.Add(HttpConstants.HttpHeaders.IsBatchAtomic, bool.TrueString);
requestMessage.Headers.Add(HttpConstants.HttpHeaders.IsBatchOrdered, bool.TrueString);
},
diagnosticsScope: this.diagnosticsContext,
diagnosticsContext: this.diagnosticsContext,
cancellationToken);

using (this.diagnosticsContext.CreateScope("TransactionalBatchResponse"))
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ private TransactionalBatchResponse(
this.RequestCharge = requestCharge;
this.RetryAfter = retryAfter;
this.ActivityId = activityId;
this.Diagnostics = diagnosticsContext;
this.Diagnostics = diagnosticsContext.Diagnostics;
this.DiagnosticsContext = diagnosticsContext ?? throw new ArgumentNullException(nameof(diagnosticsContext));
}

Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/CosmosClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -819,7 +819,7 @@ private Task<ResponseMessage> CreateDatabaseStreamInternalAsync(
partitionKey: null,
streamPayload: streamPayload,
requestEnricher: (httpRequestMessage) => httpRequestMessage.AddThroughputHeader(throughput),
diagnosticsScope: null,
diagnosticsContext: null,
cancellationToken: cancellationToken);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,16 +15,14 @@ namespace Microsoft.Azure.Cosmos.Diagnostics
internal sealed class CosmosDiagnosticScope : CosmosDiagnosticsInternal, IDisposable
{
private readonly Stopwatch ElapsedTimeStopWatch;
private readonly Action<TimeSpan> ElapsedTimeCallback;
private bool isDisposed = false;

public CosmosDiagnosticScope(
string name,
Action<TimeSpan> elapsedTimeCallback = null)
Stopwatch stopwatch = null)
{
this.Id = name;
this.ElapsedTimeStopWatch = Stopwatch.StartNew();
this.ElapsedTimeCallback = elapsedTimeCallback;
this.ElapsedTimeStopWatch = stopwatch ?? Stopwatch.StartNew();
}

public string Id { get; }
Expand All @@ -48,7 +46,6 @@ public void Dispose()
}

this.ElapsedTimeStopWatch.Stop();
j82w marked this conversation as resolved.
Show resolved Hide resolved
this.ElapsedTimeCallback?.Invoke(this.ElapsedTimeStopWatch.Elapsed);
this.isDisposed = true;
}

Expand Down
Original file line number Diff line number Diff line change
@@ -1,14 +1,21 @@
//------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
//------------------------------------------------------------

namespace Microsoft.Azure.Cosmos
{
using System;

/// <summary>
/// Contains the cosmos diagnostic information for the current request to Azure Cosmos DB service.
/// </summary>
public abstract class CosmosDiagnostics
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I assume this is the envelope meant to expose additional diagnostics information for customers as well that are currently only available in the opaque diagnostics string? Like ActivityIds related to the current request etc.?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, this is the public contract. Then we have a separate implementation class.

{
/// <summary>
/// This represent the current elapsed latency of the request.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

request [](start = 62, length = 7)

request: qualify it very explicitly that its E2E elapsed time.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please check the updated text

/// </summary>
/// <returns>The elapsed time since the start of the request.</returns>
public abstract TimeSpan GetElapsedClientLatency();
j82w marked this conversation as resolved.
Show resolved Hide resolved

/// <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 @@ -6,6 +6,7 @@ namespace Microsoft.Azure.Cosmos
using System;
using System.Collections;
using System.Collections.Generic;
using System.Diagnostics;
using Microsoft.Azure.Cosmos.Diagnostics;
using Microsoft.Azure.Documents;
using static Microsoft.Azure.Cosmos.CosmosClientSideRequestStatistics;
Expand All @@ -21,10 +22,12 @@ internal abstract class CosmosDiagnosticsContext : CosmosDiagnosticsInternal, IE

public abstract int FailedRequestCount { get; protected set; }

public abstract TimeSpan? TotalElapsedTime { get; protected set; }

public abstract string UserAgent { get; protected set; }

internal abstract CosmosDiagnostics Diagnostics { get; }
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why internal if the class in internal?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It makes it easier to read. You don't have to scroll to the top to see if the class is internal.


public abstract Stopwatch OverallClientRequestTime { get; }

internal abstract CosmosDiagnosticScope CreateOverallScope(string name);

internal abstract CosmosDiagnosticScope CreateScope(string name);
Expand All @@ -42,7 +45,7 @@ internal abstract class CosmosDiagnosticsContext : CosmosDiagnosticsInternal, IE
internal abstract void AddDiagnosticsInternal(CosmosDiagnosticsContext newContext);

internal abstract void SetSdkUserAgent(string userAgent);

public abstract IEnumerator<CosmosDiagnosticsInternal> GetEnumerator();

IEnumerator IEnumerable.GetEnumerator()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,9 @@ namespace Microsoft.Azure.Cosmos
{
using System;
using System.Collections.Generic;
using System.Collections.ObjectModel;
using System.Diagnostics;
using System.Linq;
using Microsoft.Azure.Cosmos.Diagnostics;

/// <summary>
Expand Down Expand Up @@ -37,6 +40,8 @@ public CosmosDiagnosticsContextCore()
{
this.StartUtc = DateTime.UtcNow;
this.ContextList = new List<CosmosDiagnosticsInternal>();
this.Diagnostics = new CosmosDiagnosticsCore(this);
this.OverallClientRequestTime = Stopwatch.StartNew();
}

public override DateTime StartUtc { get; }
Expand All @@ -45,10 +50,12 @@ public CosmosDiagnosticsContextCore()

public override int FailedRequestCount { get; protected set; }

public override TimeSpan? TotalElapsedTime { get; protected set; }

public override string UserAgent { get; protected set; } = CosmosDiagnosticsContextCore.DefaultUserAgentString;

internal override CosmosDiagnostics Diagnostics { get; }

public override Stopwatch OverallClientRequestTime { get; }

internal override CosmosDiagnosticScope CreateOverallScope(string name)
{
CosmosDiagnosticScope scope;
Expand All @@ -59,8 +66,8 @@ internal override CosmosDiagnosticScope CreateOverallScope(string name)
}
else
{
scope = new CosmosDiagnosticScope(name, this.SetElapsedTime);
this.isOverallScopeSet = true;
scope = new CosmosDiagnosticScope(name, this.OverallClientRequestTime);
j82w marked this conversation as resolved.
Show resolved Hide resolved
}

this.ContextList.Add(scope);
Expand Down Expand Up @@ -158,11 +165,6 @@ private void AddRequestCount(int statusCode)
}
}

private void SetElapsedTime(TimeSpan totalElapsedTime)
{
this.TotalElapsedTime = totalElapsedTime;
}

private void AddSummaryInfo(CosmosDiagnosticsContext newContext)
{
if (Object.ReferenceEquals(this, newContext))
Expand All @@ -175,12 +177,6 @@ private void AddSummaryInfo(CosmosDiagnosticsContext newContext)
this.SetSdkUserAgent(newContext.UserAgent);
}

// Use the larger of the total elapsed times
if (this.TotalElapsedTime < newContext.TotalElapsedTime)
{
this.TotalElapsedTime = newContext.TotalElapsedTime;
}

this.TotalRequestCount += newContext.TotalRequestCount;
this.FailedRequestCount += newContext.FailedRequestCount;
}
Expand Down
33 changes: 33 additions & 0 deletions Microsoft.Azure.Cosmos/src/Diagnostics/CosmosDiagnosticsCore.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
//------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
//------------------------------------------------------------
namespace Microsoft.Azure.Cosmos
{
using System;
using System.Collections.Generic;

/// <summary>
/// Contains the cosmos diagnostic information for the current request to Azure Cosmos DB service.
/// </summary>
internal class CosmosDiagnosticsCore : CosmosDiagnostics
{
internal CosmosDiagnosticsCore(CosmosDiagnosticsContext diagnosticsContext)
ealsur marked this conversation as resolved.
Show resolved Hide resolved
{
this.Context = diagnosticsContext ?? throw new ArgumentNullException(nameof(diagnosticsContext));
}

internal CosmosDiagnosticsContext Context { get; }

/// <inheritdoc/>
public override TimeSpan GetElapsedClientLatency()
{
return this.Context.OverallClientRequestTime.Elapsed;
}

/// <inheritdoc/>
public override string ToString()
{
return this.Context.ToString();
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ namespace Microsoft.Azure.Cosmos.Diagnostics
/// <summary>
/// Extends <see cref="CosmosDiagnostics"/> to expose internal APIs.
/// </summary>
internal abstract class CosmosDiagnosticsInternal : CosmosDiagnostics
internal abstract class CosmosDiagnosticsInternal
{
public abstract void Accept(CosmosDiagnosticsInternalVisitor visitor);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -67,16 +67,16 @@ public override void Visit(CosmosDiagnosticsContext cosmosDiagnosticsContext)
this.jsonWriter.WritePropertyName("StartUtc");
this.jsonWriter.WriteValue(cosmosDiagnosticsContext.StartUtc.ToString("o", CultureInfo.InvariantCulture));

this.jsonWriter.WritePropertyName("ElapsedTime");

if (cosmosDiagnosticsContext.TotalElapsedTime.HasValue)
if (cosmosDiagnosticsContext.OverallClientRequestTime.IsRunning)
{
this.jsonWriter.WriteValue(cosmosDiagnosticsContext.TotalElapsedTime.Value);
this.jsonWriter.WritePropertyName("CurrentElapsedTime");
}
else
{
this.jsonWriter.WriteValue("Timer Never Stopped.");
this.jsonWriter.WritePropertyName("TotalElapsedTime");
}

this.jsonWriter.WriteValue(cosmosDiagnosticsContext.OverallClientRequestTime.Elapsed);

this.jsonWriter.WritePropertyName("UserAgent");
this.jsonWriter.WriteValue(cosmosDiagnosticsContext.UserAgent);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ namespace Microsoft.Azure.Cosmos
{
using System;
using System.Collections.Generic;
using System.Diagnostics;
using Microsoft.Azure.Cosmos.Diagnostics;

/// <summary>
Expand All @@ -18,20 +19,27 @@ internal sealed class EmptyCosmosDiagnosticsContext : CosmosDiagnosticsContext

public static readonly CosmosDiagnosticsContext Singleton = new EmptyCosmosDiagnosticsContext();

private static readonly Stopwatch Stopwatch = new Stopwatch();

private static readonly DateTime DefaultStartUtc = new DateTime(0);
j82w marked this conversation as resolved.
Show resolved Hide resolved

private EmptyCosmosDiagnosticsContext()
{
this.Diagnostics = new CosmosDiagnosticsCore(this);
}

public override DateTime StartUtc { get; } = new DateTime(0);
public override DateTime StartUtc { get; } = EmptyCosmosDiagnosticsContext.DefaultStartUtc;

public override int TotalRequestCount { get; protected set; }

public override int FailedRequestCount { get; protected set; }

public override TimeSpan? TotalElapsedTime { get; protected set; }

public override string UserAgent { get; protected set; } = "Empty Context";

internal override CosmosDiagnostics Diagnostics { get; }

public override Stopwatch OverallClientRequestTime => EmptyCosmosDiagnosticsContext.Stopwatch;

internal override CosmosDiagnosticScope CreateOverallScope(string name)
{
return EmptyCosmosDiagnosticsContext.DefaultScope;
Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/FeedIteratorCore.cs
Original file line number Diff line number Diff line change
Expand Up @@ -96,7 +96,7 @@ public override async Task<ResponseMessage> ReadNextAsync(CancellationToken canc
request.Headers.Add(HttpConstants.HttpHeaders.IsQuery, bool.TrueString);
}
},
diagnosticsScope: null,
diagnosticsContext: null,
j82w marked this conversation as resolved.
Show resolved Hide resolved
cancellationToken: cancellationToken);

this.ContinuationToken = response.Headers.ContinuationToken;
Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/Handler/ResponseMessage.cs
Original file line number Diff line number Diff line change
Expand Up @@ -122,7 +122,7 @@ public virtual Stream Content
/// <summary>
/// Gets the cosmos diagnostic information for the current request to Azure Cosmos DB service
/// </summary>
public virtual CosmosDiagnostics Diagnostics => this.DiagnosticsContext;
public virtual CosmosDiagnostics Diagnostics => this.DiagnosticsContext.Diagnostics;

internal CosmosDiagnosticsContext DiagnosticsContext { get; }

Expand Down
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/Linq/CosmosLinqExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -743,7 +743,7 @@ private static Task<Response<T>> ResponseHelperAsync<T>(T value)
System.Net.HttpStatusCode.OK,
new Headers(),
value,
new CosmosDiagnosticsContextCore()));
new CosmosDiagnosticsContextCore().Diagnostics));
}

private static MethodInfo GetMethodInfoOf<T1, T2>(Func<T1, T2> func)
Expand Down
8 changes: 4 additions & 4 deletions Microsoft.Azure.Cosmos/src/Linq/CosmosLinqQuery.cs
Original file line number Diff line number Diff line change
Expand Up @@ -184,15 +184,15 @@ internal async Task<Response<T>> AggregateResultAsync(CancellationToken cancella
headers.RequestCharge += response.RequestCharge;

// If the first page has a diagnostic context use that. Else create a new one and add the diagnostic to it.
if (response.Diagnostics is CosmosDiagnosticsContext responseDiagnosticContext)
if (response.Diagnostics is CosmosDiagnosticsCore diagnosticsCore)
{
if (diagnosticsContext == null)
{
diagnosticsContext = responseDiagnosticContext;
diagnosticsContext = diagnosticsCore.Context;
}
else
{
diagnosticsContext.AddDiagnosticsInternal(responseDiagnosticContext);
diagnosticsContext.AddDiagnosticsInternal(diagnosticsCore.Context);
}

}
Expand All @@ -208,7 +208,7 @@ internal async Task<Response<T>> AggregateResultAsync(CancellationToken cancella
System.Net.HttpStatusCode.OK,
headers,
result.FirstOrDefault(),
diagnosticsContext);
diagnosticsContext.Diagnostics);
}

private FeedIteratorInternal CreateStreamIterator(bool isContinuationExcpected)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -153,7 +153,7 @@ internal override async Task<QueryResponseCore> ExecuteItemQueryAsync<RequestOpt
cosmosRequestMessage.Headers.Add(HttpConstants.HttpHeaders.ContentType, MediaTypes.QueryJson);
cosmosRequestMessage.Headers.Add(HttpConstants.HttpHeaders.IsQuery, bool.TrueString);
},
diagnosticsScope: queryRequestOptions?.DiagnosticContext,
diagnosticsContext: null,
cancellationToken: cancellationToken);

schedulingStopwatch.Stop();
Expand Down Expand Up @@ -192,7 +192,7 @@ internal override async Task<PartitionedQueryExecutionInfo> ExecuteQueryPlanRequ
requestMessage.Headers.Add(HttpConstants.HttpHeaders.QueryVersion, new Version(major: 1, minor: 0).ToString());
requestMessage.UseGatewayMode = true;
},
diagnosticsScope: null,
diagnosticsContext: null,
cancellationToken: cancellationToken))
{
// Syntax exception are argument exceptions and thrown to the user.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -58,7 +58,7 @@ public override Task<ResponseMessage> DeleteAsync(
partitionKey: partitionKey,
streamPayload: null,
requestEnricher: null,
diagnosticsScope: null,
diagnosticsContext: null,
cancellationToken: cancellationToken);
}

Expand Down Expand Up @@ -169,7 +169,7 @@ public override async Task<ItemResponse<T>> ReadCurrentAsync<T>(
partitionKey: partitionKey,
streamPayload: null,
requestEnricher: null,
diagnosticsScope: null,
diagnosticsContext: null,
cancellationToken: cancellationToken);

return await this.clientContext.ResponseFactory.CreateItemResponseAsync<T>(response);
Expand Down
Loading