Metadata Providers (e.g. for Distributed Tracing) in LogHandlers

[ktoso]

This is the third, and hopefully final, revision of MetadataProvider. I believe this achieves everything we could come up with in the multiple rounds of reviews and calls, and introduces zero dependencies or api breaks to the project.

Thank you to @slashmo, the NIO and SSWG teams for the continued discussions 👍

This approach is summarized as:

• log handlers gain metadata providers
• providers, and whole of logging, remain unaware of Baggage
• a provider implementation, e.g. metadataProvider: .otel can and will pick up baggage from task-locals, since they do depend on baggage and tracing APIs.
• swift-distributed-tracing is able to implement provideMetadata(from: Baggage)

Updated proposal text: https://github.com/ktoso/swift-log/blob/wip-baggage-in-handlers-but-not-api/proposals/0001-metadata-providers.md

---

Distributed tracing is able to provide the following integration, in the Instrumentation module:

#if swift(>=5.5.0) && canImport(_Concurrency)
@available(macOS 10.15, iOS 13.0, watchOS 6.0, tvOS 13.0, *)
extension Logger {

    /// Extract any potential ``Logger/Metadata`` that might be obtained by extracting the
    /// passed ``InstrumentationBaggage/Baggage`` to this logger's configured ``Logger/MetadataProvider``.
    ///
    /// Use this when it is necessary to "materialize" contextual baggage metadata into the logger, for future use,
    /// and you cannot rely on using the task-local way of passing Baggage around, e.g. when the logger will be
    /// used from multiple callbacks, and it would be troublesome to have to restore the task-local baggage in every callback.
    ///
    /// Generally prefer to set the task-local baggage using `Baggage.current` or `Tracer.withSpan`.
    public mutating func provideMetadata(from baggage: Baggage?) {
        guard let baggage = baggage else {
            return
        }

        Baggage.withValue(baggage) {
            let metadata = self.metadataProvider.provideMetadata()
            for (k, v) in metadata {
                self[metadataKey: k] = v
            }
        }
    }
}
#endif

which allows us to "capture all baggage into metadata ONCE" and then keep using this logger with the metadata; which was a feature request from NIO-heavy libraries.

---

The API break reported is:

22:45:48 /* Protocol Requirement Change */
22:45:48 Var LogHandler.metadataProvider has been added as a protocol requirement
22:45:48 

which is accounted for by a default implementation:

public extension LogHandler {
    /// Default implementation for `metadataProvider` which defaults to a "no-op" provider.
    var metadataProvider: Logger.MetadataProvider {
        get {
            return .noop
        }
        set {
            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)
        }
    }
}

and this will never be triggered unless someone very actively in their end user library tries to make use of this, and then they'll get this warning. Existing libraries continue to work, but SHOULD implement support for invoking the metadata providers as otherwise the metadata will not be included in log statements. They can do so at their own pace though.

---

Since I wanted to include tests showing how task-locals are to be used with this, but Swift 5.0 cannot lex these properly even (confirmed this compiler bug with the compiler team; this will not be fixed), I had to make a new module for them.

This was quite painful, so either we keep this hacky separate module, or we drop those tests, or we drop 5.0 support. Either is fine with me.

[ktoso]

mismatched format versions truly are fun... Going to fix all those

[ktoso]

This is horrible, though good enough to have the discussion if we want to make this workaround less horrible, remove those few tests entirely (and remove this hack), or what else.

[tomerd]

what is this working around?

[ktoso]

A bug in Swift 5.0 that it cannot parse/lex code that has the shape of "Thing.$thing", which task-locals have to use - even when surrounded with #if swift(>=5.1) swift 5.0 will still fail to compile such code (yeah, it should ignore code in that #if, but it doesn't).

Options have are:

• don't have any tests which show how a task-local can be used with providers (we could not have those tests... and just static providers everywhere in our tests, though it's a bit annoying)
  • (no actual code is 5.0 breaking actually in this PR, it is only the tests)
• or use this separate module workaround

We can still have testing of this pattern in the tracing module, but it's a bit weird to test metadata provider patterns in a different package than the one declaring them.

I talked with the Swift team a bunch about this, there is no workaround in Swift 5.0 (and there will not be).

[ktoso]

