[Discussion] Server Logging API


(Paul Solt) #41

Is this only server logging?

Or could it be used in an iOS or macOS app?


(Jason Toffaletti) #42

I would like to see some exploration of structured logging in addition to the metadata. https://github.com/uber-go/zap for example, does this really well. Primary use case would be JSON log output that can be easily indexed by splunk/elk. Neal provided some thoughts on this above, but I didn’t see anyone addresss those points.


#43

the goal of metadata is to enable structured logging. there has been a bit of a discussion above about also adding "temporary metadata" per logging call, which is an addition under review. see discussion between @johannesweiss, @artemredkin and @ktoso above

exactly. that would be the role of a logging library implementation (aka LogHandler implementation) which will format & output the entries in different formats like json or key-value. see background overview above

note that this proposal is for the logging API that enables the creation of such logging library, but does not (and should not) include one. once the API is settled, the SSWG will work with the community to implement one or more


#44

os_log has serious performance optimizations on darwin, so if you are building an iOS or macOS app you should use it and not worry about this API

this API is designed for non-darwin and/or cross-platform code, so you can plug in different backend. see background overview above


(Johannes Weiss) #45

Indeed. We should however point out that when this lands, we should be able to adopt a few of the osLog optimisations for the server logging effort too and you should then be able to use osLog as a backend (LogHandler) with acceptable performance. Plain osLog however will always remain faster as it decides many things at compile-time that we will need to do at runtime because the server world needs more flexibility.


Custom String Interpolation and Compile-time Interpretation applied to Logging
(Konrad `Ktoso` Malawski) #46

Good ideas here.

I explored the "context offers logger" proposal in depth today.


Discussing the Optional around LoggingMetadata, there's also more discussion around this with Tom in my "exploring things" PR: https://github.com/weissi/swift-server-logging-api-proposal/pull/6#discussion_r242418606

Uff, was a bunch of back and forth on this one :slight_smile:

I also chatted with Tom inside my "exploring" PR and I believe he has use cases in mind which make use of the optional to know if "empty was set" or nothing was set at all.

We discussed the "set or not" and "inheriting" styles in depth in: https://github.com/weissi/swift-server-logging-api-proposal/pull/6/files#r242418606

And I think the conclusion is:

  • in order to support people who would like to do the style of "fall back to a global one if nothing was set" as Tom proposes, the optional has to stay.
  • the optional does not prevent anyone, semantically, from implementing the "more and more specific scopes that share the outer scopes context", so while it does not look pretty I can live with it and implement anything I'd like to.

Proposed outcome: As the proposal is about a generic API to enable all kinds of implementations, I think it is fine to let the optional stay.


For reference: I don't think we's need thread locals for this. Examples follow.
Though I think it would also be possible to leave this our of the MVP which this logging proposal is setting out to define, and one may add such extensions via a library or on their own if someone would like this.

Concurrent writers are assumed not to be present in these btw – as some other means of achieving synchronization would be in place anyway – so I think this is a fair assumption.

So a quick rough sketch of what it might be could be something like:

public extension Logger {

    // I think I prefer option 2, since it is "as lazy as it gets"

    // option 1) requires mutating outer logger; I think this is less preferable in general
    mutating public func withMetadata(_ additionalMetadata: @autoclosure () -> LoggingMetadata, _ block: (Logger) -> Void) {
        let old = self.metadata
        self.metadata.merge(additionalMetadata(), uniquingKeysWith: { (l, r) in r })
        defer { self.metadata = old }

        return block(self)
    }

    // option 2) creates composite logger; difference is that "per log call" can set/reset the additional metadata...
    //           does not protect from concurrent writes in any case though (not that it should be a goal IMHO anyway though)
    public func withMetadataDelegate(_ additionalMetadata: @escaping @autoclosure () -> LoggingMetadata, _ block: (Logger) -> Void) {
        let proxyHandler = ProxyCompositeMetadata(underlying: self.handler, additionalMetadata: additionalMetadata)

        return block(Logger(proxyHandler))
    }
}
final class ProxyCompositeMetadata: LogHandler {
    private var underlying: LogHandler
    private let additionalMetadata: () -> LoggingMetadata

