Attempted fix on flaky counter tests (#59892)

dotnet · Jan 25, 2025 · 4af8275 · 4af8275
1 parent ccaf48b
commit 4af8275
Show file tree

Hide file tree

Showing 7 changed files with 71 additions and 77 deletions.
diff --git a/src/Hosting/Hosting/test/HostingApplicationDiagnosticsTests.cs b/src/Hosting/Hosting/test/HostingApplicationDiagnosticsTests.cs
@@ -40,9 +40,9 @@ public async Task EventCountersAndMetricsValues()
         using CancellationTokenSource timeoutTokenSource = new CancellationTokenSource(timeout);
         timeoutTokenSource.Token.Register(() => Logger.LogError("Timeout while waiting for counter value."));
 
-        var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
-        var currentRequestValues = eventListener.GetCounterValues("current-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
-        var failedRequestValues = eventListener.GetCounterValues("failed-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
+        var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token);
+        var currentRequestValues = eventListener.GetCounterValues("current-requests", timeoutTokenSource.Token);
+        var failedRequestValues = eventListener.GetCounterValues("failed-requests", timeoutTokenSource.Token);
 
         eventListener.EnableEvents(hostingEventSource, EventLevel.Informational, EventKeywords.None,
             new Dictionary<string, string>
@@ -69,18 +69,18 @@ public async Task EventCountersAndMetricsValues()
         var context1 = hostingApplication1.CreateContext(features1);
         var context2 = hostingApplication2.CreateContext(features2);
 
-        await totalRequestValues.WaitForSumValueAsync(2);
-        await currentRequestValues.WaitForValueAsync(2);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         Logger.LogInformation(nameof(HostingApplication.DisposeContext));
 
         hostingApplication1.DisposeContext(context1, null);
         hostingApplication2.DisposeContext(context2, null);
 
-        await totalRequestValues.WaitForSumValueAsync(2);
-        await currentRequestValues.WaitForValueAsync(0);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 0, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         Assert.Collection(activeRequestsCollector1.GetMeasurementSnapshot(),
             m => Assert.Equal(1, m.Value),
@@ -100,9 +100,9 @@ public async Task EventCountersAndMetricsValues()
         context1 = hostingApplication1.CreateContext(features1);
         context2 = hostingApplication2.CreateContext(features2);
 
-        await totalRequestValues.WaitForSumValueAsync(4);
-        await currentRequestValues.WaitForValueAsync(2);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 4, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         context1.HttpContext.Response.StatusCode = StatusCodes.Status500InternalServerError;
         context2.HttpContext.Response.StatusCode = StatusCodes.Status500InternalServerError;
@@ -112,9 +112,9 @@ public async Task EventCountersAndMetricsValues()
         hostingApplication1.DisposeContext(context1, null);
         hostingApplication2.DisposeContext(context2, null);
 
-        await totalRequestValues.WaitForSumValueAsync(4);
-        await currentRequestValues.WaitForValueAsync(0);
-        await failedRequestValues.WaitForValueAsync(2);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 4, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 0, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 2, Logger);
 
         Assert.Collection(activeRequestsCollector1.GetMeasurementSnapshot(),
             m => Assert.Equal(1, m.Value),
@@ -134,6 +134,11 @@ public async Task EventCountersAndMetricsValues()
             m => Assert.True(m.Value > 0));
     }
 
+    private static async Task WaitForCounterValue(CounterValues values, double expectedValue, ILogger logger)
+    {
+        await values.Values.WaitForValueAsync(expectedValue, values.CounterName, logger);
+    }
+
     [Fact]
     public void EventCountersEnabled()
     {

diff --git a/src/Hosting/Hosting/test/Internal/HostingEventSourceTests.cs b/src/Hosting/Hosting/test/Internal/HostingEventSourceTests.cs
@@ -193,9 +193,9 @@ public async Task VerifyCountersFireWithCorrectValues()
         using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(30));
         timeoutTokenSource.Token.Register(() => Logger.LogError("Timeout while waiting for counter value."));
 
-        var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
-        var currentRequestValues = eventListener.GetCounterValues("current-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
-        var failedRequestValues = eventListener.GetCounterValues("failed-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
+        var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token);
+        var currentRequestValues = eventListener.GetCounterValues("current-requests", timeoutTokenSource.Token);
+        var failedRequestValues = eventListener.GetCounterValues("failed-requests", timeoutTokenSource.Token);
 
         eventListener.EnableEvents(hostingEventSource, EventLevel.Informational, EventKeywords.None,
             new Dictionary<string, string>
@@ -207,32 +207,37 @@ public async Task VerifyCountersFireWithCorrectValues()
         Logger.LogInformation(nameof(HostingEventSource.RequestStart));
         hostingEventSource.RequestStart("GET", "/");
 
-        await totalRequestValues.WaitForSumValueAsync(1);
-        await currentRequestValues.WaitForValueAsync(1);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 1, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 1, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         Logger.LogInformation(nameof(HostingEventSource.RequestStop));
         hostingEventSource.RequestStop();
 
-        await totalRequestValues.WaitForSumValueAsync(1);
-        await currentRequestValues.WaitForValueAsync(0);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 1, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 0, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         Logger.LogInformation(nameof(HostingEventSource.RequestStart));
         hostingEventSource.RequestStart("POST", "/");
 
-        await totalRequestValues.WaitForSumValueAsync(2);
-        await currentRequestValues.WaitForValueAsync(1);
-        await failedRequestValues.WaitForValueAsync(0);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 1, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 0, Logger);
 
         Logger.LogInformation(nameof(HostingEventSource.RequestFailed));
         hostingEventSource.RequestFailed();
         Logger.LogInformation(nameof(HostingEventSource.RequestStop));
         hostingEventSource.RequestStop();
 
-        await totalRequestValues.WaitForSumValueAsync(2);
-        await currentRequestValues.WaitForValueAsync(0);
-        await failedRequestValues.WaitForValueAsync(1);
+        await WaitForCounterValue(totalRequestValues, expectedValue: 2, Logger);
+        await WaitForCounterValue(currentRequestValues, expectedValue: 0, Logger);
+        await WaitForCounterValue(failedRequestValues, expectedValue: 1, Logger);
+    }
+
+    private static async Task WaitForCounterValue(CounterValues values, double expectedValue, ILogger logger)
+    {
+        await values.Values.WaitForValueAsync(expectedValue, values.CounterName, logger);
     }
 
     private static HostingEventSource GetHostingEventSource()

diff --git a/src/Hosting/Hosting/test/Microsoft.AspNetCore.Hosting.Tests.csproj b/src/Hosting/Hosting/test/Microsoft.AspNetCore.Hosting.Tests.csproj
@@ -11,6 +11,7 @@
     <Compile Include="$(SharedSourceRoot)EventSource.Testing\TestCounterListener.cs" />
     <Compile Include="$(SharedSourceRoot)SyncPoint\SyncPoint.cs" />
     <Compile Include="$(SharedSourceRoot)Metrics\TestMeterFactory.cs" LinkBase="shared" />
+    <Compile Include="$(SharedSourceRoot)AsyncEnumerableExtensions.cs" LinkBase="shared" />
     <Content Include="testroot\**\*" CopyToOutputDirectory="PreserveNewest" CopyToPublishDirectory="PreserveNewest" />
     <Content Include="Microsoft.AspNetCore.Hosting.StaticWebAssets.xml" CopyToOutputDirectory="PreserveNewest" />
   </ItemGroup>

diff --git a/src/Middleware/ConcurrencyLimiter/test/ConcurrencyLimiterEventSourceTests.cs b/src/Middleware/ConcurrencyLimiter/test/ConcurrencyLimiterEventSourceTests.cs
@@ -5,6 +5,7 @@
 using System.Diagnostics.Tracing;
 using Microsoft.AspNetCore.Internal;
 using Microsoft.AspNetCore.InternalTesting;
+using Microsoft.Extensions.Logging;
 
 namespace Microsoft.AspNetCore.ConcurrencyLimiter.Tests;
 
@@ -55,7 +56,7 @@ public async Task TracksQueueLength()
 
         using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(30));
 
-        var lengthValues = eventListener.GetCounterValues("queue-length", timeoutTokenSource.Token).GetAsyncEnumerator();
+        var lengthValues = eventListener.GetCounterValues("queue-length", timeoutTokenSource.Token);
 
         eventListener.EnableEvents(eventSource, EventLevel.Informational, EventKeywords.None,
             new Dictionary<string, string>
@@ -66,20 +67,20 @@ public async Task TracksQueueLength()
         // Act
         eventSource.RequestRejected();
 
-        Assert.True(await UntilValueMatches(lengthValues, 0));
+        await WaitForCounterValue(lengthValues, expectedValue: 0, Logger);
         using (eventSource.QueueTimer())
         {
-            Assert.True(await UntilValueMatches(lengthValues, 1));
+            await WaitForCounterValue(lengthValues, expectedValue: 1, Logger);
 
             using (eventSource.QueueTimer())
             {
-                Assert.True(await UntilValueMatches(lengthValues, 2));
+                await WaitForCounterValue(lengthValues, expectedValue: 2, Logger);
             }
 
-            Assert.True(await UntilValueMatches(lengthValues, 1));
+            await WaitForCounterValue(lengthValues, expectedValue: 1, Logger);
         }
 
-        Assert.True(await UntilValueMatches(lengthValues, 0));
+        await WaitForCounterValue(lengthValues, expectedValue: 0, Logger);
     }
 
     [Fact]
@@ -96,7 +97,7 @@ public async Task TracksDurationSpentInQueue()
 
         using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(5));
 
