Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log/slog: remove calls to Value.Resolve from slog core #59292

Closed
jba opened this issue Mar 28, 2023 · 39 comments
Closed

log/slog: remove calls to Value.Resolve from slog core #59292

jba opened this issue Mar 28, 2023 · 39 comments

Comments

@jba
Copy link
Contributor

jba commented Mar 28, 2023

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 []Attr if 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 to Resolve, and Resolve will be called on every log event.

  • This situation arises from our decision to call Resolve before 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

@ChrisHines
Copy link
Contributor

I had a note in my early slog reviews to ask who owns the slice returned by Value.Group(), but I never mentioned it because there were so many bigger topics to talk about. I'm glad you're asking about it.

The Handler docs call out that the Handler owns the slice passed to WithAttr, so documenting something like that for the return of Group would be consistent with other areas of the package. But I think it is more risky since application code is more likely to manipulate slog.Values in arbitrary ways in many places while I would expect code that calls Handler.WithAttr to be much more limited and more highly tested.

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.

This situation arises from our decision to call Resolve before 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.

It seems to me that a decision is needed for the the primary use case and semantic for LogValuer so that it is clear to everyone how they work. On the one hand they are have been described as a way to lazily perform potentially expensive work, and on the other they are eagerly resolved to support the pre-formatting optimization. I think we need to pick one and make it fully consistent in the design to simplify the mental model of LogValuers. If we need both behaviors then maybe we need separate types for each.

I was actually expecting the outcome of the discussion around "deterministic resolution" to go the opposite direction from what it did. As I was implying in #56345 (comment), I still think that the following two code snippets should always produce the same output, even if v is a LogValuer that is not idempotent. I believe that because I think the simplest mental model for log.With is that it basically pre-registers attributes with the logger that get added to every subsequent log call. I don't think we should make users of slog.Logger think about it any more than that because it will become a source of unexpected bugs and surprises if we do. I want to be able to factor out common log attributes with log.With aggressively because that helps ensure consistency in the logs. I don't want to think about whether or not that somehow changes what is in the final log output, the logging package should "just work".

func foo(log *slog.Logger, v any) {
    for i := 0; i < 5; i++ {
        log.Info("", "v", v, "i", i)
    }
}

func foo2(log *slog.Logger, v any) {
    log = log.With("v", v)
    for i := 0; i < 5; i++ {
        log.Info("", "i", i)
    }
}

@ianthehat
Copy link

For my perspective, I can find no beneficial use for a LogValuer, and in fact all the times I have tried it has made the code worse rather than better. It provides no advantage that I can see over just invoking a function that returns a slog.Attr in the call to the logging function, but produces harder to understand code.
The one case where I actually wanted it, I truly wanted a lazy evaluation, so I did it with a String() method instead that does no work unless the attribute is actually printed.
If it were up to me I would just eliminate the entire concept at this point, assuming we keep it though, I would run with safety and ease of comprehension over performance on this one, there are other ways to achieve performance if really needed. I would make the copy, so that the resolve is called for each line that uses the group in a log.

@jba
Copy link
Contributor Author

jba commented Mar 28, 2023

just invoking a function that returns a slog.Attr in the call to the logging function

That function will run even if the logger is disabled. That's the main advantage.

@jba
Copy link
Contributor Author

jba commented Mar 28, 2023

I truly wanted a lazy evaluation, so I did it with a String() method instead that does no work unless the attribute is actually printed.

How is LogValue insufficiently lazy? Once the enabled check succeeds, what would get in the way of output?

The problems with String are that it assumes something about the output, and you can't add any structure. By returning a Value, possibly a Group, you can make sure the Handler outputs something that makes sense for it and can have structure.

@ianthehat
Copy link

The only case where the value creation is expensive enough that I don't want to do it unless the logger is enabled, I end up needing to add the enabled check outside the log call to avoid the cost of creating a closure anyway, I have yet to find an expensive enough to defer but does not need specific local values case.
The insufficiently lazy was because I was handing off output writing to a different goroutine (inside the handler), so I wanted the work to be done in that thread instead.

@rsc
Copy link
Contributor