It seems most reviewers voted for dropping 5.0, so I did so and undid this hack workaround: ad2fd8f (#238)

[FranzBusch]

Just read through all of this again and I really like where we ended up now. It looks like an organic extension to swift-log which plays nicely with distributed tracing!
I left a few small comments inline but overall big +1!

W.r.r. the required hack, I would vote for increasing the min Swift version. NIO is setting precedent here already and IMO it should be fine to have the same rules for swift-log.

[FranzBusch]

If I recall correctly these don't even need to be public to work. Might be wrong though

[ktoso]

Hmmm, I'll check but I think they need to be public -- it's for other libs to know this type is Sendable after all 🤔

[FranzBusch]

If I recall correctly this also works with an internal protocol. Maybe this changed but I tried to for one of our NIO repos. Somehow the compiler still transfers the Sendable constraint 😅

[FranzBusch]

I just tested this again. Since Sendable is only a marker protocol you don't have to make this public. It works without as well and propagates across modules.

[FranzBusch]

In general, I am not a fan of using typealiases here. They are hard to discover.

[weissi]

+1 against function typealiases in Swift, super hard to work with, especially with Xcode

[ktoso]

hmmm, I'll have to re-declare a bunch of entire function bodies unless I do a typealias like that -- so pretty painful tradeoff

[FranzBusch]

Yep painful but better end user experience 😅

[yim-lee]

I vote that we drop 5.0 support

[ktoso]

Yeah, honestly it's about time. We can go careful and just drop 5.0, the others we can keep around still.

[ktoso]

Done, removed the horrible workaround with modules;
We'll have to drop 5.0 though.

[tomerd]

collapse this into make and make metadataProvider optional with default of .none?

[ktoso]

That'll cause a series of ambiguity errors AFAIR, I'll give it a shot tho.

[ktoso]

Yeah I'll push back on this one, it causes a lot more pain in our test code than necessary;
We can't do LoggingSystem.bootstrapInternal(logging.makeWithMetadataProvider) style anymore and would have to spell out all the closures to disambiguate.

Note that this is only our test code, so the verbose name is not a concern IMHO

[tomerd]

does this need to be public?

[ktoso]

Yes, this is public on purpose in order to facilitate external libraries, such as tracing, to implement the "provideMetadata" functions, like this:

#if swift(>=5.5.0) && canImport(_Concurrency)
@available(macOS 10.15, iOS 13.0, watchOS 6.0, tvOS 13.0, *)
extension Logger {

    /// Extract any potential ``Logger/Metadata`` that might be obtained by extracting the
    /// passed ``InstrumentationBaggage/Baggage`` to this logger's configured ``Logger/MetadataProvider``.
    ///
    /// Use this when it is necessary to "materialize" contextual baggage metadata into the logger, for future use,
    /// and you cannot rely on using the task-local way of passing Baggage around, e.g. when the logger will be
    /// used from multiple callbacks, and it would be troublesome to have to restore the task-local baggage in every callback.
    ///
    /// Generally prefer to set the task-local baggage using `Baggage.current` or `Tracer.withSpan`.
    public mutating func provideMetadata(from baggage: Baggage?) {
        guard let baggage = baggage else {
            return
        }

        Baggage.withValue(baggage) {
            let metadata = self.metadataProvider.provideMetadata()
            for (k, v) in metadata {
                self[metadataKey: k] = v
            }
        }
    }
}
#endif

[tomerd]

bootstrapInternalMetadataProvider? or maybe collapse the two internal bootstrap functions to one, with metadata provider optional?

[ktoso]

Dropped it entirely, we only have those ONE new shape of bootstraps:

    internal static func bootstrapInternal(_ factory: @escaping (String, Logger.MetadataProvider?) -> LogHandler,
                                           metadataProvider: Logger.MetadataProvider?) {

    public static func bootstrap(_ factory: @escaping (String, Logger.MetadataProvider?) -> LogHandler,
                                 metadataProvider: Logger.MetadataProvider?) {

[tomerd]

feels like the metadataProvider should be the second argument

[ktoso]

A while ago we came to the order of parameters recommendations around "first strict, then closures, then optional params, then optional closures" so this follows that recommendation.

I'm not sure how many people actually write

LoggingSystem.bootstrap {
  many
  lines
  return here
}

so it was intended to keep that shape 🤔

LoggingSystem.bootstrap(metadataProvider: .coolTracer) {
  many
  lines
  return here
}

if we flip it, we end up with:

LoggingSystem.bootstrap({
  many
  lines
  return here
}, metadataProvider: .coolTracer)

potentially... but arguably most uses do look like this:

LoggingSystem.bootstrap(.coolLogger, metadataProvider: .coolTracer)

potentially... so, I'm not really sure about this one. The current shape kind of follows the "usual" order, with closures last. Open to either but current seemed more natural given the usage shapes hm

[ktoso]

Okey, let's do it 😄

[tomerd]

could auto-closure be useful here?

[ktoso]

hmm, yeah we could I guess; it'd allow a simple spelling for a "constant metadata provider" that is just the dictionary

[ktoso]

Followed up on your comments in 91437c0 @tomerd -- the reordering of the params I'm doubtful about, see here: #238 (comment)

but I could flip those around still... that's the final thing i guess?

[ktoso]

this just moved "up" a little in the file, to be organized together with the other ones

[ktoso]

default impls "do the right thing"™

[ktoso]

Discussed offline with @tomerd and I did another pass and removed as much new public API as possible.

We're done! I'm going to merge and release a minor version with this. This will cause an all our tracing repos to "fall into place" and we're soon going to 1.0-beta there 🥳

[ktoso]

To make sure folks don't panic: The API breakage detector is wrong here; we add a protocol requirement, but we add a default impl as well, this is source-compatible and purely additive.