-        var durationValues = eventListener.GetCounterValues("queue-duration", timeoutTokenSource.Token).GetAsyncEnumerator();
+        var durationValues = eventListener.GetCounterValues("queue-duration", timeoutTokenSource.Token);
 
         eventListener.EnableEvents(eventSource, EventLevel.Informational, EventKeywords.None,
             new Dictionary<string, string>
@@ -105,17 +106,17 @@ public async Task TracksDurationSpentInQueue()
             });
 
         // Act
-        Assert.True(await UntilValueMatches(durationValues, 0));
+        await WaitForCounterValue(durationValues, expectedValue: 0, Logger);
 
         using (eventSource.QueueTimer())
         {
-            Assert.True(await UntilValueMatches(durationValues, 0));
+            await WaitForCounterValue(durationValues, expectedValue: 0, Logger);
         }
 
         // check that something (anything!) has been written
-        while (await durationValues.MoveNextAsync())
+        while (await durationValues.Values.MoveNextAsync())
         {
-            if (durationValues.Current > 0)
+            if (durationValues.Values.Current > 0)
             {
                 return;
             }
@@ -124,17 +125,9 @@ public async Task TracksDurationSpentInQueue()
         throw new TimeoutException();
     }
 
-    private async Task<bool> UntilValueMatches(IAsyncEnumerator<double> enumerator, int value)
+    private static async Task WaitForCounterValue(CounterValues values, double expectedValue, ILogger logger)
     {
-        while (await enumerator.MoveNextAsync())
-        {
-            if (enumerator.Current == value)
-            {
-                return true;
-            }
-        }
-
-        return false;
+        await values.Values.WaitForValueAsync(expectedValue, values.CounterName, logger);
     }
 
     private static ConcurrencyLimiterEventSource GetConcurrencyLimiterEventSource()

