diff --git a/Sources/Runner/PreflightPostflightTimeoutTrackingTestRunnerStream.swift b/Sources/Runner/PreflightPostflightTimeoutTrackingTestRunnerStream.swift new file mode 100644 index 00000000..a7b942cb --- /dev/null +++ b/Sources/Runner/PreflightPostflightTimeoutTrackingTestRunnerStream.swift @@ -0,0 +1,128 @@ +import AtomicModels +import DateProvider +import Foundation +import Logging +import RunnerModels +import Timer + +/// Tracks hangs that happen before starting any tests. or after fninishing any test, including in between test invocations. +public final class PreflightPostflightTimeoutTrackingTestRunnerStream: TestRunnerStream { + private let dateProvider: DateProvider + private let onPreflightTimeout: () -> () + private let onPostflightTimeout: (TestName) -> () + private let lastEventInfo = AtomicValue(nil) + private let maximumPreflightDuration: TimeInterval + private let maximumPostflightDuration: TimeInterval + private let pollPeriod: DispatchTimeInterval + private var trackingTimer: DispatchBasedTimer? + + struct LastEventInfo { + let finishedTestName: TestName? + let timestamp: Date + } + + public init( + dateProvider: DateProvider, + onPreflightTimeout: @escaping () -> (), + onPostflightTimeout: @escaping (TestName) -> (), + maximumPreflightDuration: TimeInterval, + maximumPostflightDuration: TimeInterval, + pollPeriod: DispatchTimeInterval + ) { + self.dateProvider = dateProvider + self.onPreflightTimeout = onPreflightTimeout + self.onPostflightTimeout = onPostflightTimeout + self.maximumPreflightDuration = maximumPreflightDuration + self.maximumPostflightDuration = maximumPostflightDuration + self.pollPeriod = pollPeriod + } + + public func openStream() { + lastEventInfo.set( + LastEventInfo( + finishedTestName: nil, + timestamp: dateProvider.currentDate() + ) + ) + startPreflightTimeoutTracking() + } + + public func testStarted(testName: TestName) { + stopAnyTracking() + } + + public func caughtException(testException: TestException) {} + + public func testStopped(testStoppedEvent: TestStoppedEvent) { + lastEventInfo.set( + LastEventInfo( + finishedTestName: testStoppedEvent.testName, + timestamp: dateProvider.currentDate() + ) + ) + startPostflightTimeoutTracking() + } + + public func closeStream() { + lastEventInfo.set(nil) + stopAnyTracking() + } + + private func startPreflightTimeoutTracking() { + startMonitoringForHangs() + } + + private func startPostflightTimeoutTracking() { + startMonitoringForHangs() + } + + private func stopAnyTracking() { + stopMonitoringForHangs() + } + + // MARK: - Logic + + private func startMonitoringForHangs() { + trackingTimer = DispatchBasedTimer.startedTimer( + repeating: pollPeriod, + leeway: pollPeriod, + handler: { [weak self] timer in + guard let strongSelf = self else { return timer.stop() } + strongSelf.processTimerFireEvent() + } + ) + } + + private func stopMonitoringForHangs() { + trackingTimer?.stop() + trackingTimer = nil + } + + private func processTimerFireEvent() { + guard let eventInfo = lastEventInfo.currentValue() else { + return stopAnyTracking() + } + + if let lastFinishedTestName = eventInfo.finishedTestName { + // some tests finished - postflight + validatePostflightTimeout(since: eventInfo.timestamp, testName: lastFinishedTestName) + } else { + // no tests finished yet - preflight + validatePreflightTimeout(since: eventInfo.timestamp) + } + } + + private func validatePreflightTimeout(since date: Date) { + if dateProvider.currentDate().timeIntervalSince(date) > maximumPostflightDuration { + stopAnyTracking() + onPreflightTimeout() + } + } + + private func validatePostflightTimeout(since date: Date, testName: TestName) { + if dateProvider.currentDate().timeIntervalSince(date) > maximumPostflightDuration { + stopAnyTracking() + onPostflightTimeout(testName) + } + } +} diff --git a/Sources/Runner/Runner.swift b/Sources/Runner/Runner.swift index c071dbc2..17406c9c 100755 --- a/Sources/Runner/Runner.swift +++ b/Sources/Runner/Runner.swift @@ -230,6 +230,20 @@ public final class Runner { streamClosedCallback.set(result: ()) } ), + PreflightPostflightTimeoutTrackingTestRunnerStream( + dateProvider: dateProvider, + onPreflightTimeout: { + Logger.debug("Detected preflight timeout", testRunnerRunningInvocationContainer.currentValue()?.subprocessInfo) + testRunnerRunningInvocationContainer.currentValue()?.cancel() + }, + onPostflightTimeout: { testName in + Logger.debug("Detected postflight timeout, last finished test was \(testName)", testRunnerRunningInvocationContainer.currentValue()?.subprocessInfo) + testRunnerRunningInvocationContainer.currentValue()?.cancel() + }, + maximumPreflightDuration: configuration.testTimeoutConfiguration.testRunnerMaximumSilenceDuration, + maximumPostflightDuration: configuration.testTimeoutConfiguration.testRunnerMaximumSilenceDuration, + pollPeriod: testTimeoutCheckInterval + ) ] ) diff --git a/Tests/RunnerTests/PreflightPostflightTimeoutTrackingTestRunnerStreamTests.swift b/Tests/RunnerTests/PreflightPostflightTimeoutTrackingTestRunnerStreamTests.swift new file mode 100644 index 00000000..0a2b43ec --- /dev/null +++ b/Tests/RunnerTests/PreflightPostflightTimeoutTrackingTestRunnerStreamTests.swift @@ -0,0 +1,120 @@ +import DateProviderTestHelpers +import Foundation +import Runner +import RunnerModels +import XCTest + +final class PreflightPostflightTimeoutTrackingTestRunnerStreamTests: XCTestCase { + lazy var dateProvider = DateProviderFixture(Date(timeIntervalSince1970: 100)) + lazy var preflightExpectation = XCTestExpectation(description: "preflight callback called") + lazy var postflightExpectation = XCTestExpectation(description: "postflight callback called") + + lazy var testStream = PreflightPostflightTimeoutTrackingTestRunnerStream( + dateProvider: dateProvider, + onPreflightTimeout: { [weak self] in self?.preflightExpectation.fulfill() }, + onPostflightTimeout: { [weak self] _ in self?.postflightExpectation.fulfill() }, + maximumPreflightDuration: 5.0, + maximumPostflightDuration: 0.01, + pollPeriod: .milliseconds(1) + ) + + func test___preflight_is_called___when_stream_opens_and_test_does_not_start() { + postflightExpectation.isInverted = true + + testStream.openStream() + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } + + func test___preflight_is_not_called___when_stream_opens_and_test_starts() { + preflightExpectation.isInverted = true + postflightExpectation.isInverted = true + + testStream.openStream() + testStream.testStarted(testName: TestName(className: "class", methodName: "test")) + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } + + func test___preflight_is_not_called___when_stream_closes() { + preflightExpectation.isInverted = true + postflightExpectation.isInverted = true + + testStream.openStream() + testStream.closeStream() + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } + + func test___postflight_is_called___when_test_finished_but_next_does_not_start() { + preflightExpectation.isInverted = true + + testStream.openStream() + testStream.testStarted( + testName: TestName(className: "class", methodName: "test1") + ) + testStream.testStopped( + testStoppedEvent: TestStoppedEvent( + testName: TestName(className: "class", methodName: "test1"), + result: .success, + testDuration: 1, + testExceptions: [], + testStartTimestamp: dateProvider.currentDate().timeIntervalSince1970) + ) + + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } + + func test___postflight_is_not_called___when_test_finished_and_next_starts() { + preflightExpectation.isInverted = true + postflightExpectation.isInverted = true + + testStream.openStream() + testStream.testStarted( + testName: TestName(className: "class", methodName: "test1") + ) + testStream.testStopped( + testStoppedEvent: TestStoppedEvent( + testName: TestName(className: "class", methodName: "test1"), + result: .success, + testDuration: 1, + testExceptions: [], + testStartTimestamp: dateProvider.currentDate().timeIntervalSince1970) + ) + testStream.testStarted( + testName: TestName(className: "class", methodName: "test2") + ) + + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } + + func test___postflight_is_not_called___when_test_finished_stream_closed() { + preflightExpectation.isInverted = true + postflightExpectation.isInverted = true + + testStream.openStream() + testStream.testStarted( + testName: TestName(className: "class", methodName: "test1") + ) + testStream.testStopped( + testStoppedEvent: TestStoppedEvent( + testName: TestName(className: "class", methodName: "test1"), + result: .success, + testDuration: 1, + testExceptions: [], + testStartTimestamp: dateProvider.currentDate().timeIntervalSince1970) + ) + testStream.closeStream() + + dateProvider.result += 5 + + wait(for: [preflightExpectation, postflightExpectation], timeout: 5) + } +}