Since it doesn't seem we're aligned about some important bits of the proposal implementation I took some time to formulate the problems that make the "partial" implementation attempt here not acceptable. I'm in favor of the proposal, but we must land it in the correct way, without locking down evolution and causing performance issues.
The way we designed swift logging hinges on two aspects, Logger must :
- a) not have performance penalties which log handlers cannot workaround; i.e. "logic" must live in
LogHandler, never in Logger.
- b) not be too-opinionated to the point that prevents log handlers from achieving their goals, which we might not even know about in detail e.g. sampling, throttling, forwarding errors to other 3rd party APIs etc.
Performance
The idea to serialize the error into strings "early" is flawed and cannot work performantly, id can only be seen as backwards compatibility until LogHandlers are updates to adopt the new LogHandler.log() method with the new :error: (some Error)?) parameter.
This is because while we may attempt to implement the serialization "lazy" in Logger layer:
@inlinable
public func traceAnyError(
_ message: @autoclosure () -> Logger.Message,
error: (any Error)? = nil,
metadata: @autoclosure () -> Logger.Metadata? = nil,
source: @autoclosure () -> String? = nil,
file: String = #fileID,
function: String = #function,
line: UInt = #line
) {
#if !MaxLogLevelDebug && !MaxLogLevelInfo && !MaxLogLevelNotice && !MaxLogLevelWarning && !MaxLogLevelError && !MaxLogLevelCritical && !MaxLogLevelNone
self._log(
level: .trace,
message(),
metadata: {
var combinedMetadata = metadata() ?? [:]
if let error = error {
combinedMetadata["error"] = "\(error)"
combinedMetadata["error.type"] = "\(String(reflecting: type(of: error)))"
}
return combinedMetadata
}(),
source: source(),
file: file,
function: function,
line: line
)
#endif
}
You might think this is fine because we're being lazy in metadata:, this is not entirely true however. We just lost the ability for the log handler to sample log statements. This can be a real technique employed especially at debug or trace levels, and this implementation approach prevents it entirely, because forwarding to LogHandler.log materializes the metadata:
@inlinable
package func _log(
level: Logger.Level,
_ message: @autoclosure () -> Logger.Message,
metadata: @autoclosure () -> Logger.Metadata? = nil,
source: @autoclosure () -> String? = nil,
file: String = #fileID,
function: String = #function,
line: UInt = #line
) {
if self.logLevel <= level {
self.handler.log(
level: level,
message: message(),
metadata: metadata(), <<<<<
source: source() ?? Logger.currentModule(fileID: (file)),
file: file,
function: function,
line: line
)
}
}
Which is forced to form the metadata:
// LogHandler
func log(
level: Logger.Level,
message: Logger.Message,
metadata: Logger.Metadata?, <<<<
source: String,
file: String,
function: String,
line: UInt
)
IMHO this is unacceptable to degrade the performance of the NoOp handler like this (and it falls out of the design principles discussed below -- the Logger must not perform "logic").
This means it is impossible for a log handler to avoid rendering the strings for the error. Even if your target is emitting backpressure and you must drop trace logs for example, you're still causing the cost of the error rendering. The difference is significant, compare passing an error and not passing one (this is to a NoOpLogger!):
In comparison, the complete approach forwarding the error and only serializing it in the LogHandler:
// LogHandler
func log(
level: Logger.Level,
message: Logger.Message,
metadata: Logger.Metadata?,
error: (some Error)?,
source: String,
file: String,
function: String,
line: UInt
)
// Logging
@inlinable
package func _log(
level: Logger.Level,
_ message: @autoclosure () -> Logger.Message,
metadata: @autoclosure () -> Logger.Metadata? = nil,
source: @autoclosure () -> String? = nil,
error: (some Error)?,
file: String = #fileID,
function: String = #function,
line: UInt = #line
) {
if self.logLevel <= level {
self.handler.log(
level: level,
message: message(),
metadata: metadata(),
error: error,
source: source() ?? Logger.currentModule(fileID: (file)),
file: file,
function: function,
line: line
)
}
}
If the log handler were to actually print (and therefore materialize the error -> strings), then it'll get the performance hit and get down to the 300k/s, that's fine. But it's up to the log handler to make that decision or not. Again, there may be factors swift-log does not, and cannot, know about, at play here so we must leave these decisions to LogHandler. None of those decisions are possible if we string-ify-too-early.
some Error vs any Error
From the previous benchmark we can observe the difference in behavior. The implicit existential opening, when we:
do { try ... } catch { logger.info(error: error) }
is actually quite costly, and gives the worst performance of all the cases in the "pass any/some Error all the way to LogHandler" benchmarks (last line):
Passing any Error generally has roughly the same performance because when it is thrown, it already is existential, so there's no "re-packing".
The best of course is the "some Error passing + an concrete (typed throw)" however I kinda think it is less common for typed throws to exist rather than the untyped throws -- that's just the reallity and direction of Swift as a whole. Typed throws are going to be more rare than untyped throws, so looking at these numbers I guess we may want to proceed with (any Error)? in all the parameters...
The with_nil benchmark isn't passing explicitly but just loggerPassAny.errorPassAnyError("Operation completed") by the way, so this 10M there confirms we've not regressed the "not passing an error" case for NoOpLogger.
Composition
swift-log must compose well with other libraries, and the fact is that Error is the part of the Swift's lingua franca, and APIs express error passing as throwing or passing errors.
Doing some weird trickery with stringifying early because "someone might maybe check the error" is unreasonable and a baffling design choice. Error is the currency type.
This matters for composition; it is entirely reasonable and correct for 3rd party logging libraries to expect to be passed an Error which they then serialize however they want. It's up to them to e.g. use "error.kind": ... or `"error.type": ..." -- again, this is entirely out of scope for swift-log and is a backend decision. LogHandlers and/or 3rd party libraries handle this decision, NOT swift-log. (with the exception of the StdOutLogHandler which we're shipping, yeah there we'll just pick something -- like the proposal proposes here).
Examples of APIs which accept Error and we want to forward to:
I don't see why swift-log should be in the business of making any of these libraries life's hader. It does not matter that all of them will just to-string the error, some of them may check NSError or something else, but either way, passing Error IS the right design for the Swift language and ecosystem.
Swift Log Design Principles
A general design principle in such libraries is to "lose" information as late as possible.
Another way to look at this is that LogHandler is the logic and Logger must not have logic in it because it is too early in the chain to make any decisions correctly.
Therefore losing all information immediately and taking the serialization hit in the Logger layer is not acceptable.
It's entirely up to log handlers to determine how to handle a log() call, they may employ sampling or be rate throttled by an API where they're emitting logs or whatnot. swift-log cannot know these things, and therefore must remain open to log handlers making these decisions.
Hardcoding serializing into specific keys means APIs may have to "re-shuffle" those values into new keys, or even construct some "FakeError" that pretends to be the original error. This also prevents future evolution, if Error ever were to gain new protocol requirements that we could rely on -- we did in fact talk about errors with backtraces after all at some point -- it is entirely reasonable for log handlers to be aware of such protocols.
I'm wholly opposed to saying "error.type" are "API", for reasons of fear that someone might inspect an error. So what? They already can smuggle anything in metadata because we explicitly provided this escape hatch ages ago: Metadata's CustomStringConvertible is exactly such escape hatch of "pass anything" that you're so worried about, so this doesn't change a thing. The "hole" exists, by design, and was not abused by any log handler in the pas.
--
Long story short, I hope this comprehensive writeup helped folks understand that just serializing the errors into some dictionary key at the Logger level is not acceptable and can only be an temporary step towards LogHandlers adopting a new log() which also accepts the passed Error.
Accepting "half" this idea and making strings "public API" is not sufficient and would cause problems for the ecosystem.
--
I'm supportive of the proposal, however it has to be "both" parts:
- we add the error parameters on the Logger level
- we add a log() which accepts a new Error parameter
- we provide a compatibility shim if the new method was not implemented; To be discussed: if we serialize the error into metadata there or not, IMHO, given my current performance findings we do not -- and you only get the new error information once your LogHandler updates to it.
You can find all prototypes and benchmarks used in the writeup here: GitHub - ktoso/swift-log at experiments-error I did use claude to help slap together the boilerplate here, but I've verified the important parts of the code executed and how/when what happens to the error.
