Skip to content

Commit 6b484ec

Browse files
authored
Make testMetricsDelegateTickInfo less flaky (#3335)
Motivation: testMetricsDelegateTickInfo fails occasionally because there are more event loop ticks than it expects. This is because the expectation in the test was incorrect. Modifications: - Update the test expectation and an explanation of how we got to that number. - Shutdown the ELG while we're at it. Result: Tests are less flaky
1 parent 4151adf commit 6b484ec

File tree

1 file changed

+37
-7
lines changed

1 file changed

+37
-7
lines changed

Tests/NIOPosixTests/EventLoopMetricsDelegateTests.swift

Lines changed: 37 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -34,15 +34,19 @@ final class RecorderDelegate: NIOEventLoopMetricsDelegate, Sendable {
3434
}
3535

3636
final class EventLoopMetricsDelegateTests: XCTestCase {
37-
func testMetricsDelegateNotCalledWhenNoEvents() {
37+
func testMetricsDelegateNotCalledWhenNoEvents() throws {
3838
let delegate = RecorderDelegate()
39-
_ = MultiThreadedEventLoopGroup(numberOfThreads: 1, metricsDelegate: delegate)
39+
let group = MultiThreadedEventLoopGroup(numberOfThreads: 1, metricsDelegate: delegate)
4040
XCTAssertEqual(delegate.infos.count, 0)
41+
try group.syncShutdownGracefully()
4142
}
4243

4344
func testMetricsDelegateTickInfo() {
4445
let delegate = RecorderDelegate()
4546
let elg = MultiThreadedEventLoopGroup(numberOfThreads: 1, metricsDelegate: delegate)
47+
defer {
48+
XCTAssertNoThrow(try elg.syncShutdownGracefully())
49+
}
4650
let el = elg.any()
4751
let testStartTime = NIODeadline.now()
4852

@@ -57,11 +61,37 @@ final class EventLoopMetricsDelegateTests: XCTestCase {
5761
}
5862

5963
promise.futureResult.whenSuccess {
60-
// There are 4 tasks (scheduleTask, scheduleTask, whenSuccess, wait) which can trigger a total of 2...4 ticks
61-
XCTAssertTrue((2...4).contains(delegate.infos.count), "Expected 2...4 ticks, got \(delegate.infos.count)")
62-
// The total number of tasks across these ticks should be either 3 or 4
63-
let totalTasks = delegate.infos.map { $0.numberOfTasks }.reduce(0, { $0 + $1 })
64-
XCTAssertTrue((3...4).contains(totalTasks), "Expected 3...4 tasks, got \(totalTasks)")
64+
// There are 4 tasks here:
65+
// 1. scheduleTask in 100ms,
66+
// 2. scheduleTask in 1s,
67+
// 3. whenSuccess (this callback),
68+
// 4. wait() (which is secrectly a whenComplete)
69+
//
70+
// These can run in 2...6 event loop ticks. The worst case happens when:
71+
// 1. The selector blocks after the EL is created and is woken by the 100ms task being
72+
// scheduled. The EL wakes up but has no tasks to run so goes blocks until no later
73+
// than the 100ms task needs running.
74+
// 2. The 1s task is scheduled which causes the selector to wakeup again but it has
75+
// nothing to do. It goes back to sleep blocking until the 100ms task is run.
76+
// 3. whenSuccess is called which wakes the selector as whenSuccess executes onto
77+
// the EL to enqueue the task. The selector goes back to sleep waiting for the
78+
// 100ms task.
79+
// 4. wait() is called which under the hood does a whenComplete which can then wake the
80+
// as per (3). The selector goes back to sleep waiting for the 100ms task.
81+
// 5. The EL wakes up and runs the 100ms task. It goes back to sleep waiting for the
82+
// 1s task.
83+
// 6. The 1s task is run which succeeds the promise and runs both this whenSuccess
84+
// callback and the whenComplete in the wait().
85+
//
86+
// Why a maximum of five? I literally just listed six times the loop can tick. This
87+
// task (whenSuccess) is running as part of the last tick, and so the info hasn't
88+
// been published to the delegate yet.
89+
XCTAssertTrue((2...5).contains(delegate.infos.count), "Expected 2...5 ticks, got \(delegate.infos.count)")
90+
91+
// The total number of tasks across these ticks should be 3. Not four, because this
92+
// task is the fourth and it hasn't finished running yet.
93+
let totalTasks = delegate.infos.map { $0.numberOfTasks }.reduce(0, +)
94+
XCTAssertEqual(totalTasks, 3, "Expected 3 tasks, got \(totalTasks)")
6595
// All tasks were run by the same event loop. The measurements are monotonically increasing.
6696
var lastEndTime: NIODeadline?
6797
for info in delegate.infos {

0 commit comments

Comments
 (0)