public void DuplicateContactedReplicasTests()
{
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary());
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")));
clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress2.com")));
clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress2.com")));
clientSideRequestStatisticsTraceDatum.ContactedReplicas.Add(new TransportAddressUri(new Uri("http://storephysicaladdress3.com")));
ITrace trace = Trace.GetRootTrace("test");
trace.AddDatum("stats", clientSideRequestStatisticsTraceDatum);
string json = new CosmosTraceDiagnostics(trace).ToString();
JObject jobject = JObject.Parse(json);
JToken contactedReplicas = jobject["data"]["stats"]["ContactedReplicas"];
Assert.AreEqual(3, contactedReplicas.Count());
int count = contactedReplicas[0]["Count"].Value <int>();
Assert.AreEqual(1, count);
string uri = contactedReplicas[0]["Uri"].Value <string>();
Assert.AreEqual("http://storephysicaladdress1.com/", uri);
count = contactedReplicas[1]["Count"].Value <int>();
Assert.AreEqual(4, count);
uri = contactedReplicas[1]["Uri"].Value <string>();
Assert.AreEqual("http://storephysicaladdress2.com/", uri);
count = contactedReplicas[2]["Count"].Value <int>();
Assert.AreEqual(1, count);
uri = contactedReplicas[2]["Uri"].Value <string>();
Assert.AreEqual("http://storephysicaladdress3.com/", uri);
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
this.jsonWriter.WriteObjectStart();
this.jsonWriter.WriteFieldName("Id");
this.jsonWriter.WriteStringValue("AggregatedClientSideRequestStatistics");
this.WriteJsonUriArrayWithDuplicatesCounted("ContactedReplicas", clientSideRequestStatisticsTraceDatum.ContactedReplicas);
this.WriteRegionsContactedArray("RegionsContacted", clientSideRequestStatisticsTraceDatum.RegionsContactedWithName);
this.WriteJsonUriArray("FailedReplicas", clientSideRequestStatisticsTraceDatum.FailedReplicas);
this.jsonWriter.WriteFieldName("AddressResolutionStatistics");
this.jsonWriter.WriteArrayStart();
foreach (ClientSideRequestStatisticsTraceDatum.AddressResolutionStatistics stat in clientSideRequestStatisticsTraceDatum.EndpointToAddressResolutionStatistics.Values)
{
VisitAddressResolutionStatistics(stat, this.jsonWriter);
}
this.jsonWriter.WriteArrayEnd();
this.jsonWriter.WriteFieldName("StoreResponseStatistics");
this.jsonWriter.WriteArrayStart();
foreach (ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics stat in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
this.VisitStoreResponseStatistics(stat);
}
this.jsonWriter.WriteArrayEnd();
this.jsonWriter.WriteObjectEnd();
}
public async Task GatewayRetryRequestStatsTest(string uriToThrow, string traceToFind, bool useGateway, int expectedHttpCalls)
{
ToDoActivity item = ToDoActivity.CreateRandomToDoActivity();
ItemResponse <ToDoActivity> createResponse = await this.Container.CreateItemAsync(item);
HttpClient httpClient = new HttpClient(new TimeOutHttpClientHandler(maxRetries: 3, uriToThrow: uriToThrow))
{
Timeout = TimeSpan.FromSeconds(1)
};
CosmosClientOptions options = new CosmosClientOptions
{
ConnectionMode = useGateway ? ConnectionMode.Gateway : ConnectionMode.Direct,
HttpClientFactory = () => httpClient
};
using (CosmosClient cosmosClient = TestCommon.CreateCosmosClient(options))
{
Container container = cosmosClient.GetContainer(this.Database.Id, this.Container.Id);
ItemResponse <ToDoActivity> response = await container.ReadItemAsync <ToDoActivity>(item.id, new PartitionKey(item.pk));
ClientSideRequestStatisticsTraceDatum datum = this.GetClientSideRequestStatsFromTrace(((CosmosTraceDiagnostics)response.Diagnostics).Value, traceToFind);
Assert.IsNotNull(datum.HttpResponseStatisticsList);
Assert.AreEqual(datum.HttpResponseStatisticsList.Count, expectedHttpCalls);
Assert.IsTrue(datum.HttpResponseStatisticsList[0].Exception is OperationCanceledException);
Assert.IsTrue(datum.HttpResponseStatisticsList[1].Exception is OperationCanceledException);
Assert.IsNull(datum.HttpResponseStatisticsList[2].Exception);
Assert.IsNotNull(datum.HttpResponseStatisticsList[2].HttpResponseMessage);
}
}
public void ValidateStoreResultSerialization()
{
HashSet <string> storeResultProperties = typeof(StoreResult).GetProperties(BindingFlags.Public | BindingFlags.Instance).Select(x => x.Name).ToHashSet <string>();
string datumKey = "ClientStats";
Trace trace = Trace.GetRootTrace("Test");
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
trace.AddDatum(datumKey, datum);
StoreResult storeResult = new StoreResult(
storeResponse: new StoreResponse(),
exception: null,
partitionKeyRangeId: 42.ToString(),
lsn: 1337,
quorumAckedLsn: 23,
requestCharge: 3.14,
currentReplicaSetSize: 4,
currentWriteQuorum: 3,
isValid: true,
storePhysicalAddress: new Uri("http://storephysicaladdress.com"),
globalCommittedLSN: 1234,
numberOfReadRegions: 13,
itemLSN: 15,
sessionToken: new SimpleSessionToken(42),
usingLocalLSN: true,
activityId: Guid.Empty.ToString(),
backendRequestDurationInMs: "4.2",
retryAfterInMs: "42",
transportRequestStats: TraceWriterBaselineTests.CreateTransportRequestStats());
StoreResponseStatistics storeResponseStatistics = new StoreResponseStatistics(
DateTime.MinValue,
DateTime.MaxValue,
storeResult,
ResourceType.Document,
OperationType.Query,
new Uri("http://someUri1.com"));
((List <StoreResponseStatistics>)datum.GetType().GetField("storeResponseStatistics", BindingFlags.NonPublic | BindingFlags.Instance).GetValue(datum)).Add(storeResponseStatistics);
CosmosTraceDiagnostics diagnostics = new CosmosTraceDiagnostics(trace);
string json = diagnostics.ToString();
JObject jObject = JObject.Parse(json);
JObject storeResultJObject = jObject["data"][datumKey]["StoreResponseStatistics"][0]["StoreResult"].ToObject <JObject>();
List <string> jsonPropertyNames = storeResultJObject.Properties().Select(p => p.Name).ToList();
storeResultProperties.Add("BELatencyInMs");
storeResultProperties.Remove(nameof(storeResult.BackendRequestDurationInMs));
storeResultProperties.Add("TransportException");
storeResultProperties.Remove(nameof(storeResult.Exception));
storeResultProperties.Add("transportRequestTimeline");
storeResultProperties.Remove(nameof(storeResult.TransportRequestStats));
foreach (string key in jsonPropertyNames)
{
Assert.IsTrue(storeResultProperties.Remove(key), $"Json contains key:{key} not a storeresult property");
}
Assert.AreEqual(0, storeResultProperties.Count, $"Json is missing properties: {string.Join(';', storeResultProperties)}");
}
public void VerifyIClientSideRequestStatisticsNullTests()
{
IClientSideRequestStatistics clientSideRequestStatistics = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new Cosmos.Tracing.TraceSummary());
Assert.IsNotNull(clientSideRequestStatistics.ContactedReplicas);
Assert.IsNotNull(clientSideRequestStatistics.FailedReplicas);
Assert.IsNotNull(clientSideRequestStatistics.RegionsContacted);
}
private void UpdateAddressesInBackground(
ClientSideRequestStatisticsTraceDatum datum,
CancellationToken cancellationToken)
{
while (!cancellationToken.IsCancellationRequested)
{
string key = datum.RecordAddressResolutionStart(ClientSideRequestStatisticsTraceDatumTests.uri);
datum.RecordAddressResolutionEnd(key);
}
}
private async Task ConcurrentUpdateTestHelper <T>(
Action <ClientSideRequestStatisticsTraceDatum, CancellationToken> backgroundUpdater,
Func <ClientSideRequestStatisticsTraceDatum, IEnumerable <T> > getList)
{
using CancellationTokenSource cancellationTokenSource = new CancellationTokenSource();
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new Cosmos.Tracing.TraceSummary());
Task backgroundTask = Task.Run(() => backgroundUpdater(datum, cancellationTokenSource.Token));
// Wait for the background thread to start
for (int i = 0; i < 100; i++)
{
if (getList(datum).Any())
{
break;
}
if (backgroundTask.Exception != null || backgroundTask.IsCompleted || backgroundTask.IsFaulted || backgroundTask.IsCanceled)
{
Assert.Fail($"BackgroundTask stopped running. {backgroundTask.Exception}");
}
await Task.Delay(TimeSpan.FromMilliseconds(50));
}
Assert.IsTrue(getList(datum).Any(), $"BackgroundTask never started running.");
foreach (T item in getList(datum))
{
Assert.IsNotNull(item);
}
int count = getList(datum).Count();
using (IEnumerator <T> enumerator = getList(datum).GetEnumerator())
{
// Wait for the background thread to start
for (int i = 0; i < 100; i++)
{
// IEnumerator should not block items being added to the list
if (getList(datum).Count() != count)
{
break;
}
await Task.Delay(TimeSpan.FromMilliseconds(50));
}
Assert.IsTrue(getList(datum).Count() > count, "Background task never updated the list.");
}
cancellationTokenSource.Cancel();
}
public async Task GatewayRequestStatsTest()
{
ToDoActivity item = ToDoActivity.CreateRandomToDoActivity();
ItemResponse <ToDoActivity> response = await this.Container.CreateItemAsync(item);
ClientSideRequestStatisticsTraceDatum datum = this.GetClientSideRequestStatsFromTrace(((CosmosTraceDiagnostics)response.Diagnostics).Value, "Transport");
Assert.IsNotNull(datum.HttpResponseStatisticsList);
Assert.AreEqual(datum.HttpResponseStatisticsList.Count, 1);
Assert.IsNotNull(datum.HttpResponseStatisticsList[0].HttpResponseMessage);
Assert.AreEqual(datum.RequestEndTimeUtc, datum.HttpResponseStatisticsList[0].RequestEndTime);
}
internal async Task <ResponseMessage> ProcessMessageAsync(
RequestMessage request,
CancellationToken cancellationToken)
{
if (request == null)
{
throw new ArgumentNullException(nameof(request));
}
DocumentServiceRequest serviceRequest = request.ToDocumentServiceRequest();
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
serviceRequest.RequestContext.ClientRequestStatistics = clientSideRequestStatisticsTraceDatum;
//TODO: extrace auth into a separate handler
string authorization = await((ICosmosAuthorizationTokenProvider)this.client.DocumentClient).GetUserAuthorizationTokenAsync(
serviceRequest.ResourceAddress,
PathsHelper.GetResourcePath(request.ResourceType),
request.Method.ToString(),
serviceRequest.Headers,
AuthorizationTokenType.PrimaryMasterKey,
request.Trace);
serviceRequest.Headers[HttpConstants.HttpHeaders.Authorization] = authorization;
IStoreModel storeProxy = this.client.DocumentClient.GetStoreProxy(serviceRequest);
using (ITrace processMessageAsyncTrace = request.Trace.StartChild(
name: $"{storeProxy.GetType().FullName} Transport Request",
component: TraceComponent.Transport,
level: Tracing.TraceLevel.Info))
{
request.Trace = processMessageAsyncTrace;
processMessageAsyncTrace.AddDatum("Client Side Request Stats", clientSideRequestStatisticsTraceDatum);
DocumentServiceResponse response = null;
try
{
response = request.OperationType == OperationType.Upsert
? await this.ProcessUpsertAsync(storeProxy, serviceRequest, cancellationToken)
: await storeProxy.ProcessMessageAsync(serviceRequest, cancellationToken);
}
finally
{
processMessageAsyncTrace.UpdateRegionContacted(clientSideRequestStatisticsTraceDatum);
}
return(response.ToCosmosResponseMessage(
request,
serviceRequest.RequestContext.RequestChargeTracker));
}
}
private void UpdateHttpResponsesInBackground(
ClientSideRequestStatisticsTraceDatum datum,
CancellationToken cancellationToken)
{
while (!cancellationToken.IsCancellationRequested)
{
datum.RecordHttpResponse(
ClientSideRequestStatisticsTraceDatumTests.request,
ClientSideRequestStatisticsTraceDatumTests.response,
Documents.ResourceType.Document,
DateTime.UtcNow - TimeSpan.FromSeconds(5));
}
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
this.jsonWriter.WriteObjectStart();
this.jsonWriter.WriteFieldName("Id");
this.jsonWriter.WriteStringValue("AggregatedClientSideRequestStatistics");
this.WriteJsonUriArrayWithDuplicatesCounted("ContactedReplicas", clientSideRequestStatisticsTraceDatum.ContactedReplicas);
this.WriteJsonUriArray("RegionsContacted", clientSideRequestStatisticsTraceDatum.RegionsContacted);
this.WriteJsonUriArray("FailedReplicas", clientSideRequestStatisticsTraceDatum.FailedReplicas);
this.jsonWriter.WriteObjectEnd();
}
private void UpdateStoreResponseStatisticsListInBackground(
ClientSideRequestStatisticsTraceDatum datum,
CancellationToken cancellationToken)
{
while (!cancellationToken.IsCancellationRequested)
{
datum.RecordRequest(ClientSideRequestStatisticsTraceDatumTests.requestDsr);
datum.RecordResponse(
ClientSideRequestStatisticsTraceDatumTests.requestDsr,
ClientSideRequestStatisticsTraceDatumTests.storeResult,
DateTime.MinValue,
DateTime.MaxValue);
}
}
private TraceDatum GetDatumObject(string regionName1, string regionName2 = null)
{
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, new TraceSummary());
Uri uri1 = new Uri("http://someUri1.com");
datum.RegionsContacted.Add((regionName1, uri1));
if (regionName2 != null)
{
Uri uri2 = new Uri("http://someUri2.com");
datum.RegionsContacted.Add((regionName2, uri2));
}
return(datum);
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
this.jsonWriter.WriteObjectStart();
this.jsonWriter.WriteFieldName("Id");
this.jsonWriter.WriteStringValue("AggregatedClientSideRequestStatistics");
this.WriteJsonUriArrayWithDuplicatesCounted("ContactedReplicas", clientSideRequestStatisticsTraceDatum.ContactedReplicas);
this.WriteRegionsContactedArray("RegionsContacted", clientSideRequestStatisticsTraceDatum.RegionsContacted);
this.WriteJsonUriArray("FailedReplicas", clientSideRequestStatisticsTraceDatum.FailedReplicas);
clientSideRequestStatisticsTraceDatum.WriteAddressCachRefreshContent(this.jsonWriter);
this.jsonWriter.WriteFieldName("AddressResolutionStatistics");
this.jsonWriter.WriteArrayStart();
foreach (KeyValuePair <string, ClientSideRequestStatisticsTraceDatum.AddressResolutionStatistics> stat in clientSideRequestStatisticsTraceDatum.EndpointToAddressResolutionStatistics)
{
this.VisitAddressResolutionStatistics(stat.Value);
}
this.jsonWriter.WriteArrayEnd();
this.jsonWriter.WriteFieldName("StoreResponseStatistics");
this.jsonWriter.WriteArrayStart();
foreach (ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics stat in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
this.VisitStoreResponseStatistics(stat);
}
this.jsonWriter.WriteArrayEnd();
if (clientSideRequestStatisticsTraceDatum.HttpResponseStatisticsList.Count > 0)
{
this.jsonWriter.WriteFieldName("HttpResponseStats");
this.jsonWriter.WriteArrayStart();
foreach (ClientSideRequestStatisticsTraceDatum.HttpResponseStatistics stat in clientSideRequestStatisticsTraceDatum.HttpResponseStatisticsList)
{
this.VisitHttpResponseStatistics(stat, this.jsonWriter);
}
this.jsonWriter.WriteArrayEnd();
}
this.jsonWriter.WriteObjectEnd();
}
public async Task RequestStatsForDirectMode()
{
ToDoActivity item = ToDoActivity.CreateRandomToDoActivity();
await this.Container.CreateItemAsync(item);
using (CosmosClient cosmosClient = TestCommon.CreateCosmosClient(useGateway: false))
{
Container container = cosmosClient.GetContainer(this.Database.Id, this.Container.Id);
ItemResponse <ToDoActivity> response = await container.ReadItemAsync <ToDoActivity>(item.id, new PartitionKey(item.pk));
ClientSideRequestStatisticsTraceDatum datum = this.GetClientSideRequestStatsFromTrace(((CosmosTraceDiagnostics)response.Diagnostics).Value, "Transport Request");
Assert.IsNotNull(datum.HttpResponseStatisticsList);
// One call for collection cache, 2 calls for PK range cache and 1 call for Address Resolution
Assert.AreEqual(datum.HttpResponseStatisticsList.Count, 4);
}
}
private async Task <AccountProperties> GetDatabaseAccountAsync(Uri serviceEndpoint)
{
INameValueCollection headers = new StoreRequestNameValueCollection();
await this.cosmosAuthorization.AddAuthorizationHeaderAsync(
headersCollection : headers,
serviceEndpoint,
HttpConstants.HttpMethods.Get,
AuthorizationTokenType.PrimaryMasterKey);
IClientSideRequestStatistics stats = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow);
try
{
using (HttpResponseMessage responseMessage = await this.httpClient.GetAsync(
uri: serviceEndpoint,
additionalHeaders: headers,
resourceType: ResourceType.DatabaseAccount,
timeoutPolicy: HttpTimeoutPolicyControlPlaneRead.Instance,
clientSideRequestStatistics: stats,
cancellationToken: default))
private ClientSideRequestStatisticsTraceDatum GetClientSideRequestStatsFromTrace(ITrace trace, string traceToFind)
{
if (trace.Name.Contains(traceToFind))
{
foreach (object datum in trace.Data.Values)
{
if (datum is ClientSideRequestStatisticsTraceDatum clientSideStats)
{
return(clientSideStats);
}
}
}
foreach (ITrace child in trace.Children)
{
ClientSideRequestStatisticsTraceDatum datum = this.GetClientSideRequestStatsFromTrace(child, traceToFind);
if (datum != null)
{
return(datum);
}
}
return(null);
}
public void TraceData()
{
List <Input> inputs = new List <Input>();
int startLineNumber;
int endLineNumber;
//----------------------------------------------------------------
// Point Operation Statistics
//----------------------------------------------------------------
{
startLineNumber = GetLineNumber();
TraceForBaselineTesting rootTrace;
using (rootTrace = TraceForBaselineTesting.GetRootTrace())
{
PointOperationStatisticsTraceDatum datum = new PointOperationStatisticsTraceDatum(
activityId: Guid.Empty.ToString(),
responseTimeUtc: new DateTime(2020, 1, 2, 3, 4, 5, 6),
statusCode: System.Net.HttpStatusCode.OK,
subStatusCode: Documents.SubStatusCodes.WriteForbidden,
requestCharge: 4,
errorMessage: null,
method: HttpMethod.Post,
requestUri: "http://localhost.com",
requestSessionToken: nameof(PointOperationStatisticsTraceDatum.RequestSessionToken),
responseSessionToken: nameof(PointOperationStatisticsTraceDatum.ResponseSessionToken));
rootTrace.AddDatum("Point Operation Statistics", datum);
}
endLineNumber = GetLineNumber();
inputs.Add(new Input("Point Operation Statistics", rootTrace, startLineNumber, endLineNumber));
}
//----------------------------------------------------------------
//----------------------------------------------------------------
// Query Metrics
//----------------------------------------------------------------
{
startLineNumber = GetLineNumber();
TraceForBaselineTesting rootTrace;
using (rootTrace = TraceForBaselineTesting.GetRootTrace())
{
QueryMetricsTraceDatum datum = new QueryMetricsTraceDatum(
new QueryMetrics(
BackendMetricsTests.MockBackendMetrics,
IndexUtilizationInfoTests.MockIndexUtilizationInfo,
ClientSideMetricsTests.MockClientSideMetrics));
rootTrace.AddDatum("Query Metrics", datum);
}
endLineNumber = GetLineNumber();
inputs.Add(new Input("Query Metrics", rootTrace, startLineNumber, endLineNumber));
}
//----------------------------------------------------------------
//----------------------------------------------------------------
// Client Side Request Stats
//----------------------------------------------------------------
{
startLineNumber = GetLineNumber();
TraceForBaselineTesting rootTrace;
using (rootTrace = TraceForBaselineTesting.GetRootTrace())
{
ClientSideRequestStatisticsTraceDatum datum = new ClientSideRequestStatisticsTraceDatum(DateTime.MinValue);
Uri uri1 = new Uri("http://someUri1.com");
Uri uri2 = new Uri("http://someUri2.com");
datum.ContactedReplicas.Add(uri1);
datum.ContactedReplicas.Add(uri2);
ClientSideRequestStatisticsTraceDatum.AddressResolutionStatistics mockStatistics = new ClientSideRequestStatisticsTraceDatum.AddressResolutionStatistics(
DateTime.MinValue,
DateTime.MaxValue,
"http://localhost.com");
datum.EndpointToAddressResolutionStatistics["asdf"] = mockStatistics;
datum.EndpointToAddressResolutionStatistics["asdf2"] = mockStatistics;
datum.FailedReplicas.Add(uri1);
datum.FailedReplicas.Add(uri2);
datum.RegionsContacted.Add(uri1);
datum.RegionsContacted.Add(uri2);
datum.RequestEndTimeUtc = DateTime.MaxValue;
StoreResponseStatistics storeResponseStatistics = new StoreResponseStatistics(
DateTime.MinValue,
DateTime.MaxValue,
new Documents.StoreResult(
storeResponse: new StoreResponse(),
exception: null,
partitionKeyRangeId: 42.ToString(),
lsn: 1337,
quorumAckedLsn: 23,
requestCharge: 3.14,
currentReplicaSetSize: 4,
currentWriteQuorum: 3,
isValid: true,
storePhysicalAddress: new Uri("http://storephysicaladdress.com"),
globalCommittedLSN: 1234,
numberOfReadRegions: 13,
itemLSN: 15,
sessionToken: new SimpleSessionToken(42),
usingLocalLSN: true,
activityId: Guid.Empty.ToString()),
ResourceType.Document,
OperationType.Query,
uri1);
datum.StoreResponseStatisticsList.Add(storeResponseStatistics);
rootTrace.AddDatum("Client Side Request Stats", datum);
}
endLineNumber = GetLineNumber();
inputs.Add(new Input("Client Side Request Stats", rootTrace, startLineNumber, endLineNumber));
}
//----------------------------------------------------------------
//----------------------------------------------------------------
// CPU History
//----------------------------------------------------------------
{
startLineNumber = GetLineNumber();
TraceForBaselineTesting rootTrace;
using (rootTrace = TraceForBaselineTesting.GetRootTrace())
{
CpuHistoryTraceDatum datum = new CpuHistoryTraceDatum(
new Documents.Rntbd.CpuLoadHistory(
new ReadOnlyCollection <Documents.Rntbd.CpuLoad>(
new List <Documents.Rntbd.CpuLoad>()
{
new Documents.Rntbd.CpuLoad(DateTime.MinValue, 42),
new Documents.Rntbd.CpuLoad(DateTime.MinValue, 23),
}),
monitoringInterval: TimeSpan.MaxValue));
rootTrace.AddDatum("CPU History", datum);
}
endLineNumber = GetLineNumber();
inputs.Add(new Input("CPU History", rootTrace, startLineNumber, endLineNumber));
}
//----------------------------------------------------------------
this.ExecuteTestSuite(inputs);
}
public void ReadFromTrace <T>(FeedResponse <T> Response, QueryStatisticsDatumVisitor queryStatisticsDatumVisitor)
{
ITrace trace = ((CosmosTraceDiagnostics)Response.Diagnostics).Value;
//POCO Materialization occurs once per iteration including all the roundtrips
List <ITrace> retrieveQueryMetricTraces = this.FindQueryMetrics(trace: trace, nodeNameOrKeyName: ClientParseTimeNode, isKeyName: false);
foreach (ITrace queryMetricTrace in retrieveQueryMetricTraces)
{
queryStatisticsDatumVisitor.AddPocoTime(queryMetricTrace.Duration.TotalMilliseconds);
}
//Get Cosmos Element Response occurs once per roundtrip for calls with status code 200
List <ITrace> retrieveCosmosElementTraces = this.FindQueryMetrics(trace: trace, nodeNameOrKeyName: ClientDeserializationTimeNode, isKeyName: false);
//Query metrics occurs once per roundtrip for calls with status code 200
List <ITrace> backendMetrics = this.FindQueryMetrics(trace: trace, nodeNameOrKeyName: BackendKeyValue, isKeyName: true);
//Client metrics occurs once per roundtrip for all status codes
List <ITrace> transitMetrics = this.FindQueryMetrics(trace: trace, nodeNameOrKeyName: TransportKeyValue, isKeyName: true, currentNodeName: TransportNodeName);
List <Tuple <ITrace, ITrace, ITrace> > backendAndClientMetrics = new();
int i = 0;
int j = 0;
int k = 0;
foreach (ITrace node in transitMetrics)
{
Debug.Assert(node.Data.Count == 1, "Exactly one transit metric expected");
KeyValuePair <string, object> kvp = node.Data.Single();
Assert.IsInstanceOfType(kvp.Value, typeof(ClientSideRequestStatisticsTraceDatum));
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = (ClientSideRequestStatisticsTraceDatum)kvp.Value;
foreach (ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics storeResponse in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
if (storeResponse.StoreResult.StatusCode == StatusCodes.Ok)
{
backendAndClientMetrics.Add(Tuple.Create(retrieveCosmosElementTraces[k], backendMetrics[j], transitMetrics[i]));
j++;
k++;
}
else
{
//We add null values to the tuple since status codes other than Ok will not have data for 'Query Metrics' and 'Get Cosmos Element Response'
backendAndClientMetrics.Add(Tuple.Create <ITrace, ITrace, ITrace>(null, null, transitMetrics[i]));
}
}
i++;
}
Debug.Assert(i == transitMetrics.Count, "All 'transit metrics' must be grouped.");
Debug.Assert(j == backendMetrics.Count, "All 'backend metrics' must be grouped.");
Debug.Assert(k == retrieveCosmosElementTraces.Count, "All 'Get Cosmos Element Response' traces must be grouped.");
int l = 1;
foreach (Tuple <ITrace, ITrace, ITrace> metrics in backendAndClientMetrics)
{
if (metrics.Item2 != null)
{
Debug.Assert(metrics.Item1 == null, "'Get Cosmos Element Response' is null");
queryStatisticsDatumVisitor.AddGetCosmosElementResponseTime(metrics.Item1.Duration.TotalMilliseconds);
foreach (KeyValuePair <string, object> kvp in metrics.Item2.Data)
{
switch (kvp.Value)
{
case TraceDatum traceDatum:
traceDatum.Accept(queryStatisticsDatumVisitor);
break;
default:
Debug.Fail("Unexpected type", $"Type not supported {metrics.Item2.GetType()}");
break;
}
}
//add metrics to the list except for last roundtrip which is taken care of in ContentSerializationPerformanceTest class
if (l != backendMetrics.Count)
{
queryStatisticsDatumVisitor.PopulateMetrics();
}
l++;
}
foreach (KeyValuePair <string, object> kvp in metrics.Item3.Data)
{
switch (kvp.Value)
{
case TraceDatum traceDatum:
traceDatum.Accept(queryStatisticsDatumVisitor);
break;
default:
Debug.Fail("Unexpected type", $"Type not supported {metrics.Item3.GetType()}");
break;
}
}
}
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
StringBuilder stringBuilder = new StringBuilder();
stringBuilder.AppendLine($"Start Time: {clientSideRequestStatisticsTraceDatum.RequestStartTimeUtc.ToString("o", CultureInfo.InvariantCulture)}");
if (clientSideRequestStatisticsTraceDatum.RequestEndTimeUtc.HasValue)
{
stringBuilder.AppendLine($"End Time: {clientSideRequestStatisticsTraceDatum.RequestEndTimeUtc.Value.ToString("o", CultureInfo.InvariantCulture)}");
}
stringBuilder.AppendLine("Contacted Replicas");
Dictionary <Uri, int> uriAndCounts = new Dictionary <Uri, int>();
foreach (Uri uri in clientSideRequestStatisticsTraceDatum.ContactedReplicas)
{
if (!uriAndCounts.TryGetValue(uri, out int count))
{
count = 0;
}
uriAndCounts[uri] = ++count;
}
foreach (KeyValuePair <Uri, int> uriAndCount in uriAndCounts)
{
stringBuilder.AppendLine($"{space}{uriAndCount.Key}: {uriAndCount.Value}");
}
stringBuilder.AppendLine("Failed to Contact Replicas");
foreach (Uri failedToContactReplica in clientSideRequestStatisticsTraceDatum.FailedReplicas)
{
stringBuilder.AppendLine($"{space}{failedToContactReplica}");
}
stringBuilder.AppendLine("Regions Contacted");
foreach (Uri regionContacted in clientSideRequestStatisticsTraceDatum.ContactedReplicas)
{
stringBuilder.AppendLine($"{space}{regionContacted}");
}
stringBuilder.AppendLine("Address Resolution Statistics");
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.TopLine);
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.Header);
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.MiddleLine);
foreach (AddressResolutionStatistics stat in clientSideRequestStatisticsTraceDatum.EndpointToAddressResolutionStatistics.Values)
{
string row = AddressResolutionStatisticsTextTable.Singleton.GetRow(
stat.StartTime,
stat.EndTime,
stat.TargetEndpoint);
stringBuilder.AppendLine(row);
}
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.BottomLine);
stringBuilder.AppendLine("Store Response Statistics");
foreach (StoreResponseStatistics stat in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
if (stat.RequestStartTime.HasValue)
{
stringBuilder.AppendLine($"{space}Start Time: {stat.RequestStartTime.Value.ToString("o", CultureInfo.InvariantCulture)}");
}
else
{
stringBuilder.AppendLine("{space}Start Time Not Found");
}
stringBuilder.AppendLine($"{space}End Time: {stat.RequestResponseTime.ToString("o", CultureInfo.InvariantCulture)}");
stringBuilder.AppendLine($"{space}Resource Type: {stat.RequestResourceType}");
stringBuilder.AppendLine($"{space}Operation Type: {stat.RequestOperationType}");
if (stat.StoreResult != null)
{
stringBuilder.AppendLine($"{space}Store Result");
stringBuilder.AppendLine($"{space}{space}Activity Id: {stat.StoreResult.ActivityId}");
stringBuilder.AppendLine($"{space}{space}Store Physical Address: {stat.StoreResult.StorePhysicalAddress}");
stringBuilder.AppendLine($"{space}{space}Status Code: {stat.StoreResult.StatusCode}/{stat.StoreResult.SubStatusCode}");
stringBuilder.AppendLine($"{space}{space}Is Valid: {stat.StoreResult.IsValid}");
stringBuilder.AppendLine($"{space}{space}LSN Info");
stringBuilder.AppendLine($"{space}{space}{space}LSN: {stat.StoreResult.LSN}");
stringBuilder.AppendLine($"{space}{space}{space}Item LSN: {stat.StoreResult.ItemLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Global LSN: {stat.StoreResult.GlobalCommittedLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Quorum Acked LSN: {stat.StoreResult.QuorumAckedLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Using LSN: {stat.StoreResult.UsingLocalLSN}");
stringBuilder.AppendLine($"{space}{space}Session Token: {stat.StoreResult.SessionToken.ConvertToString()}");
stringBuilder.AppendLine($"{space}{space}Quorum Info");
stringBuilder.AppendLine($"{space}{space}{space}Current Replica Set Size: {stat.StoreResult.CurrentReplicaSetSize}");
stringBuilder.AppendLine($"{space}{space}{space}Current Write Quorum: {stat.StoreResult.CurrentWriteQuorum}");
stringBuilder.AppendLine($"{space}{space}Is Client CPU Overloaded: {stat.StoreResult.IsClientCpuOverloaded}");
stringBuilder.AppendLine($"{space}{space}Exception");
try
{
stringBuilder.AppendLine($"{space}{space}{stat.StoreResult.GetException()}");
}
catch (Exception)
{
// This method throws if there is no exception.
}
}
}
this.toStringValue = stringBuilder.ToString();
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
if (clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList.Count > 0)
{
foreach (ClientSideRequestStatisticsTraceDatum.StoreResponseStatistics storeResponse in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
if (storeResponse.StoreResult.StatusCode == StatusCodes.Ok)
{
TransportStats transportStats = JsonConvert.DeserializeObject <TransportStats>(storeResponse.StoreResult.TransportRequestStats.ToString());
for (int i = 0; i < NumberOfEvents; i++)
{
switch (transportStats.RequestTimeline[i].Event)
{
case RequestTimeline.EventType.Created:
this.queryMetrics.Created = transportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.ChannelAcquisitionStarted:
this.queryMetrics.ChannelAcquisitionStarted = transportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Pipelined:
this.queryMetrics.Pipelined = transportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.TransitTime:
this.queryMetrics.TransitTime = transportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Received:
this.queryMetrics.Received = transportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Completed:
this.queryMetrics.Completed = transportStats.RequestTimeline[i].DurationInMs;
break;
default:
Debug.Fail("Unknown event ignored", $"Event Type not supported '{transportStats.RequestTimeline[i].Event}'");
break;
}
}
}
else
{
TransportStats badRequestTransportStats = JsonConvert.DeserializeObject <TransportStats>(storeResponse.StoreResult.TransportRequestStats.ToString());
for (int i = 0; i < NumberOfEvents; i++)
{
switch (badRequestTransportStats.RequestTimeline[i].Event)
{
case RequestTimeline.EventType.Created:
this.queryMetrics.BadRequestCreated = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.ChannelAcquisitionStarted:
this.queryMetrics.BadRequestChannelAcquisitionStarted = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Pipelined:
this.queryMetrics.BadRequestPipelined = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.TransitTime:
this.queryMetrics.BadRequestTransitTime = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Received:
this.queryMetrics.BadRequestReceived = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
case RequestTimeline.EventType.Completed:
this.queryMetrics.BadRequestCompleted = badRequestTransportStats.RequestTimeline[i].DurationInMs;
break;
default:
Debug.Fail("Unknown event ignored", $"Event Type not supported '{badRequestTransportStats.RequestTimeline[i].Event}'");
break;
}
}
this.badRequestMetricsList.Add(this.queryMetrics);
}
}
}
}
public void Visit(ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum)
{
StringBuilder stringBuilder = new StringBuilder();
stringBuilder.AppendLine($"Start Time: {clientSideRequestStatisticsTraceDatum.RequestStartTimeUtc.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture)}");
if (clientSideRequestStatisticsTraceDatum.RequestEndTimeUtc.HasValue)
{
stringBuilder.AppendLine($"End Time: {clientSideRequestStatisticsTraceDatum.RequestEndTimeUtc.Value.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture)}");
}
stringBuilder.AppendLine("Contacted Replicas");
Dictionary <Documents.TransportAddressUri, int> uriAndCounts = new Dictionary <Documents.TransportAddressUri, int>();
foreach (Documents.TransportAddressUri uri in clientSideRequestStatisticsTraceDatum.ContactedReplicas)
{
if (uri == null)
{
continue;
}
if (!uriAndCounts.TryGetValue(uri, out int count))
{
count = 0;
}
uriAndCounts[uri] = ++count;
}
foreach (KeyValuePair <Documents.TransportAddressUri, int> uriAndCount in uriAndCounts)
{
stringBuilder.AppendLine($"{space}{uriAndCount.Key?.ToString() ?? "<null>"}: {uriAndCount.Value}");
}
stringBuilder.AppendLine("Failed to Contact Replicas");
foreach (Documents.TransportAddressUri failedToContactReplica in clientSideRequestStatisticsTraceDatum.FailedReplicas)
{
stringBuilder.AppendLine($"{space}{failedToContactReplica?.ToString() ?? "<null>"}");
}
stringBuilder.AppendLine("Regions Contacted");
foreach (Documents.TransportAddressUri regionContacted in clientSideRequestStatisticsTraceDatum.ContactedReplicas)
{
stringBuilder.AppendLine($"{space}{regionContacted?.ToString() ?? "<null>"}");
}
stringBuilder.AppendLine("Address Resolution Statistics");
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.TopLine);
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.Header);
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.MiddleLine);
foreach (KeyValuePair <string, AddressResolutionStatistics> stat in clientSideRequestStatisticsTraceDatum.EndpointToAddressResolutionStatistics)
{
string row = AddressResolutionStatisticsTextTable.Singleton.GetRow(
stat.Value.StartTime.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture),
stat.Value.EndTime.HasValue ? stat.Value.EndTime.Value.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture) : "NO END TIME",
stat.Value.TargetEndpoint);
stringBuilder.AppendLine(row);
}
stringBuilder.AppendLine(AddressResolutionStatisticsTextTable.Singleton.BottomLine);
stringBuilder.AppendLine("Store Response Statistics");
foreach (StoreResponseStatistics stat in clientSideRequestStatisticsTraceDatum.StoreResponseStatisticsList)
{
if (stat.RequestStartTime.HasValue)
{
stringBuilder.AppendLine($"{space}Start Time: {stat.RequestStartTime.Value.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture)}");
}
else
{
stringBuilder.AppendLine("{space}Start Time Not Found");
}
stringBuilder.AppendLine($"{space}End Time: {stat.RequestResponseTime.ToString("hh:mm:ss:fff", CultureInfo.InvariantCulture)}");
stringBuilder.AppendLine($"{space}Resource Type: {stat.RequestResourceType}");
stringBuilder.AppendLine($"{space}Operation Type: {stat.RequestOperationType}");
if (stat.StoreResult != null)
{
stringBuilder.AppendLine($"{space}Store Result");
stringBuilder.AppendLine($"{space}{space}Activity Id: {stat.StoreResult.ActivityId ?? "<null>"}");
stringBuilder.AppendLine($"{space}{space}Store Physical Address: {stat.StoreResult.StorePhysicalAddress?.ToString() ?? "<null>"}");
stringBuilder.AppendLine($"{space}{space}Status Code: {stat.StoreResult.StatusCode}/{stat.StoreResult.SubStatusCode}");
stringBuilder.AppendLine($"{space}{space}Is Valid: {stat.StoreResult.IsValid}");
stringBuilder.AppendLine($"{space}{space}LSN Info");
stringBuilder.AppendLine($"{space}{space}{space}LSN: {stat.StoreResult.LSN}");
stringBuilder.AppendLine($"{space}{space}{space}Item LSN: {stat.StoreResult.ItemLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Global LSN: {stat.StoreResult.GlobalCommittedLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Quorum Acked LSN: {stat.StoreResult.QuorumAckedLSN}");
stringBuilder.AppendLine($"{space}{space}{space}Using LSN: {stat.StoreResult.UsingLocalLSN}");
stringBuilder.AppendLine($"{space}{space}Session Token: {stat.StoreResult.SessionToken?.ConvertToString() ?? "<null>"}");
stringBuilder.AppendLine($"{space}{space}Quorum Info");
stringBuilder.AppendLine($"{space}{space}{space}Current Replica Set Size: {stat.StoreResult.CurrentReplicaSetSize}");
stringBuilder.AppendLine($"{space}{space}{space}Current Write Quorum: {stat.StoreResult.CurrentWriteQuorum}");
stringBuilder.AppendLine($"{space}{space}Exception");
try
{
stringBuilder.AppendLine($"{space}{space}{stat.StoreResult.GetException()}");
}
catch (Exception)
{
// This method throws if there is no exception.
}
}
}
if (clientSideRequestStatisticsTraceDatum.HttpResponseStatisticsList.Any())
{
stringBuilder.AppendLine("Http Response Statistics");
foreach (HttpResponseStatistics stat in clientSideRequestStatisticsTraceDatum.HttpResponseStatisticsList)
{
stringBuilder.AppendLine($"{space}HttpResponse");
stringBuilder.AppendLine($"{space}{space}RequestStartTime: {stat.RequestStartTime.ToString("o", CultureInfo.InvariantCulture)}");
stringBuilder.AppendLine($"{space}{space}DurationInMs: {stat.Duration.TotalMilliseconds:0.00}");
stringBuilder.AppendLine($"{space}{space}RequestUri: {stat.RequestUri}");
stringBuilder.AppendLine($"{space}{space}ResourceType: {stat.ResourceType}");
stringBuilder.AppendLine($"{space}{space}HttpMethod: {stat.HttpMethod}");
if (stat.Exception != null)
{
stringBuilder.AppendLine($"{space}{space}ExceptionType: {stat.Exception.GetType()}");
stringBuilder.AppendLine($"{space}{space}ExceptionMessage: {stat.Exception.Message}");
}
if (stat.HttpResponseMessage != null)
{
stringBuilder.AppendLine($"{space}{space}StatusCode: {stat.HttpResponseMessage.StatusCode}");
if (!stat.HttpResponseMessage.IsSuccessStatusCode)
{
stringBuilder.AppendLine($"{space}{space}ReasonPhrase: {stat.HttpResponseMessage.ReasonPhrase}");
}
}
}
}
this.toStringValue = stringBuilder.ToString();
}
internal async Task <ResponseMessage> ProcessMessageAsync(
RequestMessage request,
CancellationToken cancellationToken)
{
if (request == null)
{
throw new ArgumentNullException(nameof(request));
}
DocumentServiceRequest serviceRequest = request.ToDocumentServiceRequest();
ClientSideRequestStatisticsTraceDatum clientSideRequestStatisticsTraceDatum = new ClientSideRequestStatisticsTraceDatum(DateTime.UtcNow, request.Trace.Summary);
serviceRequest.RequestContext.ClientRequestStatistics = clientSideRequestStatisticsTraceDatum;
//TODO: extrace auth into a separate handler
string authorization = await((ICosmosAuthorizationTokenProvider)this.client.DocumentClient).GetUserAuthorizationTokenAsync(
serviceRequest.ResourceAddress,
PathsHelper.GetResourcePath(request.ResourceType),
request.Method.ToString(),
serviceRequest.Headers,
AuthorizationTokenType.PrimaryMasterKey,
request.Trace);
serviceRequest.Headers[HttpConstants.HttpHeaders.Authorization] = authorization;
IStoreModel storeProxy = this.client.DocumentClient.GetStoreProxy(serviceRequest);
using (ITrace processMessageAsyncTrace = request.Trace.StartChild(
name: $"{storeProxy.GetType().FullName} Transport Request",
component: TraceComponent.Transport,
level: Tracing.TraceLevel.Info))
{
request.Trace = processMessageAsyncTrace;
processMessageAsyncTrace.AddDatum("Client Side Request Stats", clientSideRequestStatisticsTraceDatum);
DocumentServiceResponse response = null;
try
{
response = await storeProxy.ProcessMessageAsync(serviceRequest, cancellationToken);
}
catch (DocumentClientException dce)
{
// Enrich diagnostics context in-case of auth failures
if (dce.StatusCode == System.Net.HttpStatusCode.Unauthorized || dce.StatusCode == System.Net.HttpStatusCode.Forbidden)
{
TimeSpan authProvideLifeSpan = this.client.DocumentClient.cosmosAuthorization.GetAge();
processMessageAsyncTrace.AddDatum("AuthProvider LifeSpan InSec", authProvideLifeSpan.TotalSeconds);
}
throw;
}
finally
{
processMessageAsyncTrace.UpdateRegionContacted(clientSideRequestStatisticsTraceDatum);
}
ResponseMessage responseMessage = response.ToCosmosResponseMessage(
request,
serviceRequest.RequestContext.RequestChargeTracker);
// Enrich diagnostics context in-case of auth failures
if (responseMessage?.StatusCode == System.Net.HttpStatusCode.Unauthorized || responseMessage?.StatusCode == System.Net.HttpStatusCode.Forbidden)
{
TimeSpan authProvideLifeSpan = this.client.DocumentClient.cosmosAuthorization.GetAge();
processMessageAsyncTrace.AddDatum("AuthProvider LifeSpan InSec", authProvideLifeSpan.TotalSeconds);
}
return(responseMessage);
}
}