diff --git a/src/Middleware/ConcurrencyLimiter/test/Microsoft.AspNetCore.ConcurrencyLimiter.Tests.csproj b/src/Middleware/ConcurrencyLimiter/test/Microsoft.AspNetCore.ConcurrencyLimiter.Tests.csproj
@@ -7,6 +7,7 @@
   <ItemGroup>
     <Compile Include="$(SharedSourceRoot)EventSource.Testing\TestCounterListener.cs" />
     <Compile Include="$(SharedSourceRoot)EventSource.Testing\TestEventListener.cs" />
+    <Compile Include="$(SharedSourceRoot)AsyncEnumerableExtensions.cs" LinkBase="shared" />
   </ItemGroup>
 
   <ItemGroup>

diff --git a/...est/Internal/AsyncEnumerableExtensions.cs → src/Shared/AsyncEnumerableExtensions.cs b/...est/Internal/AsyncEnumerableExtensions.cs → src/Shared/AsyncEnumerableExtensions.cs
@@ -2,12 +2,13 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System.Numerics;
+using Microsoft.Extensions.Logging;
 
-namespace System.Collections.Generic;
+namespace Microsoft.AspNetCore.InternalTesting;
 
 internal static class AsyncEnumerableExtensions
 {
-    public static async Task WaitForValueAsync<T>(this IAsyncEnumerator<T> values, T expectedValue) where T : INumber<T>
+    public static async Task WaitForValueAsync<T>(this IAsyncEnumerator<T> values, T expectedValue, string operationName, ILogger logger) where T : INumber<T>
     {
         T value = T.Zero;
         try
@@ -17,37 +18,18 @@ public static async Task WaitForValueAsync<T>(this IAsyncEnumerator<T> values, T
                 value = values.Current;
                 if (value == expectedValue)
                 {
+                    logger.LogDebug("Operation {OperationName} completed with value {Value}.", operationName, value);
                     return;
                 }
-            }
-
-            throw new InvalidOperationException("Data ended without match.");
-        }
-        catch (Exception ex)
-        {
-            throw new InvalidOperationException($"Results ended with final value of {value}. Expected value of {expectedValue}.", ex);
-        }
-    }
 
