Fix reliability and time consumption of testInitialConnectionTimings …

…test
mullvad · Sep 18, 2023 · c4e55a2 · c4e55a2
1 parent a91c5d9
commit c4e55a2
Show file tree

Hide file tree

Showing 5 changed files with 130 additions and 63 deletions.
diff --git 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 = "<group>"; };
 		7A42DEC82A05164100B209BE /* SettingsInputCell.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SettingsInputCell.swift; sourceTree = "<group>"; };
 		7A42DECC2A09064C00B209BE /* SelectableSettingsCell.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SelectableSettingsCell.swift; sourceTree = "<group>"; };
+		7A6B4F582AB8412E00123853 /* TunnelMonitorTimings.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = TunnelMonitorTimings.swift; sourceTree = "<group>"; };
 		7A7AD28C29DC677800480EF1 /* FirstTimeLaunch.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = FirstTimeLaunch.swift; sourceTree = "<group>"; };
 		7A7AD28E29DEDB1C00480EF1 /* SettingsHeaderView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SettingsHeaderView.swift; sourceTree = "<group>"; };
 		7A818F1E29F0305800C7F0F4 /* RootConfiguration.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = RootConfiguration.swift; sourceTree = "<group>"; };
@@ -2521,6 +2523,7 @@
 				58FC040927B3EE03001C21F0 /* TunnelMonitor.swift */,
 				58C7A42C2A85067A0060C66F /* TunnelMonitorProtocol.swift */,
 				58A3BDAF28A1821A00C8C2C6 /* WgStats.swift */,
+				7A6B4F582AB8412E00123853 /* TunnelMonitorTimings.swift */,
 			);
 			path = TunnelMonitor;
 			sourceTree = "<group>";
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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)
     }
 }