    private lazy var compositeMetadata: LoggingMetadata? = nil

    init(underlying: LogHandler, additionalMetadata: @escaping @autoclosure () -> LoggingMetadata) {
        self.underlying = underlying
        self.additionalMetadata = additionalMetadata
    }

    func log(level: LogLevel, message: String, file: String, function: String, line: UInt) {
        if level >= self.logLevel {
            let old = self.underlying.metadata

            // attempt avoiding to have to re merge the metadata maps all the time
            let composedMeta: LoggingMetadata
            switch self.compositeMetadata {
            case .some(let meta):
                // we already composed the maps once, lets reuse that
                composedMeta = meta
            case .none:
                composedMeta = old.merging(self.additionalMetadata(), uniquingKeysWith: { (l, r) in r })
                self.compositeMetadata = composedMeta
            }

            self.underlying.metadata = composedMeta
            defer { self.underlying.metadata = old } // reset on a "call by call" basis
            self.underlying.log(level: level, message: message, file: file, function: function, line: line)
        }
    }

    private var _logLevel: LogLevel = .info
    public var logLevel: LogLevel {
        get {
            return self.underlying.logLevel
        }
        set {
            self.underlying.logLevel = newValue
        }
    }

    public var metadata: LoggingMetadata {
        get {
            return self.underlying.metadata
        }
        set {
            self.underlying.self.metadata = newValue
        }
    }

    public subscript(metadataKey metadataKey: LoggingMetadata.Key) -> LoggingMetadata.Value? {
        get {
            return self.underlying.metadata[metadataKey]
        }
        set {
            self.underlying.metadata[metadataKey] = newValue
        }
    }
}

Usage being:


outerLoggerVar.withMetadataDelegate(["hello": "helloooooooo!"]) { scoped in
    scoped.info("EXAMPLE withMetadataDelegate var logger: with additional meta")
    scoped.info("EXAMPLE withMetadataDelegate var logger: with additional meta")
    scoped.info("EXAMPLE withMetadataDelegate var logger: with additional meta")
}
outerLoggerVar.info("EXAMPLE withMetadataDelegate var logger: No more `hello` value in meta")

outerLoggerLet.withMetadataDelegate(["hello": "helloooooooo!"]) { scoped in
    scoped.info("EXAMPLE withMetadataDelegate let logger: with additional meta")
    scoped.info("EXAMPLE withMetadataDelegate let logger: with additional meta")
    scoped.info("EXAMPLE withMetadataDelegate let logger: with additional meta")
}
outerLoggerLet.info("EXAMPLE withMetadataDelegate let logger: No more `hello` value in meta")

// requires `var`, since we mutate directly
outerLoggerVar.withMetadata(["hello": "helloooooooo!"]) { scoped in
    scoped.info("EXAMPLE requires var, mutates outer: with additional meta")
    scoped.info("EXAMPLE requires var, mutates outer: with additional meta")
    scoped.info("EXAMPLE requires var, mutates outer: with additional meta")
    scoped.info("EXAMPLE requires var, mutates outer: with additional meta")

    // direct overlapping access is protected as:
    // outerLoggerVar.info("NOPE")
    //     /Users/ktoso/code/swift-server-logging-api-proposal/Sources/Examples/ExploringPerformanceExample.swift:215:13: error: overlapping accesses to 'outerLoggerVar', but modification requires exclusive access; consider copying to a local variable
    //                outerLoggerVar.withMetadata(["hello": "helloooooooo!"]) { scoped in
    //                ^~~~~~~~~~~~~~
    //    /Users/ktoso/code/swift-server-logging-api-proposal/Sources/Examples/ExploringPerformanceExample.swift:221:17: note: conflicting access is here
    //                    outerLoggerVar.info("NOPE")
    //                    ^~~~~~~~~~~~~~
}
outerLoggerVar.info("EXAMPLE: No more `hello` value in meta")

// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE withMetadataDelegate var logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE withMetadataDelegate var logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE withMetadataDelegate var logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY] EXAMPLE withMetadataDelegate var logger: No more `hello` value in meta
// [2018-12-18 06:22:44 +0000][info][hello=helloooooooo!] EXAMPLE withMetadataDelegate let logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][hello=helloooooooo!] EXAMPLE withMetadataDelegate let logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][hello=helloooooooo!] EXAMPLE withMetadataDelegate let logger: with additional meta
// [2018-12-18 06:22:44 +0000][info][] EXAMPLE withMetadataDelegate let logger: No more `hello` value in meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE requires var, mutates outer: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE requires var, mutates outer: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE requires var, mutates outer: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY hello=helloooooooo!] EXAMPLE requires var, mutates outer: with additional meta
// [2018-12-18 06:22:44 +0000][info][shared-meta=shared_YAY] EXAMPLE: No more `hello` value in meta

Summing up "scoped metadata": The existing API proposal seems to be enough to roll-your-own this feature. That was another good sanity check that it's flexible enough, I suppose.

I do not think it "has to" ship with the core library as keeping it as minimal as it gets would be the best course of action here I think, since it is to be shared across many many libraries, any additional method is a risk of introducing some edge cases.

If we end up deciding to ship such methods with the APIs I'm fine with that though, anything similar to the above would likely be fine. The worry about including it comes from that the pattern to do these things may change slightly if we get "context object" style things, though we would manage to deprecate and move to contexts if ever that needed to be the case I think.


And finally context and relation to logger metadata:

I have to say that the general pattern of "context exposes logger" is absolutely something I'd subscribe to.
It would also allow avoiding that "forces strings" issue that I yammer about currently, since the context could be well-typed, and only rendered into strings when we actually hit a log() (that does trigger, i.e. not filtered out by log level).

I explored this quite in depth today and can see why you are worried about putting "mdc" style here, if we are to consider a future more general Context abstraction. I sadly don't yet have a good idea what the best approach here is, migrating if we ever do context or co-existing.

Traces or and similar indeed do not live "inside loggers", though you may want to log some of the ids, so there is some interplay in place here.

I don't have a great answer here yet, but will try to experiment some more. In general though I'm a big fan of not letting the "perfect be the enemy of good", and a plain simple logging API as we discuss here is something I absolutely subscribe to, regardless when or if-at-all we do context separately as you mentioned @johannesweiss.


Errata to previous nitpicks

Retracting naming nitpick:

I retract the complaint about the make method name btw. Just reminded myself that that is following the standard naming conventions: https://swift.org/documentation/api-design-guidelines/#strive-for-fluent-usage
That's definitely the naming to use then it seems, I had forgotten that part of the style guide :+1:


(Johannes Weiss) #47

Sorry for the delayed response and thank you for the detailed thoughts!

I know this might be a bit annoying but I feel we should pitch these kinds of things separately in case the base + smaller changes get accepted. There will then still be time before the API will be tagged 1.0.0. In case this proposal proceeds, it'll first go to the 'sandbox' level where people are invited to try it out but we can still make changes before it even reaches 'incubation'.

I think you talked yourself out of closeLog and I think I agree because we can't have logging implementation only flush in closeLog because otherwise we'd lose messages just before a crash...

Regarding openLog, I think you're touching on something that we should really think through. It's very possible that a LogHandler may need to perform some initialisation before being able to be used. I think we should probably have some function (maybe called openLog) called at the time a LogHandler is 'installed' through Logging.bootstrap. filed here

