13 ms·

Structured logging with slog

275 points by spacey 3y ago

insanitybit 3y ago
Structured logging is a very sane default. Even if you end up with `{"msg": "blah blah blah"}` at least you have room to grow in the future.
- duskwuff 3y ago
  And if your current logging is along the lines of log.Printf("failed to frob %s: %s", thing, error) then moving from that to: slog.Error("failed to frob", "thing", thing, "error", error) isn't terribly difficult, and will make log analysis dramatically easier.
  - lsaferite 3y ago
    Given your example of log.Printf("failed to frob %s: %s", thing, error) Wouldn't you just want to use slog.Error("failed to frob", thing, error) That keeps the _value_ of `thing` as the key and the _value_ of `error` as the value. That would keep more in line with your first example.
    - duskwuff 3y ago
      Probably not. ELK-style log analysis tools benefit from having messages follow a consistent schema. Using a variable as a key makes indexing much more difficult, and can make it impossible to detect patterns where (for example) a single error appears sporadically across many different values of "thing". If "thing" were a variable with a small cardinality (like a class name or an enumeration), that might change matters. But I'd still be reluctant to do that; having the two values available in separate fields, rather than as a single key/value pair, is a lot more flexible.
      - lsaferite 3y ago
        Oh, sorry if I was unclear, I wouldn't do that. I was just suggesting that it was closer to the original log message design. :) I'm a massive structured logging fan and have used it for quite a long time. In go I've used zerolog mostly, but I bring structured logs to whatever language I'm working with.
ar_lan 3y ago
I'm so happy this is a stdlib feature. This is good enough for me to not need to bring in external loggers (e.g. zerolog) which is nice, and I strongly think that structured logging should be the default logging format. Logs are data.
geodel 3y ago
With this another most requested feature is covered by Go. This leaves error handling, enum type which are often asked by users but are not actively being worked on for now.
- earthboundkid 3y ago
  An iterator type is being actively worked on now. After that presumably the missing data types in the standard library will be filled out (set, deque, a usable heap, whatever other algorithms). After that, who knows. Maybe native bigints? I don’t really see the enum thing happened. Is lack of enums a real problem? Theoretically, it would be convenient, but I can’t say that I see bugs caused by its lack.
  - howinteresting 3y ago
    Enums with associated values are a very basic data modeling primitive. Writing code without them is like doing arithmetic with only the multiplication sign, not the plus sign.
  - LambdaComplex 3y ago
    Having "type MyType int" and defining a bunch of constants isn't a great replacement for enums. Yeah, it "works," but it still lets the developer forget to check for a possible variant, or you could have an underlying int that doesn't correspond to a valid variant. The addition of enums would move all these runtime checks to compile time.
    - deleted 3y ago
      [deleted]
    - euroderf 3y ago
      As a workaround, a list in a DB combined with a foreign key constraint. Ugly, yes.
- jmarchello 3y ago
  The lack of Error Handling in Go is a feature, not a bug. See here: https://go.dev/doc/faq#exceptions https://go.dev/doc/faq#exceptions. I think I'd be disappointed if Try/Catch ever made their way into the language.
dgb23 3y ago
The rationale: > With many structured logging packages to choose from, large programs will often end up including more than one through their dependencies. The main program might have to configure each of these logging packages so that the log output is consistent: it all goes to the same place, in the same format. By including structured logging in the standard library, we can provide a common framework that all the other structured logging packages can share. This is IMO the right way of doing it. Provide an interface with simple defaults, usable out of the box. Those who need more can use a library that builds towards the interface. So when evaluating any library, you can ask "How well does this integrate with interfaces in the standard library?". Discovering that some functionality is just a "Fooer" that pieces well together with existing stuff is calming. Not only do you already know how to "Foo", you also get a hidden stability benefit: There's an implied API surface contract here. This is in stark contrast to the "builds on top of" approach, where you end up with competing, idiosyncratic interfaces. This is often necessary, but there is always an implied risk in terms of maintenance and compatibility.
- ljm 3y ago
  Something like this would be a welcome addition to Ruby/Rails where you have to pull in dependencies that patch the multiple independent loggers in the stack, some of which break messages onto multiple lines, not to mention the common case of inconsistent tagged and structural logging in your application code. It’s a lot of effort when all you want is to log everything to STDOUT, in JSON, but you have to choose one of half a dozen logging libraries that all behave extremely differently.
- gdprrrr 3y ago
  Rust seems to do find with a de-facto logging library, and the Java ecosystem seems to have converged on a common API, but with a lot of effort I think.
  - jjice 3y ago
    PHP did so with PSR-3 as well https://www.php-fig.org/psr/psr-3/ https://www.php-fig.org/psr/psr-3/.
