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 RecordResponse(DocumentServiceRequest request, StoreResult storeResult)
{
DateTime responseTime = DateTime.UtcNow;
Uri locationEndpoint = request.RequestContext.LocationEndpointToRoute;
StoreResponseStatistics responseStatistics = new StoreResponseStatistics(
responseTime,
storeResult,
request.ResourceType,
request.OperationType,
locationEndpoint);
if (storeResult?.IsClientCpuOverloaded ?? false)
{
this.IsCpuOverloaded = true;
}
lock (this.lockObject)
{
if (!this.RequestEndTimeUtc.HasValue || responseTime > this.RequestEndTimeUtc)
{
this.RequestEndTimeUtc = responseTime;
}
if (locationEndpoint != null)
{
this.RegionsContacted.Add(locationEndpoint);
}
this.DiagnosticsContext.AddDiagnosticsInternal(responseStatistics);
}
}
internal override void AddDiagnosticsInternal(StoreResponseStatistics storeResponseStatistics)
{
if (storeResponseStatistics.StoreResult != null)
{
this.AddRequestCount((int)storeResponseStatistics.StoreResult.StatusCode);
}
this.ContextList.Add(storeResponseStatistics);
}
public void RecordResponse(DocumentServiceRequest request, StoreResult storeResult)
{
// One DocumentServiceRequest can map to multiple store results
DateTime?startDateTime = null;
if (this.RecordRequestHashCodeToStartTime.TryGetValue(request.GetHashCode(), out DateTime startRequestTime))
{
startDateTime = startRequestTime;
}
else
{
Debug.Fail("DocumentServiceRequest start time not recorded");
}
DateTime responseTime = DateTime.UtcNow;
Uri locationEndpoint = request.RequestContext.LocationEndpointToRoute;
StoreResponseStatistics responseStatistics = new StoreResponseStatistics(
startDateTime,
responseTime,
storeResult,
request.ResourceType,
request.OperationType,
locationEndpoint);
if (storeResult?.IsClientCpuOverloaded ?? false)
{
this.IsCpuOverloaded = true;
}
lock (this.lockObject)
{
if (!this.RequestEndTimeUtc.HasValue || responseTime > this.RequestEndTimeUtc)
{
this.RequestEndTimeUtc = responseTime;
}
if (locationEndpoint != null)
{
this.RegionsContacted.Add(locationEndpoint);
}
this.DiagnosticsContext.AddDiagnosticsInternal(responseStatistics);
if (!this.received429ResponseSinceLastStartRequest &&
storeResult.StatusCode == StatusCodes.TooManyRequests)
{
this.received429ResponseSinceLastStartRequest = true;
}
}
}
private static void ValidateStoreResponseStatistics(StoreResponseStatistics stats, DateTime startTimeUtc)
{
Assert.IsNotNull(stats.StoreResult);
Assert.IsNotNull(stats.LocationEndpoint);
Assert.IsTrue(startTimeUtc < stats.RequestResponseTime);
Assert.IsTrue(stats.RequestResponseTime < DateTime.UtcNow);
string info = stats.ToString();
Assert.IsNotNull(info);
JObject jObject = JObject.Parse(info.ToString());
Assert.IsNotNull(jObject["ResponseTimeUtc"].ToString());
Assert.IsNotNull(jObject["ResourceType"].ToString());
Assert.IsNotNull(jObject["OperationType"].ToString());
Assert.IsNotNull(jObject["LocationEndpoint"].ToString());
Assert.IsNotNull(jObject["StoreResult"].ToString());
}
internal abstract void AddDiagnosticsInternal(StoreResponseStatistics storeResponseStatistics);
internal override void AddDiagnosticsInternal(StoreResponseStatistics storeResponseStatistics)
{
}
public abstract TResult Visit(StoreResponseStatistics storeResponseStatistics);
public override void Visit(StoreResponseStatistics storeResponseStatistics)
{
}
public override void Visit(StoreResponseStatistics storeResponseStatistics)
{
Assert.IsTrue(this.isContextVisited);
this.isStoreResponseStatisticsVisited = true;
DiagnosticValidator.ValidateStoreResponseStatistics(storeResponseStatistics, this.StartTimeUtc.Value);
}
public override void Visit(StoreResponseStatistics storeResponseStatistics)
{
throw new ArgumentException($"Point Operation should not have {nameof(storeResponseStatistics)}");
}
public abstract void Visit(StoreResponseStatistics storeResponseStatistics);
public void AppendJsonToBuilder(StringBuilder stringBuilder)
{
if (stringBuilder == null)
{
throw new ArgumentNullException(nameof(stringBuilder));
}
//need to lock in case of concurrent operations. this should be extremely rare since ToString()
//should only be called at the end of request.
lock (this.lockObject)
{
//first trace request start time, as well as total non-head/headfeed requests made.
string endTime = this.requestEndTimeUtc.HasValue ? this.requestEndTimeUtc.Value.ToString("o", CultureInfo.InvariantCulture) : "Not set";
int regionsContacted = this.RegionsContacted.Count == 0 ? 1 : this.RegionsContacted.Count;
stringBuilder.Append($"\"ClientSideRequestStatistics\":{{\"RequestStartTimeUtc\":\"{this.requestStartTimeUtc.ToString("o", CultureInfo.InvariantCulture)}\"");
stringBuilder.Append($",\"RequestEndTimeUtc\":\"{endTime}\",\"NumberRegionsAttempted\":\"{regionsContacted}\",\"RequestLatency\":\"{this.RequestLatency}\"");
stringBuilder.Append(",\"ResponseStatisticsList\":[");
//take all responses here - this should be limited in number and each one contains relevant information.
for (int i = 0; i < this.responseStatisticsList.Count; i++)
{
if (i > 0)
{
stringBuilder.Append(",");
}
StoreResponseStatistics item = this.responseStatisticsList[i];
item.AppendJsonToBuilder(stringBuilder);
}
stringBuilder.Append("],\"AddressResolutionStatistics\":[");
//take all responses here - this should be limited in number and each one is important.
int count = 0;
foreach (AddressResolutionStatistics item in this.addressResolutionStatistics.Values)
{
if (count++ > 0)
{
stringBuilder.Append(",");
}
item.AppendJsonToBuilder(stringBuilder);
}
stringBuilder.Append("]");
//only take last 10 responses from this list - this has potential of having large number of entries.
//since this is for establishing consistency, we can make do with the last responses to paint a meaningful picture.
int supplementalResponseStatisticsListCount = this.supplementalResponseStatisticsList?.Count ?? 0;
int initialIndex = Math.Max(supplementalResponseStatisticsListCount - CosmosClientSideRequestStatistics.MaxSupplementalRequestsForToString, 0);
if (initialIndex != 0)
{
stringBuilder.AppendFormat(
CultureInfo.InvariantCulture,
",\"SupplementalResponseStatisticsCount\":\" -- Displaying only the last {0} head/headfeed requests. Total head/headfeed requests: {1}\"",
CosmosClientSideRequestStatistics.MaxSupplementalRequestsForToString,
supplementalResponseStatisticsListCount);
}
stringBuilder.Append(",\"SupplementalResponseStatistics\":[");
for (int i = initialIndex; i < supplementalResponseStatisticsListCount; i++)
{
if (i != initialIndex)
{
stringBuilder.Append(",");
}
this.supplementalResponseStatisticsList[i].AppendJsonToBuilder(stringBuilder);
}
stringBuilder.Append("]");
this.AppendJsonUriListToBuilder(
"FailedReplicas",
this.FailedReplicas,
stringBuilder);
this.AppendJsonUriListToBuilder(
"RegionsContacted",
this.RegionsContacted,
stringBuilder);
this.AppendJsonUriListToBuilder(
"ContactedReplicas",
this.ContactedReplicas,
stringBuilder);
stringBuilder.Append("}");
}
}
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);
}