I remain unconvinced that custom logging levels are worth the complexity. Your example with the Vapor database system is a good one but I believe you can achieve the same thing in two slightly different ways depending on how you plan to use the logger:

  • if you go for the explicitly passing the logger around model, I'd just add a logger[metadataKey: "subsystem"] = "com.vapor.database" and you'll later be able to filter out all database messages easily
  • if you go for the 'one logger per sub-system' then you'd have the Vapor database layer create a logger with identifier com.vapor.database and again, the filtering should be rather straightforward.

Think that would work?

Yes, they are strongly ordered and if the log-level is at warn, the LogHandler won't even see any messages that are below warn. This was a deliberate decision so that we don't need to forward the @autoclosure to the existential LogHandler type. Why? Because currently @autoclosure will alloctate if the called function cannot be inlined. And you can never inline across an existential (because well the implementation is chosen at runtime...).

There is however quite an easy workaround: Your log handler can accept setting log levels (and store that) but when asked about the log level it just always returns .trace. This way the LogHandler can see all messages and can optionally add some fancier stuff.

I believe that convention and logging meta-data is good enough here. So if everybody uses the "subsystem" key, it should work. We could also (later) add the strings as proper constants to the logging API.

it depends. There are so many different approaches to logging that this needs to be decided by the LogHandlers themselves. Maybe in the future one way of logging will 'win' and we can adjust this but currently this is deliberately left to the LogHandler.

If it covers the basic API I think it's worth mentioning. For example I'm thinking about (in a separate thread) asking the community if they like

logger.info("Hello World") and logger.error("bad") (as proposed so far)

or

logger.log(level: .info, "Hello World") and logger.log(level: .error, "bad")

better.

Yes, I think you're right here. I think we should start with something that we feel is good enough and over time we can evolve.


(Gwynne Raskind) #48

I do somewhat, but I have concerns about using the metadata in particularly this way - more on that below. I would almost always prefer to do "one logger per subsystem", but more than once in practice it's turned out that I have a lot of trouble separating out what logs belong to what subsystem, even with very well-isolated abstractions. In particular, really good abstraction layers are not something I tend to have during the early stages of a project's development - I find myself going back and changing how my logging is organized over and over and over.

The biggest hurdle with the "one logger per subsystem" model, in my experience, is keeping the logger objects accessible to the contexts using them. Calling Logger("com.exmaple.foo") everywhere that wants that subsystem (even if the API supported using it this way, which I wouldn't want it to!) presupposes either extremely cheap initialization, a global cache (with all the myriad attendant issues of that), or compile-time evaluation, none of which are desirable requirements. At the same time, passing Loggers around tends to demand certain compromises in design - vars or functions in global scope, objects that conform to a hypothetical ContainsContextualLogger protocol, ivars/methods with mostly repeated implementations in many different files and/or objects, and so on. Refactoring becomes increasingly messy. And I don't know if this has been brought up in this thread already, but there's also the question of preserving contextual metadata from one subsystem in a Logger that belongs to a "lower-level" subsystem - so now you need to be able to do Logger("com.example.bar", inheriting: fooLogger), or carefully build your subsystems to have the needed context or not need to log it without losing the specificity, or otherwise have a LogContext (which I know I've seen mentioned somewhere in here).

As unfortunately usual, I don't have a good suggestion for solutions to the issue, I'd need to spend some time tinkering. I just don't want it to pass unmentioned :confused:

I've read over this several times and still can't quite work out in my head why the @autoclosure would need to be forwarded. I think I'm missing a piece somewhere in the flow of data :sweat_smile:. In fact, re-reading this again, I'm not quite clear on which thing you were saying was deliberate by design: "passing only the configured messages to the handler", or "having only one configured logging level rather than a set". Can you clarify?

I like this - though in other logging systems I've seen, it's defined by API contract that a LogHandler always receives all log messages, regardless of level, and can decide what to do with them on that basis. I don't know how that would look for performance, but it has the virtue of both simplicity and consistency.