rsc commented Mar 28, 2023

We can always add LogValuer back later. Perhaps removing it for now would make sense.

The only way I see to fix the semantics in a reasonable way is for GroupValue and similar things to resolve the values eagerly, before storing them. And then Ian's point is extra true, that callers can do that themselves.

What is the compelling reason to keep it?

@jba
Copy link
Contributor Author

jba commented Mar 28, 2023

What is the compelling reason to keep it?

I looked back over the discussion. The original motivation was giving type authors the ability to describe how to log their type in a format-agnostic way. You can implement a String method on your type, but you don't get structure. You can implement json.Marshaler and TextMarshaler, but what if the handler uses a different format? Back in August,
@akshayjshah, one of the original Zap authors, wrote

It's convenient for end users to let types implement their own serialization logic (a la json.Marshaler or zap.ObjectMarshaler). I don't see an equivalent here. How do you imagine types customizing their representation in logs? Implementing encoding-specific interfaces like json.Marshaler is difficult, since there's no telling what encoding the owner of main prefers.

@thockin agreed:

logr defines such a method, too. It seemed "obviously useful"...

So the primary motivation is not performance. But I still think you have to call LogValue after Enabled, or the performance will be so poor that people would go back to using String and json.Marshaler.

The other use case, generating a different value on each call, was important to go-kit because it used that for timestamps and (if I recall) stack traces. But I haven't seen any examples of that that would make sense for slog. @ChrisHines, do you have any?

So I'm in favor of dropping the resolution of values in the slog core, and moving it back to the handlers. That's more error-prone work for the handlers, but the slogtest package can validate them. It means a LogValuer whose output depends on when and where it is called could produce different results with different handlers, but we could advise against doing that, and maybe no one really wants to anyway.

I'll ping the original issue to see if anyone there has more to add. I don't think we need to make a decision right away.

@ChrisHines
Copy link
Contributor

ChrisHines commented Mar 28, 2023

The other use case, generating a different value on each call, was important to go-kit because it used that for timestamps and (if I recall) stack traces. But I haven't seen any examples of that that would make sense for slog. @ChrisHines, do you have any?

That's right, go-kit/log has no "special" attributes so we needed a way for applications to register values using a With function that generate dynamic values. Our solution was a Valuer function type that is given special treatment by the Logger returned by With functions. See also Dynamic Contextual Values and the associated example.

Although this feature was primarily motivated by timestamps and caller information, it is a general tool that is not specific to those uses in any way. [1]

Outside of the Valuers that go-kit/log provides I have also written the following code a few times for use in tests. I have found that when I care about the timing of log messages in test output it is more useful to have a stopwatch instead of absolute timestamps.

// Since returns a log.Valuer that reports the time elapsed since start.
func Since(start time.Time) log.Valuer {
	return func() interface{} {
		return time.Since(start)
	}
}

I was able to find one other use case for dynamic values in a private project. It is for logging the current value of a global variable that holds some version information updated asynchronously by polling the contents of a local file. That version information is included in every log message written by the application. I think it's a pretty weird behavior and I don't really like it, but .... 🤷 .


[1]: I think it is worth pointing out that the implementation details of Valuer and the With functions in go-kit/log were driven by the necessity to keep a constant stack depth through multiple calls of With so that the Caller valuer would work correctly as explained in the comment starting here: https://github.com/go-kit/log/blob/0b69c7049332e99c25d5fd0f4d08317cfe45e7d8/log.go#L114. If it weren't for the need to maintain the constant stack depth we may never have come up with the Valuer idea and just leaned on the general decorator pattern of the core go-kit Logger interface to add timestamps and other dynamic values. That said, I think flattening the call stack in With has performance benefits as well. So maybe we still would have ended up with something like Valuer.

@StevenACoffman
Copy link

StevenACoffman commented Mar 29, 2023

Currently when using a custom error package that provides stacktraces like pkg/errors, cockroachdb/errors or (ahem) StevenACoffman/simplerr calling .Error() method on it will turn into a string without a stacktrace, and Sprintf("%+v") will turn it into a string with a stacktrace. I was hoping to use a Valuer to resolve this, as currently these Errors are printed inconsistently between JSON and Text outputs. I can override the Text output with a TextMarshaler, but a JSONMarshaller will currently do nothing for errors.

