refactor(apple): Determine logging context based on bundle ID (#7618)

This simplifies the logging API and prevents accidentally writing to the
app or tunnel log file from the wrong process.

Tested on macOS and iOS

Fixes #7616 

Draft because stacked
This commit is contained in:
Jamil
2024-12-31 12:59:22 -08:00
committed by GitHub
parent b5eccf095a
commit 635b0f37cc
14 changed files with 89 additions and 92 deletions

View File

@@ -8,47 +8,49 @@ import Foundation
import OSLog
public final class Log {
public static let app = Log(category: .app, folderURL: SharedAccess.appLogFolderURL)
public static let tunnel = Log(category: .tunnel, folderURL: SharedAccess.tunnelLogFolderURL)
public enum Category: String, Codable {
case app = "app"
case tunnel = "tunnel"
private static var logger = switch Bundle.main.bundleIdentifier {
case "dev.firezone.firezone":
Logger(subsystem: "dev.firezone.firezone", category: "app")
case "dev.firezone.firezone.network-extension":
Logger(subsystem: "dev.firezone.firezone", category: "tunnel")
default:
fatalError("Unknown bundle id: \(Bundle.main.bundleIdentifier!)")
}
private let logger: Logger
private let logWriter: LogWriter?
public init(category: Category, folderURL: URL?) {
self.logger = Logger(subsystem: "dev.firezone.firezone", category: category.rawValue)
self.logWriter = LogWriter(folderURL: folderURL, logger: self.logger)
private static var logWriter = switch Bundle.main.bundleIdentifier {
case "dev.firezone.firezone":
LogWriter(folderURL: SharedAccess.appLogFolderURL, logger: logger)
case "dev.firezone.firezone.network-extension":
LogWriter(folderURL: SharedAccess.tunnelLogFolderURL, logger: logger)
default:
fatalError("Unknown bundle id: \(Bundle.main.bundleIdentifier!)")
}
public func log(_ message: String) {
public static func log(_ message: String) {
debug(message)
}
public func trace(_ message: String) {
public static func trace(_ message: String) {
logger.trace("\(message, privacy: .public)")
logWriter?.write(severity: .trace, message: message)
}
public func debug(_ message: String) {
public static func debug(_ message: String) {
self.logger.debug("\(message, privacy: .public)")
logWriter?.write(severity: .debug, message: message)
}
public func info(_ message: String) {
public static func info(_ message: String) {
logger.info("\(message, privacy: .public)")
logWriter?.write(severity: .info, message: message)
}
public func warning(_ message: String) {
public static func warning(_ message: String) {
logger.warning("\(message, privacy: .public)")
logWriter?.write(severity: .warning, message: message)
}
public func error(_ message: String) {
public static func error(_ message: String) {
self.logger.error("\(message, privacy: .public)")
logWriter?.write(severity: .error, message: message)
}

View File

@@ -152,11 +152,11 @@ public class TunnelManager {
// Since our bundle ID can change (by us), find the one that's current and ignore the others.
guard let managers = try? await NETunnelProviderManager.loadAllFromPreferences()
else {
Log.app.error("\(#function): Could not load VPN configurations!")
Log.error("\(#function): Could not load VPN configurations!")
return
}
Log.app.log("\(#function): \(managers.count) tunnel managers found")
Log.log("\(#function): \(managers.count) tunnel managers found")
for manager in managers {
if let protocolConfiguration = manager.protocolConfiguration as? NETunnelProviderProtocol,
protocolConfiguration.providerBundleIdentifier == TunnelManager.bundleIdentifier,
@@ -199,7 +199,7 @@ public class TunnelManager {
let protocolConfiguration = manager.protocolConfiguration as? NETunnelProviderProtocol,
var providerConfiguration = protocolConfiguration.providerConfiguration
else {
Log.app.error("Manager doesn't seem initialized. Can't save settings.")
Log.error("Manager doesn't seem initialized. Can't save settings.")
throw TunnelManagerError.cannotSaveIfMissing
}
@@ -220,7 +220,7 @@ public class TunnelManager {
let protocolConfiguration = manager.protocolConfiguration as? NETunnelProviderProtocol,
let providerConfiguration = protocolConfiguration.providerConfiguration as? [String: String]
else {
Log.app.error("Manager doesn't seem initialized. Can't save settings.")
Log.error("Manager doesn't seem initialized. Can't save settings.")
throw TunnelManagerError.cannotSaveIfMissing
}
@@ -250,7 +250,7 @@ public class TunnelManager {
do {
try session()?.startTunnel(options: options)
} catch {
Log.app.error("Error starting tunnel: \(error)")
Log.error("Error starting tunnel: \(error)")
}
}
@@ -261,7 +261,7 @@ public class TunnelManager {
self.session()?.stopTunnel()
}
} catch {
Log.app.error("\(#function): \(error)")
Log.error("\(#function): \(error)")
}
} else {
session()?.stopTunnel()
@@ -294,7 +294,7 @@ public class TunnelManager {
callback(self.resourcesListCache)
}
} catch {
Log.app.error("Error: sendProviderMessage: \(error)")
Log.error("Error: sendProviderMessage: \(error)")
}
}
@@ -350,7 +350,7 @@ public class TunnelManager {
) { data in
guard let data = data
else {
Log.app.error("Error: \(#function): No data received")
Log.error("Error: \(#function): No data received")
errorHandler(TunnelManagerError.decodeIPCDataFailed)
return
@@ -360,7 +360,7 @@ public class TunnelManager {
LogChunk.self, from: data
)
else {
Log.app.error("Error: \(#function): Invalid data received")
Log.error("Error: \(#function): Invalid data received")
errorHandler(TunnelManagerError.decodeIPCDataFailed)
return
@@ -374,7 +374,7 @@ public class TunnelManager {
}
}
} catch {
Log.app.error("Error: \(#function): \(error)")
Log.error("Error: \(#function): \(error)")
}
}
@@ -420,7 +420,7 @@ public class TunnelManager {
// Subscribe to system notifications about our VPN status changing
// and let our handler know about them.
private func setupTunnelObservers() {
Log.app.log("\(#function)")
Log.log("\(#function)")
for task in tunnelObservingTasks {
task.cancel()
@@ -434,7 +434,7 @@ public class TunnelManager {
) {
guard let session = notification.object as? NETunnelProviderSession
else {
Log.app.error("\(#function): NEVPNStatusDidChange notification doesn't seem to be valid")
Log.error("\(#function): NEVPNStatusDidChange notification doesn't seem to be valid")
return
}

View File

@@ -63,7 +63,7 @@ public class SessionNotification: NSObject {
#if os(iOS)
func askUserForNotificationPermissions() {
guard case .notDetermined = self.decision else {
Log.app.log("Already determined!")
Log.log("Already determined!")
return
}
@@ -84,7 +84,7 @@ public class SessionNotification: NSObject {
public static func showSignedOutNotificationiOS() {
UNUserNotificationCenter.current().getNotificationSettings { notificationSettings in
if notificationSettings.authorizationStatus == .authorized {
Log.app.log(
Log.log(
"Notifications are allowed. Alert style is \(notificationSettings.alertStyle.rawValue)"
)
let content = UNMutableNotificationContent()
@@ -97,9 +97,9 @@ public class SessionNotification: NSObject {
)
UNUserNotificationCenter.current().add(request) { error in
if let error = error {
Log.app.error("\(#function): Error requesting notification: \(error)")
Log.error("\(#function): Error requesting notification: \(error)")
} else {
Log.app.error("\(#function): Successfully requested notification")
Log.error("\(#function): Successfully requested notification")
}
}
}
@@ -117,7 +117,7 @@ public class SessionNotification: NSObject {
NSApp.activate(ignoringOtherApps: true)
let response = alert.runModal()
if response == NSApplication.ModalResponse.alertFirstButtonReturn {
Log.app.log("\(#function): 'Sign In' clicked in notification")
Log.log("\(#function): 'Sign In' clicked in notification")
signInHandler?()
}
}
@@ -127,7 +127,7 @@ public class SessionNotification: NSObject {
#if os(iOS)
extension SessionNotification: UNUserNotificationCenterDelegate {
public func userNotificationCenter(_ center: UNUserNotificationCenter, didReceive response: UNNotificationResponse, withCompletionHandler completionHandler: @escaping () -> Void) {
Log.app.log("\(#function): 'Sign In' clicked in notification")
Log.log("\(#function): 'Sign In' clicked in notification")
let actionId = response.actionIdentifier
let categoryId = response.notification.request.content.categoryIdentifier
if categoryId == NotificationIndentifier.sessionEndedNotificationCategory.rawValue,

View File

@@ -113,7 +113,7 @@ public final class Store: ObservableObject {
func start(token: String? = nil) async throws {
guard status == .disconnected
else {
Log.app.log("\(#function): Already connected")
Log.log("\(#function): Already connected")
return
}
@@ -146,7 +146,7 @@ public final class Store: ObservableObject {
// Network Extensions don't have a 2-way binding up to the GUI process,
// so we need to periodically ask the tunnel process for them.
func beginUpdatingResources(callback: @escaping (ResourceList) -> Void) {
Log.app.log("\(#function)")
Log.log("\(#function)")
TunnelManager.shared.fetchResources(callback: callback)
let intervalInSeconds: TimeInterval = 1
@@ -169,7 +169,7 @@ public final class Store: ObservableObject {
try await TunnelManager.shared.saveSettings(newSettings)
DispatchQueue.main.async { self.settings = newSettings }
} catch {
Log.app.error("\(#function): \(error)")
Log.error("\(#function): \(error)")
}
}
}

View File

@@ -36,7 +36,7 @@ public class AppViewModel: ObservableObject {
.receive(on: DispatchQueue.main)
.sink(receiveValue: { [weak self] status in
guard let self = self else { return }
Log.app.log("Status: \(status)")
Log.log("Status: \(status)")
self.status = status
@@ -62,7 +62,7 @@ public class AppViewModel: ObservableObject {
.sink(receiveValue: { [weak self] decision in
guard let self = self else { return }
Log.app.log("Decision: \(decision)")
Log.log("Decision: \(decision)")
self.decision = decision
})
.store(in: &cancellables)

View File

@@ -16,7 +16,7 @@ final class GrantVPNViewModel: ObservableObject {
}
func grantPermissionButtonTapped() {
Log.app.log("\(#function)")
Log.log("\(#function)")
store.createVPNProfile()
}
}

View File

@@ -47,7 +47,7 @@ public final class SettingsViewModel: ObservableObject {
do {
try await store.save(settings)
} catch {
Log.app.error("Error saving settings to tunnel store: \(error)")
Log.error("Error saving settings to tunnel store: \(error)")
}
}
}
@@ -64,10 +64,10 @@ public final class SettingsViewModel: ObservableObject {
// is not started on demand, so the IPC calls hang. Thus, we use separate code
// paths for iOS and macOS.
func calculateLogDirSize() async -> String {
Log.app.log("\(#function)")
Log.log("\(#function)")
guard let logFilesFolderURL = SharedAccess.logFolderURL else {
Log.app.error("\(#function): Log folder is unavailable")
Log.error("\(#function): Log folder is unavailable")
return "Unknown"
}
@@ -90,7 +90,7 @@ public final class SettingsViewModel: ObservableObject {
return byteCountFormatter.string(fromByteCount: Int64(totalSize))
} catch {
Log.app.error("\(#function): \(error)")
Log.error("\(#function): \(error)")
return "Unknown"
}
@@ -100,7 +100,7 @@ public final class SettingsViewModel: ObservableObject {
// On macOS, we need to clear logs from the app process, then call over IPC
// to clear the provider's log directory.
func clearAllLogs() async throws {
Log.app.log("\(#function)")
Log.log("\(#function)")
try Log.clear(in: SharedAccess.logFolderURL)
@@ -135,7 +135,7 @@ extension FileManager {
let resourceValues = try url.resourceValues(forKeys: resourceKeys)
handler(url, resourceValues)
} catch {
Log.app.error("Unable to get resource value for '\(url)': \(error)")
Log.error("Unable to get resource value for '\(url)': \(error)")
}
}
}
@@ -576,7 +576,7 @@ public struct SettingsView: View {
})
else {
self.isExportingLogs = false
Log.app.log("Settings window not found. Can't show save panel.")
Log.log("Settings window not found. Can't show save panel.")
return
}
@@ -598,7 +598,7 @@ public struct SettingsView: View {
window.contentViewController?.presentingViewController?.dismiss(self)
}
} catch {
Log.app.error("\(#function): \(error)")
Log.error("\(#function): \(error)")
let alert = NSAlert()
alert.messageText = "Error exporting logs: \(error.localizedDescription)"

View File

@@ -36,12 +36,12 @@ class UpdateChecker {
guard let self = self else { return }
if let error = error {
Log.app.error("Error fetching version manifest: \(error)")
Log.error("Error fetching version manifest: \(error)")
return
}
guard let versionInfo = VersionInfo.from(data: data) else {
Log.app.error("No data or failed to decode data")
Log.error("No data or failed to decode data")
return
}
@@ -90,7 +90,7 @@ private class NotificationAdapter: NSObject, UNUserNotificationCenterDelegate {
notificationCenter.delegate = self
notificationCenter.requestAuthorization(options: [.sound, .badge, .alert]) { _, error in
if let error = error {
Log.app.error("Failed to request authorization for notifications: \(error)")
Log.error("Failed to request authorization for notifications: \(error)")
}
}
@@ -114,7 +114,7 @@ private class NotificationAdapter: NSObject, UNUserNotificationCenterDelegate {
UNUserNotificationCenter.current().add(request) { error in
if let error = error {
Log.app.error("\(#function): Error requesting notification: \(error)")
Log.error("\(#function): Error requesting notification: \(error)")
}
}

View File

@@ -69,7 +69,7 @@ class Adapter {
/// Adapter state.
private var state: AdapterState {
didSet {
Log.tunnel.log("Adapter state changed to: \(self.state)")
Log.log("Adapter state changed to: \(self.state)")
}
}
@@ -102,21 +102,21 @@ class Adapter {
// Could happen abruptly if the process is killed.
deinit {
Log.tunnel.log("Adapter.deinit")
Log.log("Adapter.deinit")
// Cancel network monitor
networkMonitor?.cancel()
// Shutdown the tunnel
if case .tunnelStarted(let session) = self.state {
Log.tunnel.log("Adapter.deinit: Shutting down connlib")
Log.log("Adapter.deinit: Shutting down connlib")
session.disconnect()
}
}
/// Start the tunnel.
public func start() async throws {
Log.tunnel.log("Adapter.start")
Log.log("Adapter.start")
guard case .tunnelStopped = self.state else {
throw AdapterError.invalidState
}
@@ -124,10 +124,10 @@ class Adapter {
callbackHandler.delegate = self
if connlibLogFolderPath.isEmpty {
Log.tunnel.error("Cannot get shared log folder for connlib")
Log.error("Cannot get shared log folder for connlib")
}
Log.tunnel.log("Adapter.start: Starting connlib")
Log.log("Adapter.start: Starting connlib")
do {
let jsonEncoder = JSONEncoder()
jsonEncoder.keyEncodingStrategy = .convertToSnakeCase
@@ -172,7 +172,7 @@ class Adapter {
/// This can happen before the tunnel is in the tunnelReady state, such as if the portal
/// is slow to send the init.
public func stop() {
Log.tunnel.log("Adapter.stop")
Log.log("Adapter.stop")
if case .tunnelStarted(let session) = state {
state = .tunnelStopped
@@ -241,7 +241,7 @@ class Adapter {
extension Adapter {
private func beginPathMonitoring() {
Log.tunnel.log("Beginning path monitoring")
Log.log("Beginning path monitoring")
let networkMonitor = NWPathMonitor()
networkMonitor.pathUpdateHandler = { [weak self] path in
self?.didReceivePathUpdate(path: path)
@@ -366,7 +366,7 @@ extension Adapter: CallbackHandlerDelegate {
packetTunnelProvider: packetTunnelProvider)
}
Log.tunnel.log(
Log.log(
"\(#function): \(tunnelAddressIPv4) \(tunnelAddressIPv6) \(dnsAddresses)")
switch state {
@@ -377,7 +377,7 @@ extension Adapter: CallbackHandlerDelegate {
networkSettings.dnsAddresses = dnsAddresses
networkSettings.apply()
case .tunnelStopped:
Log.tunnel.error(
Log.error(
"\(#function): Unexpected state: \(self.state)")
}
}
@@ -392,7 +392,7 @@ extension Adapter: CallbackHandlerDelegate {
fatalError("onUpdateRoutes called before network settings was initialized!")
}
Log.tunnel.log("\(#function): \(routeList4) \(routeList6)")
Log.log("\(#function): \(routeList4) \(routeList6)")
networkSettings.routes4 = try! JSONDecoder().decode(
[NetworkSettings.Cidr].self, from: routeList4.data(using: .utf8)!
@@ -410,7 +410,7 @@ extension Adapter: CallbackHandlerDelegate {
workQueue.async { [weak self] in
guard let self = self else { return }
Log.tunnel.log("\(#function)")
Log.log("\(#function)")
// Update resource List. We don't care what's inside.
resourceListJSON = resourceList
@@ -424,7 +424,7 @@ extension Adapter: CallbackHandlerDelegate {
// to ensure that we can clean up even if connlib exits before we are done.
workQueue.async { [weak self] in
guard let self = self else { return }
Log.tunnel.log("\(#function)")
Log.log("\(#function)")
// Set a default stop reason. In the future, we may have more to act upon in
// different ways.

View File

@@ -35,7 +35,7 @@ public class CallbackHandler {
tunnelAddressIPv6: RustString,
dnsAddresses: RustString
) {
Log.tunnel.log(
Log.log(
"""
CallbackHandler.onSetInterfaceConfig:
IPv4: \(tunnelAddressIPv4.toString())
@@ -54,18 +54,18 @@ public class CallbackHandler {
}
func onUpdateRoutes(routeList4: RustString, routeList6: RustString) {
Log.tunnel.log("CallbackHandler.onUpdateRoutes: \(routeList4) \(routeList6)")
Log.log("CallbackHandler.onUpdateRoutes: \(routeList4) \(routeList6)")
delegate?.onUpdateRoutes(routeList4: routeList4.toString(), routeList6: routeList6.toString())
}
func onUpdateResources(resourceList: RustString) {
Log.tunnel.log("CallbackHandler.onUpdateResources: \(resourceList.toString())")
Log.log("CallbackHandler.onUpdateResources: \(resourceList.toString())")
delegate?.onUpdateResources(resourceList: resourceList.toString())
}
func onDisconnect(error: RustString) {
let error = error.toString()
Log.tunnel.log("CallbackHandler.onDisconnect: \(error)")
Log.log("CallbackHandler.onDisconnect: \(error)")
delegate?.onDisconnect(error: error)
}
}

View File

@@ -53,7 +53,7 @@ class NetworkSettings {
packetTunnelProvider?.setTunnelNetworkSettings(tunnelNetworkSettings) { error in
if let error = error {
Log.tunnel.error(
Log.error(
"\(#function): Error occurred while applying network settings! Error: \(error.localizedDescription)"
)
}

View File

@@ -29,7 +29,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
completionHandler: @escaping (Error?) -> Void
) {
super.startTunnel(options: options, completionHandler: completionHandler)
Log.tunnel.log("\(#function)")
Log.log("\(#function)")
Task {
do {
@@ -90,7 +90,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
// `connected`.
completionHandler(nil)
} catch {
Log.tunnel.error("\(#function): Error! \(error)")
Log.error("\(#function): Error! \(error)")
completionHandler(error)
}
}
@@ -102,7 +102,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
override func stopTunnel(
with reason: NEProviderStopReason, completionHandler: @escaping () -> Void
) {
Log.tunnel.log("stopTunnel: Reason: \(reason)")
Log.log("stopTunnel: Reason: \(reason)")
if case .authenticationCanceled = reason {
do {
@@ -115,7 +115,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
try String(reason.rawValue).write(
to: SharedAccess.providerStopReasonURL, atomically: true, encoding: .utf8)
} catch {
Log.tunnel.error(
Log.error(
"\(#function): Couldn't write provider stop reason to file. Notification won't work.")
}
#if os(iOS)
@@ -157,7 +157,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
Task {
guard let completionHandler
else {
Log.tunnel.error(
Log.error(
"\(#function): Need a completion handler to export logs."
)
@@ -170,7 +170,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
Task {
guard let completionHandler
else {
Log.tunnel.error(
Log.error(
"\(#function): Need a completion handler to consumeStopReason."
)
@@ -188,7 +188,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
do {
try Log.clear(in: SharedAccess.logFolderURL)
} catch {
Log.tunnel.error("Error clearing logs: \(error)")
Log.error("Error clearing logs: \(error)")
}
completionHandler?(nil)
@@ -217,7 +217,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
let chunk = try tunnelLogArchive.readChunk()
completionHandler(chunk)
} catch {
Log.tunnel.error("\(#function): error reading chunk: \(error)")
Log.error("\(#function): error reading chunk: \(error)")
completionHandler(nil)
}
@@ -232,21 +232,18 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
guard let logFolderURL = SharedAccess.logFolderURL,
let logFolderPath = FilePath(logFolderURL)
else {
Log.tunnel.error("\(#function): log folder not available")
Log.error("\(#function): log folder not available")
completionHandler(nil)
return
}
let tunnelLogArchive = TunnelLogArchive(
logger: Log.tunnel,
source: logFolderPath
)
let tunnelLogArchive = TunnelLogArchive(source: logFolderPath)
do {
try tunnelLogArchive.archive()
} catch {
Log.tunnel.error("\(#function): error archiving logs: \(error)")
Log.error("\(#function): error archiving logs: \(error)")
completionHandler(nil)
return
@@ -268,7 +265,7 @@ class PacketTunnelProvider: NEPacketTunnelProvider {
completionHandler(data)
} catch {
Log.tunnel.error("\(#function): error reading stop reason: \(error)")
Log.error("\(#function): error reading stop reason: \(error)")
completionHandler(nil)
}

View File

@@ -18,7 +18,7 @@ class SystemConfigurationResolvers {
init() {
guard let dynamicStore = SCDynamicStoreCreate(nil, storeName, nil, nil)
else {
Log.tunnel.error("\(#function): Failed to create dynamic store")
Log.error("\(#function): Failed to create dynamic store")
self.dynamicStore = nil
return
}
@@ -47,7 +47,7 @@ class SystemConfigurationResolvers {
let interfaceSearchKey = "Setup:/Network/Service/.*/Interface" as CFString
guard let services = SCDynamicStoreCopyKeyList(dynamicStore, interfaceSearchKey) as? [String]
else {
Log.tunnel.error("\(#function): Unable to retrieve network services")
Log.error("\(#function): Unable to retrieve network services")
return []
}

View File

@@ -42,11 +42,9 @@ class TunnelLogArchive {
var offset: UInt64 = 0
var fileHandle: FileHandle?
var source: FilePath
var logger: Log
init(logger: Log, source: FilePath) {
init(source: FilePath) {
self.source = source
self.logger = logger
}
deinit {