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: structured, leveled logging #56345

Open
jba opened this issue Oct 20, 2022 · 678 comments
Open

log/slog: structured, leveled logging #56345

jba opened this issue Oct 20, 2022 · 678 comments

Comments

@jba
Copy link
Contributor

jba commented Oct 20, 2022

We propose a new package providing structured logging with levels. Structured logging adds key-value pairs to a human-readable output message to enable fast, accurate processing of large amounts of log data.

See the design doc for details.

@jba jba added the Proposal label Oct 20, 2022
@gopherbot gopherbot added this to the Proposal milestone Oct 20, 2022
@jba

This comment has been hidden.

@fsouza

This comment has been hidden.

@jba

This comment has been hidden.

@mpx
Copy link
Contributor

mpx commented Oct 22, 2022

This is a huge API surface without any real production testing (AIUI). Perhaps it might be better to land it under golang.org/x for some time? Eg, like context, xerrors changes.

@seankhliao
Copy link
Member

It's available under golang.org/x/exp/slog

@mpx

This comment has been hidden.

@deefdragon
Copy link

I love most of what this does, but I don't support its addition as it stands. Specifically, I have issues with the option to use inline key-value pairs in the log calls. I believe the attributes system alone is fine. Logging does not need the breakage that key-value args like that allow.

The complexity in the documentation around Log should be a warning sign.

...
The attribute arguments are processed as follows:

  • If an argument is an Attr, it is used as is.
  • If an argument is a string and this is not the last argument, the following argument is treated as the value and the two are combined into an Attr.
  • Otherwise, the argument is treated as a value with key "!BADKEY".

The suggestion was that potential problems with key-value misalignment will all be solved by vet checks. As I mentioned in this thread of the discussion, relying on vet should be viewed a warning as to potential problems with the design, not a part of the design itself. Vet should not be a catch-all, and we should do what we can to avoid requiring vet warnings to safely develop go.

An accidentally deleted/missed or added/extra argument in key value logging would offset the keys and values after it. That could easily bog down a logging system trying to index all the new "keys" it is getting. It could also lead to data being exposed in a way that it should not be.

I acknowledge that neither of these examples are all that likely in a well defined system, or somewhere with good practices around code reviewing etc.. But they are possible.

@hherman1
Copy link

@deefdragon Doesn't this concern apply to Printf as well? Is the difference the dependency on these logs by external systems..?

@prochac
Copy link

prochac commented Oct 24, 2022

Based on that the Go standard library is very often being recommended as source of idiomatic code, and this package aspires to be merged as part of it, I would like you explain to me the involvement of context package.

If some object uses logger, isn't it its dependency? Shouldn't we make the dependencies explicit? Isn't this logger smuggling bad practice? If passing the logger by context is idiomatic, is *sql.DB too?

Why has the logger stored context? It violates the most famous sentence from the documentation for context

Contexts should not be stored inside a struct type, but instead passed to each function that needs it.

Logger in context containing its own context inside ...

Frankly, I'm a bit confused.

@deefdragon
Copy link

@hherman1 The same concern does apply to printf, tho it's not as bad compared to logging. With printf, most statements are consumed as a single chunk, and only consumed locally by the programmer. Being misaligned is easy enough for a human to notice, parse, and correct.

In the case of Sprintf, where it might not be consumed by the programmer, and instead be used as an argument to something, the "testing" during development that is making sure the program starts would likely catch most misalignment.

Being off by one in a log is much harder to catch as it has no real impact in the program's execution. You only notice there is an issue when you have to go through your logs.

@mminklet
Copy link

mminklet commented Oct 25, 2022

I think I share some of @prochac 's concerns regarding context. Maybe I'm being a bit of a luddite, but recommending that the logger is passed around inside context rather than via explicit dependency injection, smells a bit funny to me. Context, from what I have always followed, is for request-scoped information, rather than dependencies. And the more clarity surfacing dependencies the better. IE just assuming the right logger is in context, and getting the default one because it's still getting some logger

@v3n
Copy link

v3n commented Oct 25, 2022

Maybe I'm being a bit of a luddite, but recommending that the logger is passed around inside context rather than via explicit dependency injection, smells a bit funny to me. Context, from what I have always followed, is for request-scoped information, rather than dependencies.