baz00 3y ago
Now all we need is the 1,000,000 other components in the multiple ecosystems to log in the same format and I won't have a perpetual headache. Good job Go though for being opinionated but rational.
- DerCed 3y ago
  There are some attempts with Elastic Common Schema [1] or OpenTelemetry [2]. [1] https://www.elastic.co/guide/en/ecs-logging/overview/current/intro.html https://www.elastic.co/guide/en/ecs-logging/overview/current... [2] https://opentelemetry.io/docs/specs/otel/logs/data-model/ https://opentelemetry.io/docs/specs/otel/logs/data-model/
mrweasel 3y ago
Admittedly I'm not a huge fan of having: slog.Info("hello, world", "user", os.Getenv("USER")) It's a little magical that "user" is a key. So what if you have multiple key-value pairs? Arguably it most likely going to be obvious which is the keys, but having every other value be a key and the rest values seems a little clumsy. I really like Pythons approach where you can have user="value" it makes things a bit more clear.
- packetlost 3y ago
  Yeah, I agree. Passing in an optional `map[string]string` or something would be better, but then you get into having to either pass in `nil` every time you don't have the extra data or needing an entirely different function for with vs without the map
  - masklinn 3y ago
    > Passing in an optional `map[string]string` or something would be better It would definitely not be better from the point of view of > We wanted slog to be fast.
    - packetlost 3y ago
      A better interface/API is really what I meant. The performance characteristics are probably worth the tradeoff.
      - returningfory2 3y ago
        Passing in a map would require an extra allocation for the map memory for each log line. I think the performance would probably not be great?
        packetlost 3y ago
        it depends. I believe map literals are stack allocated if they aren't shared across goroutines or globals.
corytheboyd 3y ago
Structured logging is such an easy to gain, massive improvement to observability. Assuming you can pay for the log processor to make sense of it all :) I’ve been working on a side project to bring something like the DataDog log explorer to the local development environment. The prototype I made has already been extremely helpful in debugging issues in a very complex async ball of Rails code. Does something like that sound useful to other folks? Does it already exist and I just can’t find it?
- merightnow 3y ago
  Have you checked lnav?
  - corytheboyd 3y ago
    I’ve seen it mentioned before, but I haven’t given it a demo yet. To be honest I wasn’t sure if TUI was the right UI for something like this, as it can’t pull off all of the things a GUI can. It’s not that I have a TUI allergy either (I can’t live without lazygit).
    - scottlamb 3y ago
      lnav is neat but doesn't really do structured logging AFAICT, just predetermined fields for the format.
      - physicles 3y ago
        Yeah it's essential to have a viewer that deals natively with structured logs. I'm iterating on a log pretty printer that accepts structured logs in a pipe and does things like color coding, adding terminal-recognized vscode:// hyperlinks for call stacks, smart wrapping based on the terminal width, and special formatting for panics and stuff. NCurses is probably coming in a couple months. Does anything like this already exist?
      - tstack 3y ago
        lnav has support for JSON-lines, logfmt, as well as the Bro and W3C Extended Log File formats that are XSV and self-describing. The contents are also accessible through SQLite tables. Is there some gap here that you're thinking of?
zknill 3y ago
The new structured logging library is a great addition, its nice to have structured logging in the standard lib. It's easy to get started with log/slog and one of the built in handlers, but as soon as you want to change something the library design pushes you towards implementing an entire handler. For example, if I want the built in JSON format, but with a different formatting of the Time field, that's not easy to do. It's not obvious how to change the built in handler. I wrote slogmw[1] to solve this problem. It's a set of middleware and examples that make it easy to make small changes to the built in handlers without having to write a whole new handler from scratch. [1] https://github.com/zknill/slogmw https://github.com/zknill/slogmw
- numbsafari 3y ago
  Nice middleware package. I have to admit, the `log.InfoContext(ctx,...` style of redundancy that permeates the standard lib at this point is really gross, especially given that the most common use case for go is going to have contexts everywhere.
  - yashap 3y ago
    Go’s decision to not support function overloading leads to a tonne of really ugly APIs. Obviously every decision in language design is a tradeoff, but IMO they made the wrong call here.
    - philosopher1234 3y ago
      I'm not sure how I feel about this. What are the actual consequences of these apis being "ugly"? Like, why does that matter?
      - numbsafari 3y ago
        To me, at least, it is like listening to a person who constantly says "uh..." while talking. Occasionally, sure fine. But it's so pervasive in commonly used APIs that it becomes annoying. Let's be clear: this is just a peeve of mine.
