From c4e55a2e4d5579ab5c6cd3677cb799f68c220fca Mon Sep 17 00:00:00 2001 From: Jon Petersson Date: Mon, 18 Sep 2023 13:49:21 +0200 Subject: [PATCH] Fix reliability and time consumption of testInitialConnectionTimings test --- ios/MullvadVPN.xcodeproj/project.pbxproj | 4 + ios/PacketTunnel/PacketTunnelProvider.swift | 3 +- .../TunnelMonitor/TunnelMonitor.swift | 76 ++++++------------- .../TunnelMonitor/TunnelMonitorTimings.swift | 69 +++++++++++++++++ .../TunnelMonitorTests.swift | 41 +++++++--- 5 files changed, 130 insertions(+), 63 deletions(-) create mode 100644 ios/PacketTunnelCore/TunnelMonitor/TunnelMonitorTimings.swift diff --git a/ios/MullvadVPN.xcodeproj/project.pbxproj b/ios/MullvadVPN.xcodeproj/project.pbxproj index f65ffd2851ea..78b4a35e9c8a 100644 --- a/ios/MullvadVPN.xcodeproj/project.pbxproj +++ b/ios/MullvadVPN.xcodeproj/project.pbxproj @@ -403,6 +403,7 @@ 7A2960FD2A964BB700389B82 /* AlertPresentation.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A2960FC2A964BB700389B82 /* AlertPresentation.swift */; }; 7A42DEC92A05164100B209BE /* SettingsInputCell.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A42DEC82A05164100B209BE /* SettingsInputCell.swift */; }; 7A42DECD2A09064C00B209BE /* SelectableSettingsCell.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A42DECC2A09064C00B209BE /* SelectableSettingsCell.swift */; }; + 7A6B4F592AB8412E00123853 /* TunnelMonitorTimings.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A6B4F582AB8412E00123853 /* TunnelMonitorTimings.swift */; }; 7A7AD28D29DC677800480EF1 /* FirstTimeLaunch.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A7AD28C29DC677800480EF1 /* FirstTimeLaunch.swift */; }; 7A7AD28F29DEDB1C00480EF1 /* SettingsHeaderView.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A7AD28E29DEDB1C00480EF1 /* SettingsHeaderView.swift */; }; 7A818F1F29F0305800C7F0F4 /* RootConfiguration.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7A818F1E29F0305800C7F0F4 /* RootConfiguration.swift */; }; @@ -1328,6 +1329,7 @@ 7A2960FC2A964BB700389B82 /* AlertPresentation.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = AlertPresentation.swift; sourceTree = ""; }; 7A42DEC82A05164100B209BE /* SettingsInputCell.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SettingsInputCell.swift; sourceTree = ""; }; 7A42DECC2A09064C00B209BE /* SelectableSettingsCell.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SelectableSettingsCell.swift; sourceTree = ""; }; + 7A6B4F582AB8412E00123853 /* TunnelMonitorTimings.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = TunnelMonitorTimings.swift; sourceTree = ""; }; 7A7AD28C29DC677800480EF1 /* FirstTimeLaunch.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = FirstTimeLaunch.swift; sourceTree = ""; }; 7A7AD28E29DEDB1C00480EF1 /* SettingsHeaderView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SettingsHeaderView.swift; sourceTree = ""; }; 7A818F1E29F0305800C7F0F4 /* RootConfiguration.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = RootConfiguration.swift; sourceTree = ""; }; @@ -2521,6 +2523,7 @@ 58FC040927B3EE03001C21F0 /* TunnelMonitor.swift */, 58C7A42C2A85067A0060C66F /* TunnelMonitorProtocol.swift */, 58A3BDAF28A1821A00C8C2C6 /* WgStats.swift */, + 7A6B4F582AB8412E00123853 /* TunnelMonitorTimings.swift */, ); path = TunnelMonitor; sourceTree = ""; @@ -3735,6 +3738,7 @@ 58C7A4552A863FB90060C66F /* TunnelMonitor.swift in Sources */, 58C7A4512A863FB50060C66F /* PingerProtocol.swift in Sources */, 58C7A4592A863FB90060C66F /* WgStats.swift in Sources */, + 7A6B4F592AB8412E00123853 /* TunnelMonitorTimings.swift in Sources */, 58C7A4582A863FB90060C66F /* TunnelMonitorProtocol.swift in Sources */, ); runOnlyForDeploymentPostprocessing = 0; diff --git a/ios/PacketTunnel/PacketTunnelProvider.swift b/ios/PacketTunnel/PacketTunnelProvider.swift index 61e308d13bf3..d9438deb1283 100644 --- a/ios/PacketTunnel/PacketTunnelProvider.swift +++ b/ios/PacketTunnel/PacketTunnelProvider.swift @@ -182,7 +182,8 @@ class PacketTunnelProvider: NEPacketTunnelProvider { eventQueue: dispatchQueue, pinger: Pinger(replyQueue: dispatchQueue), tunnelDeviceInfo: WgAdapterDeviceInfo(adapter: adapter), - defaultPathObserver: PacketTunnelPathObserver(packetTunnelProvider: self) + defaultPathObserver: PacketTunnelPathObserver(packetTunnelProvider: self), + timings: TunnelMonitorTimings() ) tunnelMonitor.onEvent = { [weak self] event in self?.handleTunnelMonitorEvent(event) diff --git a/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitor.swift b/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitor.swift index 54cbb7353275..576a29533e43 100644 --- a/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitor.swift +++ b/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitor.swift @@ -12,42 +12,6 @@ import MullvadTypes import protocol Network.IPAddress import struct Network.IPv4Address -/// Interval for periodic heartbeat ping issued when traffic is flowing. -/// Should help to detect connectivity issues on networks that drop traffic in one of directions, -/// regardless if tx/rx counters are being updated. -private let heartbeatPingInterval: Duration = .seconds(10) - -/// Heartbeat timeout that once exceeded triggers next heartbeat to be sent. -private let heartbeatReplyTimeout: Duration = .seconds(3) - -/// Timeout used to determine if there was a network activity lately. -private let trafficFlowTimeout: Duration = heartbeatPingInterval * 0.5 - -/// Ping timeout. -private let pingTimeout: Duration = .seconds(15) - -/// Interval to wait before sending next ping. -private let pingDelay: Duration = .seconds(3) - -/// Initial timeout when establishing connection. -private let initialEstablishTimeout: Duration = .seconds(4) - -/// Multiplier applied to `establishTimeout` on each failed connection attempt. -private let establishTimeoutMultiplier: UInt32 = 2 - -/// Maximum timeout when establishing connection. -private let maxEstablishTimeout = pingTimeout - -/// Connectivity check periodicity. -private let connectivityCheckInterval: Duration = .seconds(1) - -/// Inbound traffic timeout used when outbound traffic was registered prior to inbound traffic. -private let inboundTrafficTimeout: Duration = .seconds(5) - -/// Traffic timeout applied when both tx/rx counters remain stale, i.e no traffic flowing. -/// Ping is issued after that timeout is exceeded.s -private let trafficTimeout: Duration = .minutes(2) - public final class TunnelMonitor: TunnelMonitorProtocol { /// Connection state. private enum ConnectionState { @@ -98,6 +62,9 @@ public final class TunnelMonitor: TunnelMonitorProtocol { /// Retry attempt. var retryAttempt: UInt32 = 0 + // Timings and timeouts. + let timings: TunnelMonitorTimings + func evaluateConnection(now: Date, pingTimeout: Duration) -> ConnectionEvaluation { switch connectionState { case .connecting: @@ -112,17 +79,17 @@ public final class TunnelMonitor: TunnelMonitorProtocol { func getPingTimeout() -> Duration { switch connectionState { case .connecting: - let multiplier = establishTimeoutMultiplier.saturatingPow(retryAttempt) - let nextTimeout = initialEstablishTimeout * Double(multiplier) + let multiplier = timings.establishTimeoutMultiplier.saturatingPow(retryAttempt) + let nextTimeout = timings.initialEstablishTimeout * Double(multiplier) - if nextTimeout.isFinite, nextTimeout < maxEstablishTimeout { + if nextTimeout.isFinite, nextTimeout < timings.maxEstablishTimeout { return nextTimeout } else { - return maxEstablishTimeout + return timings.maxEstablishTimeout } case .pendingStart, .connected, .waitingConnectivity, .stopped, .recovering: - return pingTimeout + return timings.pingTimeout } } @@ -163,7 +130,7 @@ public final class TunnelMonitor: TunnelMonitorProtocol { return .sendInitialPing } - if now.timeIntervalSince(lastRequestDate) >= pingDelay { + if now.timeIntervalSince(lastRequestDate) >= timings.pingDelay { return .sendNextPing } @@ -181,8 +148,8 @@ public final class TunnelMonitor: TunnelMonitorProtocol { let timeSinceLastPing = now.timeIntervalSince(lastRequestDate) if let lastReplyDate = pingStats.lastReplyDate, - lastRequestDate.timeIntervalSince(lastReplyDate) >= heartbeatReplyTimeout, - timeSinceLastPing >= pingDelay, !isHeartbeatSuspended { + lastRequestDate.timeIntervalSince(lastReplyDate) >= timings.heartbeatReplyTimeout, + timeSinceLastPing >= timings.pingDelay, !isHeartbeatSuspended { return .retryHeartbeatPing } @@ -191,9 +158,9 @@ public final class TunnelMonitor: TunnelMonitorProtocol { let rxTimeElapsed = now.timeIntervalSince(lastSeenRx) let txTimeElapsed = now.timeIntervalSince(lastSeenTx) - if timeSinceLastPing >= heartbeatPingInterval { + if timeSinceLastPing >= timings.heartbeatPingInterval { // Send heartbeat if traffic is flowing. - if rxTimeElapsed <= trafficFlowTimeout || txTimeElapsed <= trafficFlowTimeout { + if rxTimeElapsed <= timings.trafficFlowTimeout || txTimeElapsed <= timings.trafficFlowTimeout { return .sendHeartbeatPing } @@ -202,12 +169,12 @@ public final class TunnelMonitor: TunnelMonitorProtocol { } } - if timeSinceLastPing >= pingDelay { - if txTimeElapsed >= trafficTimeout || rxTimeElapsed >= trafficTimeout { + if timeSinceLastPing >= timings.pingDelay { + if txTimeElapsed >= timings.trafficTimeout || rxTimeElapsed >= timings.trafficTimeout { return .trafficTimeout } - if lastSeenTx > lastSeenRx, rxTimeElapsed >= inboundTrafficTimeout { + if lastSeenTx > lastSeenRx, rxTimeElapsed >= timings.inboundTrafficTimeout { return .inboundTrafficTimeout } } @@ -233,13 +200,14 @@ public final class TunnelMonitor: TunnelMonitorProtocol { private let nslock = NSLock() private let timerQueue = DispatchQueue(label: "TunnelMonitor-timerQueue") private let eventQueue: DispatchQueue + private let timings: TunnelMonitorTimings private var pinger: PingerProtocol private var defaultPathObserver: DefaultPathObserverProtocol private var isObservingDefaultPath = false private var timer: DispatchSourceTimer? - private var state = State() + private var state: State private var probeAddress: IPv4Address? private let logger = Logger(label: "TunnelMonitor") @@ -262,12 +230,16 @@ public final class TunnelMonitor: TunnelMonitorProtocol { eventQueue: DispatchQueue, pinger: PingerProtocol, tunnelDeviceInfo: TunnelDeviceInfoProtocol, - defaultPathObserver: DefaultPathObserverProtocol + defaultPathObserver: DefaultPathObserverProtocol, + timings: TunnelMonitorTimings ) { self.eventQueue = eventQueue self.tunnelDeviceInfo = tunnelDeviceInfo self.defaultPathObserver = defaultPathObserver + self.timings = timings + state = State(timings: timings) + self.pinger = pinger self.pinger.onReply = { [weak self] reply in guard let self else { return } @@ -584,7 +556,7 @@ public final class TunnelMonitor: TunnelMonitorProtocol { timer.setEventHandler { [weak self] in self?.checkConnectivity() } - timer.schedule(wallDeadline: .now(), repeating: connectivityCheckInterval.timeInterval) + timer.schedule(wallDeadline: .now(), repeating: timings.connectivityCheckInterval.timeInterval) timer.activate() self.timer?.cancel() diff --git a/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitorTimings.swift b/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitorTimings.swift new file mode 100644 index 000000000000..dfc269509d46 --- /dev/null +++ b/ios/PacketTunnelCore/TunnelMonitor/TunnelMonitorTimings.swift @@ -0,0 +1,69 @@ +// +// TunnelMonitorTimings.swift +// PacketTunnelCore +// +// Created by Jon Petersson on 2023-09-18. +// Copyright © 2023 Mullvad VPN AB. All rights reserved. +// + +import MullvadTypes + +public struct TunnelMonitorTimings { + /// Interval for periodic heartbeat ping issued when traffic is flowing. + /// Should help to detect connectivity issues on networks that drop traffic in one of directions, + /// regardless if tx/rx counters are being updated. + let heartbeatPingInterval: Duration + + /// Heartbeat timeout that once exceeded triggers next heartbeat to be sent. + let heartbeatReplyTimeout: Duration + + /// Timeout used to determine if there was a network activity lately. + var trafficFlowTimeout: Duration { heartbeatPingInterval * 0.5 } + + /// Ping timeout. + let pingTimeout: Duration + + /// Interval to wait before sending next ping. + let pingDelay: Duration + + /// Initial timeout when establishing connection. + let initialEstablishTimeout: Duration + + /// Multiplier applied to `establishTimeout` on each failed connection attempt. + let establishTimeoutMultiplier: UInt32 + + /// Maximum timeout when establishing connection. + var maxEstablishTimeout: Duration { pingTimeout } + + /// Connectivity check periodicity. + let connectivityCheckInterval: Duration + + /// Inbound traffic timeout used when outbound traffic was registered prior to inbound traffic. + let inboundTrafficTimeout: Duration + + /// Traffic timeout applied when both tx/rx counters remain stale, i.e no traffic flowing. + /// Ping is issued after that timeout is exceeded.s + let trafficTimeout: Duration + + public init( + heartbeatPingInterval: Duration = .seconds(10), + heartbeatReplyTimeout: Duration = .seconds(3), + pingTimeout: Duration = .seconds(15), + pingDelay: Duration = .seconds(3), + initialEstablishTimeout: Duration = .seconds(4), + establishTimeoutMultiplier: UInt32 = 2, + connectivityCheckInterval: Duration = .seconds(1), + inboundTrafficTimeout: Duration = .seconds(5), + trafficTimeout: Duration = .minutes(2)) + { + self.heartbeatPingInterval = heartbeatPingInterval + self.heartbeatReplyTimeout = heartbeatReplyTimeout + self.pingTimeout = pingTimeout + self.pingDelay = pingDelay + self.initialEstablishTimeout = initialEstablishTimeout + self.establishTimeoutMultiplier = establishTimeoutMultiplier + self.connectivityCheckInterval = connectivityCheckInterval + self.inboundTrafficTimeout = inboundTrafficTimeout + self.trafficTimeout = trafficTimeout + } +} diff --git a/ios/PacketTunnelCoreTests/TunnelMonitorTests.swift b/ios/PacketTunnelCoreTests/TunnelMonitorTests.swift index 4677b042ad37..9ca9abf94257 100644 --- a/ios/PacketTunnelCoreTests/TunnelMonitorTests.swift +++ b/ios/PacketTunnelCoreTests/TunnelMonitorTests.swift @@ -6,6 +6,7 @@ // Copyright © 2023 Mullvad VPN AB. All rights reserved. // +import MullvadTypes import Network @testable import PacketTunnelCore import XCTest @@ -26,7 +27,8 @@ final class TunnelMonitorTests: XCTestCase { eventQueue: .main, pinger: pinger, tunnelDeviceInfo: MockTunnelDeviceInfo(networkStatsProviding: networkCounters), - defaultPathObserver: MockDefaultPathObserver() + defaultPathObserver: MockDefaultPathObserver(), + timings: TunnelMonitorTimings() ) tunnelMonitor.onEvent = { event in @@ -53,25 +55,37 @@ final class TunnelMonitorTests: XCTestCase { return .ignore } + let timings = TunnelMonitorTimings( + pingTimeout: .milliseconds(300), + initialEstablishTimeout: .milliseconds(100), + connectivityCheckInterval: .milliseconds(100) + ) + let tunnelMonitor = TunnelMonitor( eventQueue: .main, pinger: pinger, tunnelDeviceInfo: MockTunnelDeviceInfo(networkStatsProviding: networkCounters), - defaultPathObserver: MockDefaultPathObserver() + defaultPathObserver: MockDefaultPathObserver(), + timings: timings ) /* Tunnel monitor uses shorter timeout intervals during the initial connection sequence and picks next relay more aggressively in order to reduce connection time. - First connection attempt starts at 4 second timeout, then doubles with each subsequent attempt, while being - capped at 15s max. + In reality, first connection attempt starts at 4 second timeout, then doubles with each subsequent attempt, while being + capped at 15s max. For tests, however, we start at 100 milliseconds and cap out at 300. */ - var expectedTimings = [4, 8, 15, 15] + var expectedTimings = [ + timings.initialEstablishTimeout.milliseconds, + timings.initialEstablishTimeout.milliseconds * 2, + timings.pingTimeout.milliseconds, + timings.pingTimeout.milliseconds + ] let totalAttemptCount = expectedTimings.count // Calculate the amount of time necessary to perform the test adding some leeway. - let timeout = expectedTimings.reduce(1, +) + let timeout = expectedTimings.reduce(1000, +) let expectation = self.expectation(description: "Should respect all timings.") expectation.expectedFulfillmentCount = expectedTimings.count @@ -82,7 +96,8 @@ final class TunnelMonitorTests: XCTestCase { // Reconnection attempt counter. var currentAttempt = 0 - tunnelMonitor.onEvent = { [weak tunnelMonitor] event in + tunnelMonitor.onEvent = { [weak self, weak tunnelMonitor] event in + guard let self else { return } guard case .connectionLost = event else { return } switch event { @@ -91,8 +106,8 @@ final class TunnelMonitorTests: XCTestCase { let expectedDuration = expectedTimings.removeFirst() - // Compute amount of time elapsed between `.connectionLost` events rounding it down towards zero. - let timeElapsed = Int(Date().timeIntervalSince(startDate).rounded(.down)) + // Compute amount of time elapsed between `.connectionLost` events, rounding to nearest 100 milliseconds. + let timeElapsed = self.roundToHundreds(Int(Date().timeIntervalSince(startDate) * 1000)) currentAttempt += 1 @@ -130,6 +145,12 @@ final class TunnelMonitorTests: XCTestCase { // Start monitoring. tunnelMonitor.start(probeAddress: .loopback) - waitForExpectations(timeout: TimeInterval(timeout)) + waitForExpectations(timeout: TimeInterval(timeout) / 1000) + } +} + +extension TunnelMonitorTests { + private func roundToHundreds(_ value: Int) -> Int { + return (value / 100 * 100) + ((value % 100) / 50 * 100) } }