Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

VPN logs fix #1030

Merged
merged 2 commits into from
Oct 23, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -69,18 +69,18 @@ public actor NetworkProtectionServerStatusMonitor {
// MARK: - Start/Stop monitoring

public func start(serverName: String, callback: @escaping (ServerStatusResult) -> Void) {
Logger.networkProtectionServerStatusMonitor.debug("⚫️ Starting server status monitor for \(serverName, privacy: .public)")
Logger.networkProtectionServerStatusMonitor.log("⚫️ Starting server status monitor for \(serverName, privacy: .public)")

task = Task.periodic(delay: Self.monitoringInterval, interval: Self.monitoringInterval) {
let result = await self.checkServerStatus(for: serverName)

switch result {
case .success(let serverStatus):
if serverStatus.shouldMigrate {
Logger.networkProtectionMemory.debug("⚫️ Initiating server migration away from \(serverName, privacy: .public)")
Logger.networkProtectionMemory.log("⚫️ Initiating server migration away from \(serverName, privacy: .public)")
callback(.serverMigrationRequested)
} else {
Logger.networkProtectionMemory.debug("⚫️ No migration requested for \(serverName, privacy: .public)")
Logger.networkProtectionMemory.log("⚫️ No migration requested for \(serverName, privacy: .public)")
}
case .failure(let error):
Logger.networkProtectionMemory.error("⚫️ Error retrieving server status: \(error.localizedDescription, privacy: .public)")
Expand All @@ -90,7 +90,7 @@ public actor NetworkProtectionServerStatusMonitor {
}

public func stop() {
Logger.networkProtectionMemory.error("⚫️ Stopping server status monitor")
Logger.networkProtectionMemory.log("⚫️ Stopping server status monitor")

task?.cancel()
task = nil
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ public actor NetworkProtectionTunnelFailureMonitor {
// MARK: - Start/Stop monitoring

func start(callback: @escaping (Result) -> Void) {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Starting tunnel failure monitor")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Starting tunnel failure monitor")

failureReported = false
firstCheckSkipped = false
Expand All @@ -93,7 +93,7 @@ public actor NetworkProtectionTunnelFailureMonitor {
}

func stop() {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Stopping tunnel failure monitor")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Stopping tunnel failure monitor")

networkMonitor.cancel()
networkMonitor.pathUpdateHandler = nil
Expand All @@ -108,31 +108,31 @@ 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.
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Skipping first tunnel failure check")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Skipping first tunnel failure check")
firstCheckSkipped = true
return
}

let mostRecentHandshake = (try? await handshakeReporter.getMostRecentHandshake()) ?? 0

guard mostRecentHandshake > 0 else {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Got handshake timestamp at or below 0, skipping check")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Got handshake timestamp at or below 0, skipping check")
return
}

let difference = Date().timeIntervalSince1970 - mostRecentHandshake
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Last handshake: \(difference, privacy: .public) seconds ago")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Last handshake: \(difference, privacy: .public) seconds ago")

if difference > Result.failureDetected.threshold, isConnected {
if failureReported {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Tunnel failure already reported")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Tunnel failure already reported")
} else {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Tunnel failure reported")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Tunnel failure reported")
callback(.failureDetected)
failureReported = true
}
} else if difference <= Result.failureRecovered.threshold, failureReported {
Logger.networkProtectionTunnelFailureMonitor.debug("⚫️ Tunnel recovered from failure")
Logger.networkProtectionTunnelFailureMonitor.log("⚫️ Tunnel recovered from failure")
callback(.failureRecovered)
failureReported = false
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -75,17 +75,17 @@ public final class NetworkProtectionKeychainKeyStore: NetworkProtectionKeyStore
// MARK: - NetworkProtectionKeyStore

public func currentKeyPair() -> KeyPair? {
Logger.networkProtectionKeyManagement.debug("Querying the current key pair (publicKey: \(String(describing: self.currentPublicKey), privacy: .public), expirationDate: \(String(describing: self.currentExpirationDate), privacy: .public))")
Logger.networkProtectionKeyManagement.log("Querying the current key pair (publicKey: \(String(describing: self.currentPublicKey), privacy: .public), expirationDate: \(String(describing: self.currentExpirationDate), privacy: .public))")

guard let currentPrivateKey = currentPrivateKey else {
Logger.networkProtectionKeyManagement.debug("There's no current private key.")
Logger.networkProtectionKeyManagement.log("There's no current private key.")
return nil
}

guard let currentExpirationDate = currentExpirationDate,
Date().addingTimeInterval(validityInterval) >= currentExpirationDate else {

Logger.networkProtectionKeyManagement.debug("The expirationDate date is missing, or we're past it (now: \(String(describing: Date()), privacy: .public), expirationDate: \(String(describing: self.currentExpirationDate), privacy: .public))")
Logger.networkProtectionKeyManagement.log("The expirationDate date is missing, or we're past it (now: \(String(describing: Date()), privacy: .public), expirationDate: \(String(describing: self.currentExpirationDate), privacy: .public))")
return nil
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -152,7 +152,7 @@ public actor NetworkProtectionDeviceManager: NetworkProtectionDeviceManagement {
}

let (selectedServer, newExpiration) = try await register(keyPair: keyPair, selectionMethod: resolvedSelectionMethod)
Logger.networkProtection.debug("Server registration successul")
Logger.networkProtection.log("Server registration successul")

keyStore.updateKeyPair(keyPair)

Expand Down
4 changes: 2 additions & 2 deletions Sources/NetworkProtection/Networking/Pinger.swift
Original file line number Diff line number Diff line change
Expand Up @@ -289,7 +289,7 @@ extension Pinger {
let seq = self.nextSeq()
sentIndices.insert(Int(seq))

Logger.networkProtection.debug("PING \(self.ip.debugDescription): \(MemoryLayout<ICMP>.size) data bytes")
Logger.networkProtection.log("PING \(self.ip.debugDescription): \(MemoryLayout<ICMP>.size) data bytes")
// form ICMP packet with id, icmp_seq, timestamp and checksum
let icmp = ICMP(id: id, index: seq)

Expand Down Expand Up @@ -352,7 +352,7 @@ extension Pinger {
return self.ip
}()
let r = PingResult(ip: srcIp, bytesCount: bytesCount, seq: Int(response.index), ttl: Int(ip.ip_ttl), time: end - icmp.timestamp)
Logger.networkProtection.debug("\(r.bytesCount) bytes from \(r.ip.debugDescription): icmp_seq=\(r.seq) ttl=\(r.ttl) time=\(r.time * 1000) ms")
Logger.networkProtection.log("\(r.bytesCount) bytes from \(r.ip.debugDescription): icmp_seq=\(r.seq) ttl=\(r.ttl) time=\(r.time * 1000) ms")

return .success(r)

Expand Down
Loading
Loading