candiddevmike 3y ago
Looking for advice: logging for servers/services tends to be different than logging for CLI-based applications. How do folks differentiate them or use slog for them in a generic way? Or does it make sense to have separate logging packages for CLI vs services? CLI tends to be more verbose and procedural vs servers/service based logging which is more errors only unless debug.
- zknill 3y ago
  Assuming you are logging from some package that's shared over a CLI app and some webservice app; log/slog expects you to setup the slog logger with a specific handler. This handler controls _how_ events are written out, the format of them etc. If you want to use slog, I can imagine setting up the logger with a handler specific for the CLI output in the CLI tool, and a json or text structured handler in the webservice app. The quesiton is, do you actually want structured logging in the CLI app? Yes you probably want to print something out, but is it _structured_ in the sense that slog expects? Or is it just some output. If it's not really structured, then you probably want some other interface/library that better represents the logging you want to do. Slog will push you towards structured key-value pairs, and you might find yourself fighting against this in the CLI app.
  - candiddevmike 3y ago
    It seems like I could write an output handler for the CLI app that is more terminal-appropriate. I'd like to abstract logging for functions shared by both (especially debug logs). Today I have combined the functions of logging and tracing/sampling into one package/function call as they are equivalent in my eyes.
kusha 3y ago
Oof. We just converted all of our logging to zap[0] to get structured JSON logging for downstream parsing. Wonder how the perf stacks up. [0]: https://github.com/uber-go/zap https://github.com/uber-go/zap
- tony_cannistra 3y ago
  It looks like they've included slog in their performance benchmarks, which show zap as considerably more performant (though I don't really understand the benchmark).
  - llimllib 3y ago
    http://bench.zerolog.io/ http://bench.zerolog.io/ Is a useful set of benchmarks
  - yencabulator 3y ago
    That test puts a lot of stuff through `slog.Any`, while the zap version uses more strongly-typed variants, so I'm not sure it's a fair comparison. What it comes down to is that zap special cases things like slice-of-int, slice-of-string, slice-of-timestamp, slog doesn't, and the benchmark includes all those special cases. I question whether your typical log statement includes slices. A more fair benchmark would be just scalar types, and zap & slog optimizations there look pretty similar. https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719cc2aaf9a0e72d635/benchmarks/slog_test.go#L41 https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719... https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719cc2aaf9a0e72d635/benchmarks/zap_test.go#L127 https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719...
nwsm 3y ago
It's nice to have this in the standard library, but it doesn't solve any existing pain points around structured log metadata and contexts. We use zap [0] and store a zap logger on the request context which allows different parts of the request pipeline to log with things like tenantId, traceId, and correlationId automatically appended. But getting a logger off the context is annoying, leads to inconsistent logging practices, and creates a logger dependency throughout most of our Go code. [0] https://github.com/uber-go/zap https://github.com/uber-go/zap
- zknill 3y ago
  log/slog package essentially delegates writing log messages to some "handler" interface. The key method is: Handle(context.Context, Record) error This method has access to the context, which means you can get the logging handler to extract values from the context. Instead of storing the logger on the context, you can extract the traceId, etc values from the context and log those. It's a little bit involved to write a whole logger from scratch, but you can 'wrap' the existing logger handlers and include values from the context relatively easily. There are examples in this project (which aims to help solve your usecase): https://github.com/zknill/slogmw https://github.com/zknill/slogmw
  - ryandotsmith 3y ago
    Here's an example of extracting context values in a custom slog handler: https://github.com/indexsupply/x/blob/main/wslog/slog_test.go#L14-L26 https://github.com/indexsupply/x/blob/main/wslog/slog_test.g...
- thiht 3y ago
  This is addressed in the article. > As the call to LogAttrs shows, you can pass a context.Context to some log functions so a handler can extract context information like trace IDs. I’m not a fan of slog’s syntax, but the convenience of having it in the stdlib trumps that, for me.
__loam 3y ago
Slog is an amazing name
mihaitodor 3y ago
Benthos just adopted it: https://github.com/benthosdev/benthos/commit/ee0000450413ad37685ecbfe0d1ef40d178d29fb https://github.com/benthosdev/benthos/commit/ee0000450413ad3...
- icholy 3y ago
  I might have misunderstood, but shouldn't the adapter be operating on a `slog.Handler`?
  - mihaitodor 3y ago
    slog’s top-level functions use the default logger, so using that made the most sense for now. There are some custom labels being injected (see the `WithFields()` method) but that's about it.
Femolo 3y ago
Log everything as Json! We need to start making Json viewer were we look into log files without tooling the default. It's so much easier to use Json automatically and ship them to systems out of the box. Linux logging should do that too. Not just container in k8s
- benatkin 3y ago
  This supports quoting values. There isn't much JSON would add except overhead and making it a bit simpler to read and write them. I really don't think it's worth the overhead.
mi_lk 3y ago
Q: what do people use for structured logging in Java?
- monknomo 3y ago
  Logback has structured logging. I think log4j has it as well
- paulddraper 3y ago
  Any Java logger has structured logging. The prevailing solution is SLF4J, which is a facade that can be implemented by any number of backends, e.g. Logback. There is logging in the stdlib (java.util.logging), but it's the less common choice, for whatever reason.