The JSONHandler will call:

	case KindAny:
		a := v.Any()
		if err, ok := a.(error); ok {
			s.appendString(err.Error())
		} else {
			return appendJSONMarshal(s.buf, a)
		}

But TextHandler will call:

	case KindAny:
		if tm, ok := v.any.(encoding.TextMarshaler); ok {
			data, err := tm.MarshalText()
			if err != nil {
				return err
			}
			// TODO: avoid the conversion to string.
			s.appendString(string(data))
			return nil
		}
		if bs, ok := byteSlice(v.any); ok {
			// As of Go 1.19, this only allocates for strings longer than 32 bytes.
			s.buf.WriteString(strconv.Quote(string(bs)))
			return nil
		}
		s.appendString(fmt.Sprintf("%+v", v.Any()))

@thockin
Copy link

thockin commented Mar 29, 2023

Thanks for the mention. Is the proposal to drop LogValuer entirely or just to change where/how/when it's called? I don't object to the latter (though I admit I have not taken slog out for a real track day yet).

@pohly
Copy link

pohly commented Mar 29, 2023

So the primary motivation is not performance.

It was for one usage of logr.Marshaler (the corresponding feature in go-logr): https://github.com/kubernetes/klog/blob/d7fc50528570f8276de46570f916682257821e22/k8s_references.go#L119-L154

That function captures a slice and only processes it when the slice is about to get logged. That made the handling of log calls that aren't enabled a lot faster.

@mkungla
Copy link
Contributor

mkungla commented Mar 29, 2023

You can implement json.Marshaler and TextMarshaler, but what if the handler uses a different format? Back in August, @akshayjshah, one of the original Zap authors, wrote...

I had same question when writing text handler for github actions log handler. Since github actions require specific control how attributes and levels are logged then that usecase illustrates well some limitations of current handler implementation and value resolution.
Imho creating such custom handlerers ishould be much easier than it is currently.

@ianthehat
Copy link

I think the proposal should be to keep the LogValuer interface, but treat it just like any other marshaling function. A handler can choose to detect it and use it on a value just like it does json.Marshaler
This means removing KindLogValuer and all functionality around it, and just keeping the interface declaration as a way for values to signal to handlers that they are special.
Handlers would have to document wether they use it or not (just like they do any other marshaller). Handlers that can use more than one marshaling function would have to document the order they try them in but they already have to do that anyway. Handlers still have to make opinionated decisions, but that is fine, and if you want most of a handler's features but need to treat a value differently, just put a handler middleware in the way and convert the value before it sees it.
This does lead to questions like, the built in json handler, should it try for a json.Marshaler first, or a slog.LogValuer first?).

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

I have also written the following code a few times for use in tests.

You can always get the effect of log.Valuer in slog by establishing a convention. If you control both the handler and the log calls, as you would in tests, your handler could look for attribute values of type func() slog.Value and invoke them.

logging the current value of a global variable that holds some version information updated asynchronously by polling the contents of a local file.

Since it's asynchronous, it wouldn't matter if the call happened just after the enabled check, or a microsecond or two later during output. You'd just have to be careful to avoid Logger.With.

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

@StevenACoffman, I think the problem there is that JSONHandler should check if a type implements json.Marshaler before checking if it implements error. That seems like a straight-up bug to me. See https://go-review.googlesource.com/c/go/+/480155 for a fix.

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

Is the proposal to drop LogValuer entirely or just to change where/how/when it's called? I don't object to the latter

@thockin, not clear yet, but I also favor the latter.

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

That made the handling of log calls that aren't enabled a lot faster.

@pohly, if we keep LogValuer, the call will definitely happen after the enabled check.

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

Imho creating such custom handlers should be much easier than it is currently.

@mkungla, agreed, and an area of active research. See https://github.com/jba/slog for some ideas.

If you want to continue that discussion, let's do so elsewhere, since it's not really on topic for this issue.

@jba
Copy link
Contributor Author

jba commented Mar 29, 2023

