diff --git a/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionBandwidthAnalyzer.swift b/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionBandwidthAnalyzer.swift index 31de5820c..e28611f08 100644 --- a/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionBandwidthAnalyzer.swift +++ b/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionBandwidthAnalyzer.swift @@ -90,7 +90,6 @@ final class NetworkProtectionConnectionBandwidthAnalyzer { os_log("Bytes per second in last time-interval: (rx: %{public}@, tx: %{public}@)", log: .networkProtectionBandwidthAnalysis, - type: .info, String(describing: rx), String(describing: tx)) idle = UInt64(rx) < Self.rxThreshold && UInt64(tx) < Self.txThreshold @@ -103,7 +102,7 @@ final class NetworkProtectionConnectionBandwidthAnalyzer { /// Useful when servers are swapped /// func reset() { - os_log("Bandwidth analyzer reset", log: .networkProtectionBandwidthAnalysis, type: .info) + os_log("Bandwidth analyzer reset", log: .networkProtectionBandwidthAnalysis) entries.removeAll() } diff --git a/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionTester.swift b/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionTester.swift index be98ebf95..642086cca 100644 --- a/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionTester.swift +++ b/Sources/NetworkProtection/Diagnostics/NetworkProtectionConnectionTester.swift @@ -222,7 +222,7 @@ final class NetworkProtectionConnectionTester { // After completing the connection tests we check if the tester is still supposed to be running // to avoid giving results when it should not be running. guard isRunning else { - os_log("Tester skipped returning results as it was stopped while running the tests", log: log, type: .info) + os_log("Tester skipped returning results as it was stopped while running the tests", log: log) return } diff --git a/Sources/NetworkProtection/Diagnostics/NetworkProtectionTunnelFailureMonitor.swift b/Sources/NetworkProtection/Diagnostics/NetworkProtectionTunnelFailureMonitor.swift index 58eedab19..037361c1c 100644 --- a/Sources/NetworkProtection/Diagnostics/NetworkProtectionTunnelFailureMonitor.swift +++ b/Sources/NetworkProtection/Diagnostics/NetworkProtectionTunnelFailureMonitor.swift @@ -108,7 +108,7 @@ public actor NetworkProtectionTunnelFailureMonitor { guard firstCheckSkipped else { // Avoid running the first tunnel failure check after startup to avoid reading the first handshake after sleep, which will almost always // be out of date. In normal operation, the first check will frequently be 0 as WireGuard hasn't had the chance to handshake yet. - os_log("⚫️ Skipping first tunnel failure check", log: .networkProtectionTunnelFailureMonitorLog, type: .debug) + os_log("⚫️ Skipping first tunnel failure check", log: .networkProtectionTunnelFailureMonitorLog) firstCheckSkipped = true return } @@ -116,23 +116,23 @@ public actor NetworkProtectionTunnelFailureMonitor { let mostRecentHandshake = (try? await handshakeReporter.getMostRecentHandshake()) ?? 0 guard mostRecentHandshake > 0 else { - os_log("⚫️ Got handshake timestamp at or below 0, skipping check", log: .networkProtectionTunnelFailureMonitorLog, type: .debug) + os_log("⚫️ Got handshake timestamp at or below 0, skipping check", log: .networkProtectionTunnelFailureMonitorLog) return } let difference = Date().timeIntervalSince1970 - mostRecentHandshake - os_log("⚫️ Last handshake: %{public}f seconds ago", log: .networkProtectionTunnelFailureMonitorLog, type: .debug, difference) + os_log("⚫️ Last handshake: %{public}f seconds ago", log: .networkProtectionTunnelFailureMonitorLog, difference) if difference > Result.failureDetected.threshold, isConnected { if failureReported { - os_log("⚫️ Tunnel failure already reported", log: .networkProtectionTunnelFailureMonitorLog, type: .debug) + os_log("⚫️ Tunnel failure already reported", log: .networkProtectionTunnelFailureMonitorLog) } else { - os_log("⚫️ Tunnel failure reported", log: .networkProtectionTunnelFailureMonitorLog, type: .debug) + os_log("⚫️ Tunnel failure reported", log: .networkProtectionTunnelFailureMonitorLog) callback(.failureDetected) failureReported = true } } else if difference <= Result.failureRecovered.threshold, failureReported { - os_log("⚫️ Tunnel failure recovery", log: .networkProtectionTunnelFailureMonitorLog, type: .debug) + os_log("⚫️ Tunnel recovered from failure", log: .networkProtectionTunnelFailureMonitorLog) callback(.failureRecovered) failureReported = false } diff --git a/Sources/NetworkProtection/KeyManagement/NetworkProtectionKeychainStore.swift b/Sources/NetworkProtection/KeyManagement/NetworkProtectionKeychainStore.swift index 384a87e5a..88ecb495d 100644 --- a/Sources/NetworkProtection/KeyManagement/NetworkProtectionKeychainStore.swift +++ b/Sources/NetworkProtection/KeyManagement/NetworkProtectionKeychainStore.swift @@ -72,7 +72,7 @@ final class NetworkProtectionKeychainStore { case errSecItemNotFound: return nil default: - os_log("🔵 SecItemCopyMatching status %{public}@", type: .error, String(describing: status)) + os_log("🔴 SecItemCopyMatching status %{public}@", type: .error, String(describing: status)) throw NetworkProtectionKeychainStoreError.keychainReadError(field: name, status: status) } } diff --git a/Sources/NetworkProtection/Logging/Logging.swift b/Sources/NetworkProtection/Logging/Logging.swift index 240599f1d..2cfb99633 100644 --- a/Sources/NetworkProtection/Logging/Logging.swift +++ b/Sources/NetworkProtection/Logging/Logging.swift @@ -41,10 +41,6 @@ extension OSLog { Logging.networkProtectionTunnelFailureMonitorLoggingEnabled ? Logging.networkProtectionTunnelFailureMonitor : .disabled } - public static var networkProtectionServerFailureRecoveryLog: OSLog { - Logging.networkProtectionServerFailureRecoveryLoggingEnabled ? Logging.networkProtectionServerFailureRecovery : .disabled - } - public static var networkProtectionConnectionTesterLog: OSLog { Logging.networkProtectionConnectionTesterLoggingEnabled ? Logging.networkProtectionConnectionTesterLog : .disabled } @@ -84,7 +80,7 @@ extension OSLog { struct Logging { - static let subsystem = "com.duckduckgo.macos.browser.network-protection" + static let subsystem = Bundle.main.bundleIdentifier! fileprivate static let networkProtectionLoggingEnabled = true fileprivate static let networkProtection: OSLog = OSLog(subsystem: subsystem, category: "Network Protection") diff --git a/Sources/NetworkProtection/PacketTunnelProvider.swift b/Sources/NetworkProtection/PacketTunnelProvider.swift index a97e80fbc..730c044e7 100644 --- a/Sources/NetworkProtection/PacketTunnelProvider.swift +++ b/Sources/NetworkProtection/PacketTunnelProvider.swift @@ -126,9 +126,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { private lazy var adapter: WireGuardAdapter = { WireGuardAdapter(with: self) { logLevel, message in if logLevel == .error { - os_log("🔵 Received error from adapter: %{public}@", log: .networkProtection, type: .error, message) + os_log("🔴 Received error from adapter: %{public}@", log: .networkProtection, type: .error, message) } else { - os_log("🔵 Received message from adapter: %{public}@", log: .networkProtection, message) + os_log("Received message from adapter: %{public}@", log: .networkProtection, message) } } }() @@ -245,14 +245,15 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { return } - os_log("Rekeying...", log: .networkProtectionKeyManagement) providerEvents.fire(.rekeyAttempt(.begin)) do { - try await updateTunnelConfiguration(reassert: false, regenerateKey: true) + try await updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: false, + regenerateKey: true) providerEvents.fire(.rekeyAttempt(.success)) } catch { - os_log("Rekey attempt failed. This is not an error if you're using debug Key Management options: %{public}@", log: .networkProtectionKeyManagement, type: .error, String(describing: error)) providerEvents.fire(.rekeyAttempt(.failure(error))) throw error } @@ -636,14 +637,11 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { let errorDescription = (error as? LocalizedError)?.localizedDescription ?? String(describing: error) - os_log("Tunnel startup error: %{public}@", type: .error, errorDescription) self.controllerErrorStore.lastErrorMessage = errorDescription self.connectionStatus = .disconnected self.knownFailureStore.lastKnownFailure = KnownFailure(error) providerEvents.fire(.tunnelStartAttempt(.failure(error))) - - os_log("🔴 Stopping VPN due to error: %{public}s", log: .networkProtection, error.localizedDescription) throw error } } @@ -672,22 +670,19 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { private func startTunnel(onDemand: Bool) async throws { do { - os_log("🔵 Generating tunnel config", log: .networkProtection, type: .info) - os_log("🔵 Excluded ranges are: %{public}@", log: .networkProtection, type: .info, String(describing: settings.excludedRanges)) - os_log("🔵 Server selection method: %{public}@", log: .networkProtection, type: .info, currentServerSelectionMethod.debugDescription) - os_log("🔵 DNS server: %{public}@", log: .networkProtection, type: .info, String(describing: settings.dnsSettings)) + os_log("Generating tunnel config", log: .networkProtection) + os_log("Excluded ranges are: %{public}@", log: .networkProtection, String(describing: settings.excludedRanges)) + os_log("Server selection method: %{public}@", log: .networkProtection, currentServerSelectionMethod.debugDescription) + os_log("DNS server: %{public}@", log: .networkProtection, String(describing: settings.dnsSettings)) let tunnelConfiguration = try await generateTunnelConfiguration(serverSelectionMethod: currentServerSelectionMethod, includedRoutes: includedRoutes ?? [], excludedRoutes: settings.excludedRanges, dnsSettings: settings.dnsSettings, regenerateKey: true) try await startTunnel(with: tunnelConfiguration, onDemand: onDemand) - os_log("🔵 Done generating tunnel config", log: .networkProtection, type: .info) + os_log("Done generating tunnel config", log: .networkProtection) } catch { - os_log("🔵 Error starting tunnel: %{public}@", log: .networkProtection, type: .info, error.localizedDescription) - controllerErrorStore.lastErrorMessage = error.localizedDescription - throw error } } @@ -697,7 +692,6 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { try await withCheckedThrowingContinuation { (continuation: CheckedContinuation) in adapter.start(tunnelConfiguration: tunnelConfiguration) { [weak self] error in if let error { - os_log("🔵 Starting tunnel failed with %{public}@", log: .networkProtection, type: .error, error.localizedDescription) self?.debugEvents?.fire(error.networkProtectionError) continuation.resume(throwing: error) return @@ -719,7 +713,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { #if os(iOS) if #available(iOS 17.0, *), startReason == .manual { try? await updateConnectOnDemand(enabled: true) - os_log("Enabled Connect on Demand due to user-initiated startup", log: .networkProtection, type: .info) + os_log("Enabled Connect on Demand due to user-initiated startup", log: .networkProtection) } #endif } catch { @@ -737,7 +731,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { open override func stopTunnel(with reason: NEProviderStopReason) async { providerEvents.fire(.tunnelStopAttempt(.begin)) - os_log("Stopping tunnel with reason %{public}@", log: .networkProtection, type: .info, String(describing: reason)) + os_log("Stopping tunnel with reason %{public}@", log: .networkProtection, String(describing: reason)) do { try await stopTunnel() @@ -746,7 +740,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { // Disable Connect on Demand when disabling the tunnel from iOS settings on iOS 17.0+. if #available(iOS 17.0, *), case .userInitiated = reason { try? await updateConnectOnDemand(enabled: false) - os_log("Disabled Connect on Demand due to user-initiated shutdown", log: .networkProtection, type: .info) + os_log("Disabled Connect on Demand due to user-initiated shutdown", log: .networkProtection) } } catch { providerEvents.fire(.tunnelStopAttempt(.failure(error))) @@ -794,7 +788,6 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { } if let error { - os_log("🔵 Error while stopping adapter: %{public}@", log: .networkProtection, type: .error, error.localizedDescription) self?.debugEvents?.fire(error.networkProtectionError) continuation.resume(throwing: error) @@ -824,20 +817,15 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { // MARK: - Tunnel Configuration - @MainActor - public func updateTunnelConfiguration(reassert: Bool, - regenerateKey: Bool = false) async throws { - try await updateTunnelConfiguration( - serverSelectionMethod: currentServerSelectionMethod, - reassert: reassert, - regenerateKey: regenerateKey - ) + enum TunnelUpdateMethod { + case selectServer(_ method: NetworkProtectionServerSelectionMethod) + case useConfiguration(_ configuration: TunnelConfiguration) } @MainActor - public func updateTunnelConfiguration(serverSelectionMethod: NetworkProtectionServerSelectionMethod, - reassert: Bool, - regenerateKey: Bool = false) async throws { + func updateTunnelConfiguration(updateMethod: TunnelUpdateMethod, + reassert: Bool, + regenerateKey: Bool = false) async throws { providerEvents.fire(.tunnelUpdateAttempt(.begin)) @@ -845,55 +833,50 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { await stopMonitors() } - let tunnelConfiguration: TunnelConfiguration do { - tunnelConfiguration = try await generateTunnelConfiguration(serverSelectionMethod: serverSelectionMethod, - includedRoutes: includedRoutes ?? [], - excludedRoutes: settings.excludedRanges, - dnsSettings: settings.dnsSettings, - regenerateKey: regenerateKey) + let tunnelConfiguration: TunnelConfiguration + + switch updateMethod { + case .selectServer(let serverSelectionMethod): + tunnelConfiguration = try await generateTunnelConfiguration(serverSelectionMethod: serverSelectionMethod, + includedRoutes: includedRoutes ?? [], + excludedRoutes: settings.excludedRanges, + dnsSettings: settings.dnsSettings, + regenerateKey: regenerateKey) + case .useConfiguration(let newTunnelConfiguration): + tunnelConfiguration = newTunnelConfiguration + } + + try await updateAdapterConfiguration(tunnelConfiguration: tunnelConfiguration, reassert: reassert) + + if reassert { + try await handleAdapterStarted(startReason: .reconnected) + } + + providerEvents.fire(.tunnelUpdateAttempt(.success)) } catch { providerEvents.fire(.tunnelUpdateAttempt(.failure(error))) throw error } - try await updateAdapterConfiguration(tunnelConfiguration: tunnelConfiguration, reassert: reassert) } @MainActor private func updateAdapterConfiguration(tunnelConfiguration: TunnelConfiguration, reassert: Bool) async throws { - do { - try await withCheckedThrowingContinuation { [weak self] (continuation: CheckedContinuation) in - guard let self = self else { - continuation.resume() + try await withCheckedThrowingContinuation { [weak self] (continuation: CheckedContinuation) in + guard let self = self else { + continuation.resume() + return + } + + self.adapter.update(tunnelConfiguration: tunnelConfiguration, reassert: reassert) { [weak self] error in + if let error = error { + self?.debugEvents?.fire(error.networkProtectionError) + continuation.resume(throwing: error) return } - self.adapter.update(tunnelConfiguration: tunnelConfiguration, reassert: reassert) { [weak self] error in - if let error = error { - os_log("🔵 Failed to update the configuration: %{public}@", type: .error, error.localizedDescription) - self?.debugEvents?.fire(error.networkProtectionError) - continuation.resume(throwing: error) - return - } - - Task { [weak self] in - if reassert { - do { - try await self?.handleAdapterStarted(startReason: .reconnected) - } catch { - continuation.resume(throwing: error) - return - } - } - - continuation.resume() - } - } + continuation.resume() } - providerEvents.fire(.tunnelUpdateAttempt(.success)) - } catch { - providerEvents.fire(.tunnelUpdateAttempt(.failure(error))) - throw error } } @@ -927,11 +910,11 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { let newSelectedServer = configurationResult.server self.lastSelectedServer = newSelectedServer - os_log("🔵 Generated tunnel configuration for server at location: %{public}s (preferred server is %{public}s)", + os_log("⚪️ Generated tunnel configuration for server at location: %{public}s (preferred server is %{public}s)", log: .networkProtection, newSelectedServer.serverInfo.serverLocation, newSelectedServer.serverInfo.name) - os_log("🔵 Excluded routes: %{public}@", log: .networkProtection, type: .info, String(describing: excludedRoutes)) + os_log("Excluded routes: %{public}@", log: .networkProtection, String(describing: excludedRoutes)) return configurationResult.tunnelConfiguration } @@ -949,11 +932,19 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { // swiftlint:disable:next cyclomatic_complexity @MainActor public override func handleAppMessage(_ messageData: Data, completionHandler: ((Data?) -> Void)? = nil) { + guard let message = ExtensionMessage(rawValue: messageData) else { + os_log("🔴 Received unknown app message", log: .networkProtectionIPCLog, type: .error) completionHandler?(nil) return } + /// We're skipping messages that are very frequent and not likely to affect anything in terms of functionality. + /// We can opt to aggregate them somehow if we ever need them - for now I'm disabling. + if message != .getDataVolume { + os_log("⚪️ Received app message: %{public}@", log: .networkProtectionIPCLog, String(describing: message)) + } + switch message { case .request(let request): handleRequest(request, completionHandler: completionHandler) @@ -1017,7 +1008,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { case .setExcludeLocalNetworks: Task { @MainActor in if case .connected = connectionStatus { - try? await updateTunnelConfiguration(reassert: false) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: false) } completionHandler?(nil) } @@ -1033,7 +1026,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { Task { @MainActor in if case .connected = connectionStatus { - try? await updateTunnelConfiguration(serverSelectionMethod: serverSelectionMethod, reassert: true) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(serverSelectionMethod), + reassert: true) } completionHandler?(nil) } @@ -1049,14 +1044,18 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { Task { @MainActor in if case .connected = connectionStatus { - try? await updateTunnelConfiguration(serverSelectionMethod: serverSelectionMethod, reassert: true) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(serverSelectionMethod), + reassert: true) } completionHandler?(nil) } case .setDNSSettings: Task { @MainActor in if case .connected = connectionStatus { - try? await updateTunnelConfiguration(reassert: true) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: true) } completionHandler?(nil) } @@ -1144,7 +1143,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { settings.selectedServer = .automatic if case .connected = connectionStatus { - try? await updateTunnelConfiguration(reassert: true) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: true) } } completionHandler?(nil) @@ -1158,7 +1159,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { settings.selectedServer = .endpoint(serverName) if case .connected = connectionStatus { - try? await updateTunnelConfiguration(serverSelectionMethod: .preferredServer(serverName: serverName), reassert: true) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(.preferredServer(serverName: serverName)), + reassert: true) } completionHandler?(nil) } @@ -1209,7 +1212,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { return } - os_log("🔵 Disabling Connect On Demand and shutting down the tunnel", log: .networkProtection, type: .info) + os_log("⚪️ Disabling Connect On Demand and shutting down the tunnel", log: .networkProtection) manager.isOnDemandEnabled = false try await manager.saveToPreferences() @@ -1227,7 +1230,9 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { self.includedRoutes = includedRoutes if case .connected = connectionStatus { - try? await updateTunnelConfiguration(reassert: false) + try? await updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: false) } completionHandler?(nil) } @@ -1235,12 +1240,12 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { private func simulateTunnelFailure(completionHandler: ((Data?) -> Void)? = nil) { Task { - os_log("Simulating tunnel failure", log: .networkProtection, type: .info) + os_log("Simulating tunnel failure", log: .networkProtection) adapter.stop { [weak self] error in if let error { self?.debugEvents?.fire(error.networkProtectionError) - os_log("🔵 Failed to stop WireGuard adapter: %{public}@", log: .networkProtection, type: .info, error.localizedDescription) + os_log("🔴 Failed to stop WireGuard adapter: %{public}@", log: .networkProtection, error.localizedDescription) } completionHandler?(error.map { ExtensionMessageString($0.localizedDescription).rawValue }) @@ -1297,7 +1302,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { connectionStatus = .connected(connectedDate: Date()) } - os_log("🔵 Tunnel interface is %{public}@", log: .networkProtection, type: .info, adapter.interfaceName ?? "unknown") + os_log("⚪️ Tunnel interface is %{public}@", log: .networkProtection, adapter.interfaceName ?? "unknown") // These cases only make sense in the context of a connection that had trouble // and is being fixed, so we want to test the connection immediately. @@ -1365,7 +1370,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { @MainActor private func handleFailureRecoveryConfigUpdate(result: NetworkProtectionDeviceManagement.GenerateTunnelConfigurationResult) async throws { self.lastSelectedServer = result.server - try await self.updateAdapterConfiguration(tunnelConfiguration: result.tunnelConfiguration, reassert: true) + try await updateTunnelConfiguration(updateMethod: .useConfiguration(result.tunnelConfiguration), reassert: true) } @MainActor @@ -1425,13 +1430,19 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { await serverStatusMonitor.start(serverName: serverName) { status in if status.shouldMigrate { - Task { - self.providerEvents.fire(.serverMigrationAttempt(.begin)) + Task { [ weak self] in + guard let self else { return } + + providerEvents.fire(.serverMigrationAttempt(.begin)) + do { - try await self.updateTunnelConfiguration(reassert: true, regenerateKey: true) - self.providerEvents.fire(.serverMigrationAttempt(.success)) + try await self.updateTunnelConfiguration( + updateMethod: .selectServer(currentServerSelectionMethod), + reassert: true, + regenerateKey: true) + providerEvents.fire(.serverMigrationAttempt(.success)) } catch { - self.providerEvents.fire(.serverMigrationAttempt(.failure(error))) + providerEvents.fire(.serverMigrationAttempt(.failure(error))) } } } @@ -1474,7 +1485,7 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { do { try await startConnectionTester(testImmediately: testImmediately) } catch { - os_log("🔵 Connection Tester error: %{public}@", log: .networkProtectionConnectionTesterLog, type: .error, String(reflecting: error)) + os_log("🔴 Connection Tester error: %{public}@", log: .networkProtectionConnectionTesterLog, type: .error, String(reflecting: error)) throw error } } @@ -1546,14 +1557,14 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { @MainActor public override func sleep() async { - os_log("Sleep", log: .networkProtectionSleepLog, type: .info) + os_log("Sleep", log: .networkProtectionSleepLog) await stopMonitors() } @MainActor public override func wake() { - os_log("Wake up", log: .networkProtectionSleepLog, type: .info) + os_log("Wake up", log: .networkProtectionSleepLog) // macOS can launch the extension due to calls to `sendProviderMessage`, so there's // a chance this is being called when the VPN isn't really meant to be connected or @@ -1568,8 +1579,10 @@ open class PacketTunnelProvider: NEPacketTunnelProvider { do { try await handleAdapterStarted(startReason: .wake) + os_log("🟢 Wake success", log: .networkProtectionConnectionTesterLog) providerEvents.fire(.tunnelWakeAttempt(.success)) } catch { + os_log("🔴 Wake error: ${public}@", log: .networkProtectionConnectionTesterLog, type: .error, error.localizedDescription) providerEvents.fire(.tunnelWakeAttempt(.failure(error))) } } diff --git a/Sources/NetworkProtection/Recovery/FailureRecoveryHandler.swift b/Sources/NetworkProtection/Recovery/FailureRecoveryHandler.swift index f638d8767..88d13db41 100644 --- a/Sources/NetworkProtection/Recovery/FailureRecoveryHandler.swift +++ b/Sources/NetworkProtection/Recovery/FailureRecoveryHandler.swift @@ -144,14 +144,13 @@ actor FailureRecoveryHandler: FailureRecoveryHandling { isKillSwitchEnabled: isKillSwitchEnabled, regenerateKey: false ) - os_log("🟢 Failure recovery fetched new config.", log: .networkProtectionServerFailureRecoveryLog, type: .info) + os_log("🟢 Failure recovery fetched new config.", log: .networkProtectionTunnelFailureMonitorLog) let newServer = configurationResult.server os_log( "🟢 Failure recovery - originalServerName: %{public}s, newServerName: %{public}s, originalAllowedIPs: %{public}s, newAllowedIPs: %{public}s", log: .networkProtection, - type: .info, lastConnectedServer.serverName, newServer.serverName, String(describing: lastConnectedServer.allowedIPs), @@ -159,7 +158,7 @@ actor FailureRecoveryHandler: FailureRecoveryHandling { ) guard lastConnectedServer.shouldReplace(with: newServer) else { - os_log("🟢 Server failure recovery not necessary.", log: .networkProtectionServerFailureRecoveryLog, type: .info) + os_log("🟢 Server failure recovery not necessary.", log: .networkProtectionTunnelFailureMonitorLog) return .noRecoveryNecessary } @@ -182,10 +181,10 @@ actor FailureRecoveryHandler: FailureRecoveryHandling { } do { try await action() - os_log("🟢 Failure recovery success!", log: .networkProtectionServerFailureRecoveryLog, type: .info) + os_log("🟢 Failure recovery success!", log: .networkProtectionTunnelFailureMonitorLog) return } catch { - os_log("🟢 Failure recovery failed. Retrying...", log: .networkProtectionServerFailureRecoveryLog, type: .info) + os_log("🟢 Failure recovery failed. Retrying...", log: .networkProtectionTunnelFailureMonitorLog) } do { try await Task.sleep(interval: currentDelay)