Log Levels guidelines #19
Conversation
Co-authored-by: Tim Condon <0xTim@users.noreply.github.com>
Co-authored-by: Kaitlin Mahar <kaitlinmahar@gmail.com>
Co-authored-by: tomer doron <tomerd@apple.com>
Co-authored-by: tomer doron <tomerd@apple.com>
| "connection.id": "\(connnection.id)", | ||
| "connection.peer": "\(connection.peer)", | ||
| "connections.total": "\(connections.count)" |
There was a problem hiding this comment.
Do we want to give any guidance on the formatting of metadata keys?
camelCase vs. snake_case vs. snake_case but with dots? prefixes for libraries?
There was a problem hiding this comment.
I currently use ahc:request-url (although AHC itself still uses ahc-request-id which was my previous preferred style :P), ie. short library ID then colon, then whatever-the-name-of-this-case-is
There was a problem hiding this comment.
well i could see problems with the colon in some query interfaces. anyway. whatever we decide on, i think we should write this down somewhere, to get some consistency.
There was a problem hiding this comment.
I'm not sure what various collector systems survive but a typical "key separator" is . because those can treat things as "well, basically it's json keys". I'll add it as n idea but i don't think we have a strong recommendation here.
log-levels.md
Outdated
|
|
||
| And a minor yet important hint: avoid inserting newlines and other control characters into log statements (!). Many log aggregation systems assume that a single line in a logged output is specifically "one log statement" which can accidentally break if we log not sanitized, potentially multi-line, strings. This isn't a problem for _all_ log backends, e.g. some will automatically sanitize and form a JSON payload with `{message: "..."}` before emitting it to a backend service collecting the logs, but plain old stream (or file) loggers usually assume that one line equals one log statement - it also makes grepping through logs more reliable. | ||
|
|
||
| #### Logging with Correlation IDs / Trace IDs |
There was a problem hiding this comment.
I think we should go into some detail regarding background/connection loggers for longer running services/clients. I mean the kind of that we inject into
It is worth mentioning that those long running instances in normal circumstances should not be started with a logger that already has a correlation id attached.
There was a problem hiding this comment.
It is worth mentioning that those long running instances in normal circumstances should not be started with a logger that already has a correlation id attached.
That is specifically the reason swift-distributed-tracing logging context / baggage is designed like it is. Specifically, these are called "top level" logging contexts: https://apple.github.io/swift-distributed-tracing-baggage/docs/current/Baggage/Structs/DefaultLoggingContext.html#/s:7Baggage21DefaultLoggingContextV8topLevel6loggerAC0C06LoggerV_tFZ and they don't contain a baggage, as such, they would not contain correlation IDs.
Really, whenever we talk about any correlation IDs we should be thinking in terms of LoggingContext and tracing APIs. Using "just logger metadata" as carrying these is a workaround rather than the proper way IMHO.
There was a problem hiding this comment.
I can explain this a bit more here, thanks!
|
|
||
| - to report errors which the end-user of the library has the means of logging themselfes, e.g. if a database driver fails to fetch all rows of a query, it should not log an error or warning, but instead e.g. error the stream of values (or function, async function, or even the async sequence) that was representing the returned values. | ||
| - since the end-user is consuming these values, and has a mean of reporting (or swallowing) this error, the library should not log anything on their behalf. | ||
| - never report as warnings which is merely an information, e.g. "weird header detected" may look like a good idea to log as a warning at first sight, however if the "weird header" is simply a misconfigured client (or just a "weird browser") you may be accidentally completely flooding an end-users logs with these "weird header" warnings (!) |
There was a problem hiding this comment.
We might want to have an additional explanation as to why not to log a warning once, then fall back to debug/trace. (Must always check an atomic)
There was a problem hiding this comment.
I expanded it a bit
It may be tempting to implement a "log as warning only once" technique for per-request style situations which may be almost important enough to be a warning, but should not be logged repeatedly after all. Authors may think of smart techniques to log a warning only once per "weird header discovered" and later on log the same issue on a different, e.g. trace level... Such techniques result in confusing hard to debug logs, where developers of a system unaware of the stateful nature of the logging would be left confused when trying to reproduce the issue.
- For example, if a developer spots such warning in a productiuon system, they may attempt to reproduce it thinking that it only happens in the production environment. However if the logging systems' log level choice is sateful they may actually be successfully reproducing the issue but never seeing it manifest. For this, and related performance reasons (as implementing "only once per X" implies growing storage and per-request additional checking requirements), it is not recommended to apply this pattern.
|
Awesome, thanks @kmahar, I think I'll go over again and perhaps let's merge it? |
+1 |
|
Okey I think I covered all feedback, happy to keep iterating on this as we go. Going to merge this as a good starting point though 👍 Thanks for all the feedback! |
Work in progress about log level guidelines.