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

CosmosClient: Fixes missing Trace when converting HTTP Timeout to 503 #3866

Merged
14 commits merged into from
Jun 1, 2023
Merged
Show file tree
Hide file tree
Changes from 9 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
2 changes: 1 addition & 1 deletion Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ await this.cosmosAuthorization.AddAuthorizationHeaderAsync(

using (ITrace trace = Trace.GetRootTrace("Account Read", TraceComponent.Transport, TraceLevel.Info))
{
IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace.Summary);
IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace);

try
{
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, request.Trace.Summary);
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, request.Trace);
serviceRequest.RequestContext.ClientRequestStatistics = clientSideRequestStatisticsTraceDatum;

//TODO: extrace auth into a separate handler
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ namespace Microsoft.Azure.Cosmos
using System.Threading.Tasks;
using Microsoft.Azure.Cosmos.Core.Trace;
using Microsoft.Azure.Cosmos.Resource.CosmosExceptions;
using Microsoft.Azure.Cosmos.Tracing;
using Microsoft.Azure.Cosmos.Tracing.TraceData;
using Microsoft.Azure.Documents;
using Microsoft.Azure.Documents.Collections;
Expand Down Expand Up @@ -361,9 +362,11 @@ private async Task<HttpResponseMessage> SendHttpHelperAsync(
}
catch (Exception e)
{
ITrace trace = NoOpTrace.Singleton;
if (clientSideRequestStatistics is ClientSideRequestStatisticsTraceDatum datum)
{
datum.RecordHttpException(requestMessage, e, resourceType, requestStartTime);
trace = datum.Trace;
}
bool isOutOfRetries = CosmosHttpClientCore.IsOutOfRetries(timeoutPolicy, startDateTimeUtc, timeoutEnumerator);

Expand Down Expand Up @@ -394,6 +397,7 @@ private async Task<HttpResponseMessage> SendHttpHelperAsync(
ActivityId = System.Diagnostics.Trace.CorrelationManager.ActivityId.ToString(),
SubStatusCode = SubStatusCodes.TransportGenerated503
},
trace: trace,
innerException: e);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -186,7 +186,7 @@ private async Task<ContainerProperties> ReadCollectionAsync(
{
headers.XDate = Rfc1123DateTimeCache.UtcNow();

request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace.Summary);
request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace);
if (clientSideRequestStatistics == null)
{
childTrace.AddDatum(
Expand Down
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, trace.Summary);
request.RequestContext.ClientRequestStatistics = clientSideRequestStatistics ?? new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace);
if (clientSideRequestStatistics == null)
{
childTrace.AddDatum("Client Side Request Stats", request.RequestContext.ClientRequestStatistics);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,9 +33,8 @@ 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, TraceSummary summary)
public ClientSideRequestStatisticsTraceDatum(DateTime startTime, ITrace trace)
{
this.RequestStartTimeUtc = startTime;
this.RequestEndTimeUtc = null;
Expand All @@ -45,7 +44,7 @@ public ClientSideRequestStatisticsTraceDatum(DateTime startTime, TraceSummary su
this.FailedReplicas = new HashSet<TransportAddressUri>();
this.RegionsContacted = new HashSet<(string, Uri)>();
this.httpResponseStatistics = new List<HttpResponseStatistics>();
this.TraceSummary = summary;
this.Trace = trace;
}

public DateTime RequestStartTimeUtc { get; }
Expand Down Expand Up @@ -75,6 +74,10 @@ public IReadOnlyDictionary<string, AddressResolutionStatistics> EndpointToAddres

public HashSet<(string, Uri)> RegionsContacted { get; }

public ITrace Trace { get; private set; }

public TraceSummary TraceSummary => this.Trace?.Summary;

public IReadOnlyList<StoreResponseStatistics> StoreResponseStatisticsList
{
get
Expand Down Expand Up @@ -502,11 +505,11 @@ public HttpResponseStatistics(
if (responseMessage != null)
{
Headers headers = new Headers(GatewayStoreClient.ExtractResponseHeaders(responseMessage));
this.ActivityId = headers.ActivityId ?? Trace.CorrelationManager.ActivityId.ToString();
this.ActivityId = headers.ActivityId ?? System.Diagnostics.Trace.CorrelationManager.ActivityId.ToString();
}
else
{
this.ActivityId = Trace.CorrelationManager.ActivityId.ToString();
this.ActivityId = System.Diagnostics.Trace.CorrelationManager.ActivityId.ToString();
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ private ITrace CreateTestTraceTree()

private TraceDatum GetDatumObject(string regionName1, string regionName2 = null)
{
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary());
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, Trace.GetRootTrace(nameof(RegionContactedInDiagnosticsBenchmark)));
Uri uri1 = new Uri("http://someUri1.com");
datum.RegionsContacted.Add((regionName1, uri1));
if (regionName2 != null)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -42,14 +42,17 @@ static Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellati

HttpRequestMessage httpRequestMessage = new HttpRequestMessage(HttpMethod.Post, new Uri("http://localhost"));

HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(httpRequestMessage),
ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyDefault.Instance,
new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow,new TraceSummary()),
default);

Assert.AreEqual(httpRequestMessage, responseMessage.RequestMessage);
using (ITrace trace = Trace.GetRootTrace(nameof(ResponseMessageHasRequestMessageAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(httpRequestMessage),
ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyDefault.Instance,
new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
default);

Assert.AreEqual(httpRequestMessage, responseMessage.RequestMessage);
}
}

[TestMethod]
Expand Down Expand Up @@ -111,15 +114,18 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio
HttpMessageHandler messageHandler = new MockMessageHandler(sendFunc);
using CosmosHttpClient cosmoshttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(messageHandler));

HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(RetryTransientIssuesTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Get, new Uri("http://localhost"))),
resourceType: ResourceType.Collection,
timeoutPolicy: currentTimeoutPolicy.Key,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
}
}
}

Expand Down Expand Up @@ -178,15 +184,18 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio
HttpMessageHandler messageHandler = new MockMessageHandler(sendFunc);
using CosmosHttpClient cosmoshttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(messageHandler));

HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(RetryTransient408sTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Get, new Uri("http://localhost"))),
resourceType: ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRetriableHotPath.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
}
}

[TestMethod]
Expand Down Expand Up @@ -216,15 +225,18 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio
HttpMessageHandler messageHandler = new MockMessageHandler(sendFunc);
using CosmosHttpClient cosmoshttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(messageHandler));

HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(DoesNotRetryTransient408sOnDefaultPolicyTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Get, new Uri("http://localhost"))),
resourceType: ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRead.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.RequestTimeout, responseMessage.StatusCode, "Should be a request timeout");

Assert.AreEqual(HttpStatusCode.RequestTimeout, responseMessage.StatusCode, "Should be a request timeout");
}
}

[TestMethod]
Expand All @@ -245,13 +257,16 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio

try
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(Retry3TimesOnDefaultPolicyTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Get, new Uri("http://localhost"))),
resourceType: ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyDefault.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);
}
}
catch (Exception ex)
{
Expand Down Expand Up @@ -282,14 +297,16 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio

try
{

HttpResponseMessage responseMessage1 = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(NoRetryOnNoRetryPolicyTestAsync)))
{
HttpResponseMessage responseMessage1 = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(method, new Uri("http://localhost"))),
resourceType: resourceType,
timeoutPolicy: timeoutPolicy,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);
}
}
catch (Exception e)
{
Expand All @@ -301,6 +318,8 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio
CosmosException cosmosException = (CosmosException)e;
rinatmini marked this conversation as resolved.
Show resolved Hide resolved
Assert.AreEqual(cosmosException.StatusCode, System.Net.HttpStatusCode.ServiceUnavailable);
Assert.AreEqual((int)cosmosException.SubStatusCode,(int)SubStatusCodes.TransportGenerated503);

Assert.IsNotNull(cosmosException.Trace);
}
}

Expand Down Expand Up @@ -344,13 +363,16 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio

try
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
using (ITrace trace = Trace.GetRootTrace(nameof(NoRetryOnNoRetryPolicyTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Get, new Uri("http://localhost"))),
resourceType: ResourceType.Collection,
timeoutPolicy: HttpTimeoutPolicyNoRetry.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);
}
}
catch (Exception ex)
{
Expand Down Expand Up @@ -401,15 +423,18 @@ async Task<HttpResponseMessage> sendFunc(HttpRequestMessage request, Cancellatio
HttpMessageHandler messageHandler = new MockMessageHandler(sendFunc);
using CosmosHttpClient cosmoshttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(messageHandler));

HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Post, new Uri("http://localhost"))),
resourceType: ResourceType.Document,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRetriableHotPath.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
cancellationToken: default);
using (ITrace trace = Trace.GetRootTrace(nameof(RetryTransientIssuesForQueryPlanTestAsync)))
{
HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() =>
new ValueTask<HttpRequestMessage>(
result: new HttpRequestMessage(HttpMethod.Post, new Uri("http://localhost"))),
resourceType: ResourceType.Document,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRetriableHotPath.Instance,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace),
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
Assert.AreEqual(HttpStatusCode.OK, responseMessage.StatusCode);
}
}

[TestMethod]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -57,15 +57,20 @@ public async Task DocumentClient_BuildHttpClientFactory_WithHandler()
receivedResponseEventArgs: null);

Assert.IsNotNull(httpClient);
HttpResponseMessage response = await httpClient.GetAsync(
uri: new Uri("https://localhost"),
additionalHeaders: new RequestNameValueCollection(),
resourceType: ResourceType.Document,
timeoutPolicy: HttpTimeoutPolicyDefault.InstanceShouldThrow503OnTimeout,
clientSideRequestStatistics: new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()),
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.Conflict, response.StatusCode);

using (ITrace trace = Trace.GetRootTrace(nameof(DocumentClient_BuildHttpClientFactory_WithHandler)))
{
IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace);
HttpResponseMessage response = await httpClient.GetAsync(
uri: new Uri("https://localhost"),
additionalHeaders: new RequestNameValueCollection(),
resourceType: ResourceType.Document,
timeoutPolicy: HttpTimeoutPolicyDefault.InstanceShouldThrow503OnTimeout,
clientSideRequestStatistics: stats,
cancellationToken: default);

Assert.AreEqual(HttpStatusCode.Conflict, response.StatusCode);
}
}

[TestMethod]
Expand Down
Loading