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.
`[level]w` supports both key/value pairs and individual `zap.Type(key, value)` values combined fwiw, so for that part the API is essentially the same too
It's also the reflect on the value part which slows down things. It could be improved but it's hard to do that without breaking interface. It's so widely used that a major bump wouldn't that useful.
I'd expect it to be mostly called on map literals, at least a compile time constant set of keys. That should be amenable to a targeted compiler optimisation.
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
This is structured logging. Stubbornly insisting that "structured logging" === "map" is dumb and ignores a large fraction of use cases where performance matters.
You don’t need LogAttrs to pass in Attr entries, it should work fine with normal functions
The reason it doesn’t use maps is that maps are significantly slower, TFA has an entire section on performances.
However if you prefer that interface and don’t mind the performance hit, nothing precludes writing your own Logger (it’s just a façade over the Handler interface) and taking maps.
It can do that because Rust’s macros can have their own mini language at the top level, and can transform that into whatever data structure they want under the cover.
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
It's most definitely not. Logging is crucial for monitoring services, and making logging statements many times slower will either sink your service or push developers to avoid logging and making the service impossible to debug.
Most log metadata will be attached by libraries and middleware, so service/application devs won't even see most of it.
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.
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?
> 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.
I hadn't even considered collecting traces/spans in this way yet, and have taken the approach of "stuff outputting logs in JSON format to stderr/local file". I usually end up writing a (temporary, structured) log message with the relevant span tags, but wouldn't it be much better to run the actual trace/span code and be able to verify it locally without the ad-hoc log message?
The prototype I built is a web application that creates websocket connections, and if those connections receive messages that are JSON, log lines are added. Columns are built dynamically as log messages arrive, and then you can pick which columns to render in the table. If you're curious here's the code, including a screenshot: https://github.com/corytheboyd-smartsheet/json-log-explorer
With websockets, it's very easy to use websocketd (http://websocketd.com), which will watch input files for new lines, and write them verbatim as websocket messages to listeners (the web app).
To make the idea real, would want to figure out how to not require the user to run websocketd out of band, but watching good ol' files is dead simple, and very easy to add to most code (add a new log sink, use existing log file, 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.
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).
There are certainly limits on what can be displayed and done interactively due to the low resolution. Especially, when it comes to charting data. Some visualizations are available within lnav, mostly bar charts and the like. What type of things are you trying to do that you think are not possible within a TUI?
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?
The idea of structured logs is that every place in the code where you define a log message, you can throw in extra attributes (key/value) pairs.
As far as I can tell, the lnav feature you describing allows you to define a JSON log format with predefined fields. But if some log message uses an attribute you haven't anticipated in the format definition, there's no way to see it in the pretty-printed output or filter on it in the UI and no ability to see it in the SQLite virtual table. That's why I say lnav doesn't appear to support structured logs.
edit: oh, I missed `"hide-extra": false`! That significantly improves things! Still, I don't see a way to access it from the SQLite virtual table. I also don't see something else I might want: a way to have a different "view" for certain log messages; maybe to switch between filtering/viewing particular ones, maybe to just have line-format be conditional based on the detected format. (I guess I can sort of do this based on `module-field`? but I might want it lighter-weight/finer-grained than that.)
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.
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.
> 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.
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.
The core question of this subthread was what, if anything, the effect of only having a de facto logging solution was on a language community. The community easily coalescing around a de jure solution (and for a different problem with a significantly smaller API surface) is not really relevant to that.
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.
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.
Great, so Go has support for native stacktraces so bubbled errors don't get shadowed?
Just because Go made opinionated design decisions around their error handling a decade ago when developing the language doesn't mean that there's not practical room for improvement as the language is widely in production and shortcomings in its error handling have been found.
The number of hacks I've seen over the years to try and solve the "wait, where did this error originate" problem in Go are legion, with little standardization.
And no, using Errorf with '%w' to wrap error messages along the stack isn't exactly an elegant solution.
Even if they want to keep the core error behavior as it is for compatibility, providing a core library way of wrapping with stacktraces would be a very useful next step, particularly given the most popular package doing that previously is now unmaintained.
> providing a core library way of wrapping with stacktraces would be a very useful next step
What eventually became the standard library error wrapping proposal evolved from the work done on the Upspin project. It did include stacktraces, and believed like you that it would be useful to have them. But analysis of the data showed that nobody ever really used them in practice and, for that reason, was removed from the final proposal.
> particularly given the most popular package doing that previously is now unmaintained.
Lacking wide appeal doesn't mean there isn't a niche need, of course. However, with the standard library accepting a standard for error wrapping, which this package you speak of has been updated to be compatible with, what further maintenance would be needed, exactly? It would be more concerning if it wasn't considered finished by now. It seems the solution for niche needs is right there.
In the last few months I've realized what I desperately need: a way to wrap an error with a call stack at the point where it enters our code base. This would probably save me on average 20-30 minutes a week.
I see this all the time:
main.go:141 error: could not transmogrify the thing: a144cd21c48
And then I literally grep the code base to find the error message. That works ~50% of the time, but the other 50%, I see this:
main.go:141 error: not found
And then I have to spend 5-10 minutes spelunking to try to find where that error might have originated from.
This is such an infuriating problem. I'm convinced I'm using Go wrong, because I simply can't understand how this doesn't make it a toy language. Why the $expletive am I wasting 20-30 and more minutes per week of my life looking for the source of an error!?
Have you seen https://github.com/tomarrell/wrapcheck? It's a linter than does a fairly good job of warning when an error originates from an external package but hasn't been wrapped in your codebase to make it unique or stacktraced. It comes with https://github.com/golangci/golangci-lint and can even be made part of your in-editor LSP diagnostics.
But still, it's not perfect. And so I remain convinced that I'm misunderstanding something fundamental about the language because not being able to consistently find the source of an error is such an egregious failing for a programming language.
Yeah I have to agree that the Go-style error handling does actually lead to better code. At least when I write it. It makes me think through how I am going to handle error states rather than chucking it in try/except in Python and hoping nothing breaks lol.
Rust-style error handling works better though - similar to Go, but with the addition of enums such that the precise types of errors which may be encountered can be easily documented in the type system.
Yes - if Go had sum types (and they were idiomatically used in the standard library), it would take it from a pretty good platform to a first class one.
The library ecosystem is already excellent, and the tooling is good, lack of sum types is the single wart that makes me regret it every time I pick Go up for a project.
Try/catch/finally is in the language, its just called panic/defer/recover, where panic works like throw, every function works like try, defer works like a combination of a nonselective catch that rethrows by default and finally, and recover disables the rethrows-by-default behavior, while also being the only way to interrogate the panic to see if you should do that.
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.
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.
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.
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.
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.
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.
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.
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.
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.
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.
> 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.
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.
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.
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.
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.
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 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.
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.
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).
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.
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:
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."
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.
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.
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.
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.
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.
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.
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.
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.
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.
I really like Pythons approach where you can have user="value" it makes things a bit more clear.