-    public static async Task WaitForSumValueAsync<T>(this IAsyncEnumerator<T> values, T expectedValue) where T: INumber<T>
-    {
-        T value = T.Zero;
-        try
-        {
-            while (await values.MoveNextAsync())
-            {
-                value += values.Current;
-                if (value == expectedValue)
-                {
-                    return;
-                }
+                logger.LogDebug("Operation {OperationName} expected {ExpectedValue} but got {Value}.", operationName, expectedValue, value);
             }
 
             throw new InvalidOperationException("Data ended without match.");
         }
         catch (Exception ex)
         {
-            throw new InvalidOperationException($"Results ended with final sum value of {value}. Expected sum value of {expectedValue}.", ex);
+            throw new InvalidOperationException($"Results ended with final value of {value}. Expected value of {expectedValue}.", ex);
         }
     }
 }
diff --git a/src/Shared/EventSource.Testing/TestCounterListener.cs b/src/Shared/EventSource.Testing/TestCounterListener.cs
@@ -9,6 +9,12 @@
 
 namespace Microsoft.AspNetCore.Internal;
 
+internal sealed class CounterValues(string counterName, IAsyncEnumerator<double> values)
+{
+    public string CounterName { get; } = counterName;
+    public IAsyncEnumerator<double> Values { get; } = values;
+}
+
 internal sealed class TestCounterListener : EventListener
 {
     private readonly Dictionary<string, Channel<double>> _counters = new Dictionary<string, Channel<double>>();
@@ -30,9 +36,10 @@ public TestCounterListener(ILoggerFactory loggerFactory, string eventSourceName,
         _eventSourceName = eventSourceName;
     }
 
-    public IAsyncEnumerable<double> GetCounterValues(string counterName, CancellationToken cancellationToken = default)
+    public CounterValues GetCounterValues(string counterName, CancellationToken cancellationToken = default)
     {
-        return _counters[counterName].Reader.ReadAllAsync(cancellationToken);
+        var values = _counters[counterName].Reader.ReadAllAsync(cancellationToken).GetAsyncEnumerator(cancellationToken);
+        return new CounterValues(counterName, values);
     }
 
     protected override void OnEventWritten(EventWrittenEventArgs eventData)