BaggageContext and Swift Logging: Design alternatives

[slashmo]

Logging support has now been implemented as part of a BaggageLogging library (that depends on swift-log). It allows for setting a base Logger that is then being used to compute the context.logger property. In the current implementation, this base Logger is injected into the BaggageContext by stuffing it in the baggage via a special BaggageContext.BaseLoggerKey.

Below are some pro/cons on this approach and a possible alternative.

(1) Storing the Logger inside the BaggageContexts storage

Pros 👍

• It's easy, no need to pass a Logger while initializing a BaggageContext
• It allows us to add the logger property in a separate library, as the BaggageContext itself becomes the "property storage"

Cons 👎

• When setting the metadata on the Logger we had to manually exclude the BaggageContext.BaseLoggerKey so that it's not included in the log
• This may set an example for others to stuff in non-metadata related things into the BaggageContext
• It feels like a hack because we weren't able to add the Logger as a stored property in the BaggageContext extension

(2) Adding Logger to BaggageContext directly

Pros 👍

• Feels more natural, no need to make an exception for the otherwise metadata-only BaggageContext
• Doesn't lead to exclusion of certain keys when adding to the Logger metadata

Cons 👎

• BaggageContext would need to depend on swift-log directly

---

What are your thoughts on this. Other pros/cons, or even other alternatives to this approach?

[ktoso]

More approaches to consider (and I guess we may need to PoC around).

(I'm not really proposing the below, does not feel right, but let's list potential solutions before we decide on one)

(3) Logger to be created or "updated with" a Context

This would take the form of something like

func doThings(..., context: BaggageContext) { 
    Logger("label", context).info("hello") // ad-hoc creating, some projects do not want that...
}

func doThings(..., log: Logger, context: BaggageContext) { 
    logger(context).info("hello") // "app wide passed around logger" and "enrich" with context
} // this can get confusing perhaps?

Would it be possible perhaps to avoid this with the below?

func doThings(..., logger: BaggageLogger) { 
  logger.baggage // ...
  logger.info("xxx") // ...
}

It's an opposite take on (2) I guess, rather than the context depending on logging, there could be a special logger...

Pros 👍

• More clear in types what's going on
• No mixing context with logging? No special field or anything in baggage context

Cons 👎

• it can be confusing what is in context and what is already in the logger metadata, hard to explain the right rule?
• may be hard to do this one without passing around logger and context explicitly...?
• No mixing context with logging also a downside... more passing around and confusing that is logger.metadata and what is in context 👎

See also: https://blog.gopheracademy.com/advent-2016/context-logging/
I believe this works out in Go since they are fine with "ad hoc create a logger" in-place, and then just do (context) on it to give it metadata.

[ktoso]

(4) Logger functions to accept baggage context and "merge" with metadata when emitting logs

Another style that comes to mind is providing an extension over Logger that would:

// add accepting baggage to loggers
extension Logger { 
    @inlinable
    public func debug(
            _ message: @autoclosure () -> Logger.Message,
            context: BaggageContext,
            metadata: @autoclosure () -> Logger.Metadata? = nil,
            file: String = #file, function: String = #function, line: UInt = #line) {
        self.log(level: .debug, message(), metadata: merge metadata and context (extract context as Logger.MetadataValue), file: file, function: function, line: line)
    }
}

We'd provide some protocol and "known key" for setting an "extractor" that would do that merge metadata and context (extract context as Logger.MetadataValue).

Pros 👍

• on demand converting to metadata
• in user control which keys to expose as logging, by configuring that extractor

Cons 👎

• wouldn't this mean we'd end up having to sometimes pass around both a context and a logger?
  • since we'd need log.info(bla, context) where log is passed to us as well as context is...
  • how would this look in APIs like HTTPClient which today accept a logger; would they have to accept a logger and a context?

The go solution AFAICS is to not pass loggers around -- just pass context, and whenever I make a logger just pass a context to it. That's nice and clean. What about the present day pattern in Swift that some people like about "pass logger around" though -- it makes it tricky.

We need to figure out how that would look like here to serve all cases and not be too boilerplate heavy; passing both log and context seems to be an unpleasant outcome.

[tachyonics]

There is a broader consideration here of how cross-cutting concerns potentially interact with each other.

For example, consider a couple of use cases-

1. It may be most performant to push all metrics to a remote service as a batch at the end of a request/span rather than pushing them individually as they happen or having an out-of-band thread that may introduce performance variability.
2. It may be desirable to log particular metrics - duration, maybe some or all of metrics - for debugging purposes at the end of that span.

We have a number of actors in these scenarios-

1. The application that determines what cross-cutting implementations are to be used
2. A web/request framework that may create requests/spans and potentially loggers for them
3. Clients that may create metrics that can be emitted (for example per API metrics[1])

The difference between what has been discussed above and these use cases is that these are interactions between Metrics or Logging and Tracing/Spans rather than with the BaggageContext itself but the pattern extends itself to situations where there is just a BaggageContext

From an API level, I think we need some mechanism that can tell an implementation - called by the web/request framework and clients as appropriate - here is an existing Metric or Logger and a span/baggage that I want it to operate in, give me back something I can use for metrics/logging within this scope. It is then up to the implementation to decide what to do - potentially nothing and pass back the original object or return some kind of span/baggage-aware Logging or Metrics implementation that handles the interactions between these concerns.

let spanAwareLogger = logger.forSpan(currentSpan)
let baggageAwareLogger = logger.forBaggage(currentBaggage)

let spanAwareMetric = metric.forSpan(currentSpan)
let baggageAwareMetric = metric.forBaggage(currentBaggage)

[1] https://github.com/amzn/smoke-aws/blob/efd0465c322aa90868e459490b51235866a32e33/Sources/SmokeAWSCore/SmokeAWSOperationReporting.swift#L66

[ktoso]

Thanks for chiming in Simon!

Yes, I think that's right -- it's a variation on (3) listed here, but with the implication that we'll want to allow the tracing instrument to decide how things are to be mapped into a logger.

I think we can do the right things here... esp. since the forBaggage (good naming idea, we'll see :-)) can then create a special LogHandler which would only have to render the context's values into metadata values / strings when a log is actually performed (the usual log level check done by the swift-log protecting that).

I'm going to poke at this during this week and report back / ask for review :)