From 291eba3029b55ecdc612028cf967a0e7d8a50893 Mon Sep 17 00:00:00 2001 From: Jake Willey Date: Mon, 29 Apr 2024 14:03:40 -0400 Subject: [PATCH 1/5] Add StoreResponseStatistics startTime to diagnostics --- .../src/Tracing/TraceWriter.TraceJsonWriter.cs | 9 ++++++--- .../TestBaseline/TraceWriterBaselineTests.TraceData.xml | 2 ++ 2 files changed, 8 insertions(+), 3 deletions(-) diff --git a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs index 247c9f2587..ad83340bae 100644 --- a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs +++ b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs @@ -319,6 +319,9 @@ private void VisitStoreResponseStatistics( { this.jsonWriter.WriteObjectStart(); + this.jsonWriter.WriteFieldName("StartTimeUTC"); + this.WriteDateTimeStringValue(storeResponseStatistics.RequestStartTime); + this.jsonWriter.WriteFieldName("ResponseTimeUTC"); this.WriteDateTimeStringValue(storeResponseStatistics.RequestResponseTime); @@ -578,15 +581,15 @@ private void WriteStringValueOrNull(string value) } } - private void WriteDateTimeStringValue(DateTime value) + private void WriteDateTimeStringValue(DateTime? value) { - if (value == null) + if (value == null || !value.HasValue) { this.jsonWriter.WriteNullValue(); } else { - this.jsonWriter.WriteStringValue(value.ToString("o", CultureInfo.InvariantCulture)); + this.jsonWriter.WriteStringValue(value.Value.ToString("o", CultureInfo.InvariantCulture)); } } 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 75cd9894de..753b57e6c3 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 @@ -316,6 +316,7 @@ ], "StoreResponseStatistics": [ { + "StartTimeUTC": "0001-01-01T00:00:00", "ResponseTimeUTC": "9999-12-31T23:59:59.9999999", "ResourceType": "Document", "OperationType": "Query", @@ -512,6 +513,7 @@ ], "StoreResponseStatistics": [ { + "StartTimeUTC": null, "ResponseTimeUTC": "0001-01-01T00:00:00", "ResourceType": "Database", "OperationType": "Create", From 81d70e35159c96f92185c2b4830da1e9911c79dd Mon Sep 17 00:00:00 2001 From: jakewilley_microsoft <--global> Date: Tue, 30 Apr 2024 17:23:40 -0400 Subject: [PATCH 2/5] Add latency in ms to make it easier to read. --- .../src/Tracing/TraceWriter.TraceJsonWriter.cs | 11 +++++++++++ .../TraceWriterBaselineTests.TraceData.xml | 2 ++ 2 files changed, 13 insertions(+) diff --git a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs index ad83340bae..0ede2dce20 100644 --- a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs +++ b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs @@ -325,6 +325,17 @@ private void VisitStoreResponseStatistics( this.jsonWriter.WriteFieldName("ResponseTimeUTC"); this.WriteDateTimeStringValue(storeResponseStatistics.RequestResponseTime); + this.jsonWriter.WriteFieldName("LatencyInMs"); + if (storeResponseStatistics.RequestStartTime.HasValue) + { + TimeSpan latency = storeResponseStatistics.RequestResponseTime - storeResponseStatistics.RequestStartTime.Value; + this.jsonWriter.WriteNumber64Value(latency.TotalMilliseconds); + } + else + { + this.jsonWriter.WriteNullValue(); + } + this.jsonWriter.WriteFieldName("ResourceType"); this.jsonWriter.WriteStringValue(storeResponseStatistics.RequestResourceType.ToString()); 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 753b57e6c3..c81c021ae4 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 @@ -318,6 +318,7 @@ { "StartTimeUTC": "0001-01-01T00:00:00", "ResponseTimeUTC": "9999-12-31T23:59:59.9999999", + "LatencyInMs": 315537897600000, "ResourceType": "Document", "OperationType": "Query", "RequestSessionToken": "42", @@ -515,6 +516,7 @@ { "StartTimeUTC": null, "ResponseTimeUTC": "0001-01-01T00:00:00", + "LatencyInMs": null, "ResourceType": "Database", "OperationType": "Create", "LocationEndpoint": null, From bff793344e3d86cb7c660adbadcbe789e0d75bac Mon Sep 17 00:00:00 2001 From: jakewilley_microsoft <--global> Date: Tue, 30 Apr 2024 21:20:52 -0400 Subject: [PATCH 3/5] Converted to DurationInMs --- .../src/Tracing/TraceWriter.TraceJsonWriter.cs | 2 +- .../TestBaseline/TraceWriterBaselineTests.TraceData.xml | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs index 0ede2dce20..af2e930596 100644 --- a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs +++ b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs @@ -325,7 +325,7 @@ private void VisitStoreResponseStatistics( this.jsonWriter.WriteFieldName("ResponseTimeUTC"); this.WriteDateTimeStringValue(storeResponseStatistics.RequestResponseTime); - this.jsonWriter.WriteFieldName("LatencyInMs"); + this.jsonWriter.WriteFieldName("DurationInMs"); if (storeResponseStatistics.RequestStartTime.HasValue) { TimeSpan latency = storeResponseStatistics.RequestResponseTime - storeResponseStatistics.RequestStartTime.Value; 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 c81c021ae4..a942b15a14 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 @@ -318,7 +318,7 @@ { "StartTimeUTC": "0001-01-01T00:00:00", "ResponseTimeUTC": "9999-12-31T23:59:59.9999999", - "LatencyInMs": 315537897600000, + "DurationInMs": 315537897600000, "ResourceType": "Document", "OperationType": "Query", "RequestSessionToken": "42", @@ -516,7 +516,7 @@ { "StartTimeUTC": null, "ResponseTimeUTC": "0001-01-01T00:00:00", - "LatencyInMs": null, + "DurationInMs": null, "ResourceType": "Database", "OperationType": "Create", "LocationEndpoint": null, From d8ee98d25cc651a07fe0a54c0a199b9909d3a22a Mon Sep 17 00:00:00 2001 From: jakewilley_microsoft <--global> Date: Thu, 2 May 2024 09:09:55 -0400 Subject: [PATCH 4/5] Remove start time --- .../src/Tracing/TraceWriter.TraceJsonWriter.cs | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs index af2e930596..db7512e82b 100644 --- a/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs +++ b/Microsoft.Azure.Cosmos/src/Tracing/TraceWriter.TraceJsonWriter.cs @@ -319,9 +319,6 @@ private void VisitStoreResponseStatistics( { this.jsonWriter.WriteObjectStart(); - this.jsonWriter.WriteFieldName("StartTimeUTC"); - this.WriteDateTimeStringValue(storeResponseStatistics.RequestStartTime); - this.jsonWriter.WriteFieldName("ResponseTimeUTC"); this.WriteDateTimeStringValue(storeResponseStatistics.RequestResponseTime); @@ -592,15 +589,15 @@ private void WriteStringValueOrNull(string value) } } - private void WriteDateTimeStringValue(DateTime? value) + private void WriteDateTimeStringValue(DateTime value) { - if (value == null || !value.HasValue) + if (value == null) { this.jsonWriter.WriteNullValue(); } else { - this.jsonWriter.WriteStringValue(value.Value.ToString("o", CultureInfo.InvariantCulture)); + this.jsonWriter.WriteStringValue(value.ToString("o", CultureInfo.InvariantCulture)); } } From 679e306adb3f203c8d2736992176bebbd6d16274 Mon Sep 17 00:00:00 2001 From: jakewilley_microsoft <--global> Date: Thu, 2 May 2024 09:42:19 -0400 Subject: [PATCH 5/5] Update baseline file. --- .../TestBaseline/TraceWriterBaselineTests.TraceData.xml | 2 -- 1 file changed, 2 deletions(-) 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 a942b15a14..d2c33b99b2 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 @@ -316,7 +316,6 @@ ], "StoreResponseStatistics": [ { - "StartTimeUTC": "0001-01-01T00:00:00", "ResponseTimeUTC": "9999-12-31T23:59:59.9999999", "DurationInMs": 315537897600000, "ResourceType": "Document", @@ -514,7 +513,6 @@ ], "StoreResponseStatistics": [ { - "StartTimeUTC": null, "ResponseTimeUTC": "0001-01-01T00:00:00", "DurationInMs": null, "ResourceType": "Database",