bobbyi 3y ago
Walking past an eatery with outdoor seating, I overheard one diner say the phrase "process raw logs" and I thought, "wow, I guess that is one of those tricky problems that basically everyone ends up dealing with". And then I heard "... with a chainsaw. It's a chainsaw mill" and realized I may have misunderstood the context.
- deleted 3y ago
  [deleted]
politician 3y ago
I wish there was a better approach for the problem of avoiding function calls when the log level at runtime is higher than the call site. So, slog.Info("failed to frob", "thing", GetThing(1)) Still calls GetThing(1) when the log level is greater than Info. The only solution right now for this is to test the log level before making the logging call. It would be amazing if language designers could make the arguments late bound instead or used aspect-oriented programming approaches to protect each logging call site.
- jeffbee 3y ago
  There are other languages of course where the logging avoids this, even in libraries written by the same company that writes Go. In C++, the Abseil logging library (f.k.a. glog) will not evaluate a condition for a disabled log level. LOG(INFO) << WowExpensiveFunction(); This is safe when the log level is set to WARN or higher. For the same reasons, LOG_EVERY_N and LOG_FIRST_N in the same library are pretty cheap.
- sa46 3y ago
  There is. See slog.LogValuer https://pkg.go.dev/golang.org/x/exp/slog#LogValuer https://pkg.go.dev/golang.org/x/exp/slog#LogValuer
- yencabulator 3y ago
  https://pkg.go.dev/log/slog#hdr-Performance_considerations https://pkg.go.dev/log/slog#hdr-Performance_considerations
tastysandwich 3y ago
I'm really glad they've introduced this, I just wish it also had the traditional formatting methods, eg Infof, Debugf, Errorf, etc, for backwards compatibility. I've got a few packages that accept a basic logger interface, eg: type debugLogger interface { Debugf(format string, args ...any) } type MyThing struct { logger debugLogger } func New(logger debugLogger) *MyThing { return &MyThing{logger} } I'd love to switch to slog but I'll have to v2 these packages now.
- crdrost 3y ago
  I would defend slog's decision there. Infof/Debugf/Errorf are like fine especially when I'm making a little CLI tool for myself, but my main consumption of logs at work is other peoples' logs via a cloud log aggregator, and so when you give other devs who are not me Sprintf they start to do things like "[%s] default/%v - %v" or so, which makes sense to them but doesn't give me great strings to search for when I'm trying to figure out "what were all of the situations in which this strange thing happened". It's like when you're trying to internationalize, you want to emit as constant of a string as reasonably practical, so that it can be straightforwardly matched and substituted into a different language. Except in this case that different language is regexes being used to change the thing into a SQL statement to fix the mess (or whatever). So much easier to say "stop trying to Sprintf your logs, just add the values as key-value pairs at the end of the function call."
  - physicles 3y ago
    I'm slowly retraining myself to write structured logs instead of Infof, etc. The extra effort really is negligible. There's a nice benefit too: my log printer takes structured logs and adds color coding, which isn't possible with Infof.
jasonhansel 3y ago
I must admit: I'm not a huge fan of structured logging, beyond simple use cases like tagging messages by the thread that produced them. If you want something machine-readable, use a dedicated metrics system, analytics database, or document store. If you want something human-readable, structured logging will only make things worse.
- jimmcslim 3y ago
  I feel what is missing here is message templates [1] - the logging API should permit the key-value pairs to be substituted into a template which results in a human-readable message, while preserving the KV data separately. Take a hash of the template and add it as a KV pair so that messages of the same type can be easily filtered. [1] https://messagetemplates.org https://messagetemplates.org
  - masklinn 3y ago
    Loggers are just façade objects on Handlers, which is an interface. It’s really designed to be a minimum necessary package to allow interop (via handlers) and a baseline of standalone usability (via loggers). The stdlib only provides a text and a json handler, not even a no-op handler which I think is sorely neededor a multi handler which I think would make a lot of sense. But nothing precludes you publishing a messagetemplates handler, or whatever else you may want.
- andreygrehov 3y ago
  Structured logging is not meant for humans to read. It's meant for machines to read and represent in a human readable format. Additionally, these logs can _later_ be streamed into a metrics system, analytics database, or a document store. Sort of in a plug & play fashion.
User23 3y ago
Just log to sqlite. It’s literally better than all the alternatives, but for some reason nobody does.
- yencabulator 3y ago
  That'd be a slog.Handler, not a reason to avoid the new standard API.
  - User23 3y ago
    That’s missing the point. SQL itself, specifically the sqlite dialect, is the new standard API I’m advocating. I’m claiming that any traditional log library interface is going to be worse.
Seb-C 3y ago
I guess it's nice to have a standard, but I wish the Golang developers stopped introducing stuff like "args ...any" all over the place in the standard library. It's not the level of type-safety that I expect from a strongly typed language.