This is one where I'm just not sure I agree. Well-known subscripts to an arbitrary metadata map are still stringly-typed data, and that level of flexibility is typically most useful to clients of an API, not the API itself. If the API goes to the trouble to define "well-known" metadata in the first place, it should make that metadata part of the API contract and provide explicit properties. This preserves the maximum amount of static type information, keeps the metadata namespace unambiguous, and makes it less likely that clients will accidentally miss the existence of the keys and end up pointlessly duplicating the functionality.

That being said, this is certainly something that would stand outside the scope of the first version/draft of the API - it deals much more in concrete implementations than protocols. I would say file an issue for this and address it later, but do address it.

On this one, I'm pretty sure I come down on the side of leaving it to the LogHandler, especially if we end up saying that handlers always receive all messages. I don't see a need to provide extra guidance from the API for it, all that could ever do is limit the API's capabilities.

Well, I certainly can't speak for the community as a whole :slightly_smiling_face:. But speaking for myself, I very much prefer the former (current) style as bother more "fluent" and more terse. Ultimately, I would say "provide both but visibly prefer the shorter form".


(Johannes Weiss) #49

Right, but that's not solved by custom log levels either, right?

Yes, these are all valid issues. I personally am the 'passing the logger around explicitly' kind of person which makes the contextual logging fairly straightforward and Loggers can be value types etc. But it does make it harder to have per sub-system logging messages. Sometimes you can use #file as a proxy for what sub-system it is but it's not great either. The thing is that I don't think there's a good answer for everybody, we just can't force everybody to pass loggers around explicitly nor can we tell people that that's not supported.

If you want to have both 'sub-system' loggers and contextual logging then I think the only way is to built the context separately and then pass it onto the logging methods manually (with added metadata: parameters to every log method, like @artemredkin was proposing up-thread). Or obviously MDC which propagates the contextual information through thread-locals but sub-system loggers + MDC + Dispatch == needs-manual-assistance propagating the context :slight_smile:

I know, there's no perfect solutions here that work for every architecture and belief...

Sure, at the moment in Swift, both @autoclosure and closure arguments (with non-nil contexts) will allocate (ie. call malloc). So if you have a ModuleA which defines func foo(_ body: () -> String) and you call it from ModuleB as

let a = "hello"
foo {
  return a
}

an allocation will happen when foo is called for the closure's context (the captured variables). @autoclosures are the same, they just are a nicer syntax for this. The only way to get around that is inlining. Ie. making it @inlinable func foo(_ body: () -> String). That way the compiler will (hopefully) inline foo's body into the caller and it's no longer actually building a closure.

That's why Logger is a struct and all its methods are inlineable: Within the (hopefully) inlined code we know if we need to produce the log message string (by evaluating the @autoclosure) or not. And only after having decided that we do need to log, we evaluate the @autoclosure and pass the result on as a String to the LogHandler. So with a bit of support from the inlining gods, we no longer need to allocate.

If we passed the @autoclosure straight through to the LogHandler, it can't inline that and we do actually need to allocate for the closure. And there's no way we can inline the LogHandler implementation into the caller because the LogHandler is selected at runtime.

Really, this should be addressed in the compiler and the closure context should be stack allocated (because the closure is non-escaping) but that hasn't been done AFAIK.

Agreed, but then every log message would be an allocation, if actually logged or not. That's unacceptable for a non-starter for now. I'd hope that this is fixed in Swift rather sooner than later but I think we need a solution before that. For more information, check this thread, especially the newer messages.

I still think that it might open a kitchen sink of information that one or the other person needs and (totally contrary to my normal opinions) I think here stringly typed is okay. Why? Because everybody I've seen on the server-side analyses logs with textual tools anyway. I mean we teach Splunk how to parse the messages that we serialised costly on the other end. But I don't want to say 'no' to this but for this proposal at this stage I don't think we should do it. If this goes forward and we have gained experience, then I think we can pitch enhancements but at this point I feel it's too risky to design features for a system that nobody has used in production quite yet.

