log/slog: remove calls to Value.Resolve from slog core #59292
Description
The logging methods of slog resolve values after they check that they are enabled and before calling Handler.Handle. This was done so LogValue methods whose result may vary behave the same way independent of handler implementation.
The problem is that resolving values in a Group must either be done in place, inviting aliasing bugs and data races, or be done on a copy of the slice, which can be expensive.
The discussion here shows that there isn't much need for varying LogValue methods. The main use case of LogValue is providing a way for type authors to provide structured, format-independent log output, which is deterministic. When varying output is required, all that is needed to make sure it doesn't run afoul of a preformatting Handler.WithAttrs method is a simple handler wrapper that disables preformatting.
So I propose removing the calls to Value.Resolve from slog proper and adding them back to the built-in handlers, essentially reverting https://go.dev/cl/464100. Checks for proper calls to Resolve will be added to the slogtest package.
slog proposal: #56345.
Original top post preserved below for posterity.
I'm not sure if this is a bug, or acceptable behavior.
A Group value holds a []Attr. Calling Resolve on the Group value will destructively modify the slice elements with their resolutions.
For example, say we have a simple LogValuer like this:
type replace struct { v slog.Value }
func (r replace) LogValue() slog.Value { return r.v }
Then we construct a Group value containing a replace:
g := slog.GroupValue(slog.Int("a", 1), slog.Any("r", replace{slog.IntValue(2)}))
The replace is at g.Group()[1].Value.
After calling g.Resolve(), the contents of g.Group()[1].Value will be modified to IntValue(2). You can see this behavior at https://go.dev/play/p/UqjXZ76o78K.
The implementation behaves this way to avoid making a copy of the slice when resolving.
Most of the time this behavior won't be noticeable. Code that constructs groups on the fly, like
logger.Info("message", slog.Group("g", slog.Int("a", 1), slog.Any("r", replace{slog.IntValue(2)})))
or
func (lv myLogValuer) LogValue() slog.Value {
return slog.GroupValue(slog.String("a", lv.a), slog.Any("r", replace{slog.StringValue(lv.b)}))
will not observe the modification. But code that retains groups, like
commonAttrs := slog.Group("", slog.Int("a", 1), slog.Any("r", replace{slog.IntValue(2)}))
can observe the change. And if commonAttrs is shared among multiple goroutines, a data race can happen. Also, the resolution will happen only once, rather than for each log event. That may be fine if the LogValuer's purpose is just to delay an expensive, deterministic computation until it is needed, but it will be wrong if the intent is to generate a value that varies with the log event, like a timestamp.
The alternatives I see are:
-
Leave this behavior as it is, a rare "gotcha" that is forgivable because it improves performance. (Of course, we would document it.)
-
Copy the
[]Attrif it contains any LogValuers. This can result in a lot of copying when Group values nest. A Group value containing two other Group values each of which contains a LogValuer will result in three slice copies for each call toResolve, andResolvewill be called on every log event. -
This situation arises from our decision to call
Resolvebefore calling a handler. We made that choice both for the convenience of handler writers and to make resolution more deterministic. We could revisit it. If a handler performs resolution on the fly, as it is producing output, then it need not copy the group slice. -
We could say that slog resolves top-level Attrs, but not those inside groups. That is probably too subtle.
slog proposal: #56345.
/cc @ChrisHines, @ianthehat