diff --git a/Package.swift b/Package.swift index 840a20d59..aad0c1c53 100644 --- a/Package.swift +++ b/Package.swift @@ -40,7 +40,7 @@ let package = Package( .package(url: "https://github.com/apple/swift-nio-http2.git", from: "1.36.0"), .package(url: "https://github.com/apple/swift-nio-extras.git", from: "1.26.0"), .package(url: "https://github.com/apple/swift-nio-transport-services.git", from: "1.24.0"), - .package(url: "https://github.com/apple/swift-log.git", from: "1.6.0"), + .package(url: "https://github.com/apple/swift-log.git", from: "1.7.1"), .package(url: "https://github.com/apple/swift-atomics.git", from: "1.0.2"), .package(url: "https://github.com/apple/swift-algorithms.git", from: "1.0.0"), .package(url: "https://github.com/apple/swift-distributed-tracing.git", from: "1.3.0"), @@ -92,6 +92,7 @@ let package = Package( .product(name: "Algorithms", package: "swift-algorithms"), // Observability support .product(name: "Logging", package: "swift-log"), + .product(name: "InMemoryLogging", package: "swift-log"), .product(name: "Tracing", package: "swift-distributed-tracing"), .product(name: "InMemoryTracing", package: "swift-distributed-tracing"), ], diff --git a/Tests/AsyncHTTPClientTests/HTTPClient+SOCKSTests.swift b/Tests/AsyncHTTPClientTests/HTTPClient+SOCKSTests.swift index af32284b0..d5e1c895b 100644 --- a/Tests/AsyncHTTPClientTests/HTTPClient+SOCKSTests.swift +++ b/Tests/AsyncHTTPClientTests/HTTPClient+SOCKSTests.swift @@ -13,6 +13,7 @@ //===----------------------------------------------------------------------===// import AsyncHTTPClient // NOT @testable - tests that need @testable go into HTTPClientInternalTests.swift +import InMemoryLogging import Logging import NIOCore import NIOHTTP1 @@ -27,7 +28,7 @@ class HTTPClientSOCKSTests: XCTestCase { var serverGroup: EventLoopGroup! var defaultHTTPBin: HTTPBin! var defaultClient: HTTPClient! - var backgroundLogStore: CollectEverythingLogHandler.LogStore! + var backgroundLogStore: InMemoryLogHandler! var defaultHTTPBinURLPrefix: String { "http://localhost:\(self.defaultHTTPBin.port)/" @@ -43,14 +44,8 @@ class HTTPClientSOCKSTests: XCTestCase { self.clientGroup = getDefaultEventLoopGroup(numberOfThreads: 1) self.serverGroup = MultiThreadedEventLoopGroup(numberOfThreads: 1) self.defaultHTTPBin = HTTPBin() - self.backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: self.backgroundLogStore!) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) + self.backgroundLogStore = backgroundLogStore self.defaultClient = HTTPClient( eventLoopGroupProvider: .shared(self.clientGroup), backgroundActivityLogger: backgroundLogger diff --git a/Tests/AsyncHTTPClientTests/HTTPClientBase.swift b/Tests/AsyncHTTPClientTests/HTTPClientBase.swift index 15620dd24..90ab12fe5 100644 --- a/Tests/AsyncHTTPClientTests/HTTPClientBase.swift +++ b/Tests/AsyncHTTPClientTests/HTTPClientBase.swift @@ -14,6 +14,7 @@ import AsyncHTTPClient import Atomics +import InMemoryLogging import Logging import NIOConcurrencyHelpers import NIOCore @@ -37,7 +38,7 @@ class XCTestCaseHTTPClientTestsBaseClass: XCTestCase { var serverGroup: EventLoopGroup! var defaultHTTPBin: HTTPBin! var defaultClient: HTTPClient! - var backgroundLogStore: CollectEverythingLogHandler.LogStore! + var backgroundLogStore: InMemoryLogHandler! var defaultHTTPBinURLPrefix: String { self.defaultHTTPBin.baseURL @@ -53,14 +54,8 @@ class XCTestCaseHTTPClientTestsBaseClass: XCTestCase { self.clientGroup = getDefaultEventLoopGroup(numberOfThreads: 1) self.serverGroup = MultiThreadedEventLoopGroup(numberOfThreads: 1) self.defaultHTTPBin = HTTPBin() - self.backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: self.backgroundLogStore!) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) + self.backgroundLogStore = backgroundLogStore self.defaultClient = HTTPClient( eventLoopGroupProvider: .shared(self.clientGroup), diff --git a/Tests/AsyncHTTPClientTests/HTTPClientTestUtils.swift b/Tests/AsyncHTTPClientTests/HTTPClientTestUtils.swift index 093dc8a6a..689b4358e 100644 --- a/Tests/AsyncHTTPClientTests/HTTPClientTestUtils.swift +++ b/Tests/AsyncHTTPClientTests/HTTPClientTestUtils.swift @@ -14,6 +14,7 @@ import Atomics import Foundation +import InMemoryLogging import Logging import NIOConcurrencyHelpers import NIOCore @@ -1290,65 +1291,21 @@ extension EventLoopFuture where Value: Sendable { } } -struct CollectEverythingLogHandler: LogHandler { - var metadata: Logger.Metadata = [:] - var logLevel: Logger.Level = .info - let logStore: LogStore - - final class LogStore: Sendable { - struct Entry { - var level: Logger.Level - var message: String - var metadata: [String: String] - } - - private let logs = NIOLockedValueBox<[Entry]>([]) - - var allEntries: [Entry] { - get { - self.logs.withLockedValue { $0 } - } - set { - self.logs.withLockedValue { $0 = newValue } +extension InMemoryLogHandler { + static func makeLogger( + logLevel: Logger.Level = .info, + function: String = #function + ) -> (InMemoryLogHandler, Logger) { + let handler = InMemoryLogHandler() + + var logger = Logger( + label: "\(function)", + factory: { _ in + handler } - } - - func append(level: Logger.Level, message: Logger.Message, metadata: Logger.Metadata?) { - self.logs.withLockedValue { - $0.append( - Entry( - level: level, - message: message.description, - metadata: metadata?.mapValues { $0.description } ?? [:] - ) - ) - } - } - } - - init(logStore: LogStore) { - self.logStore = logStore - } - - func log( - level: Logger.Level, - message: Logger.Message, - metadata: Logger.Metadata?, - source: String, - file: String, - function: String, - line: UInt - ) { - self.logStore.append(level: level, message: message, metadata: self.metadata.merging(metadata ?? [:]) { $1 }) - } - - subscript(metadataKey key: String) -> Logger.Metadata.Value? { - get { - self.metadata[key] - } - set { - self.metadata[key] = newValue - } + ) + logger.logLevel = logLevel + return (handler, logger) } } diff --git a/Tests/AsyncHTTPClientTests/HTTPClientTests.swift b/Tests/AsyncHTTPClientTests/HTTPClientTests.swift index bc8feb853..054cf3487 100644 --- a/Tests/AsyncHTTPClientTests/HTTPClientTests.swift +++ b/Tests/AsyncHTTPClientTests/HTTPClientTests.swift @@ -14,6 +14,7 @@ import AsyncHTTPClient // NOT @testable - tests that need @testable go into HTTPClientInternalTests.swift import Atomics +import InMemoryLogging import Logging import NIOConcurrencyHelpers import NIOCore @@ -2751,15 +2752,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { } func testLoggingCorrectlyAttachesRequestInformationEvenAfterDuringRedirect() { - let logStore = CollectEverythingLogHandler.LogStore() - - var logger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: logStore) - } - ) - logger.logLevel = .trace + var (logStore, logger) = InMemoryLogHandler.makeLogger(logLevel: .trace) logger[metadataKey: "custom-request-id"] = "abcd" var maybeRequest: HTTPClient.Request? @@ -2782,7 +2775,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - let logs = logStore.allEntries + let logs = logStore.entries XCTAssertTrue(logs.allSatisfy { $0.metadata["custom-request-id"] == "abcd" }) @@ -2804,12 +2797,12 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { } func testLoggingCorrectlyAttachesRequestInformation() { - let logStore = CollectEverythingLogHandler.LogStore() + let logStore = InMemoryLogHandler() var loggerYolo001 = Logger( label: "\(#function)", factory: { _ in - CollectEverythingLogHandler(logStore: logStore) + logStore } ) loggerYolo001.logLevel = .trace @@ -2817,7 +2810,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { var loggerACME002 = Logger( label: "\(#function)", factory: { _ in - CollectEverythingLogHandler(logStore: logStore) + logStore } ) loggerACME002.logLevel = .trace @@ -2840,8 +2833,8 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: loggerYolo001 ).wait() ) - let logsAfterReq1 = logStore.allEntries - logStore.allEntries = [] + let logsAfterReq1 = logStore.entries + logStore.clear() // === Request 2 (Yolo001) XCTAssertNoThrow( @@ -2852,8 +2845,8 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: loggerYolo001 ).wait() ) - let logsAfterReq2 = logStore.allEntries - logStore.allEntries = [] + let logsAfterReq2 = logStore.entries + logStore.clear() // === Request 3 (ACME002) XCTAssertNoThrow( @@ -2864,8 +2857,8 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: loggerACME002 ).wait() ) - let logsAfterReq3 = logStore.allEntries - logStore.allEntries = [] + let logsAfterReq3 = logStore.entries + logStore.clear() // === Assertions XCTAssertGreaterThan(logsAfterReq1.count, 0) @@ -2879,7 +2872,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { { XCTAssertNil(entry.metadata["acme-request-id"]) XCTAssertEqual("yolo-001", yoloRequestID) - XCTAssertNotNil(Int(httpRequestMetadata)) + XCTAssertNotNil(Int("\(httpRequestMetadata)")) return true } else { XCTFail("log message doesn't contain the right IDs: \(entry)") @@ -2912,7 +2905,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { { XCTAssertNil(entry.metadata["acme-request-id"]) XCTAssertEqual("yolo-001", yoloRequestID) - XCTAssertNotNil(Int(httpRequestMetadata)) + XCTAssertNotNil(Int("\(httpRequestMetadata)")) return true } else { XCTFail("log message doesn't contain the right IDs: \(entry)") @@ -2940,7 +2933,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { { XCTAssertNil(entry.metadata["yolo-request-id"]) XCTAssertEqual("acme-002", acmeRequestID) - XCTAssertNotNil(Int(httpRequestMetadata)) + XCTAssertNotNil(Int("\(httpRequestMetadata)")) return true } else { XCTFail("log message doesn't contain the right IDs: \(entry)") @@ -2963,15 +2956,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { } func testNothingIsLoggedAtInfoOrHigher() { - let logStore = CollectEverythingLogHandler.LogStore() - - var logger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: logStore) - } - ) - logger.logLevel = .info + let (logStore, logger) = InMemoryLogHandler.makeLogger(logLevel: .info) guard let request1 = try? HTTPClient.Request(url: self.defaultHTTPBinURLPrefix + "get"), let request2 = try? HTTPClient.Request(url: self.defaultHTTPBinURLPrefix + "stats") @@ -2989,7 +2974,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - XCTAssertEqual(0, logStore.allEntries.count) + XCTAssertEqual(0, logStore.entries.count) // === Request 2 XCTAssertNoThrow( @@ -3000,7 +2985,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - XCTAssertEqual(0, logStore.allEntries.count) + XCTAssertEqual(0, logStore.entries.count) // === Synthesized Request XCTAssertNoThrow( @@ -3012,21 +2997,14 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - XCTAssertEqual(0, logStore.allEntries.count) + XCTAssertEqual(0, logStore.entries.count) - XCTAssertEqual(0, self.backgroundLogStore.allEntries.filter { $0.level >= .info }.count) + XCTAssertEqual(0, self.backgroundLogStore.entries.filter { $0.level >= .info }.count) // === Synthesized Socket Path Request XCTAssertNoThrow( try TemporaryFileHelpers.withTemporaryUnixDomainSocketPathName { path in - let backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: backgroundLogStore) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) let localSocketPathHTTPBin = HTTPBin(bindTarget: .unixDomainSocket(path)) let localClient = HTTPClient( @@ -3048,23 +3026,16 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - XCTAssertEqual(0, logStore.allEntries.count) + XCTAssertEqual(0, logStore.entries.count) - XCTAssertEqual(0, backgroundLogStore.allEntries.filter { $0.level >= .info }.count) + XCTAssertEqual(0, backgroundLogStore.entries.filter { $0.level >= .info }.count) } ) // === Synthesized Secure Socket Path Request XCTAssertNoThrow( try TemporaryFileHelpers.withTemporaryUnixDomainSocketPathName { path in - let backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: backgroundLogStore) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) let localSocketPathHTTPBin = HTTPBin(.http1_1(ssl: true), bindTarget: .unixDomainSocket(path)) let localClient = HTTPClient( @@ -3087,33 +3058,25 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { logger: logger ).wait() ) - XCTAssertEqual(0, logStore.allEntries.count) + XCTAssertEqual(0, logStore.entries.count) - XCTAssertEqual(0, backgroundLogStore.allEntries.filter { $0.level >= .info }.count) + XCTAssertEqual(0, backgroundLogStore.entries.filter { $0.level >= .info }.count) } ) } func testAllMethodsLog() { func checkExpectationsWithLogger(type: String, _ body: (Logger, String) throws -> T) throws -> T { - let logStore = CollectEverythingLogHandler.LogStore() - - var logger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: logStore) - } - ) - logger.logLevel = .trace + var (logStore, logger) = InMemoryLogHandler.makeLogger(logLevel: .trace) logger[metadataKey: "req"] = "yo-\(type)" let url = "not-found/request/\(type))" let result = try body(logger, url) - XCTAssertGreaterThan(logStore.allEntries.count, 0) - for entry in logStore.allEntries { + XCTAssertGreaterThan(logStore.entries.count, 0) + for entry in logStore.entries { XCTAssertEqual("yo-\(type)", entry.metadata["req"] ?? "n/a") - XCTAssertNotNil(Int(entry.metadata["ahc-request-id"] ?? "n/a")) + XCTAssertNotNil(Int(entry.metadata["ahc-request-id"]?.description ?? "n/a")) } return result } @@ -3162,18 +3125,11 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { ) // No background activity expected here. - XCTAssertEqual(0, self.backgroundLogStore.allEntries.filter { $0.level >= .debug }.count) + XCTAssertEqual(0, self.backgroundLogStore.entries.filter { $0.level >= .debug }.count) XCTAssertNoThrow( try TemporaryFileHelpers.withTemporaryUnixDomainSocketPathName { path in - let backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: backgroundLogStore) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) let localSocketPathHTTPBin = HTTPBin(bindTarget: .unixDomainSocket(path)) let localClient = HTTPClient( @@ -3193,20 +3149,13 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { ) // No background activity expected here. - XCTAssertEqual(0, backgroundLogStore.allEntries.filter { $0.level >= .debug }.count) + XCTAssertEqual(0, backgroundLogStore.entries.filter { $0.level >= .debug }.count) } ) XCTAssertNoThrow( try TemporaryFileHelpers.withTemporaryUnixDomainSocketPathName { path in - let backgroundLogStore = CollectEverythingLogHandler.LogStore() - var backgroundLogger = Logger( - label: "\(#function)", - factory: { _ in - CollectEverythingLogHandler(logStore: backgroundLogStore) - } - ) - backgroundLogger.logLevel = .trace + let (backgroundLogStore, backgroundLogger) = InMemoryLogHandler.makeLogger(logLevel: .trace) let localSocketPathHTTPBin = HTTPBin(.http1_1(ssl: true), bindTarget: .unixDomainSocket(path)) let localClient = HTTPClient( @@ -3227,7 +3176,7 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { ) // No background activity expected here. - XCTAssertEqual(0, backgroundLogStore.allEntries.filter { $0.level >= .debug }.count) + XCTAssertEqual(0, backgroundLogStore.entries.filter { $0.level >= .debug }.count) } ) } @@ -3237,14 +3186,14 @@ final class HTTPClientTests: XCTestCaseHTTPClientTestsBaseClass { XCTAssertNoThrow(try self.defaultClient.syncShutdown()) - XCTAssertGreaterThanOrEqual(self.backgroundLogStore.allEntries.count, 0) + XCTAssertGreaterThanOrEqual(self.backgroundLogStore.entries.count, 0) XCTAssert( - self.backgroundLogStore.allEntries.contains { entry in + self.backgroundLogStore.entries.contains { entry in entry.message == "Shutting down connection pool" } ) XCTAssert( - self.backgroundLogStore.allEntries.allSatisfy { entry in + self.backgroundLogStore.entries.allSatisfy { entry in entry.metadata["ahc-request-id"] == nil && entry.metadata["ahc-request"] == nil && entry.metadata["ahc-pool-key"] != nil }