yes

I do too but the same applies to me, can't speak for the community hence I'm considering asking (on a separate thread) if we should change. But that's really a small detail so maybe not now :).


(Neal Lester) #50

Sorry to reply to your question in this thread (If you do open another thread soon I will try to reply there also but may not be able to in a timely manner depending on when you post).

Including the .log(level: style would make it possible to make the Logger generic on LogLevel. This would add a lot of flexibility to the API and the .warn style API could still be provided through conditional extensions for the default LogLevel enum.

That said, I'm ok with a hard coded LogLevel provided that a case emergency is added (although I would prefer the levels I outlined previously).

To me, warning indicate events which may or may not require action, while errors generally do require corrective action. However, while one user encountered an unsupported edge case and the application can't reach the database may both require action (and thus classify as errors) they are different enough to justify different log levels.


(Jon Shier) #51

os_log has serious issues that prevent it from being used in apps, even if the API update suggested goes through. Console-only logs being useless for anyone who isn't a dev most of all. So this effort will likely be adopted by the larger community as the basis for their logging efforts. I think it's important to keep that in mind here (though I don't think such a consideration would really change anything so far).


(Nick Keets) #52

That sounds very shortsighted. I'm assuming Xcode will eventually integrate SPM, turning steps 1-5 into a few clicks. Also what about UI apps? What about CLI apps? Logging is something generally usefull, why artifically constrain this to pure server apps?

Again why are you constraining this to only "enterprisey" projects?

So you are advocating for left-pad style minimal functionality packages to cover the shortcomings of the builtin libraries? Or maybe follow Python's "lead" and go for Logging2 and Logging3 packages?

In general, I agree with @xwu. Logging is something that any app can use, from single-file scripts, to CLI apps, to iOS apps, to simple servers, to enterprise servers. By assuming that it is only going to be used by multi-layer, multi-framework enterprise server apps, you are compromising the usability of all other scenarios.


(Benjamin Hawkes-Lewis) #53

@johannesweiss @tomerd Thanks for your efforts pushing this forward!

Log management systems like Splunk do not always operate on flat string-to-string maps.

A value in Splunk can be a list (“multi-value” in Splunk-speak) and Splunk supports locators into deeply nested list and map structures from ingested XML or JSON (see the documentation for spath).

LogStash supports a fairly rich explicit type system including lists, hashes, bytes, numbers, URIs, strings.

Some example use cases for complex metadata (lists and maps) include:

  • A service fulfills user requests by spawning a tree of sub-requests to other services. When logging from those services, you want to include the request ancestry as list of request IDs in a request_lineage field, then query for all sub-requests of a node in the tree using that field when analyzing logs.

  • A service enables users to share some content with a selection of users. You want to log the creation of the share including a list of users in a sharees field, then query for logs with specific sharees within that field when analyzing logs.

  • A service consumes and produces events with complex structures. You want to produce logs that include triggering and generated events in an event field, then query within the events when analyzing logs.

Forcing structured data such as a list or dictionary into a string-to-string flat map implies an extra serialization/deserialization hop somewhere. For example, take a triggering event, serialize it to JSON, stick the JSON in a string in a log entry, serialize the log entry to JSON, then after deserializing the log entry from JSON also deserialize the nested event JSON on the other end.

For comparison purposes, structured logging libraries in other ecosystems tend to support complex values like Rust’s slog and Python’s structlog.

In the Swift ecosystem:

I think it would be good at least to have a plan for how this API could be evolved to support complex metadata, even if it does not support it from the start.


(Johannes Weiss) #54

I agree with what you say and this API is very much built with JSON/XML/... logging in mind but as you say, currently only one level deep.

I’m fine lifting that restriction but I don’t think [String: Any] is a solution. It would be burdensome for the LogHandlers to handle sensibly. What types should they support? Mostly String and [String: Any] nested? If that’s what we’re after then we should make it explicit and the meta-data dict should be [String: MetadataValue] where enum MetadataValue { case string(String); indirect case dictionary([String: MetadataValue]).

We can make MetadataValue StringLiteralConvertible so people can pass string literals.

String:Any will just make it unclear for LogHandlers what they should do with the value but I can see why one would need more than one level deep meta-data dictionaries.

Let me know if that would help you.


(Paul Solt) #55

Yes, but I don't care for the "extreme" performance, I want ease of use as an app developer. os_log() doesn't fill those needs as @davedelong mentioned in the other thread.

Sorry if this is a beginner question. Out of the box, do I have to change the backend to get it functional?

Or can I just log to a file on the iOS filesystem, and then allow the user to email the file from their Documents directory (in-app)?


(Konrad `Ktoso` Malawski) #56

As the [String: String] remains my probably single remaining issue about the proposal I think it would indeed be good to do something about it. And have it be future proof, for a potential "context carrying" if/when it were to happen.

From my end, as library author, I'd be happy with any container that allows delaying the -> String rendering until it actually is used (if used at least once, we can cache the metadata string in the logger though; discussed in depth more with Tom in the "exploring" PR I made to the proposal). The rationale is to not penalize performance and have to avoid useful metadata that adds costs "up front", rather than costing only when it is in use in logging (while it would always be there in "the context" but as the raw object, so no overhead there.

MetadataValue sounds fine as a container. However the case string(String) does not solve the above issue, one still would always have to render the string when populating the metadata, regardless if it will be actually printed or not. It would have to be : () -> String I suppose; though we could offer both then, string(:String) and lazyString(:() -> String) perhaps?

Having that said, I need to do more actual benchmarking and “homework” before committing fully here... looking at some examples I have in mind and simple checks I did it seems it should definitely help... but I’ll do more homework on this soon (now stuck in airplane for many hours tho :-))

As for what "container types" to support in it I'm less opinionated. Perhaps just dictionary so things can express nesting would be good enough™. Seems to me like it is general enough to be able to cover many cases.

WDYT?


(Johannes Weiss) #57

No, you don’t need to change it, by default it’ll just log to stdout.

Yes, you can do that. That would require you to

Logging.bootstrap(MyFileSystemLoggingHandler.self)

You could either implement class MyFileSystemLoggignHandler yourself or more advisable you would use a package that provides such a LogHandler which formats it to your liking.

Why aren’t we providing that here? This is just the API, there will hopefully be plenty of concrete logging packages we will then work with all packages that adopt the API without further changes.


(Johannes Weiss) #58

Yes, that would work.

As discussed earlier with @artemredkin and others I’ll add a metadata parameter to each of the logging functions when I’ll put together a revision (very early next year) of this proposal. That parameter will also be @autoclosure which will delay the string rendering.

But I reckon you will also want the ability to get logger[metadataKey: “foo”] = .lazy({ makeExpensiveString })?

Performance-wise this should be okay as we’ll only allocate (the closure context) for all the lazy ones and not the strict ones... I’ll think about it but I think I can be convinced.

@graskind you also asked for more general meta-data values, does this sound okay? @bhawkeslewis does this cover your use-cases? We could even make the MetadataValue both String and DictionaryLiteralConvertible so unless you’d use .lazy you wouldn’t even know it’s not an Any.


(Alejandro Martinez) #59

Although I'm really excited for server logging and I agree it's really important and needs maybe a different set of requirements, I would love to see it used also for application development.

I can see this flexibility be really good for apps to be able to send logs to different services (Fabric, analytics, inhouse, etc).


(Paul Solt) #60

Thank you for working on this @johannesweiss and @tomerd

  1. Are there any considerations that I need to keep in mind if I write a file system logging handler?

  2. Maybe this is a beginner question, but is it common to put "main()" functions in enum types? What's the rational on that (from your tests)?