Extend NIOEventLoopTickInfo with end-time and loop sleep time

Sources/NIOPosix/SelectableEventLoop.swift

@@ -53,13 +53,25 @@ public struct NIOEventLoopTickInfo: Sendable, Hashable {
     public var eventLoopID: ObjectIdentifier
     /// The number of tasks which were executed in this tick
     public var numberOfTasks: Int
+    /// The time the event loop slept since the last tick
+    public var sleepTime: TimeAmount
     /// The time at which the tick began
     public var startTime: NIODeadline
+    /// The time at which the tick finished
+    public var endTime: NIODeadline
 
-    internal init(eventLoopID: ObjectIdentifier, numberOfTasks: Int, startTime: NIODeadline) {
+    internal init(
+        eventLoopID: ObjectIdentifier,
+        numberOfTasks: Int,
+        sleepTime: TimeAmount,
+        startTime: NIODeadline,
+        endTime: NIODeadline
+    ) {
         self.eventLoopID = eventLoopID
         self.numberOfTasks = numberOfTasks
+        self.sleepTime = sleepTime
         self.startTime = startTime
+        self.endTime = endTime
     }
 }
 
@@ -169,6 +181,8 @@ internal final class SelectableEventLoop: EventLoop, @unchecked Sendable {
 
     private let metricsDelegate: (any NIOEventLoopMetricsDelegate)?
 
+    private var lastTickEndTime: NIODeadline
+
     @usableFromInline
     internal func _promiseCreated(futureIdentifier: _NIOEventLoopFutureIdentifier, file: StaticString, line: UInt) {
         precondition(_isDebugAssertConfiguration())
@@ -246,6 +260,7 @@ internal final class SelectableEventLoop: EventLoop, @unchecked Sendable {
         self.msgBufferPool = Pool<PooledMsgBuffer>(maxSize: 16)
         self.tasksCopy.reserveCapacity(Self.tasksCopyBatchSize)
         self.canBeShutdownIndividually = canBeShutdownIndividually
+        self.lastTickEndTime = .now()
         // note: We are creating a reference cycle here that we'll break when shutting the SelectableEventLoop down.
         // note: We have to create the promise and complete it because otherwise we'll hit a loop in `makeSucceededFuture`. This is
         //       fairly dumb, but it's the only option we have.
@@ -722,14 +737,19 @@ internal final class SelectableEventLoop: EventLoop, @unchecked Sendable {
 
     private func runLoop(selfIdentifier: ObjectIdentifier) -> NIODeadline? {
         let tickStartTime: NIODeadline = .now()
+        let sleepTime: TimeAmount = tickStartTime - self.lastTickEndTime
         var tasksProcessedInTick = 0
         defer {
+            let tickEndTime: NIODeadline = .now()
             let tickInfo = NIOEventLoopTickInfo(
                 eventLoopID: selfIdentifier,
                 numberOfTasks: tasksProcessedInTick,
-                startTime: tickStartTime
+                sleepTime: sleepTime,
+                startTime: tickStartTime,
+                endTime: tickEndTime
             )
             self.metricsDelegate?.processedTick(info: tickInfo)
+            self.lastTickEndTime = tickEndTime
         }
         while true {
             let nextReadyDeadline = self._tasksLock.withLock { () -> NIODeadline? in

Tests/NIOPosixTests/EventLoopMetricsDelegateTests.swift

@@ -49,22 +49,36 @@ final class EventLoopMetricsDelegateTests: XCTestCase {
         XCTAssertEqual(delegate.infos.count, 0)
 
         let promise = el.makePromise(of: Void.self)
+        el.scheduleTask(in: .milliseconds(100)) {
+            // Nop. Ensures that we collect multiple tick infos.
+        }
         el.scheduleTask(in: .seconds(1)) {
             promise.succeed()
         }
+
         promise.futureResult.whenSuccess {
-            // There are 3 tasks (scheduleTask, whenSuccess, wait) which can trigger a total of 1...3 ticks
-            XCTAssertTrue((1...3).contains(delegate.infos.count), "Expected 1...3 ticks, got \(delegate.infos.count)")
-            // the total number of tasks across these ticks should be either 2 or 3
+            // There are 4 tasks (scheduleTask, scheduleTask, whenSuccess, wait) which can trigger a total of 2...4 ticks
+            XCTAssertTrue((2...4).contains(delegate.infos.count), "Expected 2...4 ticks, got \(delegate.infos.count)")
+            // The total number of tasks across these ticks should be either 3 or 4
             let totalTasks = delegate.infos.map { $0.numberOfTasks }.reduce(0, { $0 + $1 })
-            XCTAssertTrue((2...3).contains(totalTasks), "Expected 2...3 tasks, got \(totalTasks)")
+            XCTAssertTrue((3...4).contains(totalTasks), "Expected 3...4 tasks, got \(totalTasks)")
+            // All tasks were run by the same event loop. The measurements are monotonically increasing.
+            var lastEndTime: NIODeadline?
             for info in delegate.infos {
                 XCTAssertEqual(info.eventLoopID, ObjectIdentifier(el))
+                XCTAssertTrue(info.startTime < info.endTime)
+                // If this is not the first tick, verify the sleep time.
+                if let lastEndTime {
+                    XCTAssertTrue(lastEndTime < info.startTime)
+                    XCTAssertEqual(lastEndTime + info.sleepTime, info.startTime)
+                }
+                // Keep track of the last event time to verify the sleep interval.
+                lastEndTime = info.endTime
             }
             if let lastTickStartTime = delegate.infos.last?.startTime {
                 let timeSinceStart = lastTickStartTime - testStartTime
-                // This should be near instant, limiting to 100ms
-                XCTAssertLessThan(timeSinceStart.nanoseconds, 100_000_000)
+                // This should be near instantly after the delay of the first run.
+                XCTAssertLessThan(timeSinceStart.nanoseconds, 200_000_000)
                 XCTAssertGreaterThan(timeSinceStart.nanoseconds, 0)
             }
         }