# Logging

**URL:** <https://forums.swift.org/t/logging/16027>\
**Category:** Pitches\
**Created:** [September 10, 2018, 3:14pm UTC](https://forums.swift.org/t/logging/16027 "2018-09-10T15:14:46Z")\
**Posts on this page:** 20\
**Page:** 4

<div class="post-metadata">

**Author:** ![johannesweiss](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/johannesweiss/32/38183_2.png) [@johannesweiss](https://forums.swift.org/u/johannesweiss)\
**Post date:** [September 12, 2018, 4:07pm UTC](https://forums.swift.org/t/logging/16027/68 "2018-09-12T16:07:14Z")

</div>

> [@IanPartridge](#):
>
> To go back to your distinction between "global" and "local" loggers, my personal view is that a solution that requires passing a logging existential around everywhere as a parameter to every function is not likely to see widespread adoption, simply because of how ugly it makes the code. People won't bother, they will think "oh I'll never want to log from this tiny function, I won't bother passing in the logger, just to keep it simple". And then in the future you find that of course you do want to log from there and now you have a refactoring exercise on your hands...
> 
> If it could be stashed in a struct/class and accessed via `self.logger.log()` then maybe that would see more usage, but there is a lot to be said for the simplicity of offering a global `Log.info("hello world")` .

Right, I hear you (and others). Having a global logger used like `Log.info("hello world")` however means that you won't be able to have extra payload (such as request UUID) automatically attached to all log messages issued by anything that logs whilst a particular HTTP request is being handled.

Just for the record, in synchronous systems thread-local storage can be used to store this extra payload. And for synchronous systems it is possible to wrap all libraries that cross threads and make them propagate thread-local storage appropriately. I do however believe that this is infeasible in Swift because we don't really want to wrap libdispatch, NIO's futures, and everything else that doesn't just synchronously run on the calling thread.

@IanPartridge for Kitura deployments, do you add extra information to all log messages issues by a certain request? If so, how? And what about metrics?

---

<div class="post-metadata">

**Author:** ![johannesweiss](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/johannesweiss/32/38183_2.png) [@johannesweiss](https://forums.swift.org/u/johannesweiss)\
**Post date:** [September 12, 2018, 4:10pm UTC](https://forums.swift.org/t/logging/16027/69 "2018-09-12T16:10:22Z")

</div>

> [@davedelong](#):
>
> Logging is a different form of gathering analytics

Indeed. We usually wire an explicit `Context` through to everywhere and you retrieve the logger as well as metrics systems from that context. And you rightly point out that all the problems we're discussing with logging also apply for metrics and other things.

---

<div class="post-metadata">

**Author:** ![plorenzi](https://avatars.discourse-cdn.com/v4/letter/p/bc8723/32.png) [@plorenzi](https://forums.swift.org/u/plorenzi)\
**Post date:** [September 12, 2018, 4:58pm UTC](https://forums.swift.org/t/logging/16027/70 "2018-09-12T16:58:53Z")

</div>

If we allow both "global" and "local" loggers, the problem is that programmers can't easily switch from a global logger to a local one when they want to improve diagnotics. They have to change every single log.

Whereas with a local logger then could, for example, switch from:

```swift
common.swift:
internal let log = Log()

file1.swift:
log.info("...")

file2.swift:
log.info("...)

```

to

```swift
file1.swift:
fileprivate let log = Log(file: "file1")
log.info("...")

file2.swift:
fileprivate let log = Log(file: "file2")
log.info("...)

```

edit. typo

---

<div class="post-metadata">

**Author:** ![ahti](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/ahti/32/604_2.png) [@ahti](https://forums.swift.org/u/ahti)\
**Post date:** [September 13, 2018, 8:01am UTC](https://forums.swift.org/t/logging/16027/71 "2018-09-13T08:01:00Z")

</div>

I've uploaded a playground here: [Hackish Swift clone of Rusts `log` crate · GitHub](https://gist.github.com/ahti/bb292a8324d7f3b385e89f6915518605)

It would work pretty nicely, if it were not for the fact that there's no good replacement for Rusts module path (those look something like `my_app::model::sync`). `#file` is often an absolute path, depending on how the compiler is invoked. A `#module` or `#package` would be pretty useful here, and I suspect for any logging solution. A [structured `#sourcelocation`](https://github.com/apple/swift-evolution/blob/74d62ec62b742848ee03005c478eccdc5f7d504d/proposals/0028-modernizing-debug-identifiers.md#possible-future-extensions) would be even better.

---

<div class="post-metadata">

**Author:** ![tomerd](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/tomerd/32/3402_2.png) [@tomerd](https://forums.swift.org/u/tomerd)\
**Post date:** [September 13, 2018, 4:11pm UTC](https://forums.swift.org/t/logging/16027/72 "2018-09-13T16:11:16Z")

</div>

on how to obtain an instance of a logger, aka "global" vs "local" loggers, i believe there is a third option which is a global logger factory, which is then used to obtain logger instances in the local scope. this model offers nice separation of concerns where the logger factory handles the configuration aspects and the local logger handles the logging API (eg trace, info, debug, etc) .

so in the local scope, you will do something like:

```swift
let logger = LoggerFactory.geLogger("foo")
logger.info("hello world!")

```

having `LoggerFactory` a global singleton that is initialized by the application, or a higher level framework like Vapor/Kitura using config files, or programmatically at application start, etc

(class and method names for illustration purposes only)

the key disadvantage of this approach is that it does not allow you to attach context level metadata to log entries and cascade it down. for example, its difficult to attached a "requestId" and "userId" that will then be part of the all logging entries related to that user request, since the various user code and libraries involved in processing such request will obtain their own logger instance with no context. and this is where passing the logger/context object around really shines. that said, while i love the technical attributes of passing the logger/context around, i believe asking users to do so is too high of a bar and not practical in a large ecosystem like the one we want to build. happy to learn about creative ways to achieve that, if anyone has ideas

the java server world has largely adopted this global factory, local instance model through the SLF4J library, and it seems to work reasonably well there. it also jells well with some of the other proposals made in this thread about local handlers. what SLF4J does to address the context challenge is to offer something called MDC which basically is a temporary storage of metadata that is shared between all the code that is processing on the same processing unit (eg a thread), and the logger instances then read the metadata and include it in the log entries as they write them out. in the simplest form of MDC, the metadata storage is thread locals so that everything that is processed on that thread shares the metadata. using thread locals works well when work (eg a request) is guaranteed to stay on the same thread, but obviously systems like NIO require different handling to correctly pass it around as it moves work on/off threads. I am not familiar with dispatch enough to know if an MDC like solution could be made to work with it, so would be interesting to better understand that aspect from someone who is more familiar with it. if they can't play nice together, we can consider building this in stages, where we address the context aspect of work done through dispatch if/when the core team gives us additional extension points to make it work

---

<div class="post-metadata">

**Author:** ![gps](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/gps/32/4621_2.png) [@gps](https://forums.swift.org/u/gps)\
**Post date:** [September 13, 2018, 11:16pm UTC](https://forums.swift.org/t/logging/16027/73 "2018-09-13T23:16:45Z")

</div>

IMO this is the ideal way to go.

There is a Java framework called [Ratpack](https://ratpack.io), that is based on Netty, and its API is not very dissimilar to Vapor in that it is future based, and makes no guarantees about a given request being completed on the same thread.

It does however have something called MDCInterceptor which allows you to use MDC as you always would: [Documentation](https://ratpack.io/manual/current/api/index.html?ratpack/logging/MDCInterceptor.html), [Source code](https://github.com/ratpack/ratpack/blob/master/ratpack-core/src/main/java/ratpack/logging/MDCInterceptor.java).

Works pretty well!

---

<div class="post-metadata">

**Author:** ![IanPartridge](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/ianpartridge/32/434_2.png) [@IanPartridge](https://forums.swift.org/u/IanPartridge)\
**Post date:** [September 14, 2018, 8:15am UTC](https://forums.swift.org/t/logging/16027/74 "2018-09-14T08:15:06Z")

</div>

> [@tomerd](#):
>
> what SLF4J does to address the context challenge is to offer something called MDC which basically is a temporary storage of metadata that is shared between all the code that is processing on the same processing unit (eg a thread), and the logger instances then read the metadata and include it in the log entries as they write them out. in the simplest form of MDC, the metadata storage is thread locals so that everything that is processed on that thread shares the metadata.

Perhaps [`DispatchSpecificKey<T>`](https://developer.apple.com/documentation/dispatch/dispatchspecifickey) could be used for this.

---

<div class="post-metadata">

**Author:** ![vi4m](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/vi4m/32/5090_2.png) [@vi4m](https://forums.swift.org/u/vi4m)\
**Post date:** [September 14, 2018, 10:02am UTC](https://forums.swift.org/t/logging/16027/75 "2018-09-14T10:02:16Z")

</div>

> [@tomerd](#):
>
> let logger = LoggerFactory.geLogger("foo")  
> logger.info("hello world!")

Besides the obvious lack of context, this is a really nice and lightweight solution, and I came with the same idea in my implementation of `LoggerManager` factory:

> <https://github.com/vi4m/SwiftHelpers/blob/da33bcdbb3381242cf1e14400c98911fdff8047e/Sources/SwiftHelpers/Logging.swift#L172>

- Appenders allow plugging different implementations.
- I also gather some file / lineno information.

Example:

```swift
LoggerManager.configure(appenders: [LogstashAppender()])
let logger = LoggerManager.getLogger(name: "test")
logger.debug("test")

```

I'm wondering about the hierarchical contexts, to have more structured logging, though.

---

<div class="post-metadata">

**Author:** ![neallester](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/neallester/32/4528_2.png) [@neallester](https://forums.swift.org/u/neallester)\
**Post date:** [September 14, 2018, 11:02am UTC](https://forums.swift.org/t/logging/16027/76 "2018-09-14T11:02:35Z")

</div>

Surely adding context: String? = nil to the logging API is not a huge burden to anyone. Well designed subsystems could arrange to accept and pass around such a context string. Users and library authors who can't be bothered could ignore it; those of us who actually need to debug our systems would probably use it.

---

<div class="post-metadata">

**Author:** ![MikeWeller](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/mikeweller/32/1280_2.png) [@MikeWeller](https://forums.swift.org/u/MikeWeller)\
**Post date:** [September 14, 2018, 2:46pm UTC](https://forums.swift.org/t/logging/16027/77 "2018-09-14T14:46:01Z")

</div>

[GitHub - Wolg/awesome-swift: A curated list of awesome Swift frameworks, libraries and software.](https://github.com/Wolg/awesome-swift#logging) lists some more Swift logging frameworks that may be worth comparing

---

<div class="post-metadata">

**Author:** ![feldur](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/feldur/32/23543_2.png) [@feldur](https://forums.swift.org/u/feldur)\
**Post date:** [September 14, 2018, 7:58pm UTC](https://forums.swift.org/t/logging/16027/78 "2018-09-14T19:58:00Z")

</div>

Logging level should be accompanied by an optional category, making it possible to select (for example) all dataloss level messages in the networking category, or all normal level messages in the user login category. If no category is provided for a given logging call, it matches all/no categories, depending on the query.

The defined levels and categories should be enums so that the abstract logging framework can be shaped to the specific application.

---

<div class="post-metadata">

**Author:** ![frameworklabs](https://avatars.discourse-cdn.com/v4/letter/f/13edae/32.png) [@frameworklabs](https://forums.swift.org/u/frameworklabs)\
**Post date:** [September 14, 2018, 9:10pm UTC](https://forums.swift.org/t/logging/16027/79 "2018-09-14T21:10:03Z")

</div>

Sometimes the necessary logging makes your code harder to read.

Any ambitions of the Swift community to tackle the task with aspect oriented programming or some functional programming magic instead?

---

<div class="post-metadata">

**Author:** ![tomerd](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/tomerd/32/3402_2.png) [@tomerd](https://forums.swift.org/u/tomerd)\
**Post date:** [September 15, 2018, 12:12am UTC](https://forums.swift.org/t/logging/16027/80 "2018-09-15T00:12:04Z")

</div>

@neallester the challenge with making context an argument of the logging api, is that unless there is an implicit way to retrieve the context, such argument needs to also be added to most/all other functions of the program and libraries, since one would want to log from potentially anywhere in the program. as for ignoring context, when the context carries critical information like tracing (eg requestId) log entries become useless without it: you are left to do timestamp matching which is non-deterministic in a system that does concurrency, such as a server. i take your point that in a small, well contained system, passing context around between functions is achievable, but imo at an ecosystem scale this will prove to be "too hard" and not pragmatic

---

<div class="post-metadata">

**Author:** ![Neal\_Lester](https://avatars.discourse-cdn.com/v4/letter/n/51bf81/32.png) [@Neal\_Lester](https://forums.swift.org/u/Neal_Lester)\
**Post date:** [September 15, 2018, 12:23am UTC](https://forums.swift.org/t/logging/16027/81 "2018-09-15T00:23:30Z")

</div>

Omitting the argument from the logging API doesn’t make it easier.

---

<div class="post-metadata">

**Author:** ![gwynne](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/gwynne/32/24337_2.png) [@gwynne](https://forums.swift.org/u/gwynne)\
**Post date:** [September 15, 2018, 9:30pm UTC](https://forums.swift.org/t/logging/16027/82 "2018-09-15T21:30:44Z")

</div>

Historically, my approach has essentially been one of the hybrid forms - a global `Logger` object is accessible which provides a "generic" logging facility, with an extension that supports adding context (typically Vapor's `Request` object) and utility methods such that individual request handler classes would do `private let log: RequestSpecificLogger` and do something like `self.log = req.make(Logger.self).logger(forRequest: req)` in their `init` (the latter call being necessary due to design limitations in Vapor's Services framework). The `logger(forRequest:)` method then saves off the `Request` object and chains it to the `log(request:level:message:file:line:)` method(s) on the "global" `Logger`, which through the extensions that take a `Request` input know how to obtain appropriate context such as a request ID, and ultimately funnel the contextualized log message down to `Logger`'s original `log()` methods.

This approach is great if the context you want to add for any given log message is consistent across most or all of your implementation, and the same "fake currying" technique allows for creating per-subsystem loggers and other various levels of specificity.

The drawbacks, of course, are the additional layers of complexity and leaving the burden of making sure the appropriate logger object is used in the appropriate places on the library/app author. I'm not entirely sure what a generic form of this approach would look like, but I wanted to put it out there as a variation on some of the approaches suggested so far in this thread.

---

<div class="post-metadata">

**Author:** ![lukasa](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/lukasa/32/1232_2.png) [@lukasa](https://forums.swift.org/u/lukasa)\
**Post date:** [September 17, 2018, 10:30am UTC](https://forums.swift.org/t/logging/16027/83 "2018-09-17T10:30:41Z")

</div>

> [@Neal\_Lester](#):
>
> Omitting the argument from the logging API doesn’t make it easier.

Sure, but it doesn't make it meaningfully harder either.

I would strongly encourage reducing the scope of the discussion here by aggressively considering some proposals as "out of scope" for an initial prototype. For large group discussions with many stakeholders it is very easy to become buried in the pile of great features that people love from other programming ecosystems and to attempt to satisfy them all on the first go. This is a recipe for failure.

We'll likely be best served by identifying which things have to be decided correctly up front and working on those initially, while ensuring we do not prevent any of the other, richer, features we want from emerging. I'd argue that logging contexts fall outside the "must get right the first time" category. They can be added after the fact with small API changes, and are not mandatory for many use cases. Additionally, they are themselves a quite substantial feature that deserves the proper focus of this WG, not something that we should assume is simply solved by throwing a `String` around.

---

<div class="post-metadata">

**Author:** ![johannesweiss](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/johannesweiss/32/38183_2.png) [@johannesweiss](https://forums.swift.org/u/johannesweiss)\
**Post date:** [September 17, 2018, 1:03pm UTC](https://forums.swift.org/t/logging/16027/84 "2018-09-17T13:03:59Z")

</div>

Thanks @tomerd, that's a good summary and as you point out, the MDC approach won't work if not all thread-crossing libraries collaborate which I don't think will happen in the Swift space. Dispatch doesn't do that today (on Linux) and we also don't want to wait for a year.

@gps The issue with MDC is that it needs to have special support from all involved libraries that do cross threads. In Swift I think this is unrealistic as we first and foremost would all need to switch to a Dispatch wrapper that propagates the context. I think MDC as is a necessary crutch which implicitly propagates the context in a 'magic' and hard to understand way. When it was designed we lived in a thread-per-request world and thread locals seemed like a good solution. And in a mostly blocking world, thread-locals do a fine job, when the Java world moved more and more toward non-blocking they just had to make MDC work by having the libraries all propagate the context implicitly like the thread-locals did before.

I wanted to discuss the explicit passing of context in Swift because we have a fresh start and because lots of Cocoa is already asynchronous so I think our issue with automatic context propagation is harder than it ever was in Java. Just to point it out: There is [`os_activity`](http://www.manpagez.com/man/3/os_activity_initiate/) which does propagation of some sort of context through Dispatch/XPC/... but it's Darwin-only and is only documented in the manpages.

@IanPartridge queue/thread locals can indeed be used to hold the context but something needs to put it in there and that's the complicated part. So every queue/thread crossing library needs to forward the context.

---

<div class="post-metadata">

**Author:** ![tanner0101](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/tanner0101/32/675_2.png) [@tanner0101](https://forums.swift.org/u/tanner0101)\
**Post date:** [September 17, 2018, 2:18pm UTC](https://forums.swift.org/t/logging/16027/85 "2018-09-17T14:18:38Z")

</div>

After thinking about this a bit last week and discussing with @johannesweiss, I think the best solution would be a global Logger that allows you to pass an optional context.

```swift
Logger.info("foo")
Logger.info("foo", ctx)

```

In cases where you can't easily pass this context (such as a computed property getter), you could just use the global log method. For cases where you _can_ get access to the context, passing it would enhance your log output.

As @johannesweiss has mentioned, it seems there is no way in Swift to relate asynchronous work w/ a given "activity" (i.e., request). For example, if an incoming request triggers an async database query, there is no way for SwiftNIO to know that static logging done as a result of the async database query should share a context with the request that triggered it. The only way to form a relation between the request and other async work it performs is with a context.

The good news is that if SwiftNIO can provide general-purpose context type, this would be useful tool for solving other problems (such as metrics). Frameworks built on top of NIO would be expected to assist in passing around this context as much as possible.

---

<div class="post-metadata">

**Author:** ![neallester](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/neallester/32/4528_2.png) [@neallester](https://forums.swift.org/u/neallester)\
**Post date:** [September 17, 2018, 3:59pm UTC](https://forums.swift.org/t/logging/16027/86 "2018-09-17T15:59:26Z")

</div>

> [@lukasa](#):
>
> Sure, but it doesn't make it meaningfully harder either.

I agree that omitting an argument of the type we are discussing (e.g. context, subsystem) from the logging API doesn't make adding a context or subsystem value to the log message meaningfully harder. However, what is harder is arranging for all log messages the system emits to format those values in a consistent manner. Thus, I think there is value in including separate parameters in the API, especially since swift parameter defaults can make it easy for users to ignore those parameters if they want to. Plus the documentation for those parameters in the API can describe how well behaved libraries (and applications) are to use the parameters. That documentation can also point out to users and library authors how valuable information like request context is during debugging to encourage them to go to the trouble of using it. Finally the parameter names (for information which must be passed around) can be adopted as standards by users and library authors making those systems easier to design and understand.

---

<div class="post-metadata">

**Author:** ![neallester](https://sea2.discourse-cdn.com/swift/user_avatar/forums.swift.org/neallester/32/4528_2.png) [@neallester](https://forums.swift.org/u/neallester)\
**Post date:** [September 17, 2018, 4:17pm UTC](https://forums.swift.org/t/logging/16027/87 "2018-09-17T16:17:39Z")

</div>

Another parameter which I would suggest adding to the logging API is

```swift
data: [(name: String, value: CustomStringConvertible?)]? = nil

```

I find that having a convenient way of passing in name/value pairs to my logging system without having to format them in application code encourages me to think about what data would be useful when reading the message and encourages me to actually include it with the message. It would also enable application developers to format all of the name/value data in their log messages consistently system wide.

[Previous page](https://forums.swift.org/t/logging/16027.md?page=3)

[Next page](https://forums.swift.org/t/logging/16027.md?page=5)