275 points by spacey 3y ago

Structured logging is a very sane default. Even if you end up with `{"msg": "blah blah blah"}` at least you have room to grow in the future.

duskwuff 3y ago
And if your current logging is along the lines of log.Printf("failed to frob %s: %s", thing, error) then moving from that to: slog.Error("failed to frob", "thing", thing, "error", error) isn't terribly difficult, and will make log analysis dramatically easier.
- lsaferite 3y ago
  Given your example of log.Printf("failed to frob %s: %s", thing, error) Wouldn't you just want to use slog.Error("failed to frob", thing, error) That keeps the _value_ of `thing` as the key and the _value_ of `error` as the value. That would keep more in line with your first example.
  - duskwuff 3y ago
    Probably not. ELK-style log analysis tools benefit from having messages follow a consistent schema. Using a variable as a key makes indexing much more difficult, and can make it impossible to detect patterns where (for example) a single error appears sporadically across many different values of "thing". If "thing" were a variable with a small cardinality (like a class name or an enumeration), that might change matters. But I'd still be reluctant to do that; having the two values available in separate fields, rather than as a single key/value pair, is a lot more flexible.
    - lsaferite 3y ago
      Oh, sorry if I was unclear, I wouldn't do that. I was just suggesting that it was closer to the original log message design. :) I'm a massive structured logging fan and have used it for quite a long time. In go I've used zerolog mostly, but I bring structured logs to whatever language I'm working with.

ar_lan 3y ago

I'm so happy this is a stdlib feature. This is good enough for me to not need to bring in external loggers (e.g. zerolog) which is nice, and I strongly think that structured logging should be the default logging format. Logs are data.

geodel 3y ago

With this another most requested feature is covered by Go. This leaves error handling, enum type which are often asked by users but are not actively being worked on for now.

earthboundkid 3y ago
An iterator type is being actively worked on now. After that presumably the missing data types in the standard library will be filled out (set, deque, a usable heap, whatever other algorithms). After that, who knows. Maybe native bigints? I don’t really see the enum thing happened. Is lack of enums a real problem? Theoretically, it would be convenient, but I can’t say that I see bugs caused by its lack.
- howinteresting 3y ago
  Enums with associated values are a very basic data modeling primitive. Writing code without them is like doing arithmetic with only the multiplication sign, not the plus sign.
- LambdaComplex 3y ago
  Having "type MyType int" and defining a bunch of constants isn't a great replacement for enums. Yeah, it "works," but it still lets the developer forget to check for a possible variant, or you could have an underlying int that doesn't correspond to a valid variant. The addition of enums would move all these runtime checks to compile time.
  - deleted 3y ago
    [deleted]
  - euroderf 3y ago
    As a workaround, a list in a DB combined with a foreign key constraint. Ugly, yes.
jmarchello 3y ago
The lack of Error Handling in Go is a feature, not a bug. See here: https://go.dev/doc/faq#exceptions https://go.dev/doc/faq#exceptions. I think I'd be disappointed if Try/Catch ever made their way into the language.

dgb23 3y ago

The rationale: > With many structured logging packages to choose from, large programs will often end up including more than one through their dependencies. The main program might have to configure each of these logging packages so that the log output is consistent: it all goes to the same place, in the same format. By including structured logging in the standard library, we can provide a common framework that all the other structured logging packages can share. This is IMO the right way of doing it. Provide an interface with simple defaults, usable out of the box. Those who need more can use a library that builds towards the interface. So when evaluating any library, you can ask "How well does this integrate with interfaces in the standard library?". Discovering that some functionality is just a "Fooer" that pieces well together with existing stuff is calming. Not only do you already know how to "Foo", you also get a hidden stability benefit: There's an implied API surface contract here. This is in stark contrast to the "builds on top of" approach, where you end up with competing, idiosyncratic interfaces. This is often necessary, but there is always an implied risk in terms of maintenance and compatibility.

ljm 3y ago
Something like this would be a welcome addition to Ruby/Rails where you have to pull in dependencies that patch the multiple independent loggers in the stack, some of which break messages onto multiple lines, not to mention the common case of inconsistent tagged and structural logging in your application code. It’s a lot of effort when all you want is to log everything to STDOUT, in JSON, but you have to choose one of half a dozen logging libraries that all behave extremely differently.
gdprrrr 3y ago
Rust seems to do find with a de-facto logging library, and the Java ecosystem seems to have converged on a common API, but with a lot of effort I think.
- jjice 3y ago
  PHP did so with PSR-3 as well https://www.php-fig.org/psr/psr-3/ https://www.php-fig.org/psr/psr-3/.

baz00 3y ago

Now all we need is the 1,000,000 other components in the multiple ecosystems to log in the same format and I won't have a perpetual headache. Good job Go though for being opinionated but rational.

