iOS file backed app logger

ios/ConduitModule/AppLogger.swift

@@ -0,0 +1,124 @@
+/*
+ * Copyright (c) 2024, Psiphon Inc.
+ * All rights reserved.
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ *
+ */
+
+
+import Foundation
+import Puppy
+import Logging
+
+struct JSONLogFormatter : LogFormattable {
+
+    let jsonEncoder: JSONEncoder = JSONEncoder()
+
+    func formatMessage(_ level: LogLevel, message: String, tag: String, function: String,
+                       file: String, line: UInt, swiftLogInfo: [String: String],
+                       label: String, date: Date, threadID: UInt64) -> String {
+
+        let category = swiftLogInfo["label"]! // Category must always be set.
+
+        do {
+            var metadata: GenericJSON? = nil
+            if let metadataString = swiftLogInfo["metadata"] {
+                // TODO: Puppy API limits us to encoding and decoding metadata.
+                let jsonObj = try JSONSerialization.jsonObject(with: metadataString.data(using: .utf8)!)
+                metadata = try GenericJSON(jsonObj)
+            }
+
+            let log = Log(
+                timestamp: date,
+                level: FeedbackLogLevel(from: level),
+                category: category,
+                message: message,
+                data: metadata
+            )
+
+            let jsonData = try self.jsonEncoder.encode(log)
+            guard let logString = String(data: jsonData, encoding: .utf8) else {
+                throw Err("Failed to convert JSON data to String")
+            }
+            return logString
+
+        } catch {
+            os_log(.fault, "Failed to encode log")
+            return "Error formatting log: \(String(describing: error))"
+        }
+    }
+}
+
+
+/// Manages an instance of Puppy as backend for swift-log.
+enum AppLogger {
+
+    #if DEBUG
+    static let minLogLevel = Logging.Logger.Level.trace
+    #else
+    static let minLogLevel = Logging.Logger.Level.info
+    #endif
+
+    static let subsystem: String = Bundle.main.bundleIdentifier!
+    private static let maxArchivedCount: UInt8 = 2
+
+    private static let baseFileURL = {
+        var appSupportDir = try getApplicationSupportDirectory()
+        if #available(iOS 16.0, *) {
+            appSupportDir.append(components: Self.subsystem, "appLogs", "app.log")
+        } else {
+            appSupportDir.appendPathComponent(Self.subsystem)
+            appSupportDir.appendPathComponent("appLogs")
+            appSupportDir.appendPathComponent("app.log")
+        }
+
+        return appSupportDir.absoluteURL
+    }
+
+    static func initializePuppy() -> Puppy {
+        var puppy = Puppy()
+
+        let fileLogger = try! FileRotationLogger(
+            "\(AppLogger.subsystem).log.file", // DispatchQueue label
+            logLevel: Self.minLogLevel.toPuppy(),
+            logFormat: JSONLogFormatter(),
+            fileURL: AppLogger.baseFileURL(),
+            filePermission: "600",
+            rotationConfig: RotationConfig(
+                suffixExtension: .numbering,
+                maxFileSize: 100 * 1024,
+                maxArchivedFilesCount: AppLogger.maxArchivedCount
+            )
+        )
+
+        puppy.add(fileLogger)
+        return puppy
+    }
+
+    static func readLogs() throws -> ([Log], [ParseError]) {
+
+        var files = [URL]()
+        for i in 0...maxArchivedCount {
+            var fileURL = try! baseFileURL()
+            if i > 0 {
+                fileURL = fileURL.appendingPathExtension("\(i)")
+            }
+            files.append(fileURL)
+        }
+
+        return try readLogFiles(withLogType: Log.self, paths: files, transform: { $0 })
+    }
+
+}

ios/ConduitModule/ConduitManager.swift

@@ -17,16 +17,14 @@
  *
  */
 
+import Collections
 import Foundation
 import PsiphonTunnel
-import Collections
+import Logging
 
-extension Logger {
-    private static var subsystem = Bundle.main.bundleIdentifier!
-
-    static let conduitMan = Logger(subsystem: subsystem, category: "ConduitManager")
-
-    static let psiphonTunnel = Logger(subsystem: subsystem, category: "PsiphonTunnel")
+extension Logging.Logger {
+    static let conduitMan = Logger(label: "ConduitManager")
+    static let psiphonTunnel = Logger(label: "PsiphonTunnel")
 }
 
 struct ConduitParams: Equatable {
@@ -331,7 +329,7 @@ fileprivate final class PsiphonTunnelListener: NSObject, TunneledAppDelegate {
             let data = try Data(contentsOf: ResourceFile.embeddedServerEntries.url)
             return String(data: data, encoding: .utf8)
         } catch {
-            Logger.conduitMan.fault("Failed to read embedded server entries")
+            Logger.conduitMan.critical("Failed to read embedded server entries")
             return nil
         }
     }
@@ -371,7 +369,7 @@ fileprivate final class PsiphonTunnelListener: NSObject, TunneledAppDelegate {
 
             return config
         } catch {
-            Logger.conduitMan.error("getPsiphonConfig failed: \(error, privacy: .public)")
+            Logger.conduitMan.error("getPsiphonConfig failed", metadata: ["error": "\(error)"])
             return nil
         }
     }
