[HN Gopher] Structured logging with slog
___________________________________________________________________
Structured logging with slog
Author : spacey
Score : 178 points
Date : 2023-08-22 16:02 UTC (6 hours ago)
(HTM) web link (go.dev)
(TXT) w3m dump (go.dev)
| __loam wrote:
| Slog is an amazing name
| corytheboyd wrote:
| 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 wrote:
| Have you checked lnav?
| corytheboyd wrote:
| 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).
| Femolo wrote:
| 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
| tastysandwich wrote:
| 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 wrote:
| 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."
| mi_lk wrote:
| Q: what do people use for structured logging in Java?
| monknomo wrote:
| Logback has structured logging. I think log4j has it as well
| ar_lan wrote:
| 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.
| zknill wrote:
| 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
| numbsafari wrote:
| 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 wrote:
| 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.
| mihaitodor wrote:
| Benthos just adopted it:
| https://github.com/benthosdev/benthos/commit/ee0000450413ad3...
| icholy wrote:
| I might have misunderstood, but shouldn't the adapter be
| operating on a `slog.Handler`?
| mihaitodor wrote:
| 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.
| baz00 wrote:
| 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.
| candiddevmike wrote:
| 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 wrote:
| 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 wrote:
| 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 wrote:
| 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
| tony_cannistra wrote:
| 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).
| geodel wrote:
| 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 wrote:
| 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 wrote:
| 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 wrote:
| 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]
| euroderf wrote:
| As a workaround, a list in a DB combined with a foreign key
| constraint. Ugly, yes.
| jmarchello wrote:
| 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.
| progbits wrote:
| Error handling != exceptions.
|
| Step one would bee sum types, so only valid value space can
| be represented (return value or error, but not both or
| neither).
| jmarchello wrote:
| Good point, a poor assumption on my part
| geodel wrote:
| I am not demanding either of these things. Just making
| general comment based on observing folks.
| dinkleberg wrote:
| 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.
| [deleted]
| dgb23 wrote:
| 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.
| gdprrrr wrote:
| 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 wrote:
| PHP did so with PSR-3 as well https://www.php-
| fig.org/psr/psr-3/.
| ljm wrote:
| 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.
| nwsm wrote:
| 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
| zknill wrote:
| 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
| ryandotsmith wrote:
| Here's an example of extracting context values in a custom
| slog handler:
|
| https://github.com/indexsupply/x/blob/main/wslog/slog_test.g.
| ..
| politician wrote:
| 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 wrote:
| 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.
| bobbyi wrote:
| 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]
| mrweasel wrote:
| 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.
| candiddevmike wrote:
| Today I'm pulling this out of a context object, can I still do
| that?
| taeric wrote:
| 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.
| nerdponx wrote:
| I'm really happy there's a name for this idea. I've been
| looking for something like this.
| jupp0r wrote:
| 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
| masklinn wrote:
| Slog allows doing that by creating Attr structs directly.
| bpicolo wrote:
| As mentioned in the article, Zap's SugaredLogger has roughly
| the same thing https://pkg.go.dev/go.uber.org/zap
| sugar.Infow("failed to fetch URL", "url",
| "http://example.com", "attempt", 3,
| "backoff", time.Second, )
|
| Really slog presents mostly the same two APIs as Zap, with a
| single entrypoint.
| grose wrote:
| 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
| gdprrrr wrote:
| Is ordering of the keys guaranteed to be the same as in the
| literal?
| grose wrote:
| That's a good point. I think it would be random without
| some sorting shenanigans.
| ben0x539 wrote:
| I think go loggers have tried to move away from passing log
| entries as maps for performance reasons.
| eska wrote:
| If you had read more than the introduction you'd have found a
| paragraph about this in the middle and multiple at the end.
| richardwhiuk wrote:
| Rust's slog ( https://docs.rs/slog/ ) does: use
| slog::info; ... info!("hello, world"; "user" =>
| std::env::var("USER"));
| baq wrote:
| 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"}}
| packetlost wrote:
| 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 wrote:
| > 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 wrote:
| A better interface/API is really what I meant. The
| performance characteristics are probably worth the
| tradeoff.
| returningfory2 wrote:
| 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 wrote:
| it depends. I _believe_ map literals are stack allocated
| if they aren 't shared across goroutines or globals.
| hamandcheese wrote:
| The same pattern can be seen in Java using Map.of(...)
| masklinn wrote:
| > 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://w
| ww.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.
| johnmaguire wrote:
| It sure has maps though... logrus famously uses
| `logrus.Fields{"key": "value"}`
| morelisp wrote:
| And logrus is one of the slowest loggers by far, in part
| because of its heavy map usage.
| insanitybit wrote:
| 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 wrote:
| 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.
___________________________________________________________________
(page generated 2023-08-22 23:00 UTC)