this means removing KindLogValuer

@ianthehat, we added a special Kind to make it harder for handlers to miss. Most will switch on Kind with a default that fails in some way with "unknown kind". That will make forgetting to call LogValue a much easier bug to find.

@ChrisHines
Copy link
Contributor

If you control both the handler and the log calls, as you would in tests, your handler could look for attribute values of type func() slog.Value and invoke them.

Of course. Writing a custom Handler can be the answer to just about anything with slog, just like writing a custom Logger is often the answer for anything with go-kit/log. The question is, are there any cases for which that presents a poor user experience (and there is a way to make a better experience) or integrates badly with other parts of the system and for which slog should provide a solution without requiring everyone to roll their own?

The Valuer type in go-kit/log was required to reduce the need for custom Loggers on the front end because those custom loggers would make it too difficult to keep a consistent stack depth which would interact poorly with the desire to provide a mechanism to log source code location data. Once we had that mechanism it also worked nicely for timestamps and other dynamic data that didn't depend on other information in the log event.

With slog we might want to be careful about putting all the burden on custom Handlers because it is a four method interface. The friction for implementing a Handler is greater than for simpler interfaces.

Take the stopwatch example I gave above. With go-kit/log the implementation is only a few lines and integrates seamlessly with go-kit's log.With functions. So using it in a test is quite trivial. Also, since go-kit doesn't add an absolute timestamp by default there is no work to remove that either, just don't add it in tests.

With slog it is still possible, but it's a lot more involved. You have to arrange for the stopwatch attribute to get added with a handler middleware (which requires four methods and another handler to forward calls to) and to also zero out the timestamp on the record to avoid it getting written. I don't think it's a critical flaw, but it is an inconvenience by comparison.

Possibly more frustrating is that LogValuer looks like it could be used for dynamic values; until you try to use it with logger.With and learn its value is frozen by that call. At that point in the journey one might give up, or possibly consider other ideas and realize a custom Handler could do the job but realize that's far less convenient and proceed (albeit a bit grumpier).

I don't know that it's a compelling case, but it's worth considering the developer experience.

You'd just have to be careful to avoid Logger.With

Yes, but as I said, that attribute is included with every log message from the app. It is setup in main.main and forgotten about. So, with slog that probably means a special Handler to add the attribute to the Record on every call to Handle. Which brings us back to the above thought process.