@@ -401,7 +399,7 @@ fileprivate final class PsiphonTunnelListener: NSObject, TunneledAppDelegate {
     }
 
     func onDiagnosticMessage(_ message: String, withTimestamp timestamp: String) {
-        Logger.psiphonTunnel.debug("\(message, privacy: .public)")
+        Logger.psiphonTunnel.debug("\(message)")
     }
 
 }

ios/ConduitModule/ConduitModule.swift

@@ -19,15 +19,11 @@
 
 import Foundation
 import PsiphonTunnel
-import OSLog
+import Logging
 
-
-extension Logger {
-    private static var subsystem = Bundle.main.bundleIdentifier!
-
-    static let conduitModule = Logger(subsystem: subsystem, category: "ConduitModule")
-
-    static let feedbackUploadService = Logger(subsystem: subsystem, category: "FeedbackUploadService")
+extension Logging.Logger {
+    static let conduitModule = Logger(label: "ConduitModule")
+    static let feedbackUploadService = Logger(label: "FeedbackUploadService")
 }
 
 /// A type that is used for cross-langauge interaction with JavaScript codebase.
@@ -188,8 +184,20 @@ final class ConduitModule: RCTEventEmitter {
     // synchronous execution to reuse the same thread.
     // Note that using `.sync` and targeting the same queue will result in a deadlock.
     let dispatchQueue: dispatch_queue_t
-
+    
     override init() {
+
+        LoggingSystem.bootstrap { label in
+            MultiplexLogHandler([
+                OSLogger(subsystem: AppLogger.subsystem,
+                         label: label,
+                         logLevel: AppLogger.minLogLevel),
+                PsiphonLogHandler(label: label,
+                                  logLevel: AppLogger.minLogLevel,
+                                  puppy: AppLogger.initializePuppy()),
+            ])
+        }
+
         dispatchQueue = DispatchQueue(label: "ca.psiphon.conduit.module", qos: .default)
         super.init()
 
@@ -223,7 +231,7 @@ final class ConduitModule: RCTEventEmitter {
 
     func sendEvent(_ event: ConduitEvent) {
         sendEvent(withName: ConduitEvent.eventName, body: event.asDictionary)
-        Logger.conduitModule.debug("ConduitEvent: \(String(describing: event))")
+        Logger.conduitModule.trace("ConduitEvent", metadata: ["event": "\(String(describing: event))"])
     }
 
 }
@@ -252,8 +260,7 @@ extension ConduitModule {
                     }
                 } catch {
                     sendEvent(.proxyError(.inProxyStartFailed))
-                    Logger.conduitModule.error(
-                        "Proxy start failed: \(String(describing: error), privacy: .public)")
+                    Logger.conduitModule.error( "Proxy start failed", metadata: ["error": "\(error)"])
                 }
             case .started:
                 await self.conduitManager.stopConduit()
@@ -316,7 +323,6 @@ extension ConduitModule {
     ) {
 
         do {
-            // Read psiphon-tunnel-core notices.
 
             let dataRootDirectory = try getApplicationSupportDirectory()
 
@@ -326,21 +332,30 @@ extension ConduitModule {
                 olderNoticesFilePath(dataRootDirectory: dataRootDirectory)
             ]
 
-            let (tunnelCoreEntries, parseErrors) = try readDiagnosticLogFiles(
-                TunnelCoreLog.self,
+            let (tunnelCoreLogs, parseErrors) = try readLogFiles(
+                withLogType: TunnelCoreLog.self,
                 paths: tunnelCoreNoticesPath,
-                transform: DiagnosticEntry.create(from:))
-
+                transform: Log.create(from:))
             if parseErrors.count > 0 {
-                Logger.conduitModule.error(
-                    "Log parse errors: \(String(describing: parseErrors), privacy: .public)")
+                os_log(.error, "Log parse error: \(parseErrors)")
+            }
+
+            let (appLogs, appLogParseErrors) = try AppLogger.readLogs()
+            if appLogParseErrors.count > 0 {
+                os_log(.error, "Log parse error: \(parseErrors)")
             }
 
+            var allLogs = tunnelCoreLogs
+            allLogs.append(contentsOf: appLogs)
+            allLogs.append(contentsOf: (parseErrors + appLogParseErrors).map {
+                Log(timestamp: Date(), level: .error, category: "LogParser", message: $0.message)
+            })
+            allLogs.sort()
 
             // Prepare Feedback Diagnostic Report
 
             let feedbackId = try generateFeedbackId()
-            Logger.conduitModule.info("Preparing feedback report with ID = \(feedbackId, privacy: .public)")
+            Logger.conduitModule.info("Preparing feedback report", metadata: ["feedback.id": "\(feedbackId)"])
 
             let psiphonConfig = try defaultPsiphonConfig()
 
@@ -358,26 +373,26 @@ extension ConduitModule {
                 inproxyId: inproxyId
             )
 
-            let report = FeedbackDiagnosticReport(
-                metadata: Metadata(
+            let report = FeedbackDiagnosticReportV2(
+                metadata: MetadataV2(
                     id: feedbackId,
                     appName: "conduit",
-                    platform: ClientPlatform.platformString,
-                    date: Date()
+                    platform: ClientPlatform.platformString
                 ),
-                feedback: nil,
-                diagnosticInfo: DiagnosticInfo(
-                    systemInformation: SystemInformation(
-                        build: DeviceInfo.gatherDeviceInfo(device: .current),
-                        tunnelCoreBuildInfo: PsiphonTunnel.getBuildInfo(),
-                        psiphonInfo: psiphonInfo,
-                        isAppStoreBuild: true,
-                        isJailbroken: false,
-                        language: getLanguageMinimalIdentifier(),
-                        // TODO: get networkTypeName
-                        networkTypeName: "WIFI"),
-                    diagnosticHistory: tunnelCoreEntries
-                ))
+                systemInformation: SystemInformationV2(
+                    build: DeviceInfo.gatherDeviceInfo(device: .current),
+                    tunnelCoreBuildInfo: PsiphonTunnel.getBuildInfo(),
+                    isAppStoreBuild: true,
+                    isJailbroken: false,
+                    language: getLanguageMinimalIdentifier(),
+                    // TODO: get networkTypeName
+                    networkTypeName: "WIFI"),
+                psiphonInfo: psiphonInfo,
+                applicationInfo: ApplicationInfo(
+                    applicationId: getApplicagtionId(),
+                    clientVersion: getClientVersion()),
+                logs: allLogs
+                )
 
             let json = String(data: try JSONEncoder().encode(report), encoding: .utf8)!
 
@@ -391,42 +406,45 @@ extension ConduitModule {
                         uploadPath: "")
 
                     resolve(nil)
-                    Logger.conduitModule.info("Finished uploading feedback diagnostic report.")
+                    Logger.conduitModule.info("Finished uploading feedback diagnostic report", metadata: ["feedback.id": "\(feedbackId)"])
                 } catch {
                     reject("error", "Feedback upload failed", nil)
-                    Logger.conduitModule.error(
-                        "Feedback upload failed: \(String(describing: error), privacy: .public)")
+                    Logger.conduitModule.error("Feedback upload failed", metadata: [
+                        "feedback.id": "\(feedbackId)",
+                        "error": "\(error)"
+                    ])
                 }
             }
 
         } catch {
-            reject("error", "Feedback upload failed", nil)
-            Logger.conduitModule.error(
-                "Feedback upload failed: \(String(describing: error), privacy: .public)")
+            reject("error", "Feedback preparation failed", nil)
+            Logger.conduitModule.error("Feedback preparation failed", metadata: ["error": "\(error)"])
         }
     }
 
     @objc(logInfo:msg:withResolver:withRejecter:)
     func logInfo(_ tag: String, msg: String, resolve: RCTPromiseResolveBlock, reject: RCTPromiseRejectBlock) {
-        Logger.conduitModule.info("\(tag, privacy: .public): \(msg, privacy: .public)")
+        let logger = Logger(label: tag)
+        logger.info("\(msg)")
         resolve(nil)
     }
 
     @objc(logWarn:msg:withResolver:withRejecter:)
     func logWarn(_ tag: String, msg: String, resolve: RCTPromiseResolveBlock, reject: RCTPromiseRejectBlock) {
-        Logger.conduitModule.info("\(tag, privacy: .public): \(msg, privacy: .public)")
+        let logger = Logger(label: tag)
+        logger.warning("\(msg)")
         resolve(nil)
     }
 
     @objc(logError:msg:withResolver:withRejecter:)
     func logError(_ tag: String, msg: String, resolve: RCTPromiseResolveBlock, reject: RCTPromiseRejectBlock) {
-        Logger.conduitModule.info("\(tag, privacy: .public): \(msg, privacy: .public)")
+        let logger = Logger(label: tag)
+        logger.error("\(msg)")
         resolve(nil)
     }
 
 }
 
-
 extension ConduitModule: ConduitManager.Listener {
 
     func onConduitStatusUpdate(_ status: ConduitManager.ConduitStatus,
@@ -480,7 +498,7 @@ extension ConduitModule: ConduitManager.Listener {
 extension ConduitModule: FeedbackUploadService.Listener {
 
     func onDiagnosticMessage(_ message: String, withTimestamp timestamp: String) {
-        Logger.feedbackUploadService.info("DiagnosticMessage: \(timestamp, privacy: .public) \(message, privacy: .public)")
+        Logger.feedbackUploadService.info("DiagnosticMessage", metadata: ["timestamp": "\(timestamp)", "message": "\(message)"])
     }
 
 }