feat!: Clean up logging (#870)

* Clean up logging

* Update tests

* Update test

* Make message param autoclosure for LogAgent

* Revert breaking API changes

* Misc changes

* Use [] syntax for capturing self's variable.

---------

Co-authored-by: Sichan Yoo <[email protected]>

Author: sichanyoo

Sources/ClientRuntime/Networking/Http/CRT/SDKDefaultIO.swift

@@ -16,15 +16,11 @@ public final class SDKDefaultIO: @unchecked Sendable {
     /// Provide singleton access since we want to share and re-use the instance properties
     public static let shared = SDKDefaultIO()
 
-    /// The setter for changing log level of SDKDefaultIO logger.
-    /// If any log level other than the default log level of `.none` is desired,
-    /// this setter needs to be called as the first thing in the program.
+    /// The public setter for setting log level of CRT logger.
+    ///
+    /// If any log level other than the default log level of `.none` is desired, this setter **MUST** be called before accessing the `SDKDefaultIO.shared` static field.
     public static func setLogLevel(level: LogLevel) {
-        do {
-            try Logger.initialize(target: .standardOutput, level: level)
-        } catch {
-            failOnLogger()
-        }
+        SDKDefaultIO.setupLogger(level: level)
     }
 
     private init() {

Sources/ClientRuntime/Telemetry/Logging/ClientLogMode.swift

@@ -5,6 +5,7 @@
 // SPDX-License-Identifier: Apache-2.0
 //
 
+/// Additional logging opt-in for request / response flow. For each selected option other than `.none`, the additional info gets logged at `.debug` level by the `LoggingMiddleware`.
 public enum ClientLogMode {
     case none
     case request

Sources/ClientRuntime/Telemetry/Logging/LogLevel+StringExtension.swift

@@ -5,6 +5,7 @@
 
 import AwsCommonRuntimeKit
 
+/// Extension for CRT's LogLevel enum
 extension LogLevel {
     public var stringValue: String {
         switch self {

Sources/ClientRuntime/Telemetry/Logging/SDKLogHandlerFactory.swift

@@ -7,6 +7,7 @@
 
 import Logging
 
+/// Implement this protocol and add an instance of the implementation to `SDKLoggingSystem` to use custom log handlers.
 public protocol SDKLogHandlerFactory {
     var label: String { get }
     func construct(label: String) -> LogHandler

Sources/ClientRuntime/Telemetry/Logging/SDKLogLevel.swift

@@ -7,6 +7,7 @@
 
 import Logging
 
+/// Wrapper for Logger.Level; used by SDKLoggingSystem.
 public enum SDKLogLevel: String, Codable, CaseIterable {
     case trace
     case debug

Sources/ClientRuntime/Telemetry/Logging/SDKLoggingSystem.swift

@@ -7,22 +7,35 @@
 
 import Logging
 
+/// Use this to turn SDK logging on.
 public actor SDKLoggingSystem {
     private var isInitialized = false
-    private var factories: [String: SDKLogHandlerFactory] = [:]
+    private var logHandlerFactories: [String: SDKLogHandlerFactory] = [:]
 
     public init() {}
 
+    /// Adds custom log handler factory to `this.logHandlerFactories`.
+    ///
+    /// The added log handler factory will be dedicated log handler for any logger with identical label.
     public func add(logHandlerFactory: SDKLogHandlerFactory) {
-        let label = logHandlerFactory.label
-        factories[label] = logHandlerFactory
+        logHandlerFactories[logHandlerFactory.label] = logHandlerFactory
     }
 
+    /// Initializes the logging handler factory for the SDK.
+    /// The default behavior is to log messages at `.error` or more severe levels.
+    ///
+    /// The handler factory closure first checks if there exists a custom handler factory in `this.logHandlerFactories` with the same label as the label given to logger initializer. If it exists, then that factory gets used to create the log handler.
+    ///
+    /// If no custom handler factory is found for the given label, the factory closure creates and returns a `StreamLogHandler` with minimum log level set to `logLevel`.
+    ///
+    /// Loggers output log only if the log level of the message is equal to or more severe than the underlying log handler's log level. E.g., `logger.info(...)` executes only if the underlying log handler's log level is `.info`, `.debug`, or `.trace`. It does not execute if the underlying log handler's minimum log level is any one of the following levels that are more severe than `.info`: `.notice`, `.warning`, `error`, `critical`.
+    ///
+    /// - parameters:
+    ///     - logLevel: The minimum log level to use for the log handler if no custom log handler factory was found. Default is `.error`.
     public func initialize(defaultLogLevel: SDKLogLevel = .error) async {
         if isInitialized { return } else { isInitialized = true }
-        let ptr = factories
-        LoggingSystem.bootstrap { label in
-            if let factory = ptr[label] {
+        LoggingSystem.bootstrap { [logHandlerFactories] label in
+            if let factory = logHandlerFactories[label] {
                 return factory.construct(label: label)
             }
             var handler = StreamLogHandler.standardOutput(label: label)
@@ -32,11 +45,6 @@ public actor SDKLoggingSystem {
     }
 
     public func initialize(logLevel: SDKLogLevel) async {
-        if isInitialized { return } else { isInitialized = true }
-        LoggingSystem.bootstrap { label in
-            var handler = StreamLogHandler.standardOutput(label: label)
-            handler.logLevel = logLevel.toLoggerType()
-            return handler
-        }
+        await self.initialize(defaultLogLevel: logLevel)
     }
 }

Sources/Smithy/Logging/LogAgent.swift

@@ -9,9 +9,6 @@ public protocol LogAgent {
     /// name of the struct or class where the logger was instantiated from
     var name: String { get }
 
-    /// Get or set the configured log level.
-    var level: LogAgentLevel { get set }
-
     /// This method is called when a `LogAgent` must emit a log message.
     ///
     /// - parameters:
@@ -31,76 +28,114 @@ public protocol LogAgent {
              line: UInt)
 }
 
-public enum LogAgentLevel: String, Codable, CaseIterable {
-    case trace
-    case debug
-    case info
-    case warn
-    case error
-    case fatal
-}
-
+/// Convenience wrapper functions that call `self.log()` with corresponding log level.
 public extension LogAgent {
+    /// Use for messages that are typically seen during tracing.
+    func trace(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .trace,
+                 message: message(),
+                 metadata: nil,
+                 source: currentModule(fileID: file),
+                 file: file,
+                 function: function,
+                 line: line)
+    }
 
-    /// Log a message passing with the `.info` log level.
-    func info(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
-        self.log(level: .info,
-                 message: message,
+    /// Use for messages that are typically seen during debugging.
+    func debug(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .debug,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,
                  function: function,
                  line: line)
     }
 
-    /// Log a message passing with the `LogLevel.warn` log level.
-    func warn(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
-        self.log(level: .warn,
-                 message: message,
+    /// Use for informational messages.
+    func info(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .info,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,
                  function: function,
                  line: line)
     }
 
-    /// Log a message passing with the `.debug` log level.
-    func debug(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
-        self.log(level: .debug,
-                 message: message,
+    /// Use for non-error messages that may need special attention.
+    func notice(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .notice,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,
                  function: function,
                  line: line)
     }
 
-    /// Log a message passing with the `.error` log level.
-    func error(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
-        self.log(level: .error,
-                 message: message,
+    /// Use for non-error messages that are more severe than `.notice`.
+    func warn(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .warn,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,
                  function: function,
                  line: line)
     }
 
-    /// Log a message passing with the `.trace` log level.
-    func trace(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
-        self.log(level: .trace,
-                 message: message,
+    /// Use for errors.
+    func error(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
+        self.log(level: .error,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,
                  function: function,
                  line: line)
     }
 
-    /// Log a message passing with the `.fatal` log level.
-    func fatal(_ message: String, file: String = #fileID, function: String = #function, line: UInt = #line) {
+    /// Appropriate for critical error conditions that usually require immediate
+    /// attention.
+    func fatal(
+        _ message: @autoclosure() -> String,
+        file: String = #fileID,
+        function: String = #function,
+        line: UInt = #line
+    ) {
         self.log(level: .fatal,
-                 message: message,
+                 message: message(),
                  metadata: nil,
                  source: currentModule(fileID: file),
                  file: file,

Sources/Smithy/Logging/LogAgentLevel.swift

@@ -0,0 +1,38 @@
+//
+// Copyright Amazon.com Inc. or its affiliates.
+// All Rights Reserved.
+//
+// SPDX-License-Identifier: Apache-2.0
+//
+
+import Logging
+
+/// Wrapper for Logger.Level; used by LogAgent and SwiftLogger.
+public enum LogAgentLevel: String, Codable, CaseIterable {
+    case trace
+    case debug
+    case info
+    case notice
+    case warn
+    case error
+    case fatal
+
+    func toLoggerLevel() -> Logger.Level {
+        switch self {
+        case .trace:
+            return .trace
+        case .debug:
+            return .debug
+        case .info:
+            return .info
+        case .notice:
+            return .notice
+        case .warn:
+            return .warning
+        case .error:
+            return .error
+        case .fatal:
+            return .critical
+        }
+    }
+}

Sources/Smithy/Logging/SwiftLog+LogAgent.swift

@@ -8,27 +8,22 @@
 import Logging
 
 public struct SwiftLogger: LogAgent {
-    public var level: LogAgentLevel
-
     private let logger: Logger
     private let label: String
 
     public init(label: String) {
         self.label = label
         self.logger = Logger(label: label)
-        self.level = LogAgentLevel.info
     }
 
+    @available(*, deprecated, message: "This API is deprecated. Use init(label:) instead.")
     public init(label: String, logLevel: LogAgentLevel) {
-        self.label = label
-        self.logger = Logger(label: label)
-        self.level = logLevel
+        self.init(label: label)
     }
 
     // This initializer is currently only used in tests, to inject a mock LogHandler.
-    init(label: String, logLevel: LogAgentLevel, factory: (String) -> any LogHandler) {
+    init(label: String, factory: (String) -> any LogHandler) {
         self.label = label
-        self.level = logLevel
         self.logger = Logger(label: label, factory: factory)
     }
 
@@ -56,23 +51,3 @@ public struct SwiftLogger: LogAgent {
         )
     }
 }
-
-extension LogAgentLevel {
-
-    func toLoggerLevel() -> Logger.Level {
-        switch self {
-        case .trace:
-            return .trace
-        case .debug:
-            return .debug
-        case .info:
-            return .info
-        case .warn:
-            return .warning
-        case .error:
-            return .error
-        case .fatal:
-            return .critical
-        }
-    }
-}

Tests/ClientRuntimeTests/LoggingTests/SwiftLoggerTests.swift

@@ -38,7 +38,7 @@ final class SwiftLoggerTests: XCTestCase {
 
     private func logsLeveledMessage(
         logLevel: Logger.Level,
-        loggerBlock: (SwiftLogger) -> (String, String, String, UInt) -> Void,
+        loggerBlock: (SwiftLogger) -> (@autoclosure() -> String, String, String, UInt) -> Void,
         testFile: StaticString = #filePath,
         testLine: UInt = #line
     ) throws {
@@ -53,7 +53,7 @@ final class SwiftLoggerTests: XCTestCase {
         // Create a TestLogHandler, then create a SwiftLogger (the test subject)
         // with it.
         var logHandler: TestLogHandler!
-        let subject = SwiftLogger(label: "Test", logLevel: .trace, factory: { label in
+        let subject = SwiftLogger(label: "Test", factory: { label in
             logHandler = TestLogHandler(label: label)
             return logHandler
         })

Tests/ClientRuntimeTests/NetworkingTests/URLSession/FoundationStreamBridgeTests.swift

@@ -109,12 +109,9 @@ private class TestLogger: LogAgent {
 
     var messages: [(level: LogAgentLevel, message: String)] = []
 
-    var level: LogAgentLevel
-
     init(name: String = "Test", messages: [(level: LogAgentLevel, message: String)] = [], level: LogAgentLevel = .info) {
         self.name = name
         self.messages = messages
-        self.level = level
     }
 
     func log(level: LogAgentLevel = .info, message: @autoclosure () -> String, metadata: @autoclosure () -> [String : String]? = nil, source: @autoclosure () -> String = "ChecksumUnitTests", file: String = #file, function: String = #function, line: UInt = #line) {