Leveled fields: Fields present only at certain log levels

[abhinav]

An issue that users sometimes have is this:

They have a log statement like the following,

logger.Info("processing request", zap.String("fromUser", fromUser))

They would like to include additional information in that log statement, but only if the debug level is enabled.

Currently, the options are:

1. Copy paste the log statement

if debugLevel {
  logger.Info("processing request", zap.String("fromUser", fromUser), zap.Object("request", request))
} else {
  logger.Info("processing request", zap.String("fromUser", fromUser))
}

2. Add another log statement

logger.Info("processing request", zap.String("fromUser", fromUser))
logger.Debug("processing request", zap.Object("request", request))

3. custom helpers like the following:

func levelField(log *zap.Logger, lvl zap.Level, field zap.Field) zap.Field {
  if !log.Core().Enabled(lvl) { return zap.Skip() }
  return field
}

logger.Info("processing request",
  zap.String("fromUser", fromUser),
  levelField(logger, zap.DebugLevel, zap.Object("request", request)))

I think it might be valuable for Zap to natively provide some concept of "leveled fields"—fields present only at certain log levels—based on something like the levelField helper above.

I don't have an exact design in mind, but Zap-native support for something like this would likely be able to drop that extra log argument.

[abhinav]

Summarizing discussion with @mway here:

Matt proposed the following options:

1. Add options to existing field constructors.

   func String(key, value string, opts ...FieldOption)
   
   type FieldOption
     func FieldLevel(Level) FieldOption
     
   // Usage:
   // logger.Info("msg", zap.String("foo", "bar", zap.FieldLevel(zap.DebugLevel)))

2. Parallel constructors.

   func String(key, value string)
   func StringLevel(key, value string, lvl Level)
   
   // Usage:
   // logger.Info("msg", zap.StringLevel("foo", "bar", zap.DebugLevel))

3. Method on zapcore.Field.

   package zapcore
   
   type Field struct{ ... }
       func (Field) IfLevel(Level) Field
   // Usage:
   // logger.Info("msg", zap.String("foo", "bar").IfLevel(zap.DebugLevel))

4. Name-based filtering at the logger level:

   func WithFieldLevelFilters(map[string]Level) Option
   
   // Usage:
   // logger = zap.New(..., zap.WithFieldLevelFilters(map[string]zap.Level{
   //   "foo": zap.DebugLevel,
   // }))
   // logger.Info("msg", zap.String("foo", "bar"))

---

My thoughts on the options:

1. Breaking change. I would like to avoid that for such a small feature.
2. Too much noise. It'll double the number of field constructors.
3. I like this. Maybe we can come up with a better name.
4. Stringly-typed API. Would prefer to avoid. Requires field name to be stable/unique across the application.

So if we were going to solve this problem, based on current options, I lean (3).
I'm also okay with saying that this isn't something Zap should support natively at this time,
and that it's okay for users to have to write the helper function I suggested above.

[prashantv]

I think this is a useful feature, and more generally have found cases where the fields to log depend on some condition, and I find myself writing code like:

fieldsToLog := []zap.Field{...}
if someCondition {
  fieldsToLog = append(fieldsToLog, zap.String(...), zap.Int(...))
}

Looking at the options, agree on (1), (2), and (4) with @abhinav.

Re: 3: This is an interesting idea, and could be used for more generic helpers, like func (Field) If(condition bool) Field as well. The chaining approach does feel like a builder which we don't see too frequently in Go.