DerCed 3y ago
There are some attempts with Elastic Common Schema [1] or OpenTelemetry [2]. [1] https://www.elastic.co/guide/en/ecs-logging/overview/current/intro.html https://www.elastic.co/guide/en/ecs-logging/overview/current... [2] https://opentelemetry.io/docs/specs/otel/logs/data-model/ https://opentelemetry.io/docs/specs/otel/logs/data-model/

mrweasel 3y ago

Admittedly I'm not a huge fan of having: slog.Info("hello, world", "user", os.Getenv("USER")) It's a little magical that "user" is a key. So what if you have multiple key-value pairs? Arguably it most likely going to be obvious which is the keys, but having every other value be a key and the rest values seems a little clumsy. I really like Pythons approach where you can have user="value" it makes things a bit more clear.

packetlost 3y ago
Yeah, I agree. Passing in an optional `map[string]string` or something would be better, but then you get into having to either pass in `nil` every time you don't have the extra data or needing an entirely different function for with vs without the map
- masklinn 3y ago
  > Passing in an optional `map[string]string` or something would be better It would definitely not be better from the point of view of > We wanted slog to be fast.
  - packetlost 3y ago
    A better interface/API is really what I meant. The performance characteristics are probably worth the tradeoff.
    - returningfory2 3y ago
      Passing in a map would require an extra allocation for the map memory for each log line. I think the performance would probably not be great?
      - packetlost 3y ago
        it depends. I believe map literals are stack allocated if they aren't shared across goroutines or globals.

corytheboyd 3y ago

Structured logging is such an easy to gain, massive improvement to observability. Assuming you can pay for the log processor to make sense of it all :) I’ve been working on a side project to bring something like the DataDog log explorer to the local development environment. The prototype I made has already been extremely helpful in debugging issues in a very complex async ball of Rails code. Does something like that sound useful to other folks? Does it already exist and I just can’t find it?

merightnow 3y ago
Have you checked lnav?
- corytheboyd 3y ago
  I’ve seen it mentioned before, but I haven’t given it a demo yet. To be honest I wasn’t sure if TUI was the right UI for something like this, as it can’t pull off all of the things a GUI can. It’s not that I have a TUI allergy either (I can’t live without lazygit).
  - scottlamb 3y ago
    lnav is neat but doesn't really do structured logging AFAICT, just predetermined fields for the format.
    - physicles 3y ago
      Yeah it's essential to have a viewer that deals natively with structured logs. I'm iterating on a log pretty printer that accepts structured logs in a pipe and does things like color coding, adding terminal-recognized vscode:// hyperlinks for call stacks, smart wrapping based on the terminal width, and special formatting for panics and stuff. NCurses is probably coming in a couple months. Does anything like this already exist?
    - tstack 3y ago
      lnav has support for JSON-lines, logfmt, as well as the Bro and W3C Extended Log File formats that are XSV and self-describing. The contents are also accessible through SQLite tables. Is there some gap here that you're thinking of?

zknill 3y ago

The new structured logging library is a great addition, its nice to have structured logging in the standard lib. It's easy to get started with log/slog and one of the built in handlers, but as soon as you want to change something the library design pushes you towards implementing an entire handler. For example, if I want the built in JSON format, but with a different formatting of the Time field, that's not easy to do. It's not obvious how to change the built in handler. I wrote slogmw[1] to solve this problem. It's a set of middleware and examples that make it easy to make small changes to the built in handlers without having to write a whole new handler from scratch. [1] https://github.com/zknill/slogmw https://github.com/zknill/slogmw

numbsafari 3y ago
Nice middleware package. I have to admit, the `log.InfoContext(ctx,...` style of redundancy that permeates the standard lib at this point is really gross, especially given that the most common use case for go is going to have contexts everywhere.
- yashap 3y ago
  Go’s decision to not support function overloading leads to a tonne of really ugly APIs. Obviously every decision in language design is a tradeoff, but IMO they made the wrong call here.
  - philosopher1234 3y ago
    I'm not sure how I feel about this. What are the actual consequences of these apis being "ugly"? Like, why does that matter?
    - numbsafari 3y ago
      To me, at least, it is like listening to a person who constantly says "uh..." while talking. Occasionally, sure fine. But it's so pervasive in commonly used APIs that it becomes annoying. Let's be clear: this is just a peeve of mine.

candiddevmike 3y ago

Looking for advice: logging for servers/services tends to be different than logging for CLI-based applications. How do folks differentiate them or use slog for them in a generic way? Or does it make sense to have separate logging packages for CLI vs services? CLI tends to be more verbose and procedural vs servers/service based logging which is more errors only unless debug.

