Skip to content

Commit e6ca651

Browse files
ktososlashmoyim-lee
authoredJan 18, 2023
Metadata Providers (e.g. for Distributed Tracing) in LogHandlers (#238)
Co-authored-by: Moritz Lang <[email protected]> Co-authored-by: Yim Lee <[email protected]>
·
1.6.31.5.0
1 parent dc77805 commit e6ca651

10 files changed

+950
-33
lines changed
 

‎Sources/Logging/LogHandler.swift

+19
Original file line numberDiff line numberDiff line change
@@ -114,6 +114,12 @@
114114
/// level has not been overridden. And most importantly it passes the requirement listed above: A change to the log
115115
/// level on one `Logger` should not affect the log level of another `Logger` variable.
116116
public protocol LogHandler: _SwiftLogSendableLogHandler {
117+
/// The metadata provider this `LogHandler` will use when a log statement is about to be emitted.
118+
///
119+
/// A ``Logger/MetadataProvider`` may add a constant set of metadata,
120+
/// or use task-local values to pick up contextual metadata and add it to emitted logs.
121+
var metadataProvider: Logger.MetadataProvider? { get set }
122+
117123
/// This method is called when a `LogHandler` must emit a log message. There is no need for the `LogHandler` to
118124
/// check if the `level` is above or below the configured `logLevel` as `Logger` already performed this check and
119125
/// determined that a message should be logged.
@@ -163,6 +169,19 @@ public protocol LogHandler: _SwiftLogSendableLogHandler {
163169
var logLevel: Logger.Level { get set }
164170
}
165171

172+
extension LogHandler {
173+
/// Default implementation for `metadataProvider` which defaults to `nil`.
174+
/// This default exists in order to facilitate source-compatible introduction of the `metadataProvider` protocol requirement.
175+
public var metadataProvider: Logger.MetadataProvider? {
176+
get {
177+
nil
178+
}
179+
set {
180+
self.log(level: .warning, message: "Attempted to set metadataProvider on \(Self.self) that did not implement support for them. Please contact the log handler maintainer to implement metadata provider support.", metadata: nil, source: "Logging", file: #file, function: #function, line: #line)
181+
}
182+
}
183+
}
184+
166185
extension LogHandler {
167186
@available(*, deprecated, message: "You should implement this method instead of using the default implementation")
168187
public func log(level: Logger.Level,

‎Sources/Logging/Logging.swift

+172-20
Original file line numberDiff line numberDiff line change
@@ -43,6 +43,11 @@ public struct Logger {
4343
/// An identifier of the creator of this `Logger`.
4444
public let label: String
4545

46+
/// The metadata provider this logger was created with.
47+
public var metadataProvider: Logger.MetadataProvider? {
48+
return self.handler.metadataProvider
49+
}
50+
4651
internal init(label: String, _ handler: LogHandler) {
4752
self.label = label
4853
self.handler = handler
@@ -264,6 +269,7 @@ extension Logger {
264269
}
265270

266271
#else
272+
@inlinable
267273
public func debug(_ message: @autoclosure () -> Logger.Message,
268274
metadata: @autoclosure () -> Logger.Metadata? = nil,
269275
source: @autoclosure () -> String? = nil,
@@ -435,6 +441,7 @@ extension Logger {
435441
}
436442

437443
#else
444+
@inlinable
438445
public func notice(_ message: @autoclosure () -> Logger.Message,
439446
metadata: @autoclosure () -> Logger.Metadata? = nil,
440447
file: String = #file, function: String = #function, line: UInt = #line) {
@@ -653,7 +660,8 @@ extension Logger {
653660
/// configured. `LoggingSystem` is set up just once in a given program to set up the desired logging backend
654661
/// implementation.
655662
public enum LoggingSystem {
656-
private static let _factory = FactoryBox(StreamLogHandler.standardOutput)
663+
private static let _factory = FactoryBox { label, _ in StreamLogHandler.standardOutput(label: label) }
664+
private static let _metadataProviderFactory = MetadataProviderBox(nil)
657665

658666
/// `bootstrap` is a one-time configuration function which globally selects the desired logging backend
659667
/// implementation. `bootstrap` can be called at maximum once in any given program, calling it more than once will
@@ -662,36 +670,106 @@ public enum LoggingSystem {
662670
/// - parameters:
663671
/// - factory: A closure that given a `Logger` identifier, produces an instance of the `LogHandler`.
664672
public static func bootstrap(_ factory: @escaping (String) -> LogHandler) {
673+
self._factory.replaceFactory({ label, _ in
674+
factory(label)
675+
}, validate: true)
676+
}
677+
678+
/// `bootstrap` is a one-time configuration function which globally selects the desired logging backend
679+
/// implementation.
680+
///
681+
/// - Warning:
682+
/// `bootstrap` can be called at maximum once in any given program, calling it more than once will
683+
/// lead to undefined behavior, most likely a crash.
684+
///
685+
/// - parameters:
686+
/// - metadataProvider: The `MetadataProvider` used to inject runtime-generated metadata from the execution context.
687+
/// - factory: A closure that given a `Logger` identifier, produces an instance of the `LogHandler`.
688+
public static func bootstrap(_ factory: @escaping (String, Logger.MetadataProvider?) -> LogHandler,
689+
metadataProvider: Logger.MetadataProvider?) {
690+
self._metadataProviderFactory.replaceMetadataProvider(metadataProvider, validate: true)
665691
self._factory.replaceFactory(factory, validate: true)
666692
}
667693

668-
// for our testing we want to allow multiple bootstraping
694+
// for our testing we want to allow multiple bootstrapping
669695
internal static func bootstrapInternal(_ factory: @escaping (String) -> LogHandler) {
696+
self._metadataProviderFactory.replaceMetadataProvider(nil, validate: false)
697+
self._factory.replaceFactory({ label, _ in
698+
factory(label)
699+
}, validate: false)
700+
}
701+
702+
// for our testing we want to allow multiple bootstrapping
703+
internal static func bootstrapInternal(_ factory: @escaping (String, Logger.MetadataProvider?) -> LogHandler,
704+
metadataProvider: Logger.MetadataProvider?) {
705+
self._metadataProviderFactory.replaceMetadataProvider(metadataProvider, validate: false)
670706
self._factory.replaceFactory(factory, validate: false)
671707
}
672708

673-
fileprivate static var factory: (String) -> LogHandler {
674-
return self._factory.underlying
709+
fileprivate static var factory: (String, Logger.MetadataProvider?) -> LogHandler {
710+
return { label, metadataProvider in
711+
var handler = self._factory.underlying(label, metadataProvider)
712+
handler.metadataProvider = metadataProvider
713+
return handler
714+
}
715+
}
716+
717+
/// System wide ``Logger/MetadataProvider`` that was configured during the logging system's `bootstrap`.
718+
///
719+
/// When creating a ``Logger`` using the plain ``Logger/init(label:)`` initializer, this metadata provider
720+
/// will be provided to it.
721+
///
722+
/// When using custom log handler factories, make sure to provide the bootstrapped metadata provider to them,
723+
/// or the metadata will not be filled in automatically using the provider on log-sites. While using a custom
724+
/// factory to avoid using the bootstrapped metadata provider may sometimes be useful, usually it will lead to
725+
/// un-expected behavior, so make sure to always propagate it to your handlers.
726+
public static var metadataProvider: Logger.MetadataProvider? {
727+
return self._metadataProviderFactory.metadataProvider
675728
}
676729

677730
private final class FactoryBox {
678731
private let lock = ReadWriteLock()
679-
fileprivate var _underlying: (String) -> LogHandler
732+
fileprivate var _underlying: (_ label: String, _ provider: Logger.MetadataProvider?) -> LogHandler
680733
private var initialized = false
681734

682-
init(_ underlying: @escaping (String) -> LogHandler) {
735+
init(_ underlying: @escaping (String, Logger.MetadataProvider?) -> LogHandler) {
683736
self._underlying = underlying
684737
}
685738

686-
func replaceFactory(_ factory: @escaping (String) -> LogHandler, validate: Bool) {
739+
func replaceFactory(_ factory: @escaping (String, Logger.MetadataProvider?) -> LogHandler, validate: Bool) {
687740
self.lock.withWriterLock {
688741
precondition(!validate || !self.initialized, "logging system can only be initialized once per process.")
689742
self._underlying = factory
690743
self.initialized = true
691744
}
692745
}
693746

694-
var underlying: (String) -> LogHandler {
747+
var underlying: (String, Logger.MetadataProvider?) -> LogHandler {
748+
return self.lock.withReaderLock {
749+
return self._underlying
750+
}
751+
}
752+
}
753+
754+
private final class MetadataProviderBox {
755+
private let lock = ReadWriteLock()
756+
757+
internal var _underlying: Logger.MetadataProvider?
758+
private var initialized = false
759+
760+
init(_ underlying: Logger.MetadataProvider?) {
761+
self._underlying = underlying
762+
}
763+
764+
func replaceMetadataProvider(_ metadataProvider: Logger.MetadataProvider?, validate: Bool) {
765+
self.lock.withWriterLock {
766+
precondition(!validate || !self.initialized, "logging system can only be initialized once per process.")
767+
self._underlying = metadataProvider
768+
self.initialized = true
769+
}
770+
}
771+
772+
var metadataProvider: Logger.MetadataProvider? {
695773
return self.lock.withReaderLock {
696774
return self._underlying
697775
}
@@ -786,7 +864,7 @@ extension Logger {
786864
/// - parameters:
787865
/// - label: An identifier for the creator of a `Logger`.
788866
public init(label: String) {
789-
self.init(label: label, LoggingSystem.factory(label))
867+
self.init(label: label, LoggingSystem.factory(label, LoggingSystem.metadataProvider))
790868
}
791869

792870
/// Construct a `Logger` given a `label` identifying the creator of the `Logger` or a non-standard `LogHandler`.
@@ -803,6 +881,39 @@ extension Logger {
803881
public init(label: String, factory: (String) -> LogHandler) {
804882
self = Logger(label: label, factory(label))
805883
}
884+
885+
/// Construct a `Logger` given a `label` identifying the creator of the `Logger` or a non-standard `LogHandler`.
886+
///
887+
/// The `label` should identify the creator of the `Logger`. This can be an application, a sub-system, or even
888+
/// a datatype.
889+
///
890+
/// This initializer provides an escape hatch in case the global default logging backend implementation (set up
891+
/// using `LoggingSystem.bootstrap` is not appropriate for this particular logger.
892+
///
893+
/// - parameters:
894+
/// - label: An identifier for the creator of a `Logger`.
895+
/// - factory: A closure creating non-standard `LogHandler`s.
896+
public init(label: String, factory: (String, Logger.MetadataProvider?) -> LogHandler) {
897+
self = Logger(label: label, factory(label, LoggingSystem.metadataProvider))
898+
}
899+
900+
/// Construct a `Logger` given a `label` identifying the creator of the `Logger` and a non-standard ``Logger/MetadataProvider``.
901+
///
902+
/// The `label` should identify the creator of the `Logger`. This can be an application, a sub-system, or even
903+
/// a datatype.
904+
///
905+
/// This initializer provides an escape hatch in case the global default logging backend implementation (set up
906+
/// using `LoggingSystem.bootstrap` is not appropriate for this particular logger.
907+
///
908+
/// - parameters:
909+
/// - label: An identifier for the creator of a `Logger`.
910+
/// - metadataProvider: The custom metadata provider this logger should invoke,
911+
/// instead of the system wide bootstrapped one, when a log statement is about to be emitted.
912+
public init(label: String, metadataProvider: MetadataProvider) {
913+
self = Logger(label: label, factory: { label in
914+
LoggingSystem.factory(label, metadataProvider)
915+
})
916+
}
806917
}
807918

808919
extension Logger.Level {
@@ -1081,6 +1192,11 @@ let systemStdout = WASILibc.stdout!
10811192

10821193
/// `StreamLogHandler` is a simple implementation of `LogHandler` for directing
10831194
/// `Logger` output to either `stderr` or `stdout` via the factory methods.
1195+
///
1196+
/// Metadata is merged in the following order:
1197+
/// 1. Metadata set on the log handler itself is used as the base metadata.
1198+
/// 2. The handler's ``metadataProvider`` is invoked, overriding any existing keys.
1199+
/// 3. The per-log-statement metadata is merged, overriding any previously set keys.
10841200
public struct StreamLogHandler: LogHandler {
10851201
#if compiler(>=5.6)
10861202
internal typealias _SendableTextOutputStream = TextOutputStream & Sendable
@@ -1090,19 +1206,21 @@ public struct StreamLogHandler: LogHandler {
10901206

10911207
/// Factory that makes a `StreamLogHandler` to directs its output to `stdout`
10921208
public static func standardOutput(label: String) -> StreamLogHandler {
1093-
return StreamLogHandler(label: label, stream: StdioOutputStream.stdout)
1209+
return StreamLogHandler(label: label, stream: StdioOutputStream.stdout, metadataProvider: LoggingSystem.metadataProvider)
10941210
}
10951211

10961212
/// Factory that makes a `StreamLogHandler` to directs its output to `stderr`
10971213
public static func standardError(label: String) -> StreamLogHandler {
1098-
return StreamLogHandler(label: label, stream: StdioOutputStream.stderr)
1214+
return StreamLogHandler(label: label, stream: StdioOutputStream.stderr, metadataProvider: LoggingSystem.metadataProvider)
10991215
}
11001216

11011217
private let stream: _SendableTextOutputStream
11021218
private let label: String
11031219

11041220
public var logLevel: Logger.Level = .info
11051221

1222+
public var metadataProvider: Logger.MetadataProvider?
1223+
11061224
private var prettyMetadata: String?
11071225
public var metadata = Logger.Metadata() {
11081226
didSet {
@@ -1121,38 +1239,72 @@ public struct StreamLogHandler: LogHandler {
11211239

11221240
// internal for testing only
11231241
internal init(label: String, stream: _SendableTextOutputStream) {
1242+
self.init(label: label, stream: stream, metadataProvider: LoggingSystem.metadataProvider)
1243+
}
1244+
1245+
// internal for testing only
1246+
internal init(label: String, stream: _SendableTextOutputStream, metadataProvider: Logger.MetadataProvider?) {
11241247
self.label = label
11251248
self.stream = stream
1249+
self.metadataProvider = metadataProvider
11261250
}
11271251

11281252
public func log(level: Logger.Level,
11291253
message: Logger.Message,
1130-
metadata: Logger.Metadata?,
1254+
metadata explicitMetadata: Logger.Metadata?,
11311255
source: String,
11321256
file: String,
11331257
function: String,
11341258
line: UInt) {
1135-
let prettyMetadata = metadata?.isEmpty ?? true
1136-
? self.prettyMetadata
1137-
: self.prettify(self.metadata.merging(metadata!, uniquingKeysWith: { _, new in new }))
1259+
let effectiveMetadata = StreamLogHandler.prepareMetadata(base: self.metadata, provider: self.metadataProvider, explicit: explicitMetadata)
1260+
1261+
let prettyMetadata: String?
1262+
if let effectiveMetadata = effectiveMetadata {
1263+
prettyMetadata = self.prettify(effectiveMetadata)
1264+
} else {
1265+
prettyMetadata = self.prettyMetadata
1266+
}
11381267

11391268
var stream = self.stream
11401269
stream.write("\(self.timestamp()) \(level) \(self.label) :\(prettyMetadata.map { " \($0)" } ?? "") [\(source)] \(message)\n")
11411270
}
11421271

1272+
internal static func prepareMetadata(base: Logger.Metadata, provider: Logger.MetadataProvider?, explicit: Logger.Metadata?) -> Logger.Metadata? {
1273+
var metadata = base
1274+
1275+
let provided = provider?.get() ?? [:]
1276+
1277+
guard !provided.isEmpty || !((explicit ?? [:]).isEmpty) else {
1278+
// all per-log-statement values are empty
1279+
return nil
1280+
}
1281+
1282+
if !provided.isEmpty {
1283+
metadata.merge(provided, uniquingKeysWith: { _, provided in provided })
1284+
}
1285+
1286+
if let explicit = explicit, !explicit.isEmpty {
1287+
metadata.merge(explicit, uniquingKeysWith: { _, explicit in explicit })
1288+
}
1289+
1290+
return explicit
1291+
}
1292+
11431293
private func prettify(_ metadata: Logger.Metadata) -> String? {
1144-
return !metadata.isEmpty
1145-
? metadata.lazy.sorted(by: { $0.key < $1.key }).map { "\($0)=\($1)" }.joined(separator: " ")
1146-
: nil
1294+
if metadata.isEmpty {
1295+
return nil
1296+
} else {
1297+
return metadata.lazy.sorted(by: { $0.key < $1.key }).map { "\($0)=\($1)" }.joined(separator: " ")
1298+
}
11471299
}
11481300

11491301
private func timestamp() -> String {
11501302
var buffer = [Int8](repeating: 0, count: 255)
11511303
#if os(Windows)
1152-
var timestamp: __time64_t = __time64_t()
1304+
var timestamp = __time64_t()
11531305
_ = _time64(&timestamp)
11541306

1155-
var localTime: tm = tm()
1307+
var localTime = tm()
11561308
_ = _localtime64_s(&localTime, &timestamp)
11571309

11581310
_ = strftime(&buffer, buffer.count, "%Y-%m-%dT%H:%M:%S%z", &localTime)

‎Sources/Logging/MetadataProvider.swift

+113
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,113 @@
1+
//===----------------------------------------------------------------------===//
2+
//
3+
// This source file is part of the Swift Logging API open source project
4+
//
5+
// Copyright (c) 2018-2022 Apple Inc. and the Swift Logging API project authors
6+
// Licensed under Apache License v2.0
7+
//
8+
// See LICENSE.txt for license information
9+
// See CONTRIBUTORS.txt for the list of Swift Logging API project authors
10+
//
11+
// SPDX-License-Identifier: Apache-2.0
12+
//
13+
//===----------------------------------------------------------------------===//
14+
15+
#if os(macOS) || os(iOS) || os(tvOS) || os(watchOS)
16+
import Darwin
17+
#elseif os(Windows)
18+
import CRT
19+
#elseif canImport(Glibc)
20+
import Glibc
21+
#elseif canImport(WASILibc)
22+
import WASILibc
23+
#else
24+
#error("Unsupported runtime")
25+
#endif
26+
27+
#if compiler(>=5.6)
28+
@preconcurrency protocol _SwiftLogSendable: Sendable {}
29+
#else
30+
protocol _SwiftLogSendable {}
31+
#endif
32+
33+
extension Logger {
34+
/// A `MetadataProvider` is used to automatically inject runtime-generated metadata
35+
/// to all logs emitted by a logger.
36+
///
37+
/// ### Example
38+
/// A metadata provider may be used to automatically inject metadata such as
39+
/// trace IDs:
40+
///
41+
/// ```swift
42+
/// import Tracing // https://github.com/apple/swift-distributed-tracing
43+
///
44+
/// let metadataProvider = MetadataProvider {
45+
/// guard let traceID = Baggage.current?.traceID else { return nil }
46+
/// return ["traceID": "\(traceID)"]
47+
/// }
48+
/// let logger = Logger(label: "example", metadataProvider: metadataProvider)
49+
/// var baggage = Baggage.topLevel
50+
/// baggage.traceID = 42
51+
/// Baggage.withValue(baggage) {
52+
/// logger.info("hello") // automatically includes ["traceID": "42"] metadata
53+
/// }
54+
/// ```
55+
///
56+
/// We recommend referring to [swift-distributed-tracing](https://github.com/apple/swift-distributed-tracing)
57+
/// for metadata providers which make use of its tracing and metadata propagation infrastructure. It is however
58+
/// possible to make use of metadata providers independently of tracing and instruments provided by that library,
59+
/// if necessary.
60+
public struct MetadataProvider: _SwiftLogSendable {
61+
/// Provide ``Logger.Metadata`` from current context.
62+
#if swift(>=5.5) && canImport(_Concurrency) // we could instead typealias the function type, but it was requested that we avoid this for better developer experience
63+
@usableFromInline
64+
internal let _provideMetadata: @Sendable() -> Metadata
65+
#else
66+
@usableFromInline
67+
internal let _provideMetadata: () -> Metadata
68+
#endif
69+
70+
/// Create a new `MetadataProvider`.
71+
///
72+
/// - Parameter provideMetadata: A closure extracting metadata from the current execution context.
73+
#if swift(>=5.5) && canImport(_Concurrency)
74+
public init(_ provideMetadata: @escaping @Sendable() -> Metadata) {
75+
self._provideMetadata = provideMetadata
76+
}
77+
78+
#else
79+
public init(_ provideMetadata: @escaping () -> Metadata) {
80+
self._provideMetadata = provideMetadata
81+
}
82+
#endif
83+
84+
/// Invoke the metadata provider and return the generated contextual ``Logger/Metadata``.
85+
public func get() -> Metadata {
86+
return self._provideMetadata()
87+
}
88+
}
89+
}
90+
91+
extension Logger.MetadataProvider {
92+
/// A pseudo-`MetadataProvider` that can be used to merge metadata from multiple other `MetadataProvider`s.
93+
///
94+
/// ### Merging conflicting keys
95+
///
96+
/// `MetadataProvider`s are invoked left to right in the order specified in the `providers` argument.
97+
/// In case multiple providers try to add a value for the same key, the last provider "wins" and its value is being used.
98+
///
99+
/// - Parameter providers: An array of `MetadataProvider`s to delegate to. The array must not be empty.
100+
/// - Returns: A pseudo-`MetadataProvider` merging metadata from the given `MetadataProvider`s.
101+
public static func multiplex(_ providers: [Logger.MetadataProvider]) -> Logger.MetadataProvider? {
102+
assert(!providers.isEmpty, "providers MUST NOT be empty")
103+
return Logger.MetadataProvider {
104+
providers.reduce(into: [:]) { metadata, provider in
105+
let providedMetadata = provider.get()
106+
guard !providedMetadata.isEmpty else {
107+
return
108+
}
109+
metadata.merge(providedMetadata, uniquingKeysWith: { _, rhs in rhs })
110+
}
111+
}
112+
}
113+
}

‎Tests/LinuxMain.swift

+1
Original file line numberDiff line numberDiff line change
@@ -31,5 +31,6 @@ XCTMain([
3131
testCase(LocalLoggerTest.allTests),
3232
testCase(LoggingTest.allTests),
3333
testCase(MDCTest.allTests),
34+
testCase(MetadataProviderTest.allTests),
3435
])
3536
#endif

‎Tests/LoggingTests/LoggingTest+XCTest.swift

+4
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,10 @@ extension LoggingTest {
4444
("testLogsEmittedFromSubdirectoryGetCorrectModuleInNewerSwifts", testLogsEmittedFromSubdirectoryGetCorrectModuleInNewerSwifts),
4545
("testLogMessageWithStringInterpolation", testLogMessageWithStringInterpolation),
4646
("testLoggingAString", testLoggingAString),
47+
("testMultiplexMetadataProviderMergesInSpecifiedOrder", testMultiplexMetadataProviderMergesInSpecifiedOrder),
48+
("testLoggerWithoutFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider", testLoggerWithoutFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider),
49+
("testLoggerWithPredefinedLibraryMetadataProvider", testLoggerWithPredefinedLibraryMetadataProvider),
50+
("testLoggerWithFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider", testLoggerWithFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider),
4751
("testMultiplexerIsValue", testMultiplexerIsValue),
4852
("testLoggerWithGlobalOverride", testLoggerWithGlobalOverride),
4953
("testLogLevelCases", testLogLevelCases),

‎Tests/LoggingTests/LoggingTest.swift

+74-5
Original file line numberDiff line numberDiff line change
@@ -537,6 +537,69 @@ class LoggingTest: XCTestCase {
537537
testLogging.history.assertExist(level: .debug, message: "hello world!")
538538
}
539539

540+
func testMultiplexMetadataProviderMergesInSpecifiedOrder() {
541+
let logging = TestLogging()
542+
543+
let providerA = Logger.MetadataProvider { ["provider": "a", "a": "foo"] }
544+
let providerB = Logger.MetadataProvider { ["provider": "b", "b": "bar"] }
545+
let logger = Logger(label: #function,
546+
factory: { label in
547+
logging.makeWithMetadataProvider(label: label, metadataProvider: .multiplex([providerA, providerB]))
548+
})
549+
550+
logger.log(level: .info, "test", metadata: ["one-off": "42"])
551+
552+
logging.history.assertExist(level: .info,
553+
message: "test",
554+
metadata: ["provider": "b", "a": "foo", "b": "bar", "one-off": "42"])
555+
}
556+
557+
func testLoggerWithoutFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider() {
558+
let logging = TestLogging()
559+
LoggingSystem.bootstrapInternal({ label, metadataProvider in
560+
logging.makeWithMetadataProvider(label: label, metadataProvider: metadataProvider)
561+
}, metadataProvider: .init { ["provider": "42"] })
562+
563+
let logger = Logger(label: #function)
564+
565+
logger.log(level: .info, "test", metadata: ["one-off": "42"])
566+
567+
logging.history.assertExist(level: .info,
568+
message: "test",
569+
metadata: ["provider": "42", "one-off": "42"])
570+
}
571+
572+
func testLoggerWithPredefinedLibraryMetadataProvider() {
573+
let logging = TestLogging()
574+
LoggingSystem.bootstrapInternal(
575+
logging.makeWithMetadataProvider,
576+
metadataProvider: .exampleMetadataProvider
577+
)
578+
579+
let logger = Logger(label: #function)
580+
581+
logger.log(level: .info, "test", metadata: ["one-off": "42"])
582+
583+
logging.history.assertExist(level: .info,
584+
message: "test",
585+
metadata: ["example": "example-value", "one-off": "42"])
586+
}
587+
588+
func testLoggerWithFactoryOverrideDefaultsToUsingLoggingSystemMetadataProvider() {
589+
let logging = TestLogging()
590+
LoggingSystem.bootstrapInternal(logging.makeWithMetadataProvider, metadataProvider: .init { ["provider": "42"] })
591+
592+
let logger = Logger(label: #function, factory: { label in
593+
logging.makeWithMetadataProvider(label: label, metadataProvider: LoggingSystem.metadataProvider)
594+
})
595+
596+
logger.log(level: .info, "test", metadata: ["one-off": "42"])
597+
598+
logging.history.assertExist(level: .info,
599+
message: "test",
600+
metadata: ["provider": "42", "one-off": "42"])
601+
}
602+
540603
func testMultiplexerIsValue() {
541604
let multi = MultiplexLogHandler([StreamLogHandler.standardOutput(label: "x"), StreamLogHandler.standardOutput(label: "y")])
542605
LoggingSystem.bootstrapInternal { _ in
@@ -702,7 +765,7 @@ class LoggingTest: XCTestCase {
702765
func testStreamLogHandlerOutputFormat() {
703766
let interceptStream = InterceptStream()
704767
let label = "testLabel"
705-
LoggingSystem.bootstrapInternal { _ in
768+
LoggingSystem.bootstrapInternal { label in
706769
StreamLogHandler(label: label, stream: interceptStream)
707770
}
708771
let source = "testSource"
@@ -722,7 +785,7 @@ class LoggingTest: XCTestCase {
722785
func testStreamLogHandlerOutputFormatWithMetaData() {
723786
let interceptStream = InterceptStream()
724787
let label = "testLabel"
725-
LoggingSystem.bootstrapInternal { _ in
788+
LoggingSystem.bootstrapInternal { label in
726789
StreamLogHandler(label: label, stream: interceptStream)
727790
}
728791
let source = "testSource"
@@ -742,7 +805,7 @@ class LoggingTest: XCTestCase {
742805
func testStreamLogHandlerOutputFormatWithOrderedMetadata() {
743806
let interceptStream = InterceptStream()
744807
let label = "testLabel"
745-
LoggingSystem.bootstrapInternal { _ in
808+
LoggingSystem.bootstrapInternal { label in
746809
StreamLogHandler(label: label, stream: interceptStream)
747810
}
748811
let log = Logger(label: label)
@@ -757,8 +820,8 @@ class LoggingTest: XCTestCase {
757820
return
758821
}
759822

760-
XCTAssert(interceptStream.strings[0].contains("a=a0 b=b0"))
761-
XCTAssert(interceptStream.strings[1].contains("a=a1 b=b1"))
823+
XCTAssert(interceptStream.strings[0].contains("a=a0 b=b0"), "LINES: \(interceptStream.strings[0])")
824+
XCTAssert(interceptStream.strings[1].contains("a=a1 b=b1"), "LINES: \(interceptStream.strings[1])")
762825
}
763826

764827
func testStdioOutputStreamWrite() {
@@ -890,6 +953,12 @@ extension Logger {
890953
#endif
891954
}
892955

956+
extension Logger.MetadataProvider {
957+
static var exampleMetadataProvider: Self {
958+
.init { ["example": .string("example-value")] }
959+
}
960+
}
961+
893962
// Sendable
894963

895964
#if compiler(>=5.6)

‎Tests/LoggingTests/MetadataProviderTest+XCTest.swift

+33
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,33 @@
1+
//===----------------------------------------------------------------------===//
2+
//
3+
// This source file is part of the Swift Logging API open source project
4+
//
5+
// Copyright (c) 2018-2019 Apple Inc. and the Swift Logging API project authors
6+
// Licensed under Apache License v2.0
7+
//
8+
// See LICENSE.txt for license information
9+
// See CONTRIBUTORS.txt for the list of Swift Logging API project authors
10+
//
11+
// SPDX-License-Identifier: Apache-2.0
12+
//
13+
//===----------------------------------------------------------------------===//
14+
//
15+
// MetadataProviderTest+XCTest.swift
16+
//
17+
import XCTest
18+
19+
///
20+
/// NOTE: This file was generated by generate_linux_tests.rb
21+
///
22+
/// Do NOT edit this file directly as it will be regenerated automatically when needed.
23+
///
24+
25+
extension MetadataProviderTest {
26+
static var allTests: [(String, (MetadataProviderTest) -> () throws -> Void)] {
27+
return [
28+
("testLoggingMergesOneOffMetadataWithProvidedMetadataFromExplicitlyPassed", testLoggingMergesOneOffMetadataWithProvidedMetadataFromExplicitlyPassed),
29+
("testLogHandlerThatDidNotImplementProvidersButSomeoneAttemptsToSetOneOnIt", testLogHandlerThatDidNotImplementProvidersButSomeoneAttemptsToSetOneOnIt),
30+
("testLogHandlerThatDidImplementProvidersButSomeoneAttemptsToSetOneOnIt", testLogHandlerThatDidImplementProvidersButSomeoneAttemptsToSetOneOnIt),
31+
]
32+
}
33+
}

‎Tests/LoggingTests/MetadataProviderTest.swift

+131
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,131 @@
1+
//===----------------------------------------------------------------------===//
2+
//
3+
// This source file is part of the Swift Logging API open source project
4+
//
5+
// Copyright (c) 2018-2019 Apple Inc. and the Swift Logging API project authors
6+
// Licensed under Apache License v2.0
7+
//
8+
// See LICENSE.txt for license information
9+
// See CONTRIBUTORS.txt for the list of Swift Logging API project authors
10+
//
11+
// SPDX-License-Identifier: Apache-2.0
12+
//
13+
//===----------------------------------------------------------------------===//
14+
@testable import Logging
15+
import XCTest
16+
17+
#if os(macOS) || os(iOS) || os(tvOS) || os(watchOS)
18+
import Darwin
19+
#elseif os(Windows)
20+
import WinSDK
21+
#else
22+
import Glibc
23+
#endif
24+
25+
final class MetadataProviderTest: XCTestCase {
26+
func testLoggingMergesOneOffMetadataWithProvidedMetadataFromExplicitlyPassed() throws {
27+
let logging = TestLogging()
28+
LoggingSystem.bootstrapInternal(logging.make)
29+
30+
let logger = Logger(label: #function, metadataProvider: .init {
31+
[
32+
"common": "provider",
33+
"provider": "42",
34+
]
35+
})
36+
37+
logger.log(level: .info, "test", metadata: ["one-off": "42", "common": "one-off"])
38+
39+
logging.history.assertExist(level: .info,
40+
message: "test",
41+
metadata: ["common": "one-off", "one-off": "42", "provider": "42"])
42+
}
43+
44+
func testLogHandlerThatDidNotImplementProvidersButSomeoneAttemptsToSetOneOnIt() {
45+
let logging = TestLogging()
46+
var handler = LogHandlerThatDidNotImplementMetadataProviders(testLogging: logging)
47+
48+
handler.metadataProvider = .simpleTestProvider
49+
50+
logging.history.assertExist(level: .warning, message: "Attempted to set metadataProvider on LogHandlerThatDidNotImplementMetadataProviders that did not implement support for them. Please contact the log handler maintainer to implement metadata provider support.", source: "Logging")
51+
}
52+
53+
func testLogHandlerThatDidImplementProvidersButSomeoneAttemptsToSetOneOnIt() {
54+
let logging = TestLogging()
55+
var handler = LogHandlerThatDidImplementMetadataProviders(testLogging: logging)
56+
57+
handler.metadataProvider = .simpleTestProvider
58+
59+
logging.history.assertNotExist(level: .warning, message: "Attempted to set metadataProvider on LogHandlerThatDidImplementMetadataProviders that did not implement support for them. Please contact the log handler maintainer to implement metadata provider support.", source: "Logging")
60+
}
61+
}
62+
63+
extension Logger.MetadataProvider {
64+
static var simpleTestProvider: Logger.MetadataProvider {
65+
return Logger.MetadataProvider {
66+
return ["test": "provided"]
67+
}
68+
}
69+
}
70+
71+
public struct LogHandlerThatDidNotImplementMetadataProviders: LogHandler {
72+
let testLogging: TestLogging
73+
init(testLogging: TestLogging) {
74+
self.testLogging = testLogging
75+
}
76+
77+
public subscript(metadataKey _: String) -> Logging.Logger.Metadata.Value? {
78+
get {
79+
return nil
80+
}
81+
set(newValue) {
82+
// ignore
83+
}
84+
}
85+
86+
public var metadata: Logging.Logger.Metadata = [:]
87+
88+
public var logLevel: Logging.Logger.Level = .trace
89+
90+
public func log(level: Logger.Level,
91+
message: Logger.Message,
92+
metadata: Logger.Metadata?,
93+
source: String,
94+
file: String,
95+
function: String,
96+
line: UInt) {
97+
self.testLogging.make(label: "fake").log(level: level, message: message, metadata: metadata, source: source, file: file, function: function, line: line)
98+
}
99+
}
100+
101+
public struct LogHandlerThatDidImplementMetadataProviders: LogHandler {
102+
let testLogging: TestLogging
103+
init(testLogging: TestLogging) {
104+
self.testLogging = testLogging
105+
}
106+
107+
public subscript(metadataKey _: String) -> Logging.Logger.Metadata.Value? {
108+
get {
109+
return nil
110+
}
111+
set(newValue) {
112+
// ignore
113+
}
114+
}
115+
116+
public var metadata: Logging.Logger.Metadata = [:]
117+
118+
public var logLevel: Logging.Logger.Level = .trace
119+
120+
public var metadataProvider: Logger.MetadataProvider?
121+
122+
public func log(level: Logger.Level,
123+
message: Logger.Message,
124+
metadata: Logger.Metadata?,
125+
source: String,
126+
file: String,
127+
function: String,
128+
line: UInt) {
129+
self.testLogging.make(label: "fake").log(level: level, message: message, metadata: metadata, source: source, file: file, function: function, line: line)
130+
}
131+
}

‎Tests/LoggingTests/TestLogger.swift

+75-8
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,21 @@ internal struct TestLogging {
2323
private let recorder = Recorder() // shared among loggers
2424

2525
func make(label: String) -> LogHandler {
26-
return TestLogHandler(label: label, config: self.config, recorder: self.recorder)
26+
return TestLogHandler(
27+
label: label,
28+
config: self.config,
29+
recorder: self.recorder,
30+
metadataProvider: LoggingSystem.metadataProvider
31+
)
32+
}
33+
34+
func makeWithMetadataProvider(label: String, metadataProvider: Logger.MetadataProvider?) -> LogHandler {
35+
return TestLogHandler(
36+
label: label,
37+
config: self.config,
38+
recorder: self.recorder,
39+
metadataProvider: metadataProvider
40+
)
2741
}
2842

2943
var config: Config { return self._config }
@@ -36,16 +50,43 @@ internal struct TestLogHandler: LogHandler {
3650
private var logger: Logger // the actual logger
3751

3852
let label: String
39-
init(label: String, config: Config, recorder: Recorder) {
53+
public var metadataProvider: Logger.MetadataProvider?
54+
55+
init(label: String, config: Config, recorder: Recorder, metadataProvider: Logger.MetadataProvider?) {
4056
self.label = label
4157
self.config = config
4258
self.recorder = recorder
4359
self.logger = Logger(label: "test", StreamLogHandler.standardOutput(label: label))
4460
self.logger.logLevel = .debug
61+
self.metadataProvider = metadataProvider
4562
}
4663

47-
func log(level: Logger.Level, message: Logger.Message, metadata: Logger.Metadata?, source: String, file: String, function: String, line: UInt) {
48-
let metadata = (self._metadataSet ? self.metadata : MDC.global.metadata).merging(metadata ?? [:], uniquingKeysWith: { _, new in new })
64+
init(label: String, config: Config, recorder: Recorder) {
65+
self.label = label
66+
self.config = config
67+
self.recorder = recorder
68+
self.logger = Logger(label: "test", StreamLogHandler.standardOutput(label: label))
69+
self.logger.logLevel = .debug
70+
self.metadataProvider = LoggingSystem.metadataProvider
71+
}
72+
73+
func log(level: Logger.Level,
74+
message: Logger.Message,
75+
metadata explicitMetadata: Logger.Metadata?,
76+
source: String,
77+
file: String, function: String, line: UInt) {
78+
// baseline metadata, that was set on handler:
79+
var metadata = self._metadataSet ? self.metadata : MDC.global.metadata
80+
// contextual metadata, e.g. from task-locals:
81+
let contextualMetadata = self.metadataProvider?.get() ?? [:]
82+
if !contextualMetadata.isEmpty {
83+
metadata.merge(contextualMetadata, uniquingKeysWith: { _, contextual in contextual })
84+
}
85+
// override using any explicit metadata passed for this log statement:
86+
if let explicitMetadata = explicitMetadata {
87+
metadata.merge(explicitMetadata, uniquingKeysWith: { _, explicit in explicit })
88+
}
89+
4990
self.logger.log(level: level, message, metadata: metadata, source: source, file: file, function: function, line: line)
5091
self.recorder.record(level: level, metadata: metadata, message: message, source: source)
5192
}
@@ -224,10 +265,36 @@ extension History {
224265

225266
func find(level: Logger.Level, message: String, metadata: Logger.Metadata? = nil, source: String) -> LogEntry? {
226267
return self.entries.first { entry in
227-
entry.level == level &&
228-
entry.message == message &&
229-
entry.metadata ?? [:] == metadata ?? [:] &&
230-
entry.source == source
268+
if entry.level != level {
269+
return false
270+
}
271+
if entry.message != message {
272+
return false
273+
}
274+
if let lhs = entry.metadata, let rhs = metadata {
275+
if lhs.count != rhs.count {
276+
return false
277+
}
278+
279+
for lk in lhs.keys {
280+
if lhs[lk] != rhs[lk] {
281+
return false
282+
}
283+
}
284+
285+
for rk in rhs.keys {
286+
if lhs[rk] != rhs[rk] {
287+
return false
288+
}
289+
}
290+
291+
return true
292+
}
293+
if entry.source != source {
294+
return false
295+
}
296+
297+
return true
231298
}
232299
}
233300
}

‎proposals/0001-metadata-providers.md

+328
Large diffs are not rendered by default.

0 commit comments

Comments
 (0)
Please sign in to comment.