From 5a31f2553d9d90207ac93d2014752f779c761b6c Mon Sep 17 00:00:00 2001 From: Diego Rey Mendez Date: Fri, 5 Jul 2024 12:37:43 +0200 Subject: [PATCH] Improve VPN logging logic (#3032) Task/Issue URL: https://app.asana.com/0/1206580121312550/1207223772590802/f macOS PR: https://github.com/duckduckgo/macos-browser/pull/2939 BSK PR: https://github.com/duckduckgo/BrowserServicesKit/pull/877 ## Description Improves the logging logic for the VPN. --- DuckDuckGo.xcodeproj/project.pbxproj | 6 +- .../xcshareddata/swiftpm/Package.resolved | 4 +- ...etworkProtectionPacketTunnelProvider.swift | 24 +++- .../NetworkProtection/VPNLogger.swift | 108 ++++++++++++++++++ 4 files changed, 138 insertions(+), 4 deletions(-) create mode 100644 PacketTunnelProvider/NetworkProtection/VPNLogger.swift diff --git a/DuckDuckGo.xcodeproj/project.pbxproj b/DuckDuckGo.xcodeproj/project.pbxproj index c7a42731e3..6067a74e9a 100644 --- a/DuckDuckGo.xcodeproj/project.pbxproj +++ b/DuckDuckGo.xcodeproj/project.pbxproj @@ -285,6 +285,7 @@ 6FE127462C2054A900EB5724 /* NewTabPageViewController.swift in Sources */ = {isa = PBXBuildFile; fileRef = 6FE127452C2054A900EB5724 /* NewTabPageViewController.swift */; }; 6FE1274B2C20943500EB5724 /* ShortcutItemView.swift in Sources */ = {isa = PBXBuildFile; fileRef = 6FE1274A2C20943500EB5724 /* ShortcutItemView.swift */; }; 6FF915822B88E07A0042AC87 /* AdAttributionFetcherTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 6FF915802B88E0750042AC87 /* AdAttributionFetcherTests.swift */; }; + 7B0D52352C35FEAD0035A60E /* VPNLogger.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7B0D52342C35FEAD0035A60E /* VPNLogger.swift */; }; 7BC571202BDBB877003B0CCE /* VPNActivationDateStore.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7BC5711F2BDBB877003B0CCE /* VPNActivationDateStore.swift */; }; 7BC571212BDBB977003B0CCE /* VPNActivationDateStore.swift in Sources */ = {isa = PBXBuildFile; fileRef = 7BC5711F2BDBB877003B0CCE /* VPNActivationDateStore.swift */; }; 83004E802193BB8200DA013C /* WKNavigationExtension.swift in Sources */ = {isa = PBXBuildFile; fileRef = 83004E7F2193BB8200DA013C /* WKNavigationExtension.swift */; }; @@ -1401,6 +1402,7 @@ 6FE127452C2054A900EB5724 /* NewTabPageViewController.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = NewTabPageViewController.swift; sourceTree = ""; }; 6FE1274A2C20943500EB5724 /* ShortcutItemView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = ShortcutItemView.swift; sourceTree = ""; }; 6FF915802B88E0750042AC87 /* AdAttributionFetcherTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = AdAttributionFetcherTests.swift; sourceTree = ""; }; + 7B0D52342C35FEAD0035A60E /* VPNLogger.swift */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.swift; path = VPNLogger.swift; sourceTree = ""; }; 7BC5711F2BDBB877003B0CCE /* VPNActivationDateStore.swift */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.swift; path = VPNActivationDateStore.swift; sourceTree = ""; }; 83004E7F2193BB8200DA013C /* WKNavigationExtension.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = WKNavigationExtension.swift; sourceTree = ""; }; 83004E832193E14C00DA013C /* UIAlertControllerExtension.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; name = UIAlertControllerExtension.swift; path = ../Core/UIAlertControllerExtension.swift; sourceTree = ""; }; @@ -4727,6 +4729,7 @@ EE3766DC2AC5940A00AAB575 /* NetworkProtection */ = { isa = PBXGroup; children = ( + 7B0D52342C35FEAD0035A60E /* VPNLogger.swift */, EEEB80A22A421CE600386378 /* NetworkProtectionPacketTunnelProvider.swift */, EE3766DD2AC5945500AAB575 /* NetworkProtectionUNNotificationPresenter.swift */, ); @@ -6465,6 +6468,7 @@ EEEB80A32A421CE600386378 /* NetworkProtectionPacketTunnelProvider.swift in Sources */, EE3766DE2AC5945500AAB575 /* NetworkProtectionUNNotificationPresenter.swift in Sources */, F1FDC9362BF51E41006B1435 /* VPNSettings+Environment.swift in Sources */, + 7B0D52352C35FEAD0035A60E /* VPNLogger.swift in Sources */, BDFF03212BA3D3CF00F324C9 /* NetworkProtectionVisibilityForTunnelProvider.swift in Sources */, EEFC6A602AC0F2F80065027D /* UserText.swift in Sources */, 7BC571212BDBB977003B0CCE /* VPNActivationDateStore.swift in Sources */, @@ -9966,7 +9970,7 @@ repositoryURL = "https://github.com/DuckDuckGo/BrowserServicesKit"; requirement = { kind = exactVersion; - version = 165.0.0; + version = 165.0.1; }; }; 9F8FE9472BAE50E50071E372 /* XCRemoteSwiftPackageReference "lottie-spm" */ = { diff --git a/DuckDuckGo.xcodeproj/project.xcworkspace/xcshareddata/swiftpm/Package.resolved b/DuckDuckGo.xcodeproj/project.xcworkspace/xcshareddata/swiftpm/Package.resolved index 15eb24cbec..75c78d0626 100644 --- a/DuckDuckGo.xcodeproj/project.xcworkspace/xcshareddata/swiftpm/Package.resolved +++ b/DuckDuckGo.xcodeproj/project.xcworkspace/xcshareddata/swiftpm/Package.resolved @@ -32,8 +32,8 @@ "kind" : "remoteSourceControl", "location" : "https://github.com/DuckDuckGo/BrowserServicesKit", "state" : { - "revision" : "777e5ae1ab890d9ec22e069bc5dc0f0ada4b35af", - "version" : "165.0.0" + "revision" : "2df7f9d9063c9f8f8f07ccb80c95d7e35738d1ea", + "version" : "165.0.1" } }, { diff --git a/PacketTunnelProvider/NetworkProtection/NetworkProtectionPacketTunnelProvider.swift b/PacketTunnelProvider/NetworkProtection/NetworkProtectionPacketTunnelProvider.swift index 7b66f1efa8..8ef890d60c 100644 --- a/PacketTunnelProvider/NetworkProtection/NetworkProtectionPacketTunnelProvider.swift +++ b/PacketTunnelProvider/NetworkProtection/NetworkProtectionPacketTunnelProvider.swift @@ -34,6 +34,7 @@ import WidgetKit // Initial implementation for initial Network Protection tests. Will be fleshed out with https://app.asana.com/0/1203137811378537/1204630829332227/f final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { + private static var vpnLogger = VPNLogger() private var cancellables = Set() private let accountManager: AccountManager @@ -48,6 +49,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { withAdditionalParameters: [PixelParameters.vpnCohort: UniquePixel.cohort(from: defaults.vpnFirstEnabled)], includedParameters: [.appVersion, .atb]) case .reportConnectionAttempt(attempt: let attempt): + vpnLogger.log(attempt) + switch attempt { case .connecting: DailyPixel.fireDailyAndCount(pixel: .networkProtectionEnableAttemptConnecting, @@ -63,6 +66,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { includedParameters: [.appVersion, .atb]) } case .reportTunnelFailure(result: let result): + vpnLogger.log(result) + switch result { case .failureDetected: DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelFailureDetected, includedParameters: [.appVersion, .atb]) @@ -72,6 +77,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { defaults.updateNetworkPath(with: newPath) } case .reportLatency(result: let result): + vpnLogger.log(result) + switch result { case .error: DailyPixel.fire(pixel: .networkProtectionLatencyError, includedParameters: [.appVersion, .atb]) @@ -80,6 +87,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionLatency(quality: quality), includedParameters: [.appVersion, .atb]) } case .rekeyAttempt(let step): + vpnLogger.log(step, named: "Rekey") + switch step { case .begin: DailyPixel.fireDailyAndCount(pixel: .networkProtectionRekeyAttempt) @@ -89,6 +98,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionRekeyCompleted) } case .tunnelStartAttempt(let step): + vpnLogger.log(step, named: "Tunnel Start") + switch step { case .begin: DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelStartAttempt) @@ -98,6 +109,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelStartSuccess) } case .tunnelStopAttempt(let step): + vpnLogger.log(step, named: "Tunnel Stop") + switch step { case .begin: Pixel.fire(pixel: .networkProtectionTunnelStopAttempt) @@ -107,6 +120,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelStopSuccess) } case .tunnelUpdateAttempt(let step): + vpnLogger.log(step, named: "Tunnel Update") + switch step { case .begin: DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelUpdateAttempt) @@ -116,6 +131,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelUpdateSuccess) } case .tunnelWakeAttempt(let step): + vpnLogger.log(step, named: "Tunnel Wake") + switch step { case .begin: Pixel.fire(pixel: .networkProtectionTunnelWakeAttempt) @@ -125,6 +142,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelWakeSuccess) } case .failureRecoveryAttempt(let step): + vpnLogger.log(step) + switch step { case .started: DailyPixel.fireDailyAndCount(pixel: .networkProtectionFailureRecoveryStarted) @@ -136,6 +155,8 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionFailureRecoveryFailed, error: error) } case .serverMigrationAttempt(let step): + vpnLogger.log(step, named: "Server Migration") + switch step { case .begin: DailyPixel.fireDailyAndCount(pixel: .networkProtectionServerMigrationAttempt) @@ -145,6 +166,7 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { DailyPixel.fireDailyAndCount(pixel: .networkProtectionServerMigrationAttemptSuccess) } case .tunnelStartOnDemandWithoutAccessToken: + vpnLogger.logStartingWithoutAuthToken() DailyPixel.fireDailyAndCount(pixel: .networkProtectionTunnelStartAttemptOnDemandWithoutAccessToken) } } @@ -391,5 +413,5 @@ final class NetworkProtectionPacketTunnelProvider: PacketTunnelProvider { } // swiftlint:enable type_body_length - +// swiftlint:disable:next file_length #endif diff --git a/PacketTunnelProvider/NetworkProtection/VPNLogger.swift b/PacketTunnelProvider/NetworkProtection/VPNLogger.swift new file mode 100644 index 0000000000..e60e048d4e --- /dev/null +++ b/PacketTunnelProvider/NetworkProtection/VPNLogger.swift @@ -0,0 +1,108 @@ +// +// VPNLogger.swift +// DuckDuckGo +// +// Copyright © 2023 DuckDuckGo. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +import Foundation +import NetworkProtection +// swiftlint:disable:next enforce_os_log_wrapper +import OSLog + +/// Logger for the VPN +/// +/// Since we'll want to ensure this adheres to our privacy standards, grouping the logging logic to be mostly +/// handled by a single class sounds like a good approach to be able to review what's being logged.. +/// +public final class VPNLogger { + public typealias AttemptStep = PacketTunnelProvider.AttemptStep + public typealias ConnectionAttempt = PacketTunnelProvider.ConnectionAttempt + public typealias LogCallback = (OSLogType, OSLogMessage) -> Void + + public init() {} + + public func logStartingWithoutAuthToken() { + os_log("🔴 Starting tunnel without an auth token", log: .networkProtection, type: .error) + } + + public func log(_ step: AttemptStep, named name: String) { + let log = OSLog.networkProtection + + switch step { + case .begin: + os_log("🔵 %{public}@ attempt begins", log: log, name) + case .failure(let error): + os_log("🔴 %{public}@ attempt failed with error: %{public}@", log: log, type: .error, name, error.localizedDescription) + case .success: + os_log("🟢 %{public}@ attempt succeeded", log: log, name) + } + } + + public func log(_ step: ConnectionAttempt) { + let log = OSLog.networkProtection + + switch step { + case .connecting: + os_log("🔵 Connection attempt detected", log: log) + case .failure: + os_log("🔴 Connection attempt failed", log: log, type: .error) + case .success: + os_log("🟢 Connection attempt successful", log: log) + } + } + + public func log(_ step: FailureRecoveryStep) { + let log = OSLog.networkProtectionTunnelFailureMonitorLog + + switch step { + case .started: + os_log("🔵 Failure Recovery attempt started", log: log) + case .failed(let error): + os_log("🔴 Failure Recovery attempt failed with error: %{public}@", log: log, type: .error, error.localizedDescription) + case .completed(let health): + switch health { + case .healthy: + os_log("🟢 Failure Recovery attempt completed", log: log) + case .unhealthy: + os_log("🔴 Failure Recovery attempt ended as unhealthy", log: log, type: .error) + } + } + } + + public func log(_ step: NetworkProtectionTunnelFailureMonitor.Result) { + let log = OSLog.networkProtectionTunnelFailureMonitorLog + + switch step { + case .failureDetected: + os_log("🔴 Tunnel failure detected", log: log, type: .error) + case .failureRecovered: + os_log("🟢 Tunnel failure recovered", log: log) + case .networkPathChanged: + os_log("🔵 Tunnel recovery detected path change", log: log) + } + } + + public func log(_ result: NetworkProtectionLatencyMonitor.Result) { + let log = OSLog.networkProtectionLatencyMonitorLog + + switch result { + case .error: + os_log("🔴 There was an error logging the latency", log: log, type: .error) + case .quality(let quality): + os_log("Connection quality is: %{public}@", log: log, quality.rawValue) + } + } +}