zknill 3y ago
Assuming you are logging from some package that's shared over a CLI app and some webservice app; log/slog expects you to setup the slog logger with a specific handler. This handler controls _how_ events are written out, the format of them etc. If you want to use slog, I can imagine setting up the logger with a handler specific for the CLI output in the CLI tool, and a json or text structured handler in the webservice app. The quesiton is, do you actually want structured logging in the CLI app? Yes you probably want to print something out, but is it _structured_ in the sense that slog expects? Or is it just some output. If it's not really structured, then you probably want some other interface/library that better represents the logging you want to do. Slog will push you towards structured key-value pairs, and you might find yourself fighting against this in the CLI app.
- candiddevmike 3y ago
  It seems like I could write an output handler for the CLI app that is more terminal-appropriate. I'd like to abstract logging for functions shared by both (especially debug logs). Today I have combined the functions of logging and tracing/sampling into one package/function call as they are equivalent in my eyes.

kusha 3y ago

Oof. We just converted all of our logging to zap[0] to get structured JSON logging for downstream parsing. Wonder how the perf stacks up. [0]: https://github.com/uber-go/zap https://github.com/uber-go/zap

tony_cannistra 3y ago
It looks like they've included slog in their performance benchmarks, which show zap as considerably more performant (though I don't really understand the benchmark).
- llimllib 3y ago
  http://bench.zerolog.io/ http://bench.zerolog.io/ Is a useful set of benchmarks
- yencabulator 3y ago
  That test puts a lot of stuff through `slog.Any`, while the zap version uses more strongly-typed variants, so I'm not sure it's a fair comparison. What it comes down to is that zap special cases things like slice-of-int, slice-of-string, slice-of-timestamp, slog doesn't, and the benchmark includes all those special cases. I question whether your typical log statement includes slices. A more fair benchmark would be just scalar types, and zap & slog optimizations there look pretty similar. https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719cc2aaf9a0e72d635/benchmarks/slog_test.go#L41 https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719... https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719cc2aaf9a0e72d635/benchmarks/zap_test.go#L127 https://github.com/uber-go/zap/blob/fd37f1f613a87773fc30f719...

nwsm 3y ago

It's nice to have this in the standard library, but it doesn't solve any existing pain points around structured log metadata and contexts. We use zap [0] and store a zap logger on the request context which allows different parts of the request pipeline to log with things like tenantId, traceId, and correlationId automatically appended. But getting a logger off the context is annoying, leads to inconsistent logging practices, and creates a logger dependency throughout most of our Go code. [0] https://github.com/uber-go/zap https://github.com/uber-go/zap

zknill 3y ago
log/slog package essentially delegates writing log messages to some "handler" interface. The key method is: Handle(context.Context, Record) error This method has access to the context, which means you can get the logging handler to extract values from the context. Instead of storing the logger on the context, you can extract the traceId, etc values from the context and log those. It's a little bit involved to write a whole logger from scratch, but you can 'wrap' the existing logger handlers and include values from the context relatively easily. There are examples in this project (which aims to help solve your usecase): https://github.com/zknill/slogmw https://github.com/zknill/slogmw
- ryandotsmith 3y ago
  Here's an example of extracting context values in a custom slog handler: https://github.com/indexsupply/x/blob/main/wslog/slog_test.go#L14-L26 https://github.com/indexsupply/x/blob/main/wslog/slog_test.g...
thiht 3y ago
This is addressed in the article. > As the call to LogAttrs shows, you can pass a context.Context to some log functions so a handler can extract context information like trace IDs. I’m not a fan of slog’s syntax, but the convenience of having it in the stdlib trumps that, for me.

__loam 3y ago

Slog is an amazing name

mihaitodor 3y ago

Benthos just adopted it: https://github.com/benthosdev/benthos/commit/ee0000450413ad37685ecbfe0d1ef40d178d29fb https://github.com/benthosdev/benthos/commit/ee0000450413ad3...

icholy 3y ago
I might have misunderstood, but shouldn't the adapter be operating on a `slog.Handler`?
- mihaitodor 3y ago
  slog’s top-level functions use the default logger, so using that made the most sense for now. There are some custom labels being injected (see the `WithFields()` method) but that's about it.

Femolo 3y ago

Log everything as Json! We need to start making Json viewer were we look into log files without tooling the default. It's so much easier to use Json automatically and ship them to systems out of the box. Linux logging should do that too. Not just container in k8s

benatkin 3y ago
This supports quoting values. There isn't much JSON would add except overhead and making it a bit simpler to read and write them. I really don't think it's worth the overhead.

mi_lk 3y ago

Q: what do people use for structured logging in Java?

monknomo 3y ago
Logback has structured logging. I think log4j has it as well
paulddraper 3y ago
Any Java logger has structured logging. The prevailing solution is SLF4J, which is a facade that can be implemented by any number of backends, e.g. Logback. There is logging in the stdlib (java.util.logging), but it's the less common choice, for whatever reason.

