[ruby-core:123357] [Ruby Feature#21619] logger: Context API
Issue #21619 has been reported by chucke (Tiago Cardoso). ---------------------------------------- Feature #21619: logger: Context API https://bugs.ruby-lang.org/issues/21619 * Author: chucke (Tiago Cardoso) * Status: Open ---------------------------------------- The logger gem is notoriously simple to use, but hard to extend. One can only observe a few of the gems that added tags / json / logstash formatting support to see the same functionality reimplemented in "same but different" ways. For example, `logstash-logger`, `semantic_logger`, or the `activesupport` tagged logger handle tagging in virtually the same way. sidekiq has a (IMO) convoluted API to add per-job context to log message, which somewhat works as long as one does not need per-fiber contexts. Several other "log as JSON" gems fight with the same issues to deliver something that works, and either heavily patch the `Logger` or `Logger::Formatter` or circumvent its usage altogether. The default formatter already supports per-message context, but that context is limited to a few "static" parameters (severity, current time, process id, progname) which are logged in the following manner: Logger.new(STDOUT).info("foo") #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo There is currently no way to add more parameters, or (if necessary) override the existing ones. These patterns could be coalesced into the main logger gem in a way that extending it should be simpler than what it is right now. == Context API This is a proposal to extend the Logger API in a way that both per-scope or per-message context can be passed downstream to the formatter(s), and logged accordingly: logger = Logger.new(STDOUT) logger.info("foo") #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo logger.info { "foo" } #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo # per message context logger.info("foo", context: {user_id: 1}) #=> I, [user_id=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo logger.info(context: { user_id: 1 }) { "foo" } #=> I, [user_id=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo # or logger.info("foo", context: ["alwaysblue"]) #=> I, [alwaysblue] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo. # per message context logger.with_context(a: 1) do logger.info("foo") #=> I, [a=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo end logger.with_context(a: 1) do logger.with_context(b: 2) do logger.info("foo") #=> I, [a=1] [b=2] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo end end This API would achieve the same goal as the examples mentioned above, or the sidekiq `Logger#with` function, in a standard manner, where formatters would just receive context as a bunch of key-value pairs (or an array of "string-able" objects, both work for me). == PR A proposal of the feature in logger can be found in https://github.com/ruby/logger/pull/132. It builds on top of the earlier addition of Logger#with_level, which does the scope-based change in a similar way, but only for the level, storing the context per fiber in the logger. Once context is standardized, adding i.e. a JSON or logstash formatter would be much simpler, formatters would receive it in the method call (instead of the indirection of using thread variables, which is what most mentioned implementations use). Drawbacks One of the main benefits of using the log.info { "msg" } idiom is that the "msg" string never gets allocated if the logger severity level skips logging the message. In the current proposal, the context is always present, and will result in a few allocations bubbling downstream. I'm not sure how important or negligible this concern is though. A concern here would be backwards compatibility, as currently, custom formatters do not expose a method signature which allows sending kwargs. Perhaps there's a way to introspect the formatter method to infer whether the signature supports kwargs, but even if it does, the check does have its cost. Other questions were raised during the PR review by jeremy evans and nevans. There's more discussion in the PR about pros and cons for each, so I'll just list them here: * supporting `with_context` block `:context` kwarg unnecessarily complex, proposal should stick to the former. * context should be stores in formatter rather than logger. * supporting hash and array as context in unnecessary complexity, pick the former * context log format should be like go, concatenated at the end of the message * extend formatter API to help users avoid leaking PII data -- https://bugs.ruby-lang.org/
Issue #21619 has been updated by byroot (Jean Boussier).
`with_context`
The problem with these sort of APIs is that it has to know what the execution model is. I see that in your PR you store the current context per `Fiber`. If you run an application with a threaded model, this isn't what you want. You want instead to use a thread local. Rails can get away with this sort of APIs because it is in control of what the execution model is, but a library like logger can't. ---------------------------------------- Feature #21619: logger: Context API https://bugs.ruby-lang.org/issues/21619#change-114728 * Author: chucke (Tiago Cardoso) * Status: Open ---------------------------------------- The logger gem is notoriously simple to use, but hard to extend. One can only observe a few of the gems that added tags / json / logstash formatting support to see the same functionality reimplemented in "same but different" ways. For example, `logstash-logger`, `semantic_logger`, or the `activesupport` tagged logger handle tagging in virtually the same way. sidekiq has a (IMO) convoluted API to add per-job context to log message, which somewhat works as long as one does not need per-fiber contexts. Several other "log as JSON" gems fight with the same issues to deliver something that works, and either heavily patch the `Logger` or `Logger::Formatter` or circumvent its usage altogether. The default formatter already supports per-message context, but that context is limited to a few "static" parameters (severity, current time, process id, progname) which are logged in the following manner: Logger.new(STDOUT).info("foo") #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo There is currently no way to add more parameters, or (if necessary) override the existing ones. These patterns could be coalesced into the main logger gem in a way that extending it should be simpler than what it is right now. == Context API This is a proposal to extend the Logger API in a way that both per-scope or per-message context can be passed downstream to the formatter(s), and logged accordingly: logger = Logger.new(STDOUT) logger.info("foo") #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo logger.info { "foo" } #=> I, [2025-08-13T15:00:03.830782 #5374] INFO -- : foo # per message context logger.info("foo", context: {user_id: 1}) #=> I, [user_id=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo logger.info(context: { user_id: 1 }) { "foo" } #=> I, [user_id=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo # or logger.info("foo", context: ["alwaysblue"]) #=> I, [alwaysblue] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo. # per message context logger.with_context(a: 1) do logger.info("foo") #=> I, [a=1] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo end logger.with_context(a: 1) do logger.with_context(b: 2) do logger.info("foo") #=> I, [a=1] [b=2] [2025-08-13T15:00:03.830782 #5374] INFO -- : foo end end This API would achieve the same goal as the examples mentioned above, or the sidekiq `Logger#with` function, in a standard manner, where formatters would just receive context as a bunch of key-value pairs (or an array of "string-able" objects, both work for me). == PR A proposal of the feature in logger can be found in https://github.com/ruby/logger/pull/132. It builds on top of the earlier addition of Logger#with_level, which does the scope-based change in a similar way, but only for the level, storing the context per fiber in the logger. Once context is standardized, adding i.e. a JSON or logstash formatter would be much simpler, formatters would receive it in the method call (instead of the indirection of using thread variables, which is what most mentioned implementations use). Drawbacks One of the main benefits of using the log.info { "msg" } idiom is that the "msg" string never gets allocated if the logger severity level skips logging the message. In the current proposal, the context is always present, and will result in a few allocations bubbling downstream. I'm not sure how important or negligible this concern is though. A concern here would be backwards compatibility, as currently, custom formatters do not expose a method signature which allows sending kwargs. Perhaps there's a way to introspect the formatter method to infer whether the signature supports kwargs, but even if it does, the check does have its cost. Other questions were raised during the PR review by jeremy evans and nevans. There's more discussion in the PR about pros and cons for each, so I'll just list them here: * supporting `with_context` block `:context` kwarg unnecessarily complex, proposal should stick to the former. * context should be stores in formatter rather than logger. * supporting hash and array as context in unnecessary complexity, pick the former * context log format should be like go, concatenated at the end of the message * extend formatter API to help users avoid leaking PII data -- https://bugs.ruby-lang.org/
participants (2)
-
byroot (Jean Boussier) -
chucke (Tiago Cardoso)