From 3e3bbe5d53bd771ead625f5aee6e55cca9dd8764 Mon Sep 17 00:00:00 2001 From: Rinat Minibaev <132935507+rinatmini@users.noreply.github.com> Date: Thu, 1 Jun 2023 15:03:04 -0700 Subject: [PATCH 1/2] CosmosClient: Fixes missing Trace when converting HTTP Timeout to 503 (#3866) * Added tracing when converting HTTP Timeout to 503 * Fixed tracing when converting HTTP Timeout to 503 * Resolved PR comments * Using ITrace as part of ClientSideRequestStatisticsTraceDatum * Refactoring * Test update * Unit tests fix --- .../src/GatewayAccountReader.cs | 2 +- .../src/Handler/TransportHandler.cs | 2 +- .../src/HttpClient/CosmosHttpClientCore.cs | 4 + .../src/Routing/ClientCollectionCache.cs | 2 +- .../src/Routing/PartitionKeyRangeCache.cs | 2 +- .../ClientSideRequestStatisticsTraceDatum.cs | 13 ++- .../RegionContactedInDiagnosticsBenchmark.cs | 2 +- .../TraceWriterBaselineTests.TraceData.xml | 6 +- .../CosmosHttpClientCoreTests.cs | 92 ++++++++++++------- .../GatewayAccountReaderTests.cs | 23 +++-- .../GatewayStoreModelTest.cs | 35 ++++--- ...entSideRequestStatisticsTraceDatumTests.cs | 6 +- .../Tracing/ContactedRegionsTests.cs | 2 +- .../Tracing/TraceTests.cs | 2 +- .../Tracing/TraceWriterBaselineTests.cs | 6 +- 15 files changed, 121 insertions(+), 78 deletions(-) diff --git a/Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs b/Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs index 2754dfaa40..5413103fee 100644 --- a/Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs +++ b/Microsoft.Azure.Cosmos/src/GatewayAccountReader.cs @@ -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 { diff --git a/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs b/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs index e524214976..7baf8a7254 100644 --- a/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs +++ b/Microsoft.Azure.Cosmos/src/Handler/TransportHandler.cs @@ -93,7 +93,7 @@ internal async Task 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 diff --git a/Microsoft.Azure.Cosmos/src/HttpClient/CosmosHttpClientCore.cs b/Microsoft.Azure.Cosmos/src/HttpClient/CosmosHttpClientCore.cs index 0fde01afb5..c29c3a5b94 100644 --- a/Microsoft.Azure.Cosmos/src/HttpClient/CosmosHttpClientCore.cs +++ b/Microsoft.Azure.Cosmos/src/HttpClient/CosmosHttpClientCore.cs @@ -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; @@ -361,9 +362,11 @@ private async Task 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); @@ -394,6 +397,7 @@ private async Task SendHttpHelperAsync( ActivityId = System.Diagnostics.Trace.CorrelationManager.ActivityId.ToString(), SubStatusCode = SubStatusCodes.TransportGenerated503 }, + trace: trace, innerException: e); } diff --git a/Microsoft.Azure.Cosmos/src/Routing/ClientCollectionCache.cs b/Microsoft.Azure.Cosmos/src/Routing/ClientCollectionCache.cs index 30ece5015b..530bbfceb5 100644 --- a/Microsoft.Azure.Cosmos/src/Routing/ClientCollectionCache.cs +++ b/Microsoft.Azure.Cosmos/src/Routing/ClientCollectionCache.cs @@ -186,7 +186,7 @@ private async Task 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( diff --git a/Microsoft.Azure.Cosmos/src/Routing/PartitionKeyRangeCache.cs b/Microsoft.Azure.Cosmos/src/Routing/PartitionKeyRangeCache.cs index 4373d61f56..d9e2854b2b 100644 --- a/Microsoft.Azure.Cosmos/src/Routing/PartitionKeyRangeCache.cs +++ b/Microsoft.Azure.Cosmos/src/Routing/PartitionKeyRangeCache.cs @@ -316,7 +316,7 @@ private async Task 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); diff --git a/Microsoft.Azure.Cosmos/src/Tracing/TraceData/ClientSideRequestStatisticsTraceDatum.cs b/Microsoft.Azure.Cosmos/src/Tracing/TraceData/ClientSideRequestStatisticsTraceDatum.cs index 10845f133f..def12c8262 100644 --- a/Microsoft.Azure.Cosmos/src/Tracing/TraceData/ClientSideRequestStatisticsTraceDatum.cs +++ b/Microsoft.Azure.Cosmos/src/Tracing/TraceData/ClientSideRequestStatisticsTraceDatum.cs @@ -33,9 +33,8 @@ internal sealed class ClientSideRequestStatisticsTraceDatum : TraceDatum, IClien private IReadOnlyList shallowCopyOfStoreResponseStatistics = null; private IReadOnlyList 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; @@ -45,7 +44,7 @@ public ClientSideRequestStatisticsTraceDatum(DateTime startTime, TraceSummary su this.FailedReplicas = new HashSet(); this.RegionsContacted = new HashSet<(string, Uri)>(); this.httpResponseStatistics = new List(); - this.TraceSummary = summary; + this.Trace = trace; } public DateTime RequestStartTimeUtc { get; } @@ -75,6 +74,10 @@ public IReadOnlyDictionary EndpointToAddres public HashSet<(string, Uri)> RegionsContacted { get; } + public ITrace Trace { get; private set; } + + public TraceSummary TraceSummary => this.Trace?.Summary; + public IReadOnlyList StoreResponseStatisticsList { get @@ -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(); } } diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Performance.Tests/Benchmarks/RegionContactedInDiagnosticsBenchmark.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Performance.Tests/Benchmarks/RegionContactedInDiagnosticsBenchmark.cs index bcf95ba776..0d3d2ffd81 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Performance.Tests/Benchmarks/RegionContactedInDiagnosticsBenchmark.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Performance.Tests/Benchmarks/RegionContactedInDiagnosticsBenchmark.cs @@ -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) diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/BaselineTest/TestBaseline/TraceWriterBaselineTests.TraceData.xml b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/BaselineTest/TestBaseline/TraceWriterBaselineTests.TraceData.xml index d3b996a0e9..8b6adc1c15 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/BaselineTest/TestBaseline/TraceWriterBaselineTests.TraceData.xml +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/BaselineTest/TestBaseline/TraceWriterBaselineTests.TraceData.xml @@ -187,7 +187,7 @@ TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); TransportAddressUri uri1 = new TransportAddressUri(new Uri("http://someUri1.com")); TransportAddressUri uri2 = new TransportAddressUri(new Uri("http://someUri2.com")); @@ -405,7 +405,7 @@ TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); datum.ContactedReplicas.Add(default); TraceWriterBaselineTests.GetPrivateField>(datum, "endpointToAddressResolutionStats").Add("asdf", default); @@ -546,7 +546,7 @@ TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); TraceWriterBaselineTests.SetEndRequestTime(datum,DateTime.MaxValue); HttpResponseStatistics httpResponseStatistics = new HttpResponseStatistics( diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/CosmosHttpClientCoreTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/CosmosHttpClientCoreTests.cs index 0d475ca370..03fdb84ead 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/CosmosHttpClientCoreTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/CosmosHttpClientCoreTests.cs @@ -42,14 +42,17 @@ static Task sendFunc(HttpRequestMessage request, Cancellati HttpRequestMessage httpRequestMessage = new HttpRequestMessage(HttpMethod.Post, new Uri("http://localhost")); - HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => - new ValueTask(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), + ResourceType.Collection, + timeoutPolicy: HttpTimeoutPolicyDefault.Instance, + new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace), + default); + + Assert.AreEqual(httpRequestMessage, responseMessage.RequestMessage); + } } [TestMethod] @@ -111,15 +114,18 @@ async Task 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( 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); + } } } @@ -178,15 +184,18 @@ async Task 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( 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] @@ -216,15 +225,18 @@ async Task 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( 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] @@ -245,13 +257,16 @@ async Task sendFunc(HttpRequestMessage request, Cancellatio try { - HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => + using (ITrace trace = Trace.GetRootTrace(nameof(Retry3TimesOnDefaultPolicyTestAsync))) + { + HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => new ValueTask( 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) { @@ -282,14 +297,16 @@ async Task sendFunc(HttpRequestMessage request, Cancellatio try { - - HttpResponseMessage responseMessage1 = await cosmoshttpClient.SendHttpAsync(() => + using (ITrace trace = Trace.GetRootTrace(nameof(NoRetryOnNoRetryPolicyTestAsync))) + { + HttpResponseMessage responseMessage1 = await cosmoshttpClient.SendHttpAsync(() => new ValueTask( 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) { @@ -301,6 +318,9 @@ async Task sendFunc(HttpRequestMessage request, Cancellatio CosmosException cosmosException = (CosmosException)e; Assert.AreEqual(cosmosException.StatusCode, System.Net.HttpStatusCode.ServiceUnavailable); Assert.AreEqual((int)cosmosException.SubStatusCode,(int)SubStatusCodes.TransportGenerated503); + + Assert.IsNotNull(cosmosException.Trace); + Assert.AreNotEqual(cosmosException.Trace, NoOpTrace.Singleton); } } @@ -344,13 +364,16 @@ async Task sendFunc(HttpRequestMessage request, Cancellatio try { - HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => + using (ITrace trace = Trace.GetRootTrace(nameof(NoRetryOnNoRetryPolicyTestAsync))) + { + HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => new ValueTask( 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) { @@ -401,15 +424,18 @@ async Task sendFunc(HttpRequestMessage request, Cancellatio HttpMessageHandler messageHandler = new MockMessageHandler(sendFunc); using CosmosHttpClient cosmoshttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(messageHandler)); - HttpResponseMessage responseMessage = await cosmoshttpClient.SendHttpAsync(() => - new ValueTask( - 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( + 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] diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayAccountReaderTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayAccountReaderTests.cs index 2fc8359f68..cf54b12a52 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayAccountReaderTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayAccountReaderTests.cs @@ -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] diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayStoreModelTest.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayStoreModelTest.cs index 36b350a751..e16f176e61 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayStoreModelTest.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/GatewayStoreModelTest.cs @@ -865,21 +865,26 @@ public async Task GatewayStatsDurationTest() HttpMessageHandler mockMessageHandler = new MockMessageHandler(sendFunc); CosmosHttpClient cosmosHttpClient = MockCosmosUtil.CreateCosmosHttpClient(() => new HttpClient(mockMessageHandler), DocumentClientEventSource.Instance); - Tracing.TraceData.ClientSideRequestStatisticsTraceDatum clientSideRequestStatistics = new Tracing.TraceData.ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()); - - await cosmosHttpClient.SendHttpAsync(() => new ValueTask(new HttpRequestMessage(HttpMethod.Get, "http://someuri.com")), - ResourceType.Document, - HttpTimeoutPolicyDefault.InstanceShouldThrow503OnTimeout, - clientSideRequestStatistics, - CancellationToken.None); - - Assert.AreEqual(clientSideRequestStatistics.HttpResponseStatisticsList.Count, 2); - // The duration is calculated using date times which can cause the duration to be slightly off. This allows for up to 15 Ms of variance. - // https://stackoverflow.com/questions/2143140/c-sharp-datetime-now-precision#:~:text=The%20precision%20is%20related%20to,35%2D40%20ms%20accuracy - Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[0].Duration.TotalMilliseconds >= 985, $"First request did was not delayed by at least 1 second. {JsonConvert.SerializeObject(clientSideRequestStatistics.HttpResponseStatisticsList[0])}"); - Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[1].Duration.TotalMilliseconds >= 985, $"Second request did was not delayed by at least 1 second. {JsonConvert.SerializeObject(clientSideRequestStatistics.HttpResponseStatisticsList[1])}"); - Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[0].RequestStartTime < - clientSideRequestStatistics.HttpResponseStatisticsList[1].RequestStartTime); + + using(ITrace trace = Tracing.Trace.GetRootTrace(nameof(GatewayStatsDurationTest))) + { + + Tracing.TraceData.ClientSideRequestStatisticsTraceDatum clientSideRequestStatistics = new Tracing.TraceData.ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace); + + await cosmosHttpClient.SendHttpAsync(() => new ValueTask(new HttpRequestMessage(HttpMethod.Get, "http://someuri.com")), + ResourceType.Document, + HttpTimeoutPolicyDefault.InstanceShouldThrow503OnTimeout, + clientSideRequestStatistics, + CancellationToken.None); + + Assert.AreEqual(clientSideRequestStatistics.HttpResponseStatisticsList.Count, 2); + // The duration is calculated using date times which can cause the duration to be slightly off. This allows for up to 15 Ms of variance. + // https://stackoverflow.com/questions/2143140/c-sharp-datetime-now-precision#:~:text=The%20precision%20is%20related%20to,35%2D40%20ms%20accuracy + Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[0].Duration.TotalMilliseconds >= 985, $"First request did was not delayed by at least 1 second. {JsonConvert.SerializeObject(clientSideRequestStatistics.HttpResponseStatisticsList[0])}"); + Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[1].Duration.TotalMilliseconds >= 985, $"Second request did was not delayed by at least 1 second. {JsonConvert.SerializeObject(clientSideRequestStatistics.HttpResponseStatisticsList[1])}"); + Assert.IsTrue(clientSideRequestStatistics.HttpResponseStatisticsList[0].RequestStartTime < + clientSideRequestStatistics.HttpResponseStatisticsList[1].RequestStartTime); + } } [TestMethod] diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ClientSideRequestStatisticsTraceDatumTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ClientSideRequestStatisticsTraceDatumTests.cs index 2ec6e9db62..a28300d82f 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ClientSideRequestStatisticsTraceDatumTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ClientSideRequestStatisticsTraceDatumTests.cs @@ -48,7 +48,7 @@ public async Task ConcurrentUpdateHttpResponseStatisticsListTests() [TestMethod] public void DuplicateContactedReplicasTests() { - ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, Trace.GetRootTrace(nameof(DuplicateContactedReplicasTests))); clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress1.com"))); clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress2.com"))); clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress2.com"))); @@ -89,7 +89,7 @@ public async Task ConcurrentUpdateStoreResponseStatisticsListTests() [TestMethod] public void VerifyIClientSideRequestStatisticsNullTests() { - IClientSideRequestStatistics clientSideRequestStatistics = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new Cosmos.Tracing.TraceSummary()); + IClientSideRequestStatistics clientSideRequestStatistics = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, Trace.GetRootTrace(nameof(VerifyIClientSideRequestStatisticsNullTests))); Assert.IsNotNull(clientSideRequestStatistics.ContactedReplicas); Assert.IsNotNull(clientSideRequestStatistics.FailedReplicas); Assert.IsNotNull(clientSideRequestStatistics.RegionsContacted); @@ -101,7 +101,7 @@ private async Task ConcurrentUpdateTestHelper( { using CancellationTokenSource cancellationTokenSource = new CancellationTokenSource(); - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new Cosmos.Tracing.TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, Trace.GetRootTrace(nameof(ConcurrentUpdateTestHelper))); Task backgroundTask = Task.Run(() => backgroundUpdater(datum, cancellationTokenSource.Token)); diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ContactedRegionsTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ContactedRegionsTests.cs index 6f6a84cbe2..53a04e5228 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ContactedRegionsTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/ContactedRegionsTests.cs @@ -54,7 +54,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(ContactedRegionsTests))); Uri uri1 = new Uri("http://someUri1.com"); datum.RegionsContacted.Add((regionName1, uri1)); if (regionName2 != null) diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceTests.cs index ff27842308..ad21070609 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceTests.cs @@ -97,7 +97,7 @@ public void ValidateStoreResultSerialization() HashSet storeResultProperties = typeof(StoreResult).GetProperties(BindingFlags.Public | BindingFlags.Instance).Select(x => x.Name).ToHashSet(); string datumKey = "ClientStats"; Trace trace = Trace.GetRootTrace("Test"); - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, trace); trace.AddDatum(datumKey, datum); ReferenceCountedDisposable storeResult = StoreResult.CreateForTesting(storeResponse: new StoreResponse()); diff --git a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceWriterBaselineTests.cs b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceWriterBaselineTests.cs index 67bafdbf56..fe3dc7054f 100644 --- a/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceWriterBaselineTests.cs +++ b/Microsoft.Azure.Cosmos/tests/Microsoft.Azure.Cosmos.Tests/Tracing/TraceWriterBaselineTests.cs @@ -336,7 +336,7 @@ public void TraceData() TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); TransportAddressUri uri1 = new TransportAddressUri(new Uri("http://someUri1.com")); TransportAddressUri uri2 = new TransportAddressUri(new Uri("http://someUri2.com")); @@ -382,7 +382,7 @@ public void TraceData() TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); datum.ContactedReplicas.Add(default); TraceWriterBaselineTests.GetPrivateField>(datum, "endpointToAddressResolutionStats").Add("asdf", default); @@ -416,7 +416,7 @@ public void TraceData() TraceForBaselineTesting rootTrace; using (rootTrace = TraceForBaselineTesting.GetRootTrace()) { - ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, new TraceSummary()); + ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue, rootTrace); TraceWriterBaselineTests.SetEndRequestTime(datum,DateTime.MaxValue); HttpResponseStatistics httpResponseStatistics = new HttpResponseStatistics( From 387ab62dbb55bcc99491bf16b88a32ad1cd663a5 Mon Sep 17 00:00:00 2001 From: Sourabh Jain Date: Fri, 2 Jun 2023 22:09:59 +0530 Subject: [PATCH 2/2] AI Integration: Fixes Open Telemetry Example (#3868) * first draft * add filter * revert csproj * fix sample * changed log message * remove unused library --- .../Usage/OpenTelemetry/AppSettings.json | 6 ++-- .../Usage/OpenTelemetry/OpenTelemetry.csproj | 4 --- .../Usage/OpenTelemetry/Program.cs | 31 +++++++++++++------ 3 files changed, 26 insertions(+), 15 deletions(-) diff --git a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/AppSettings.json b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/AppSettings.json index 1ea1245434..e0d21e3e09 100644 --- a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/AppSettings.json +++ b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/AppSettings.json @@ -1,7 +1,9 @@ { "Logging": { - "LogLevel": { - "Azure-Cosmos-Operation-Request-Diagnostics": "Information" + "OpenTelemetry": { + "LogLevel": { + "Azure.Cosmos.Operation.Request.Diagnostics": "Warning" + } } }, "CosmosDBEndPointUrl": "https://localhost:8081", diff --git a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/OpenTelemetry.csproj b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/OpenTelemetry.csproj index 46fe296b80..83224d4570 100644 --- a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/OpenTelemetry.csproj +++ b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/OpenTelemetry.csproj @@ -12,10 +12,6 @@ - - - - diff --git a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/Program.cs b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/Program.cs index 4d6431823e..b4729e41c7 100644 --- a/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/Program.cs +++ b/Microsoft.Azure.Cosmos.Samples/Usage/OpenTelemetry/Program.cs @@ -25,8 +25,8 @@ static async Task Main() try { IConfigurationRoot configuration = new ConfigurationBuilder() - .AddJsonFile("AppSettings.json") - .Build(); + .AddJsonFile("AppSettings.json") + .Build(); string endpoint = configuration["CosmosDBEndPointUrl"]; if (string.IsNullOrEmpty(endpoint)) @@ -52,12 +52,16 @@ static async Task Main() serviceVersion: "1.0.0"); // Set up logging to forward logs to chosen exporter - using ILoggerFactory loggerFactory = LoggerFactory.Create(builder => builder.AddOpenTelemetry(options => - { - options.IncludeFormattedMessage = true; - options.SetResourceBuilder(resource); - options.AddAzureMonitorLogExporter(o => o.ConnectionString = aiConnectionString); // Set up exporter of your choice - })); + using ILoggerFactory loggerFactory + = LoggerFactory.Create(builder => builder + .AddConfiguration(configuration.GetSection("Logging")) + .AddOpenTelemetry(options => + { + options.IncludeFormattedMessage = true; + options.SetResourceBuilder(resource); + options.AddAzureMonitorLogExporter(o => o.ConnectionString = aiConnectionString); // Set up exporter of your choice + })); + /*.AddFilter(level => level == LogLevel.Error) // Filter is irrespective of event type or event name*/ AzureEventSourceLogForwarder logforwader = new AzureEventSourceLogForwarder(loggerFactory); logforwader.Start(); @@ -76,6 +80,7 @@ static async Task Main() { IsDistributedTracingEnabled = true // Defaults to true, set to false to disable }; + // using (CosmosClient client = new CosmosClient(endpoint, authKey, options)) { @@ -88,7 +93,6 @@ static async Task Main() await Program.RunCrudDemo(container); } - } finally { @@ -116,6 +120,15 @@ public static async Task RunCrudDemo(Container container) Console.WriteLine($"Read document with id: {i}"); } + try + { + await container.ReadItemAsync($"random key", new PartitionKey($"random partition")); + } + catch(Exception) + { + Console.WriteLine("Generate exception by reading an invalid key"); + } + for (int i = 1; i <= 5; i++) { await container.ReplaceItemAsync(new Item { Id = $"{i}", Status = "updated" }, $"{i}", new PartitionKey($"{i}"));