These are not easy design tradeoffs to balance, especially since (not documented that I've seen, but by my observation) slog is prioritizing (potential) performance over simplicity. That's a legitimate tradeoff, but makes other things more difficult.

@AndrewHarrisSPU
Copy link

AndrewHarrisSPU commented Mar 29, 2023

From the top post, bullet points 2 ("Copy the []Attr) and 3 ("resolve on the fly") looked more compelling to me. I'd definitely prefer "resolve on the fly".

A weaker form of (2) might be a func (v Value) Serialize() Value method that returns something with no further dynamic evaluation needed, allocating as needed. After a first Serialize call, any further Serialize or Resolve calls would be fast, idempotent, and non-allocating. It'd be a way to give some control to LogValuer or Handler implementations that might have a locally understood motivation towards the behavior of (2).

It might be worth noting that zap and zerolog both use Hooks for values that vary frequently but aren't managed per Entry/Event. Similar ideas have been mentioned as an alternative to LogValuer and I want to remark that I think something like this is probably needed for anything using context.Context.

@kortschak
Copy link
Contributor

Removed previous mistaken recollection.

I am using LogValue for formatting values of types from other packages that I don't control to delay rendering. I am finding this very useful. In my deleted comment I had said that I was using it for decorating with system dynamic state variable. This is not true; I'm using a handler middleware to do this. The delayed evaluation is valuable for my use though.

@jba
Copy link
Contributor Author

jba commented Mar 31, 2023

Possibly more frustrating is that LogValuer looks like it could be used for dynamic values; until you try to use it with logger.With and learn its value is frozen by that call. At that point in the journey one might give up, or possibly consider other ideas and realize a custom Handler could do the job but realize that's far less convenient and proceed (albeit a bit grumpier).

@ChrisHines: Actually, you don't really need a fully custom handler, only one that doesn't preformat. Turns out I already wrote such a handler. It collects the information from WithGroup and WithAttrs and passes it all to Handle as a reconstructed Record. I called it SimpleHandler for lack of a better name, but maybe it should be called DePreFormatHandler, because you can use it as middleware to turn off preformatting.

@jba
Copy link
Contributor Author

jba commented Mar 31, 2023

It might be worth noting that zap and zerolog both use Hooks for values that vary frequently but aren't managed per Entry/Event. Similar ideas have been mentioned as an alternative to LogValuer and I want to remark that I think something like this is probably needed for anything using context.Context.

Zap's documentation says:

Hooks are useful for simple side effects, like capturing metrics for the number of emitted logs. More complex side effects, including anything that requires access to the Entry's structured fields, should be implemented as a zapcore.Core instead.

Which is basically what I would say for getting varying values: write a Handler. You can fulfill the stated purpose of a Zap hook by writing a middleware Handler. That is a bit less convenient that registering a hook but keeps the API small.

Zerolog hooks are more of a necessity, since it doesn't have configurable backends.

@jba
Copy link
Contributor Author

jba commented Mar 31, 2023

It seems to me that we have only one genuine example of a non-deterministic LogValuer, and there are other ways to deal with that. My conclusion is that I was mistaken to add calls to Value.Resolve to the slog core: handlers can take on the burden of calling Resolve themselves, avoiding the choice between modification and copying that the core would otherwise have to make. The slogtest package can verify that a handler behaves correctly.

Now that the course of action is clear to me, I'm going to change this to a proposal.

@jba jba changed the title log/slog: Group values are resolved in place proposal: log/slog: remove calls to Value.Resolve from slog core Mar 31, 2023
@gopherbot gopherbot added this to the Proposal milestone Mar 31, 2023
@ChrisHines
Copy link
Contributor

Possibly more frustrating is that LogValuer looks like it could be used for dynamic values; until you try to use it with logger.With and learn its value is frozen by that call. At that point in the journey one might give up, or possibly consider other ideas and realize a custom Handler could do the job but realize that's far less convenient and proceed (albeit a bit grumpier).

@ChrisHines: Actually, you don't really need a fully custom handler, only one that doesn't preformat. Turns out I already wrote such a handler. It collects the information from WithGroup and WithAttrs and passes it all to Handle as a reconstructed Record. I called it SimpleHandler for lack of a better name, but maybe it should be called DePreFormatHandler, because you can use it as middleware to turn off preformatting.

OK, it depends how you define "custom handler". What you wrote fits my definition of a custom handler in the context that I was writing. I guess I should have said "middleware handler". That doesn't change my core point that if the developer is not aware that someone has already written such a thing and it's not in slog already, their grumpiness meter goes up. ;)

@rsc
Copy link
Contributor

rsc commented Apr 5, 2023

Thanks for the careful discussion. Have all concerns about this proposal been addressed?

@ChrisHines
Copy link
Contributor

The slogtest package can verify that a handler behaves correctly.

I agree with the proposal but would like to know what slogtest will consider correct handler behavior. See #59292 (comment) for my thoughts on that which I don't think anyone else has commented on here either to agree or disagree with.

@jba
Copy link
Contributor Author

jba commented Apr 5, 2023

slogtest would only test with deterministic LogValuers. Since we're deciding (if this proposal is accepted) to let handlers choose when to call LogValue, we can only check that it is called, not when.

@ChrisHines
Copy link
Contributor

slogtest would only test with deterministic LogValuers. Since we're deciding (if this proposal is accepted) to let handlers choose when to call LogValue, we can only check that it is called, not when.

I think that is unfortunate. I think that means code that logs arbitrary values or doesn't control or wish to be coupled to the choice of handler cannot use logger.With.

@rsc
Copy link
Contributor

rsc commented Apr 6, 2023

This proposal has been added to the active column of the proposals project
and will now be reviewed at the weekly proposal review meetings.
— rsc for the proposal review group

@jba
Copy link
Contributor Author

jba commented Apr 8, 2023

code that logs arbitrary values or doesn't control or wish to be coupled to the choice of handler cannot use logger.With.

@ChrisHines, Agreed. To achieve the significant performance benefits of preformatting, we are giving up the determinism that you want.

@08d2
Copy link

08d2 commented Apr 9, 2023

It would be very surprising if With("k", v) didn't evaluate v when With was called, but instead when the returned logger was first asked to produce a log event.

In fact, deferring evaluation in this way can often be unsafe. If a handler lazy-evals logged keys or vals, it assumes those parameters are safe to copy across goroutine boundaries, and are safe to read over time. This isn't something that callers are generally going to assume or provide. For example, it's easy to imagine some code that logs a []byte val which is re-used by a subsequent request before the log event is read.

@jba
Copy link
Contributor Author

jba commented Apr 9, 2023

If you pass something to Logger.With, you should probably assume that the logger owns it, regardless of whether it is a LogValuer or not. And I think a well-written Handler.Handle that needs to hold on to something after it returns (maybe because it writes it to a channel for another goroutine to pick up) should copy that data. We haven't written these rules down anywhere. Maybe we should.

But that is only partly related to when to resolve values. I wouldn't want to require that Handler.WithAttrs resolves all its argument values. First, I think of WithAttrs and WithGroup primarily as an optimization, one that a Handler can choose to ignore; and second, to allow just the sort of time-varying LogValuers that expect to be resolved during Handler.Handle.

@ChrisHines
Copy link
Contributor

code that logs arbitrary values or doesn't control or wish to be coupled to the choice of handler cannot use logger.With.

@ChrisHines, Agreed. To achieve the significant performance benefits of preformatting, we are giving up the determinism that you want.

That is also unfortunate. I think it makes the abstraction too leaky. IMHO, the ability to use logger.With to help ensure some attrs are consistently logged in downstream code is more valuable than logger performance. I don't think we should spoil the semantics of the API for the sake of performance.

@rsc
Copy link
Contributor

rsc commented Apr 12, 2023

Based on the discussion above, this proposal seems like a likely accept.
— rsc for the proposal review group

@rsc
Copy link
Contributor

rsc commented Apr 19, 2023

No change in consensus, so accepted. 🎉
This issue now tracks the work of implementing the proposal.
— rsc for the proposal review group

@rsc rsc changed the title proposal: log/slog: remove calls to Value.Resolve from slog core log/slog: remove calls to Value.Resolve from slog core Apr 19, 2023
@rsc rsc modified the milestones: Proposal, Backlog Apr 19, 2023
@gopherbot
Copy link

Change https://go.dev/cl/486375 mentions this issue: log/slog: remove calls to Value.Resolve from core

gopherbot pushed a commit that referenced this issue Apr 20, 2023
Remove calls to Value.Resolve from Record.AddAttrs, Record.Add and Logger.With.
Handlers must resolve values themselves; document that in Handler.

Call Value.Resolve in the built-in handlers.

Updates #59292.

Change-Id: I00ba2131be0b16e3b1a22741249fd6f81c3efde1
Reviewed-on: https://go-review.googlesource.com/c/go/+/486375
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
@jba
Copy link
Contributor Author

jba commented Jul 24, 2023

The work on this was completed by the above CL.

@jba jba closed this as completed Jul 24, 2023
eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
Remove calls to Value.Resolve from Record.AddAttrs, Record.Add and Logger.With.
Handlers must resolve values themselves; document that in Handler.

Call Value.Resolve in the built-in handlers.

Updates golang#59292.

Change-Id: I00ba2131be0b16e3b1a22741249fd6f81c3efde1
Reviewed-on: https://go-review.googlesource.com/c/go/+/486375
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
Remove calls to Value.Resolve from Record.AddAttrs, Record.Add and Logger.With.
Handlers must resolve values themselves; document that in Handler.

Call Value.Resolve in the built-in handlers.

Updates golang#59292.

Change-Id: I00ba2131be0b16e3b1a22741249fd6f81c3efde1
Reviewed-on: https://go-review.googlesource.com/c/go/+/486375
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Accepted
Development

No branches or pull requests

13 participants