Another variant (more similar to the levelIfField is to have a top-level function: func IfLevel(level Level, fields... Field) Field, which may be a little more verbose, but it also allows providing multiple fields at once, so if there's more than one field being added, it'll likely be less noise.

We could take that idea a little further, and have field constructors per-level, e.g., func DebugField(Field) Field (could also take multiple fields), which might be good for readability too:

logger.Info("my message",
  zap.String("foo", "bar"),
  zap.DebugField(zap.String("debugOnly", "baz")),
)

[abhinav]

Oh, I like the idea of the top-level functions. Although I suspect that accepting multiple fields there will make that a one-alloc-each operation because we'll need to be able to turn []Field into a Field with zap.Inline—which may or may not be a dealbreaker here.

[prashantv]

True, may want to separate the single-field and multi-field functions.

[mway]

I think we should start with single-field filtering and extend to []Field if we see a compelling need. I don't personally think it's worth the complexity/overhead to support a variable number fields for callsite filtering, at least not initially:

logger.Info(
  "handled request",
  zap.String("caller", "..."),
  zap.String("method", "..."),
  zap.DebugField(zap.String("debug1", "...")),
  zap.DebugField(zap.String("debug2", "...")),
  zap.DebugField(zap.String("debug3", "...")),
)

is arguably not worse than

logger.Info(
  "handled request",
  zap.String("caller", "..."),
  zap.String("method", "..."),
  zap.DebugFields(
    zap.String("debug1", "..."),
    zap.String("debug2", "..."),
    zap.String("debug3", "..."),
  ),
)

IMO, if we want to deal with []Field as a semantic concept (i.e., "this subset of message fields relate to each other in some special way compared to the rest of the fields"), it might be better to formalize "field groups" as a concept first (if we feel strongly about discrete groups of fields), and then subsequently add support for group-level filtering.

We should probably also be clear about whether all levels add value, or only some. I can't think of a useful case in which a PanicField, FatalField, ErrorField, or even WarnField would be useful, but maybe such a case does exist. Even so, it's probably worth starting with DebugField (and maybe InfoField, if we're confident enough) and feeling it out first.

It may also be useful (if possible) to prototype the API in an experimental package (e.g. go.uber.org/zap/x/filter) first. If we can do that, and if we're not sold on APIs and/or the usefulness of filtering at some log levels, then perhaps a more general version would be good to start (e.g. filter.Field(zapcore.Level, zap.Field) zap.Field) so we can gather data/use cases before committing.

[ozfive]

I think we should start with single-field filtering and extend to []Field if we see a compelling need. I don't personally think it's worth the complexity/overhead to support a variable number fields for callsite filtering, at least not initially:

logger.Info(
  "handled request",
  zap.String("caller", "..."),
  zap.String("method", "..."),
  zap.DebugField(zap.String("debug1", "...")),
  zap.DebugField(zap.String("debug2", "...")),
  zap.DebugField(zap.String("debug3", "...")),
)

is arguably not worse than

logger.Info(
  "handled request",
  zap.String("caller", "..."),
  zap.String("method", "..."),
  zap.DebugFields(
    zap.String("debug1", "..."),
    zap.String("debug2", "..."),
    zap.String("debug3", "..."),
  ),
)

IMO, if we want to deal with []Field as a semantic concept (i.e., "this subset of message fields relate to each other in some special way compared to the rest of the fields"), it might be better to formalize "field groups" as a concept first (if we feel strongly about discrete groups of fields), and then subsequently add support for group-level filtering.

We should probably also be clear about whether all levels add value, or only some. I can't think of a useful case in which a PanicField, FatalField, ErrorField, or even WarnField would be useful, but maybe such a case does exist. Even so, it's probably worth starting with DebugField (and maybe InfoField, if we're confident enough) and feeling it out first.

It may also be useful (if possible) to prototype the API in an experimental package (e.g. go.uber.org/zap/x/filter) first. If we can do that, and if we're not sold on APIs and/or the usefulness of filtering at some log levels, then perhaps a more general version would be good to start (e.g. filter.Field(zapcore.Level, zap.Field) zap.Field) so we can gather data/use cases before committing.

If you do decide to add support for field groups in the future would you consider adding group-level filtering as well? Group level filtering would be useful in situations where you have multiple related fields that you only want to log at a certain log level. For example, let's say you have a set of fields related to HTTP requests and you only want to log them at the Debug level. You would define a "request" group that includes all of these fields and then filter the group based on log level.

So instead of:

logger.Debug("processing request",
  zap.String("url", req.URL.String()),
  zap.String("method", req.Method),
  zap.String("user-agent", req.UserAgent()),
  zap.Int("content-length", int(req.ContentLength)),
  zap.String("remote-addr", req.RemoteAddr),
  zap.String("proto", req.Proto),
)

You would do:

reqGroup := zap.Group("request", zap.String("url", req.URL.String()), zap.String("method", req.Method), zap.String("user-agent", req.UserAgent()), zap.Int("content-length", int(req.ContentLength)), zap.String("remote-addr", req.RemoteAddr), zap.String("proto", req.Proto))

logger.Debug("processing request",
  zap.Fields(reqGroup.Filter(zap.DebugLevel)),
)

This way, if you decide to add more fields to the "request" group later on, you can filter them all together without having to add individual filters for each field.

Some other ideas that I had around group-level filtering just now are

1. Allow named groups of fields: In addition to adding fields with zap.String(), zap.Int(), etc., users could create a named group of fields using a new zap.Group() function. This would return a Group object that has methods for adding fields to the group, as well as setting the log level for the group.

2. Filter by group: Users could specify a log level for each group, and then enable or disable logging of groups based on the level. For example:

g := zap.Group("user_info")
g.String("user_id", "123")
g.String("username", "jdoe")
g.Level(zap.DebugLevel) // Set debug level for this group

logger.Info("processing request", zap.Group("user_info"))

The last line would log only the fields in the "user_info" group, since it has a debug level set. If the logger was at info level, it would skip the group and only log the main message.

3. Aggregate fields for a group: When a log statement includes a group, the logger could aggregate all the fields in the group into a single field in the output. For example, the previous example might output something like:

{"level":"info","msg":"processing request","user_info":{"user_id":"123","username":"jdoe"}}

Hierarchical groups: Allow groups to be nested inside other groups, creating a hierarchical structure. This would allow for more complex filtering, where a parent group could be enabled or disabled based on its level and all child groups would inherit that level. For example:

g1 := zap.Group("foo")
g1.String("a", "1")

g2 := g1.Group("bar")
g2.String("b", "2")

g3 := g2.Group("baz")
g3.String("c", "3")

g1.Level(zap.DebugLevel)

logger.Info("processing request", zap.Group("foo"))

logger.Info("processing request", zap.Group("foo")) would only log the fields in the "foo" group, since it has a debug level set. Since "bar" and "baz" are child groups of "foo", they would also be logged even though they don't have a level set.

The key point would be to allow users to group related fields together and then selectively log those groups based on their level, without having to manually construct each log statement.

The introduction of "log contexts" for group-level filtering would be another concept. A log context would be a grouping of fields that are related to a particular context within the application. For example, you might have a "database" context with fields like "table_name", "query", "result_count", and so on. Another context might be "user" with fields like "user_id", "ip_address", "username", and so on

With log contexts, you could filter out entire contexts based on log level. For example, you might only want to log the "database" context at the debug level, but log everything else at the info level. This would allow you to easily see what's happening at the database level without cluttering up the logs with unnecessary information.

You would also have the ability to add fields to a context dynamically at runtime. For example, you might have a context for a specific request and you could add fields like "request_id" or "responsive_code" to that context as needed.

Another idea would be to allow for filtering based on the value of a field. For example you might only want to log requests that take longer than a certain amount of time, or only log errors that are related to a specific subsystem. This would require some way to define rules for which fields to match on and what values to match against.

[ChannyClaus]

took a stab at this #1251 - let me know if this is what you guys had in mind!