I think there are two approaches here:

  • For long-lived process (think the kind of thing that you would pass context.Background() to); I would absolutely recommend dependency injected loggers. This would include situations where a context logger might be available, but may use fan-in/singleflight to demux requests. For these cases, the logged is frequently implemented as a 'child logger', which in some frameworks allows you to adjust the log level per-child.

  • However, on the other hand, many APM services have a "log correlation" features (this is even part of the spec for OpenTelemetry). In this situation, you want your context to be propagated by the logger; as the correlation fields would be prebound to the logger and propogated down the stack.

I've used both patterns frequently in high-scale production services; and both have their places. I'd definitely like to see slog promote context-propagated logging as the observability benefits are huge.

@mminklet
Copy link

mminklet commented Oct 25, 2022

Appreciate your explanation @v3n . I'm still having a slightly hard time understanding the benefit of the logger itself being passed around in context. I understand propagating the log correlation information via context, and we currently use the otelzap implementation that does this sort of thing via ErrorContext(ctx, ...) etc logging methods. I like the WithContext methods proposed here, passing the context to the logger, in similar fashion. It's more the logger itself being passed around inside the context that feels a bit odd to me

The zap and otelzap libraries do allow for the same kind of thing, whereby you can get the logger from context etc (and I'm sure others do), it's just this being in the std library it's more of a recommendation for this kind of pattern

@seankhliao
Copy link
Member

I still want a standard handler for testing.TB.Log like https://pkg.go.dev/github.com/go-logr/logr@v1.2.3/testr#New

@jba
Copy link
Contributor Author

jba commented Oct 25, 2022

Being off by one in a log is much harder to catch

@deefdragon, we'll have a vet check for that.

@jba
Copy link
Contributor Author

jba commented Oct 25, 2022

I still want a standard handler for testing.TB.Log like https://pkg.go.dev/github.com/go-logr/logr@v1.2.3/testr#New

@seankhliao, such a handler seems easy to write, and it's not clear to me yet whether there is enough demand to include it. Let's hold off for now; we can always add it later.

@jba
Copy link
Contributor Author

jba commented Oct 25, 2022

Why has the logger stored context? It violates the most famous sentence from the documentation for context

Contexts should not be stored inside a struct type, but instead passed to each function that needs it.

@prochac, that is a design principle, not a hard-and-fast rule. It is there to steer people away from buggy code, but that has to be weighed against other factors. In this case, we knew that passing tracing information to logging was an important feature, but we didn't want to add a context argument to every log output method. This was our solution.

@jba
Copy link
Contributor Author

jba commented Oct 25, 2022

Context, from what I have always followed, is for request-scoped information

@mminklet, scoping a logger to a request is a common pattern, and is probably the main application of the ability to add a Logger to a context. It doesn't preclude dependency injection; if that works for you, stick with it.

@amnonbc
Copy link

amnonbc commented Oct 25, 2022

This is a significant proposal. @jba can you do a video talk on this. And, perhaps, a blog post?

@deefdragon
Copy link

Being off by one in a log is much harder to catch

@deefdragon, we'll have a vet check for that.

@jba As I said in my original post, I don't think that's a good solution.

relying on vet should be viewed a warning as to potential problems with the design, not a part of the design itself.

@fsouza
Copy link
Contributor

fsouza commented Oct 25, 2022

I like this in general. One API nit from an experiment in s3-upload-proxy: it would be good to have a way to convert a string into to the level (say you want to allow users set an environment variable like LOG_LEVEL=debug and have that translated to DebugLevel).

Other libraries (logrus, zerolog, zap) call that function ParseLevel (for zap it's ParseAtomicLevel, but same principle).

@jba
Copy link
Contributor Author

jba commented Oct 25, 2022

can you do a video talk on this.

Done.

@AndrewHarrisSPU
Copy link

Other libraries (logrus, zerolog, zap) call that function ParseLevel

The additional '+'/'-' terms put a twist on this, I think it'd be nice to have. (I had this laying around: https://go.dev/play/p/Izwzgd8Kmc9)

@amnonbc
Copy link

amnonbc commented Oct 26, 2022

Three comments on the proposal:

One thing which irritated me with zap was the existence of both sugared and attribute log methods.
This doubled the API surface, and created a coding style balkanisation of packages that used zap as their logger.
In Go there should be one, and preferably only one way of doing things.
slog does unfortunately replicate this duplication.

My second observation is that we have 10 Attr constructors, one for each common type we want to log, + any.
Could we have used Generics to reduce the API surface here?
But if we are going to have explicit Attr constructors, then I would like one which logs an error, one that logs a stringer,
and one which logs a []byte as a string.

Finally, I think it is very good (but perhaps overdue) that we are moving towards a canonical production strength logging library in stdlib. Most libraries need some level of logging, if only for debugging. And not having a standard interface of
sufficient power meant a lot of pain. If you want to import package foo, you also need to pull in the weird and wonderful
logging library that they use, construct a logger of the right type to pass to it, and arrange for the output to somehow
be integrated into the logging output and config used by the rest of your system. I have done this myself far too many
times and it quickly gets tedious. So great that this will probably soon move into the stdlib,
and that new packages will eventually start adopting it. If only we had had it earlier, much aggravation would have been saved.

@jba
Copy link
Contributor Author

jba commented Oct 26, 2022

slog does unfortunately replicate this duplication.

I disagree. There is only one Attr-based output method, LogAttrs. It is there as an optimization for those who need it. Most users will be fine with the other five output methods. (And yes, there is also the extra LogAttrsDepth method, but that will be even more rarely used.)

Could we have used Generics to reduce the API surface here?

The answer is, "hopefully." With the current implementation, you can only reduce the API surface at a considerable time penalty. But that may change before this API is frozen. See this item in the discussion.

I would like [an Attr constructor] which logs an error, one that logs a stringer,
and one which logs a []byte as a string.

According to my analysis, zap.Stringer uses are 2% of all constructors, and zap.ByteString is at 0.3%. I don't think those numbers warrant more API. (But we can always add them later if I'm wrong.) zap.Error calls are quite common, but we believe that the error argument to Logger.Error will absorb most of those.

@rsc
Copy link
Contributor

rsc commented Oct 26, 2022

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

@rabbbit
Copy link

rabbbit commented Oct 26, 2022

Why has the logger stored context? It violates the most famous sentence from the documentation for context

Contexts should not be stored inside a struct type, but instead passed to each function that needs it.

@prochac, that is a design principle, not a hard-and-fast rule. It is there to steer people away from buggy code, but that has to be weighed against other factors. In this case, we knew that passing tracing information to logging was an important feature, but we didn't want to add a context argument to every log output method. This was our solution.

I'm with @prochac and @mminklet in that passing logger in context seems awkward.

However, I see your point about context propagation and @v3n point:

I'd definitely like to see slog promote context-propagated logging as the observability benefits are huge.

But then context-propagated logging and context-propagated logg**er** are slightly different things.

@jba (apologies if this was already discussed in #54763, I tried to & failed to find it there) did you consider something like context-propagated log-context, as opposed to propagating the whole logger?

I frequently wish I could do easily is adding log-context to an already existing logger, like:

logger = slow.WithContext(ctx).With("method", r.Method ...)

.....

err := doSomething(c ctx) err {
   doSomethingElse(c ctx) {
        somethingVeryDeep(c ctx) {
             // do some other work
             slog.AddToContext(ctx, "workResult", ok)
        }
        somethingVeryDeepAgain(c ctx) {
             // do some work
             slog.AddToContext(ctx, "otherWorkResult", ok)
        }
   } ()
} ()
if err != nil {
    logger.Error("requestFailed") // `slog` extract values for me.
}

This would allow me to log once per request/error instead of tens of scattered log-lines which I then need to correlate with request/span ids.

I think this could also support https://go-review.googlesource.com/c/proposal/+/444415/5/design/56345-structured-logging.md#754

ctx, span := tracer.Start(ctx, name, opts)

since tracer.Start could add the context it needs to the log-context on the context.

This would likely require changes to the context package to support this in a performant way, but stdlib wants to support context+logging+tracing natively perhaps context can be adapted too? Maybe changes won't be necessary.

@AndrewHarrisSPU
Copy link

There may be a hint of namespace clobbring in ReplaceAttr, where matching on a key string is invoked before group prefixes are applied (example: https://go.dev/play/p/yFNXLz3gklD).

I think it's a reasonable behavior; the version of ReplaceAttr that is attentive to group prefixing doesn't seem like it would be very robust, leading to situations where it's not possible to add a Group downstream without breaking a replacement policy (or update a package because their logger added a Group, etc.). Still I wonder if it's worth noting in documentation.

A version of ReplaceAttr in Handler middleware might offer some flexibility. I really have no opinion on whether that component should be in slog - it's not very hard to implement, and eventually precisely tailoring some more elaborate replacement policies or hooks or whatever seems like it should be written outside of slog.

@gopherbot
Copy link

Change https://go.dev/cl/478355 mentions this issue: log/slog: fix window race builder

@veqryn
Copy link

veqryn commented Mar 22, 2023

@jba hey, I was wondering if you saw my message above, #56345 (comment) , on including an error field in Record?

gopherbot pushed a commit that referenced this issue Mar 22, 2023
Bench log file is created non-portably, only works on system where
"/tmp" existed and "/" is path separator.

Fixing this by using portable methods from std lib.

Updates #56345

Change-Id: I1f6b6b97b913ca56a6053beca7025652618ecbf3
Reviewed-on: https://go-review.googlesource.com/c/go/+/478355
Run-TryBot: Ian Lance Taylor <iant@google.com>
Reviewed-by: Ian Lance Taylor <iant@google.com>
Auto-Submit: Ian Lance Taylor <iant@google.com>
Reviewed-by: Jonathan Amsterdam <jba@google.com>
Run-TryBot: Cuong Manh Le <cuong.manhle.vn@gmail.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
gopherbot pushed a commit that referenced this issue Mar 22, 2023
Delete the set of bytes that need quoting in TextHandler, because it
is almost identical to the set for JSON. Use JSONHandler's safeSet
with a few exceptions.

Updates #56345.

Change-Id: Iff6d309c067affef2e5ecfcebd6e1bb8f00f95b9
Reviewed-on: https://go-review.googlesource.com/c/go/+/478198
Reviewed-by: Ian Lance Taylor <iant@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@jba
Copy link
Contributor Author

jba commented Mar 22, 2023

@veqryn, I did read it but forgot to respond. The consensus on this issue were that errors shouldn't have any special status: in terms of common key name, deduplication, and so on, they present the same problems as any other attribute. So we decided against treating them specially. That would include an error field on Record.

@veqryn
Copy link

veqryn commented Mar 22, 2023

@veqryn, I did read it but forgot to respond. The consensus on this issue were that errors shouldn't have any special status: in terms of common key name, deduplication, and so on, they present the same problems as any other attribute. So we decided against treating them specially. That would include an error field on Record.

In that case, can we bring back ErrorKey ?
I am truly not looking forward to having logs from libraries all using different error keys. (ie: "error", "err", "e", "_error", etc).
That will not be fun to deal with when they get to elasticsearch, scalyr, or whatever log aggregation and search engine people are using. Yes, a custom handler might help, but now you have to write custom handler rules for every library that uses a different key than you like, and update it overtime as those libraries change their own dependencies.
Just about every other logging library out there, whether zerolog, zap, logrus, apex, etc, all either have a public ErrorKey or they hardcode to "error".

Also, I do wish to say that the current Record fields of Time, Message, and Level, could all be treated as regular attributes too. But they aren't, for good reason, and I think those reasons extend to the Error field. I think the decision to treat errors as a regular attribute should be reconsidered.

@08d2
Copy link

08d2 commented Mar 23, 2023

Structured logging establishes rules about the structure of log events, basically that they are key=val pairs, and about the types of those keys and vals. It should have no concept of semantics of any key or val, like if it is an error or a status code or a referer address or anything else like that. Those concepts exist at a higher level of abstraction.

@veqryn
Copy link

veqryn commented Mar 23, 2023

Structured logging establishes rules about the structure of log events, basically that they are key=val pairs, and about the types of those keys and vals. It should have no concept of semantics of any key or val, like if it is an error or a status code or a referer address or anything else like that. Those concepts exist at a higher level of abstraction.

Then let there be an Error field on Record, and the handlers and higher levels can deal with it appropriately.
That would be the "pure" solution, and I would prefer that. The "practical" solution would be having a public ErrorKey field. Having neither will create big problems in the future, and there is a very good reason why every single structured logging library out there today either has an error type field or an error string key.

The fact that we are even considering a structured logger, instead of continuing with the existing builtin log package, shows that we have some practical considerations for how we and our libraries log and how we consume, view, and search those logs. Otherwise we could just say that the existing log.Println function is fine and everything else is just a higher level of abstraction.

Please explain to me why Record has fields for Time, Level, and Message, but doesn't have one for Error? They could easily be made into attributes, but then people would use different keys for them, and everyone would have to write custom handlers...

Errors are just as central to a log record/entry as the time, level, and message. Errors are we why we are even logging anything at all to begin with, rather than just using metrics. Error values are central to the golang language. We need a better solution than just ignoring this until after the interface is set and claiming the resulting problems are for the users to fix.

@08d2
Copy link

08d2 commented Mar 23, 2023

I agree with you that a structured logging package should not define a time, level, or message key, either.

@willfaught
Copy link
Contributor

willfaught commented Mar 23, 2023

An error can be a complex value. It doesn't make sense to me to squash that into a plain string before a backend Handler handles it. Handlers can handle Attrs with error values however they want to, including the uniform way you have in mind. Use your own ErrorsHaveSameKeyHandler if you like. That approach has problems that were discussed above.

Please explain to me why Record has fields for Time, Level, and Message, but doesn't have one for Error? They could easily be made into attributes, but then people would use different keys for them, and everyone would have to write custom handlers...

I and others have argued for removing Level and Message too. I haven't seen the Go Team articulate the rationale for having them, beyond trying to mimic logr. We're stuck with them, it seems.

@veqryn
Copy link

veqryn commented Mar 23, 2023

An error can be a complex value. It doesn't make sense to me to squash that into a plain string before a backend Handler handles it. Handlers can handle Attrs with error values however they want to, including the uniform way you have in mind. Use your own ErrorsHaveSameKeyHandler if you like. That approach has problems that were discussed above.

Who said anything about strings?
This field would be either any or the error interface, so that it can hold any error. Handlers can turn that into json or text or whatever they want. Some errors, even one I made once, implement MarshalJSON.

Please explain to me why Record has fields for Time, Level, and Message, but doesn't have one for Error? They could easily be made into attributes, but then people would use different keys for them, and everyone would have to write custom handlers...

I and others have argued for removing Level and Message too. I haven't seen the Go Team articulate the rationale for having them, beyond trying to mimic logr. We're stuck with them, it seems.

I can't wait for dealing with logs that look like this, because every library is using a different key string:

{
  "time": "2023-03-21 14:30:59",
  "level": "warn",
  "message": "unable to create user",
  "error": "db: bad connection"
}
{
  "t": "2023-03-21 14:31:01",
  "lvl": "warn",
  "msg": "session terminated",
  "err": "duplicate login detected"
}

That will not be fun to deal with when I search in elastic search or scalyr. Or when I setup alerting rules or dashboard based on logs. Yet this is what we will get if we don't make separate fields for Time, Level, Message, and Error.
Practicality needs to win here, please.

@hherman1
Copy link

I think there were reasonable points about the uniformity of the API, but I don’t think the difference between error, time, and message have been addressed. I don’t feel convinced that removing error support was the right decision.

@flibustenet
Copy link

@veqryn in your example you use level warn with an error. It can also be the opposite, an error level without a Go error.
I believe if we search for errors we'll use the level, not a key.
It's consistent in Go that error are just a value, a string value in logging. I'm fine with slog.Error(err.Error()), better than slog.Error("oups", err) or slog.Error("oups", fmt.Errorf("i've no go error"))...
I'd like to suggest to accept any as message and use %v to do slog.Error(err) like we already can do in testing for example t.Error(err), in all the level after all (but it's probably already discussed ?).

@ChrisHines
Copy link
Contributor

The utopia of everyone using the same keys in their logs from all software will not happen even if slog tries to make it so.

The log15 package for Go was first published nearly nine years ago on May 19, 2014. If we look at log15's abstractions it has a Logger, a Record, a Handler, and a Formatter. We haven't come that far from that design in slog.

The log15 Record type is declared as:

// A Record is what a Logger asks its handler to write
type Record struct {
	Time     time.Time
	Lvl      Lvl
	Msg      string
	Ctx      []interface{}
	Call     stack.Call
	KeyNames RecordKeyNames
}

The KeyNames field was not there in the initial version. A way to configure the keys for the fields in Record was requested four days later, however, in inconshreveable/log15#4. The KeyNames field was added a few months later in inconshreveable/log15#20 to satisfy that need.

Many times the keys we have to use in our logs are dictated by forces outside of our code, programming language, or team. slog should be a flexible tool to let us log what we need, not an enforcer of policies that are out of its hands.

See also #56345 (comment) in which I said:

Libraries that write logs that you cannot control will always be a problem to integrate with an application that requires strict control over logging output. Error values are not special in this regard.

But read the whole comment (if the Github UI lets you) because I believe it makes good points beyond what I've said in this post.

@hherman1
Copy link

@ChrisHines why do you feel ok about having built-in message and time fields but not a built in error field?

@ChrisHines
Copy link
Contributor

ChrisHines commented Mar 23, 2023

@ChrisHines why do you feel ok about having built-in message and time fields but not a built in error field?

I don't really. I argued against that a while back too. There is a semantic difference with those attributes in slog, though. They are always logged at the top level even after calling logger.WithGroup, so there is some justification for treating them differently.

Note that the logging package I am most well known for, github.com/go-kit/log, doesn't have any special attributes. That choice was based in part on the experience with log15 and also driven by the Go kit logging RFC written before I got involved in that project: go-kit/kit#4. Here's a walk down memory lane for how the design discussion based on that went: go-kit/kit#21.

My biggest regret with the go-kit/log design is leaving levels out of the core package because that caused much design difficulty to layer on later and I think the result is sub-optimal in a few ways.

slog is drawing from more experience since those days. I do like the addition of the memory efficient and more type safe Attr and Value types inspired by uber/zap. But if I had my way we would try harder to eliminate or minimize the Record type more. I made my case and accept that they were not persuasive enough. That said, I also acknowledge that most of my experience with structured logging has been with completely flat key spaces. I don't have much experience with the semantics and typical use of any equivalent of the WithGroup API. So I am reluctant to argue too forcefully one way or another when it comes to how the "special" attributes should interact with it.

@veqryn
Copy link

veqryn commented Mar 23, 2023

The utopia of everyone using the same keys in their logs from all software will not happen even if slog tries to make it so.

The great thing about having Time, Level, Message, and Error on the Record struct is that then the handler would determine what the keys are, which means it is in my control, and outside of the control of a library or sub-dependency that I am using.
If I want to use "msg" as the key in text based logging I can have the handler write that. If I want to use "message" as the key in json based logging I can have the handler do that instead.
By having the these on the record field, it takes the choice of keys away from things I can't control, like libraries, and puts my application in control of it (via the handler). If all my applications use the same handler, which I can force, then all my logs will be consistent.

@flibustenet
Copy link

Today I just upgraded slog on our current project, I had to change all the slog.Error. We choose:

  • use "err" as the conventional key for error.
  • This key is not mandatory if the message is sufficient slog.Error("oups")
  • The error key could be at any level. slog.Warn("An error occur", "err",...)

It's fine that the current slog proposal permit this. Maybe we could start an other proposal to discuss if conventional is not enough and an ErrorAttr could be included or something like that ?

@08d2
Copy link

08d2 commented Mar 23, 2023

@veqryn

The utopia of everyone using the same keys in their logs from all software will not happen even if slog tries to make it so.

The great thing about having Time, Level, Message, and Error on the Record struct is that then the handler would determine what the keys are, which means it is in my control, and outside of the control of a library or sub-dependency that I am using. If I want to use "msg" as the key in text based logging I can have the handler write that. If I want to use "message" as the key in json based logging I can have the handler do that instead. By having the these on the record field, it takes the choice of keys away from things I can't control, like libraries, and puts my application in control of it (via the handler). If all my applications use the same handler, which I can force, then all my logs will be consistent.

What you're describing here is more like semantic logging than structured logging.

@veqryn
Copy link

veqryn commented Mar 23, 2023

@veqryn

The utopia of everyone using the same keys in their logs from all software will not happen even if slog tries to make it so.

The great thing about having Time, Level, Message, and Error on the Record struct is that then the handler would determine what the keys are, which means it is in my control, and outside of the control of a library or sub-dependency that I am using. If I want to use "msg" as the key in text based logging I can have the handler write that. If I want to use "message" as the key in json based logging I can have the handler do that instead. By having the these on the record field, it takes the choice of keys away from things I can't control, like libraries, and puts my application in control of it (via the handler). If all my applications use the same handler, which I can force, then all my logs will be consistent.

What you're describing here is more like semantic logging than structured logging.

? I think you might be splitting hairs on concepts and theory here.

What I described is literally how slog works right now, with the exception that the Error field is not yet a part of a Record.
Here is the default slog handler:
https://github.com/golang/exp/blob/522b1b587ee03a85c2670377adc0d8ab3540bdee/slog/handler.go#L175-L188
https://github.com/golang/exp/blob/522b1b587ee03a85c2670377adc0d8ab3540bdee/slog/handler.go#L305-L312

@hherman1
Copy link

FWIW I think you could make the argument that error should be excluded and message/time included because error is less valuable to users than message & time is. I would be interested to see that argument though if that is the position of the go team.

@lmittmann
Copy link

@jba Have you considered making HandlerOptions.New{Text,JSON}Handler return the slog.Handler interface instead of the {Text,JSON}Handler types? Both structs don't expose any visible attributes or additional methods. Returning the Handler interface instead and making the {Text,JSON}Handler types private would reduce the exposed API quite a bit.

@StevenACoffman
Copy link

When AddSource is true, here currently slog surfaces the frame.File and frame.Line, but discards the frame.Function. In GCP StackDriver logging the sourceLocation is:

type source struct {
	File     string `json:"file,omitempty"`
	Line     string `json:"line,omitempty"`
	Function string `json:"function,omitempty"`
}

Per Dan Cliff in Gophers Slack, we can make a passable GCP StackDriver format slog without the Function name as https://go.dev/play/p/ecaOdwHTBua

If we want the Function name, the Record exposes the PC, so we can either redundantly call runtime.CallersFrames([]uintptr{r.PC}) ourselves in a handler wrapper, or have AddSource false and avoid slog's handler from also calling that same expensive operation.

Not sure if the Function name is a commonly desired requirement, but I thought I would point it out.

gopherbot pushed a commit that referenced this issue Mar 24, 2023
Give an example illustrating the problem with dots inside groups
or keys. Clarify that to fix it in general, you need to do more
than escape the keys, since that won't distinguish the group "a.b"
from the two groups "a" and "b".

Updates #56345.

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

Returning the Handler interface instead and making the {Text,JSON}Handler types private would reduce the exposed API quite a bit.

I would disagree. Neither JSONHandler nor TextHandler export any new API besides their respective implementations of Handler. The two types are otherwise opaque to users. So, I don't really see that "quite a bit" of exposed API to be reduced. If the concrete return types in function signatures really do make you that uneasy, none of us can stop you from writing and using Handler-returning wrappers. I personally see no gain in doing (nor loss in not doing) so at the moment.

gopherbot pushed a commit that referenced this issue Mar 25, 2023
Add a suite of benchmarks for the LogAttrs method, which is intended
to be fast.

Updates #56345.

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

lmittmann commented Mar 26, 2023

I would disagree. Neither JSONHandler nor TextHandler export any new API besides their respective implementations of Handler. The two types are otherwise opaque to users. So, I don't really see that "quite a bit" of exposed API to be reduced.

That is my point. The two types don't export anything but the Handler interface. Thus, they could be hidden from the package API by making them unexported and changing

-func NewJSONHandler(w io.Writer) *JSONHandler
-func NewTextHandler(w io.Writer) *TextHandler
-func (opts HandlerOptions) NewJSONHandler(w io.Writer) *JSONHandler
-func (opts HandlerOptions) NewTextHandler(w io.Writer) *TextHandler
+func NewJSONHandler(w io.Writer) Handler
+func NewTextHandler(w io.Writer) Handler
+func (opts HandlerOptions) NewJSONHandler(w io.Writer) Handler
+func (opts HandlerOptions) NewTextHandler(w io.Writer) Handler

This would be similar to the std image package, where e.g. image/png.Decode returns the image.Image interface and not a png.Image struct with the same API as the image.Image interface.

@Merovius
Copy link
Contributor

@lmittmann In general, I'd recommend returning exported types, instead of opaque interfaces. That is because it enables you to later add type-specific methods where appropriate without breaking compatibility. For example, the JSONHandler might well want to gain a field/method to set indentation or something like that. If it is an exported type, that is a backwards compatible change. If it isn't, you'd have to either break compatibility, or add more API to get the concrete type, or use type-assertions or the like. There isn't really a downside to returning an exported type, on the other hand.

Note that image/png.Decode actually is a bad example for your point, as it can return different concrete image types. But also, some parts of the standard library have been designed a long time ago and we learned some new things about API design since then.

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