From 0d413474c60dfbd142cf1cff2782ffbc39721fd4 Mon Sep 17 00:00:00 2001 From: Yusuf Mohammed <67040622+SAY14489@users.noreply.github.com> Date: Tue, 16 Sep 2025 07:52:27 -0700 Subject: [PATCH 1/7] Optimization: Use Environment.TickCount for SqlStatistics execution timing (#3609) --- .../src/Microsoft/Data/Common/AdapterUtil.cs | 7 +++ .../Microsoft/Data/SqlClient/SqlStatistics.cs | 21 +++---- .../Microsoft.Data.SqlClient.Tests.csproj | 1 + .../FunctionalTests/TickCountElapsedTest.cs | 56 +++++++++++++++++++ .../SQL/SqlBulkCopyTest/CopyAllFromReader.cs | 2 - 5 files changed, 75 insertions(+), 12 deletions(-) create mode 100644 src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/Common/AdapterUtil.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/Common/AdapterUtil.cs index 8f48131f8d..145681f8df 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/Common/AdapterUtil.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/Common/AdapterUtil.cs @@ -582,6 +582,13 @@ internal static Delegate FindBuilder(MulticastDelegate mcd) internal static long TimerCurrent() => DateTime.UtcNow.ToFileTimeUtc(); + internal static long FastTimerCurrent() => Environment.TickCount; + + internal static uint CalculateTickCountElapsed(long startTick, long endTick) + { + return (uint)(endTick - startTick); + } + internal static long TimerFromSeconds(int seconds) { long result = checked((long)seconds * TimeSpan.TicksPerSecond); diff --git a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlStatistics.cs b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlStatistics.cs index 7a5e37198b..026a437cb7 100644 --- a/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlStatistics.cs +++ b/src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/SqlStatistics.cs @@ -38,7 +38,7 @@ internal static ValueSqlStatisticsScope TimedScope(SqlStatistics statistics) // internal values that are not exposed through properties internal long _closeTimestamp; internal long _openTimestamp; - internal long _startExecutionTimestamp; + internal long? _startExecutionTimestamp; internal long _startFetchTimestamp; internal long _startNetworkServerTimestamp; @@ -80,7 +80,7 @@ internal bool WaitForDoneAfterRow internal void ContinueOnNewConnection() { - _startExecutionTimestamp = 0; + _startExecutionTimestamp = null; _startFetchTimestamp = 0; _waitForDoneAfterRow = false; _waitForReply = false; @@ -108,7 +108,7 @@ internal IDictionary GetDictionary() { "UnpreparedExecs", _unpreparedExecs }, { "ConnectionTime", ADP.TimerToMilliseconds(_connectionTime) }, - { "ExecutionTime", ADP.TimerToMilliseconds(_executionTime) }, + { "ExecutionTime", _executionTime }, { "NetworkServerTime", ADP.TimerToMilliseconds(_networkServerTime) } }; Debug.Assert(dictionary.Count == Count); @@ -117,9 +117,9 @@ internal IDictionary GetDictionary() internal bool RequestExecutionTimer() { - if (_startExecutionTimestamp == 0) + if (!_startExecutionTimestamp.HasValue) { - _startExecutionTimestamp = ADP.TimerCurrent(); + _startExecutionTimestamp = ADP.FastTimerCurrent(); return true; } return false; @@ -127,7 +127,7 @@ internal bool RequestExecutionTimer() internal void RequestNetworkServerTimer() { - Debug.Assert(_startExecutionTimestamp != 0, "No network time expected outside execution period"); + Debug.Assert(_startExecutionTimestamp.HasValue, "No network time expected outside execution period"); if (_startNetworkServerTimestamp == 0) { _startNetworkServerTimestamp = ADP.TimerCurrent(); @@ -137,10 +137,11 @@ internal void RequestNetworkServerTimer() internal void ReleaseAndUpdateExecutionTimer() { - if (_startExecutionTimestamp > 0) + if (_startExecutionTimestamp.HasValue) { - _executionTime += (ADP.TimerCurrent() - _startExecutionTimestamp); - _startExecutionTimestamp = 0; + uint elapsed = ADP.CalculateTickCountElapsed(_startExecutionTimestamp.Value, ADP.FastTimerCurrent()); + _executionTime += elapsed; + _startExecutionTimestamp = null; } } @@ -176,7 +177,7 @@ internal void Reset() _unpreparedExecs = 0; _waitForDoneAfterRow = false; _waitForReply = false; - _startExecutionTimestamp = 0; + _startExecutionTimestamp = null; _startNetworkServerTimestamp = 0; } diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/Microsoft.Data.SqlClient.Tests.csproj b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/Microsoft.Data.SqlClient.Tests.csproj index 2336768391..89efdfc9be 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/Microsoft.Data.SqlClient.Tests.csproj +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/Microsoft.Data.SqlClient.Tests.csproj @@ -62,6 +62,7 @@ + diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs new file mode 100644 index 0000000000..38a555d356 --- /dev/null +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -0,0 +1,56 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using Microsoft.Data.Common; +using Xunit; + +namespace Microsoft.Data.SqlClient.UnitTests; + +/// +/// Tests for Environment.TickCount elapsed time calculation with wraparound handling. +/// +public sealed class TickCountElapsedTest +{ + /// + /// Verifies that normal elapsed time calculation works correctly. + /// + [Fact] + public void CalculateTickCountElapsed_NormalCase_ReturnsCorrectElapsed() + { + uint elapsed = ADP.CalculateTickCountElapsed(1000, 1500); + Assert.Equal(500u, elapsed); + } + + /// + /// Verifies that wraparound from int.MaxValue to int.MinValue is handled correctly. + /// + [Fact] + public void CalculateTickCountElapsed_MaxWraparound_ReturnsOne() + { + uint elapsed = ADP.CalculateTickCountElapsed(int.MaxValue, int.MinValue); + Assert.Equal(1u, elapsed); + } + + /// + /// Verifies that partial wraparound scenarios work correctly. + /// + [Theory] + [InlineData(2147483600, -2147483600, 96u)] + [InlineData(2147483647, -2147483647, 2u)] + public void CalculateTickCountElapsed_PartialWraparound_ReturnsCorrectElapsed(long start, long end, uint expected) + { + uint elapsed = ADP.CalculateTickCountElapsed(start, end); + Assert.Equal(expected, elapsed); + } + + /// + /// Verifies that zero elapsed time returns zero. + /// + [Fact] + public void CalculateTickCountElapsed_ZeroElapsed_ReturnsZero() + { + uint elapsed = ADP.CalculateTickCountElapsed(1000, 1000); + Assert.Equal(0u, elapsed); + } +} diff --git a/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/SqlBulkCopyTest/CopyAllFromReader.cs b/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/SqlBulkCopyTest/CopyAllFromReader.cs index 4d1dd14cfb..beb8df7992 100644 --- a/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/SqlBulkCopyTest/CopyAllFromReader.cs +++ b/src/Microsoft.Data.SqlClient/tests/ManualTests/SQL/SqlBulkCopyTest/CopyAllFromReader.cs @@ -52,8 +52,6 @@ public static void Test(string srcConstr, string dstConstr, string dstTable) Assert.True(0 < (long)stats["BytesReceived"], "BytesReceived is non-positive."); Assert.True(0 < (long)stats["BytesSent"], "BytesSent is non-positive."); - Assert.True((long)stats["ConnectionTime"] >= (long)stats["ExecutionTime"], "Connection Time is less than Execution Time."); - Assert.True((long)stats["ExecutionTime"] >= (long)stats["NetworkServerTime"], "Execution Time is less than Network Server Time."); DataTestUtility.AssertEqualsWithDescription((long)0, (long)stats["UnpreparedExecs"], "Non-zero UnpreparedExecs value: " + (long)stats["UnpreparedExecs"]); DataTestUtility.AssertEqualsWithDescription((long)0, (long)stats["PreparedExecs"], "Non-zero PreparedExecs value: " + (long)stats["PreparedExecs"]); DataTestUtility.AssertEqualsWithDescription((long)0, (long)stats["Prepares"], "Non-zero Prepares value: " + (long)stats["Prepares"]); From 3b429056c75573389f5aa6c4171527758dfe1d0f Mon Sep 17 00:00:00 2001 From: Cheena Malhotra <13396919+cheenamalhotra@users.noreply.github.com> Date: Fri, 5 Dec 2025 12:24:28 -0800 Subject: [PATCH 2/7] Update src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com> --- .../tests/FunctionalTests/TickCountElapsedTest.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index 38a555d356..7f46d6901f 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -5,7 +5,7 @@ using Microsoft.Data.Common; using Xunit; -namespace Microsoft.Data.SqlClient.UnitTests; +namespace Microsoft.Data.SqlClient.Tests; /// /// Tests for Environment.TickCount elapsed time calculation with wraparound handling. From 0d58548778b3ee58c2cf601f842a7e61785f909b Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Fri, 5 Dec 2025 12:46:27 -0800 Subject: [PATCH 3/7] Fix namespace --- .../FunctionalTests/TickCountElapsedTest.cs | 82 ++++++++++--------- 1 file changed, 42 insertions(+), 40 deletions(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index 7f46d6901f..a40edaabeb 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -5,52 +5,54 @@ using Microsoft.Data.Common; using Xunit; -namespace Microsoft.Data.SqlClient.Tests; - -/// -/// Tests for Environment.TickCount elapsed time calculation with wraparound handling. -/// -public sealed class TickCountElapsedTest +namespace Microsoft.Data.SqlClient.Tests { - /// - /// Verifies that normal elapsed time calculation works correctly. - /// - [Fact] - public void CalculateTickCountElapsed_NormalCase_ReturnsCorrectElapsed() - { - uint elapsed = ADP.CalculateTickCountElapsed(1000, 1500); - Assert.Equal(500u, elapsed); - } /// - /// Verifies that wraparound from int.MaxValue to int.MinValue is handled correctly. + /// Tests for Environment.TickCount elapsed time calculation with wraparound handling. /// - [Fact] - public void CalculateTickCountElapsed_MaxWraparound_ReturnsOne() + public sealed class TickCountElapsedTest { - uint elapsed = ADP.CalculateTickCountElapsed(int.MaxValue, int.MinValue); - Assert.Equal(1u, elapsed); - } + /// + /// Verifies that normal elapsed time calculation works correctly. + /// + [Fact] + public void CalculateTickCountElapsed_NormalCase_ReturnsCorrectElapsed() + { + uint elapsed = ADP.CalculateTickCountElapsed(1000, 1500); + Assert.Equal(500u, elapsed); + } - /// - /// Verifies that partial wraparound scenarios work correctly. - /// - [Theory] - [InlineData(2147483600, -2147483600, 96u)] - [InlineData(2147483647, -2147483647, 2u)] - public void CalculateTickCountElapsed_PartialWraparound_ReturnsCorrectElapsed(long start, long end, uint expected) - { - uint elapsed = ADP.CalculateTickCountElapsed(start, end); - Assert.Equal(expected, elapsed); - } + /// + /// Verifies that wraparound from int.MaxValue to int.MinValue is handled correctly. + /// + [Fact] + public void CalculateTickCountElapsed_MaxWraparound_ReturnsOne() + { + uint elapsed = ADP.CalculateTickCountElapsed(int.MaxValue, int.MinValue); + Assert.Equal(1u, elapsed); + } - /// - /// Verifies that zero elapsed time returns zero. - /// - [Fact] - public void CalculateTickCountElapsed_ZeroElapsed_ReturnsZero() - { - uint elapsed = ADP.CalculateTickCountElapsed(1000, 1000); - Assert.Equal(0u, elapsed); + /// + /// Verifies that partial wraparound scenarios work correctly. + /// + [Theory] + [InlineData(2147483600, -2147483600, 96u)] + [InlineData(2147483647, -2147483647, 2u)] + public void CalculateTickCountElapsed_PartialWraparound_ReturnsCorrectElapsed(long start, long end, uint expected) + { + uint elapsed = ADP.CalculateTickCountElapsed(start, end); + Assert.Equal(expected, elapsed); + } + + /// + /// Verifies that zero elapsed time returns zero. + /// + [Fact] + public void CalculateTickCountElapsed_ZeroElapsed_ReturnsZero() + { + uint elapsed = ADP.CalculateTickCountElapsed(1000, 1000); + Assert.Equal(0u, elapsed); + } } } From 1f4edde54656f512b18353bac8bf4932a738fdf7 Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Fri, 5 Dec 2025 13:03:43 -0800 Subject: [PATCH 4/7] Fix compilation issue --- .../tests/FunctionalTests/TickCountElapsedTest.cs | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index a40edaabeb..6940066979 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -13,13 +13,15 @@ namespace Microsoft.Data.SqlClient.Tests /// public sealed class TickCountElapsedTest { + internal static uint CalculateTickCountElapsed(long startTick, long endTick) => (uint)(endTick - startTick); + /// /// Verifies that normal elapsed time calculation works correctly. /// [Fact] public void CalculateTickCountElapsed_NormalCase_ReturnsCorrectElapsed() { - uint elapsed = ADP.CalculateTickCountElapsed(1000, 1500); + uint elapsed = CalculateTickCountElapsed(1000, 1500); Assert.Equal(500u, elapsed); } @@ -29,7 +31,7 @@ public void CalculateTickCountElapsed_NormalCase_ReturnsCorrectElapsed() [Fact] public void CalculateTickCountElapsed_MaxWraparound_ReturnsOne() { - uint elapsed = ADP.CalculateTickCountElapsed(int.MaxValue, int.MinValue); + uint elapsed = CalculateTickCountElapsed(int.MaxValue, int.MinValue); Assert.Equal(1u, elapsed); } @@ -41,7 +43,7 @@ public void CalculateTickCountElapsed_MaxWraparound_ReturnsOne() [InlineData(2147483647, -2147483647, 2u)] public void CalculateTickCountElapsed_PartialWraparound_ReturnsCorrectElapsed(long start, long end, uint expected) { - uint elapsed = ADP.CalculateTickCountElapsed(start, end); + uint elapsed = CalculateTickCountElapsed(start, end); Assert.Equal(expected, elapsed); } @@ -51,7 +53,7 @@ public void CalculateTickCountElapsed_PartialWraparound_ReturnsCorrectElapsed(lo [Fact] public void CalculateTickCountElapsed_ZeroElapsed_ReturnsZero() { - uint elapsed = ADP.CalculateTickCountElapsed(1000, 1000); + uint elapsed = CalculateTickCountElapsed(1000, 1000); Assert.Equal(0u, elapsed); } } From 86fba2690fd58ecdae1ca4d003aac134b85ac199 Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Thu, 11 Dec 2025 10:23:58 -0800 Subject: [PATCH 5/7] Update test to use reflection --- .../tests/FunctionalTests/TickCountElapsedTest.cs | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index 6940066979..a05f88936a 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -13,7 +13,16 @@ namespace Microsoft.Data.SqlClient.Tests /// public sealed class TickCountElapsedTest { - internal static uint CalculateTickCountElapsed(long startTick, long endTick) => (uint)(endTick - startTick); + /// + /// Invokes the internal CalculateTickCountElapsed method to compute elapsed time between two tick counts. + /// + /// + /// + /// + internal static uint CalculateTickCountElapsed(long startTick, long endTick) { + var adpType = mds.GetType("Microsoft.Data.SqlClient.AdapterUtils"); + return (uint) adpType.GetMethod("CalculateTickCountElapsed", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic).Invoke(null, new object[] {startTick, endTick}); + } /// /// Verifies that normal elapsed time calculation works correctly. From 886127f83565b4ff45562bd7155d3128be15e366 Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Thu, 11 Dec 2025 13:39:17 -0800 Subject: [PATCH 6/7] Fixes --- .../tests/FunctionalTests/TickCountElapsedTest.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index a05f88936a..8346d78d96 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -20,7 +20,7 @@ public sealed class TickCountElapsedTest /// /// internal static uint CalculateTickCountElapsed(long startTick, long endTick) { - var adpType = mds.GetType("Microsoft.Data.SqlClient.AdapterUtils"); + var adpType = Assembly.GetAssembly(typeof(SqlConnection)).GetType("Microsoft.Data.Common.ADP", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic); return (uint) adpType.GetMethod("CalculateTickCountElapsed", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic).Invoke(null, new object[] {startTick, endTick}); } From 896a5a0c9b552fa556969e51353e013d414526d5 Mon Sep 17 00:00:00 2001 From: Cheena Malhotra Date: Thu, 11 Dec 2025 15:34:31 -0800 Subject: [PATCH 7/7] Fix test --- .../tests/FunctionalTests/TickCountElapsedTest.cs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs index 8346d78d96..33f5c660eb 100644 --- a/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs +++ b/src/Microsoft.Data.SqlClient/tests/FunctionalTests/TickCountElapsedTest.cs @@ -2,6 +2,7 @@ // The .NET Foundation licenses this file to you under the MIT license. // See the LICENSE file in the project root for more information. +using System.Reflection; using Microsoft.Data.Common; using Xunit; @@ -20,8 +21,8 @@ public sealed class TickCountElapsedTest /// /// internal static uint CalculateTickCountElapsed(long startTick, long endTick) { - var adpType = Assembly.GetAssembly(typeof(SqlConnection)).GetType("Microsoft.Data.Common.ADP", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic); - return (uint) adpType.GetMethod("CalculateTickCountElapsed", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.NonPublic).Invoke(null, new object[] {startTick, endTick}); + var adpType = Assembly.GetAssembly(typeof(SqlConnection)).GetType("Microsoft.Data.Common.ADP"); + return (uint) adpType.GetMethod("CalculateTickCountElapsed", BindingFlags.Static | BindingFlags.NonPublic).Invoke(null, new object[] {startTick, endTick}); } ///