Structured logging with slog (opens in new tab)

I think Uber chose a better approach for their Go logging library called Zap [1]

    logger.Info("failed to fetch URL",
      // Structured context as strongly typed Field values.
      zap.String("url", url),
      zap.Int("attempt", 3),
      zap.Duration("backoff", time.Second),
    )

They also have zap.Error(err) which generates the "error" key as a convention.

[1] https://github.com/uber-go/zap

> It's a little magical that "user" is a key. So what if you have multiple key-value pairs?

You... add them afterwards? It's really just a plist (https://www.gnu.org/software/emacs/manual/html_node/elisp/Pr...), that's hardly novel. The method takes any number of parameters and pairs them up as key, value.

Or if you really hate yourself, you use LogAttrs with explicitly constructed Attr objects.

> I really like Pythons approach where you can have user="value" it makes things a bit more clear.

The trouble is, Go doesn't have keyword parameters so that doesn't work.

It’s not without precedence, for example: https://pkg.go.dev/strings#NewReplacer

I don’t mind it. You can use LogAttrs if you want to be explicit.

Although I do wonder if there’s anything tricky with the type system that is preventing something like this from being supported: https://go.dev/play/p/_YV7sYdnZ5V

If you had read more than the introduction you’d have found a paragraph about this in the middle and multiple at the end.

You use attrs [1] instead. I personally find this much more readable, and prefer this.

  slog.Info("hello, world", slog.String("user", os.Getenv("USER")))

[1]: https://pkg.go.dev/log/slog#hdr-Attrs_and_Values

Rust's slog ( https://docs.rs/slog/ ) does:

  use slog::info;
  ...
  info!("hello, world"; "user" => std::env::var("USER"));

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

this is not uncommon. this is what I've been dealing with earlier today in Postgres:

  json_build_object ( VARIADIC "any" ) → json

  jsonb_build_object ( VARIADIC "any" ) → jsonb

  Builds a JSON object out of a variadic argument list.
  By convention, the argument list consists of alternating keys and values.
  Key arguments are coerced to text; value arguments are converted as per to_json or to_jsonb.

      json_build_object('foo', 1, 2, row(3,'bar')) → {"foo" : 1, "2" : {"f1":3,"f2":"bar"}}

Plist or named arguments doesn't really make too big of a difference, to my eyes. I do recommend Mapped Diagnostic Context style approaches, if you can do it. Passing all arguments that you think may be useful to logs gets unwieldy quickly. Looks particularly absurd when folks start adding parameters to functions for the sole purpose of letting you log them.

Personally I only intend to ever use LogAttrs/AddAttrs/GroupValue, for this reason. I really don't want to count evens and odds.

Indeed. Logging a map-like object seems like a pretty basic expectation. Separate keys and values as parameters seem very C-like.

Today I'm pulling this out of a context object, can I still do that?

The same pattern can be seen in Java using Map.of(...)

> Does something like that sound useful to other folks?

Very much so!

One piece I'd like to have is a good output format from my program. Right now I have stuff outputting logs in JSON format to stderr/local file (then picked up by the Opentelemetry OTLP collector, Datadog agent, AWS CloudWatch, whatever) and the traces/spans actually sent from my process to the collector over the network. It baffles me why the traces/spans are done in that way rather than placed in a local file (and for compressibility, ideally the same file as the logs). The local file method would make it easier to have simple local-focused tools, would lower the requirements for outputting these records (no need to have async+http client set up, just the writer thread), and would better handle the collector being in a bad mood at the moment.

That's the most important piece, but if getting that done requires inventing a new format (it seems to?!?), there are some other details I'd like to it to do well. You should be able to see all the stuff associated with each log entry's matching span, which means that spans and attributes should be recorded on open, not just on close. (Attributes can also be updated mid-span; the Rust tracing library allows this.) (OpenTelemetry notably only supports complete spans). It could be more efficient by interning the keys. some care about how rotation is handled, timestamps are handled, etc.

The Grafana stack, including Loki for logs, can be started easily in a docker-compose project in your local environment. Not that Grafanas log viewer is the best in class but it’s at least something. For terminal fans there is a logcli.

If you are concerned with cost of the log processor, Loki again has your back by being very easy and lightweight to deploy. Giving you same tools in dev as in prod.

Have you checked lnav?

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.

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.

There are some attempts with Elastic Common Schema [1] or OpenTelemetry [2].

[1] https://www.elastic.co/guide/en/ecs-logging/overview/current... [2] https://opentelemetry.io/docs/specs/otel/logs/data-model/

The lack of Error Handling in Go is a feature, not a bug. See here: https://go.dev/doc/faq#exceptions. I think I'd be disappointed if Try/Catch ever made their way into the language.

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.

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

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.

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

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.

> but as soon as you want to change something the library design pushes you towards implementing an entire handler.

Yes, it annoyed me to no end. But OTOH I think it may be wise of them to see what the ecosystem finds and provide more convenience later. After all, it's std we're talking about, and this takes time to get right.

I'm personally missing:

- A goddamn default no-op/nil logger, that can be declared before initialized in e.g. structs.

- Customization to TextHandler for changing format easily, and omit keys (AIUI ReplaceAttr cannot omit stuff like `time="..."` on each line), which is critical since CLI screen real estate is incredibly sparse.

- (Controversial) but I would like opinionated logger initialization guidance for package authors, so that you get consistency across the ecosystem. Doesn't have to be exactly one way, but say.. two ways? E.g. a package-global and a struct-initialized version? Right now, people are even confusingly wondering if they should accept slog.Handler or *slog.Logger.

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.

There is. See slog.LogValuer

https://pkg.go.dev/golang.org/x/exp/slog#LogValuer

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.

I might have misunderstood, but shouldn't the adapter be operating on a `slog.Handler`?

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).

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."

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.

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.

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.

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.

Logback has structured logging. I think log4j has it as well

That'd be a slog.Handler, not a reason to avoid the new standard API.