bobbyi 3y ago

Walking past an eatery with outdoor seating, I overheard one diner say the phrase "process raw logs" and I thought, "wow, I guess that is one of those tricky problems that basically everyone ends up dealing with". And then I heard "... with a chainsaw. It's a chainsaw mill" and realized I may have misunderstood the context.

deleted 3y ago
[deleted]

politician 3y ago

I wish there was a better approach for the problem of avoiding function calls when the log level at runtime is higher than the call site. So, slog.Info("failed to frob", "thing", GetThing(1)) Still calls GetThing(1) when the log level is greater than Info. The only solution right now for this is to test the log level before making the logging call. It would be amazing if language designers could make the arguments late bound instead or used aspect-oriented programming approaches to protect each logging call site.

jeffbee 3y ago
There are other languages of course where the logging avoids this, even in libraries written by the same company that writes Go. In C++, the Abseil logging library (f.k.a. glog) will not evaluate a condition for a disabled log level. LOG(INFO) << WowExpensiveFunction(); This is safe when the log level is set to WARN or higher. For the same reasons, LOG_EVERY_N and LOG_FIRST_N in the same library are pretty cheap.
sa46 3y ago
There is. See slog.LogValuer https://pkg.go.dev/golang.org/x/exp/slog#LogValuer https://pkg.go.dev/golang.org/x/exp/slog#LogValuer
yencabulator 3y ago
https://pkg.go.dev/log/slog#hdr-Performance_considerations https://pkg.go.dev/log/slog#hdr-Performance_considerations

tastysandwich 3y ago

I'm really glad they've introduced this, I just wish it also had the traditional formatting methods, eg Infof, Debugf, Errorf, etc, for backwards compatibility. I've got a few packages that accept a basic logger interface, eg: type debugLogger interface { Debugf(format string, args ...any) } type MyThing struct { logger debugLogger } func New(logger debugLogger) *MyThing { return &MyThing{logger} } I'd love to switch to slog but I'll have to v2 these packages now.

crdrost 3y ago
I would defend slog's decision there. Infof/Debugf/Errorf are like fine especially when I'm making a little CLI tool for myself, but my main consumption of logs at work is other peoples' logs via a cloud log aggregator, and so when you give other devs who are not me Sprintf they start to do things like "[%s] default/%v - %v" or so, which makes sense to them but doesn't give me great strings to search for when I'm trying to figure out "what were all of the situations in which this strange thing happened". It's like when you're trying to internationalize, you want to emit as constant of a string as reasonably practical, so that it can be straightforwardly matched and substituted into a different language. Except in this case that different language is regexes being used to change the thing into a SQL statement to fix the mess (or whatever). So much easier to say "stop trying to Sprintf your logs, just add the values as key-value pairs at the end of the function call."
- physicles 3y ago
  I'm slowly retraining myself to write structured logs instead of Infof, etc. The extra effort really is negligible. There's a nice benefit too: my log printer takes structured logs and adds color coding, which isn't possible with Infof.

jasonhansel 3y ago

I must admit: I'm not a huge fan of structured logging, beyond simple use cases like tagging messages by the thread that produced them. If you want something machine-readable, use a dedicated metrics system, analytics database, or document store. If you want something human-readable, structured logging will only make things worse.

jimmcslim 3y ago
I feel what is missing here is message templates [1] - the logging API should permit the key-value pairs to be substituted into a template which results in a human-readable message, while preserving the KV data separately. Take a hash of the template and add it as a KV pair so that messages of the same type can be easily filtered. [1] https://messagetemplates.org https://messagetemplates.org
- masklinn 3y ago
  Loggers are just façade objects on Handlers, which is an interface. It’s really designed to be a minimum necessary package to allow interop (via handlers) and a baseline of standalone usability (via loggers). The stdlib only provides a text and a json handler, not even a no-op handler which I think is sorely neededor a multi handler which I think would make a lot of sense. But nothing precludes you publishing a messagetemplates handler, or whatever else you may want.
andreygrehov 3y ago
Structured logging is not meant for humans to read. It's meant for machines to read and represent in a human readable format. Additionally, these logs can _later_ be streamed into a metrics system, analytics database, or a document store. Sort of in a plug & play fashion.

User23 3y ago

Just log to sqlite. It’s literally better than all the alternatives, but for some reason nobody does.

yencabulator 3y ago
That'd be a slog.Handler, not a reason to avoid the new standard API.
- User23 3y ago
  That’s missing the point. SQL itself, specifically the sqlite dialect, is the new standard API I’m advocating. I’m claiming that any traditional log library interface is going to be worse.

Seb-C 3y ago

I guess it's nice to have a standard, but I wish the Golang developers stopped introducing stuff like "args ...any" all over the place in the standard library. It's not the level of type-safety that I expect from a strongly typed language.