Skip to content

Commit a03b790

Browse files
JamesNKamcasey
andauthored
Address flaky hosting event counters tests (#57269)
Co-authored-by: Andrew Casey <amcasey@users.noreply.github.com>
1 parent 0f60869 commit a03b790

File tree

5 files changed

+140
-73
lines changed

5 files changed

+140
-73
lines changed

src/Hosting/Hosting/test/HostingApplicationDiagnosticsTests.cs

Lines changed: 27 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@
1919

2020
namespace Microsoft.AspNetCore.Hosting.Tests;
2121

22-
public class HostingApplicationDiagnosticsTests
22+
public class HostingApplicationDiagnosticsTests : LoggedTest
2323
{
2424
[Fact]
2525
[QuarantinedTest("https://github.com/dotnet/aspnetcore/issues/57259")]
@@ -28,16 +28,17 @@ public async Task EventCountersAndMetricsValues()
2828
// Arrange
2929
var hostingEventSource = new HostingEventSource(Guid.NewGuid().ToString());
3030

31-
var eventListener = new TestCounterListener(new[]
32-
{
31+
using var eventListener = new TestCounterListener(LoggerFactory, hostingEventSource.Name,
32+
[
3333
"requests-per-second",
3434
"total-requests",
3535
"current-requests",
3636
"failed-requests"
37-
});
37+
]);
3838

3939
var timeout = !Debugger.IsAttached ? TimeSpan.FromSeconds(30) : Timeout.InfiniteTimeSpan;
4040
using CancellationTokenSource timeoutTokenSource = new CancellationTokenSource(timeout);
41+
timeoutTokenSource.Token.Register(() => Logger.LogError("Timeout while waiting for counter value."));
4142

4243
var rpsValues = eventListener.GetCounterValues("requests-per-second", timeoutTokenSource.Token).GetAsyncEnumerator();
4344
var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
@@ -53,8 +54,9 @@ public async Task EventCountersAndMetricsValues()
5354
var testMeterFactory1 = new TestMeterFactory();
5455
var testMeterFactory2 = new TestMeterFactory();
5556

56-
var hostingApplication1 = CreateApplication(out var features1, eventSource: hostingEventSource, meterFactory: testMeterFactory1);
57-
var hostingApplication2 = CreateApplication(out var features2, eventSource: hostingEventSource, meterFactory: testMeterFactory2);
57+
var logger = LoggerFactory.CreateLogger<HostingApplication>();
58+
var hostingApplication1 = CreateApplication(out var features1, eventSource: hostingEventSource, meterFactory: testMeterFactory1, logger: logger);
59+
var hostingApplication2 = CreateApplication(out var features2, eventSource: hostingEventSource, meterFactory: testMeterFactory2, logger: logger);
5860

5961
using var activeRequestsCollector1 = new MetricCollector<long>(testMeterFactory1, HostingMetrics.MeterName, "http.server.active_requests");
6062
using var activeRequestsCollector2 = new MetricCollector<long>(testMeterFactory2, HostingMetrics.MeterName, "http.server.active_requests");
@@ -65,18 +67,18 @@ public async Task EventCountersAndMetricsValues()
6567
var context1 = hostingApplication1.CreateContext(features1);
6668
var context2 = hostingApplication2.CreateContext(features2);
6769

68-
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
69-
Assert.Equal(2, await rpsValues.FirstOrDefault(v => v == 2));
70-
Assert.Equal(2, await currentRequestValues.FirstOrDefault(v => v == 2));
71-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
70+
await totalRequestValues.WaitForSumValueAsync(2);
71+
await rpsValues.WaitForValueAsync(2);
72+
await currentRequestValues.WaitForValueAsync(2);
73+
await failedRequestValues.WaitForValueAsync(0);
7274

7375
hostingApplication1.DisposeContext(context1, null);
7476
hostingApplication2.DisposeContext(context2, null);
7577

76-
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
77-
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
78-
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
79-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
78+
await totalRequestValues.WaitForSumValueAsync(2);
79+
await rpsValues.WaitForValueAsync(0);
80+
await currentRequestValues.WaitForValueAsync(0);
81+
await failedRequestValues.WaitForValueAsync(0);
8082

8183
Assert.Collection(activeRequestsCollector1.GetMeasurementSnapshot(),
8284
m => Assert.Equal(1, m.Value),
@@ -93,21 +95,21 @@ public async Task EventCountersAndMetricsValues()
9395
context1 = hostingApplication1.CreateContext(features1);
9496
context2 = hostingApplication2.CreateContext(features2);
9597

96-
Assert.Equal(4, await totalRequestValues.FirstOrDefault(v => v == 4));
97-
Assert.Equal(2, await rpsValues.FirstOrDefault(v => v == 2));
98-
Assert.Equal(2, await currentRequestValues.FirstOrDefault(v => v == 2));
99-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
98+
await totalRequestValues.WaitForSumValueAsync(4);
99+
await rpsValues.WaitForValueAsync(2);
100+
await currentRequestValues.WaitForValueAsync(2);
101+
await failedRequestValues.WaitForValueAsync(0);
100102

101103
context1.HttpContext.Response.StatusCode = StatusCodes.Status500InternalServerError;
102104
context2.HttpContext.Response.StatusCode = StatusCodes.Status500InternalServerError;
103105

104106
hostingApplication1.DisposeContext(context1, null);
105107
hostingApplication2.DisposeContext(context2, null);
106108

107-
Assert.Equal(4, await totalRequestValues.FirstOrDefault(v => v == 4));
108-
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
109-
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
110-
Assert.Equal(2, await failedRequestValues.FirstOrDefault(v => v == 2));
109+
await totalRequestValues.WaitForSumValueAsync(4);
110+
await rpsValues.WaitForValueAsync(0);
111+
await currentRequestValues.WaitForValueAsync(0);
112+
await failedRequestValues.WaitForValueAsync(2);
111113

112114
Assert.Collection(activeRequestsCollector1.GetMeasurementSnapshot(),
113115
m => Assert.Equal(1, m.Value),
@@ -133,13 +135,13 @@ public void EventCountersEnabled()
133135
// Arrange
134136
var hostingEventSource = new HostingEventSource(Guid.NewGuid().ToString());
135137

136-
var eventListener = new TestCounterListener(new[]
137-
{
138+
using var eventListener = new TestCounterListener(LoggerFactory, hostingEventSource.Name,
139+
[
138140
"requests-per-second",
139141
"total-requests",
140142
"current-requests",
141143
"failed-requests"
142-
});
144+
]);
143145

144146
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational, EventKeywords.None,
145147
new Dictionary<string, string>
Lines changed: 38 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,20 +1,53 @@
11
// Licensed to the .NET Foundation under one or more agreements.
22
// The .NET Foundation licenses this file to you under the MIT license.
33

4+
using System.Numerics;
5+
46
namespace System.Collections.Generic;
57

68
internal static class AsyncEnumerableExtensions
79
{
8-
public static async Task<T> FirstOrDefault<T>(this IAsyncEnumerator<T> values, Func<T, bool> filter)
10+
public static async Task WaitForValueAsync<T>(this IAsyncEnumerator<T> values, T expectedValue) where T : INumber<T>
911
{
10-
while (await values.MoveNextAsync())
12+
T value = T.Zero;
13+
try
1114
{
12-
if (filter(values.Current))
15+
while (await values.MoveNextAsync())
1316
{
14-
return values.Current;
17+
value = values.Current;
18+
if (value == expectedValue)
19+
{
20+
return;
21+
}
1522
}
23+
24+
throw new InvalidOperationException("Data ended without match.");
25+
}
26+
catch (Exception ex)
27+
{
28+
throw new InvalidOperationException($"Results ended with final value of {value}. Expected value of {expectedValue}.", ex);
1629
}
30+
}
1731

18-
return default;
32+
public static async Task WaitForSumValueAsync<T>(this IAsyncEnumerator<T> values, T expectedValue) where T: INumber<T>
33+
{
34+
T value = T.Zero;
35+
try
36+
{
37+
while (await values.MoveNextAsync())
38+
{
39+
value += values.Current;
40+
if (value == expectedValue)
41+
{
42+
return;
43+
}
44+
}
45+
46+
throw new InvalidOperationException("Data ended without match.");
47+
}
48+
catch (Exception ex)
49+
{
50+
throw new InvalidOperationException($"Results ended with final sum value of {value}. Expected sum value of {expectedValue}.", ex);
51+
}
1952
}
2053
}

src/Hosting/Hosting/test/Internal/HostingEventSourceTests.cs

Lines changed: 30 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -6,10 +6,11 @@
66
using Microsoft.AspNetCore.Http;
77
using Microsoft.AspNetCore.Internal;
88
using Microsoft.AspNetCore.InternalTesting;
9+
using Microsoft.Extensions.Logging;
910

1011
namespace Microsoft.AspNetCore.Hosting;
1112

12-
public class HostingEventSourceTests
13+
public class HostingEventSourceTests : LoggedTest
1314
{
1415
[Fact]
1516
public void MatchesNameAndGuid()
@@ -179,17 +180,18 @@ public void UnhandledException()
179180
public async Task VerifyCountersFireWithCorrectValues()
180181
{
181182
// Arrange
182-
var eventListener = new TestCounterListener(new[]
183-
{
183+
var hostingEventSource = GetHostingEventSource();
184+
185+
using var eventListener = new TestCounterListener(LoggerFactory, hostingEventSource.Name,
186+
[
184187
"requests-per-second",
185188
"total-requests",
186189
"current-requests",
187190
"failed-requests"
188-
});
189-
190-
var hostingEventSource = GetHostingEventSource();
191+
]);
191192

192193
using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(30));
194+
timeoutTokenSource.Token.Register(() => Logger.LogError("Timeout while waiting for counter value."));
193195

194196
var rpsValues = eventListener.GetCounterValues("requests-per-second", timeoutTokenSource.Token).GetAsyncEnumerator();
195197
var totalRequestValues = eventListener.GetCounterValues("total-requests", timeoutTokenSource.Token).GetAsyncEnumerator();
@@ -199,38 +201,43 @@ public async Task VerifyCountersFireWithCorrectValues()
199201
eventListener.EnableEvents(hostingEventSource, EventLevel.Informational, EventKeywords.None,
200202
new Dictionary<string, string>
201203
{
202-
{ "EventCounterIntervalSec", "1" }
204+
{ "EventCounterIntervalSec", "1" }
203205
});
204206

205207
// Act & Assert
208+
Logger.LogInformation(nameof(HostingEventSource.RequestStart));
206209
hostingEventSource.RequestStart("GET", "/");
207210

208-
Assert.Equal(1, await totalRequestValues.FirstOrDefault(v => v == 1));
209-
Assert.Equal(1, await rpsValues.FirstOrDefault(v => v == 1));
210-
Assert.Equal(1, await currentRequestValues.FirstOrDefault(v => v == 1));
211-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
211+
await totalRequestValues.WaitForSumValueAsync(1);
212+
await rpsValues.WaitForValueAsync(1);
213+
await currentRequestValues.WaitForValueAsync(1);
214+
await failedRequestValues.WaitForValueAsync(0);
212215

216+
Logger.LogInformation(nameof(HostingEventSource.RequestStop));
213217
hostingEventSource.RequestStop();
214218

215-
Assert.Equal(1, await totalRequestValues.FirstOrDefault(v => v == 1));
216-
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
217-
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
218-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
219+
await totalRequestValues.WaitForSumValueAsync(1);
220+
await rpsValues.WaitForValueAsync(0);
221+
await currentRequestValues.WaitForValueAsync(0);
222+
await failedRequestValues.WaitForValueAsync(0);
219223

224+
Logger.LogInformation(nameof(HostingEventSource.RequestStart));
220225
hostingEventSource.RequestStart("POST", "/");
221226

222-
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
223-
Assert.Equal(1, await rpsValues.FirstOrDefault(v => v == 1));
224-
Assert.Equal(1, await currentRequestValues.FirstOrDefault(v => v == 1));
225-
Assert.Equal(0, await failedRequestValues.FirstOrDefault(v => v == 0));
227+
await totalRequestValues.WaitForSumValueAsync(2);
228+
await rpsValues.WaitForValueAsync(1);
229+
await currentRequestValues.WaitForValueAsync(1);
230+
await failedRequestValues.WaitForValueAsync(0);
226231

232+
Logger.LogInformation(nameof(HostingEventSource.RequestFailed));
227233
hostingEventSource.RequestFailed();
234+
Logger.LogInformation(nameof(HostingEventSource.RequestStop));
228235
hostingEventSource.RequestStop();
229236

230-
Assert.Equal(2, await totalRequestValues.FirstOrDefault(v => v == 2));
231-
Assert.Equal(0, await rpsValues.FirstOrDefault(v => v == 0));
232-
Assert.Equal(0, await currentRequestValues.FirstOrDefault(v => v == 0));
233-
Assert.Equal(1, await failedRequestValues.FirstOrDefault(v => v == 1));
237+
await totalRequestValues.WaitForSumValueAsync(2);
238+
await rpsValues.WaitForValueAsync(0);
239+
await currentRequestValues.WaitForValueAsync(0);
240+
await failedRequestValues.WaitForValueAsync(1);
234241
}
235242

236243
private static HostingEventSource GetHostingEventSource()

src/Middleware/ConcurrencyLimiter/test/ConcurrencyLimiterEventSourceTests.cs

Lines changed: 16 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -4,10 +4,11 @@
44
using System.Globalization;
55
using System.Diagnostics.Tracing;
66
using Microsoft.AspNetCore.Internal;
7+
using Microsoft.AspNetCore.InternalTesting;
78

89
namespace Microsoft.AspNetCore.ConcurrencyLimiter.Tests;
910

10-
public class ConcurrencyLimiterEventSourceTests
11+
public class ConcurrencyLimiterEventSourceTests : LoggedTest
1112
{
1213
[Fact]
1314
public void MatchesNameAndGuid()
@@ -44,22 +45,22 @@ public void RecordsRequestsRejected()
4445
public async Task TracksQueueLength()
4546
{
4647
// Arrange
47-
using var eventListener = new TestCounterListener(new[] {
48-
"queue-length",
49-
"queue-duration",
50-
"requests-rejected",
51-
});
52-
5348
using var eventSource = GetConcurrencyLimiterEventSource();
5449

50+
using var eventListener = new TestCounterListener(LoggerFactory, eventSource.Name, [
51+
"queue-length",
52+
"queue-duration",
53+
"requests-rejected",
54+
]);
55+
5556
using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(30));
5657

5758
var lengthValues = eventListener.GetCounterValues("queue-length", timeoutTokenSource.Token).GetAsyncEnumerator();
5859

5960
eventListener.EnableEvents(eventSource, EventLevel.Informational, EventKeywords.None,
6061
new Dictionary<string, string>
6162
{
62-
{"EventCounterIntervalSec", ".1" }
63+
{"EventCounterIntervalSec", ".1" }
6364
});
6465

6566
// Act
@@ -85,22 +86,22 @@ public async Task TracksQueueLength()
8586
public async Task TracksDurationSpentInQueue()
8687
{
8788
// Arrange
88-
using var eventListener = new TestCounterListener(new[] {
89-
"queue-length",
90-
"queue-duration",
91-
"requests-rejected",
92-
});
93-
9489
using var eventSource = GetConcurrencyLimiterEventSource();
9590

91+
using var eventListener = new TestCounterListener(LoggerFactory, eventSource.Name, [
92+
"queue-length",
93+
"queue-duration",
94+
"requests-rejected",
95+
]);
96+
9697
using var timeoutTokenSource = new CancellationTokenSource(TimeSpan.FromSeconds(5));
9798

9899
var durationValues = eventListener.GetCounterValues("queue-duration", timeoutTokenSource.Token).GetAsyncEnumerator();
99100

100101
eventListener.EnableEvents(eventSource, EventLevel.Informational, EventKeywords.None,
101102
new Dictionary<string, string>
102103
{
103-
{"EventCounterIntervalSec", ".1" }
104+
{"EventCounterIntervalSec", ".1" }
104105
});
105106

106107
// Act

0 commit comments

Comments
 (0)