json-logs VS zerolog

I think the philosophy for logs is that they are THE user interface for operators of your service. If you are SaaS, that's you! If you provide software for self-hosting, that's your customers. It can't be an afterthought; this is how ordinary people can peer deep into your system to understand what's wrong with it. If they figure it out, they don't page you. If it's useless, you can't fix it after they page you. Be paranoid and make your subsystems show their work. Anything you want to know while debugging, print it, don't make the user "hey just run this and tell me what it returns". I think there is an art here, and many treat it as an afterthought.

I always liked structured logs because it frees my mind from coming up with how I want to format arguments. "New HTTP request for /foobar from 1.2.3.4 with request-id ac31a9e0-5d57-44de-9e98-60fa94d3e866" is a pain to read and maintain. `log.Debug("incoming http request", logger.IP("remote-ip", req.Address), logger.String("request-id", req.ID), logger.String("route", req.Route))` is easy to write, and the resulting logs are easy to analyze!

I do like myself some pretty colorful logs, but prefer JSON as the intermediary. It's pretty easy to post-process the logs into something understandable. I wrote https://github.com/jrockway/json-logs for this task. Give it a stream of JSON logs, get colorful text out. Add/drop fields or select/highlight interesting lines with JQ or regular expressions (with -A -B -C of course). Installable on Linux or Mac with Homebrew ;) It's one of the few pieces of software I wrote for myself that passes the "toothbrush test". I use it twice a day every day. And that's a good day when I'm not pulling my hair out over an obscure issue ;)

I wrote a small script to convert CSVs to JSON strictly to use jq on the output. Querying things like your GCP bill with jq is quite enjoyable.

gojq is also nice. I work with a lot of structured logs and wrapped jq with a little bit of format-understanding and output sugar to make looking at and analyzing such logs an enjoyable experience: https://github.com/jrockway/json-logs

Big fan of JQ. I like it more than the traditional UNIX suite of text manipulation commands, because I get closer to "querying" rather than just filtering. It has really made me rethink where I want "interacting with a computer" to go in the future -- less typing commands, more querying stuff.

I have a few utilities involving JQ that I wrote.

For structured logs, I have jlog. Pipe JSON structured logs into it, and it pretty-prints the logs. For example, time zones are converted to your local time, if you choose; or you can make the timestamps relative to each other, or now. It includes jq so that you can select relevant log lines, delete spammy fields, join fields together, etc. Basically, every time you run it, you get the logs YOU want to look at. https://github.com/jrockway/json-logs. Not to oversell it, but this is one of the few pieces of software I've written that passes the toothbrush test -- I use it twice a day, every day. All the documentation is in --help; I should really paste that into the Github readme.

I am also a big fan of using JQ on Kubernetes objects. I know what I'm looking for, and it's often not in the default table view that kubectl prints. I integrated JQ into a kubectl extension, to save you "-o json | jq" and having to pick apart the v1.List that kubectl marshals objects into. https://github.com/jrockway/kubectl-jq. That one actually has documentation, but there is a fatal flaw -- it doesn't integrate with kubectl tab completion (limitation of k8s.io/cli-runtime), so it's not too good unless you already have a target in mind, or you're targeting everything of a particular resource type. This afternoon I wanted to see the image tag of every pod that wasn't terminated (some old Job runs exist in the namespace), and that's easy to do with JQ: `kubectl jq pods 'select(.status.containerStatuses[].state.terminated == null) | .spec.containers[].image'`. I have no idea how you'd do such a thing without JQ, probably just `kubectl describe pods | grep something` and do the filtering in your head. (The recipes in the kubectl-jq documentation are pretty useful. One time I had a Kubernetes secret that had a key set to a (base64-encoded) JSON file containing a base64-encoded piece of data I wanted. Easy to fix with jq; `.data.THING | @base64d | fromjson | .actualValue | @base64d`.

JQ is something I definitely can't live without. But I will admit to sometimes preprocessing the input with grep, `select(.key|test("regex"))` is awfully verbose compared to "grep regex" ;)

People seem to fixate on stack traces, because other languages present nearly every error in stack trace form. I think you should think about why you want them and make sure you have a good reason before mindlessly adding them. I do collect stack traces in some Go code, because Sentry requires it for categorization, but in general, you can do a much better job yourself, with very little sorcery involved.

A common problem is that when multiple producers produce failing work items and send them to a consumer -- a stack trace will just show "panic -> consumer.doWork() -> created by consumer.startWork()". Gee, thanks. You need to track the source, so that you have an actionable error message. If the consumer is broken, fine, you maybe have enough information. If a producer is producing invalid work items, you won't have enough information to find which one. You'll want that.

The idea of an error object is for the code to make a decision about how to handle that error, and if it fails, escalate it to a human for analysis. The application should be able to distinguish between classes of failures, and the human should be able to understand the state of the program that caused the failure, so they can immediately begin fixing the failure. It's up to you to capture that state, and make sure that you consistently capture the state.

Rather than leaving it to chance, I have an opinionated procedure:

1) Every error should be wrapped. This is where all the context for the operator of your software comes from, and you have to do it every time to capture the state of the application at the time of the error.

2) The error need not say "error" or "failure" or "problem". It's an error, you know it failed. As an example, prefer "upgrade foos: %w" over "problem upgrading foos: %w". (The reason is that in a long chain, if everyone does this, it's just redundant: "problem frobbing baz: problem fooing bars: problem quuxing glork: i/o timeout". Compare that to "frob baz: foo bars: quux glork: i/o timeout".)

But if you're logging an error, I pretty much always put some sort of error-sounding words in there. Makes it clear to operators that may not be as zen about failures as you that this is the line that identifies something not working. "2021-08-23T20:45:00.123 PANIC problem connecting to database postgres://1.2.3.4/: no route to host". I'm open to an argument that if you're logging at level >= WARNING that the reader knows it's a problem, though. (I also tend to phrase them as "problem x-ing y" instead of "error x-ing y" or "x-ing y failed". Not going to prescribe that to others though, use the wording that you like, or that you think causes the right level of panic.)

3) Error wrapping shouldn't duplicate any information that the caller already has. The caller knows the arguments passed to the function, and the name of the function. If its error wrapping needs those things to produce an actionable error message, it will add them. It doesn't know what sub-function failed, and it doesn't know what internally-generated state there is, and those are going to be the interesting parts for the person debugging the problem. So if you're incrementing a counter, you might do a transaction, inside of which is a read and a write -- return "commit txn: %w", "rollback txn: %w", "read: %w", "write: %w", etc. The caller can't know which part failed, or that you decided to commit vs. roll back, but it does know the record ID, that the function is "update view count", etc.

The standard library violates this rule, probably because people "return err" instead of wrapping the error, and this gives them a shred of hope. And, it's my made-up rule, not the Go team's actual rule! Investigate those cases and don't add redundant information. (For example, os.ReadFile will have the filename in the error message, because it returns an fs.PathError, which contains that. net.Dial is another culprit. Make a list of these and break the rule in these cases.)

4) Any error that the program is going to handle programmatically should have a sentinel (`var ErrFoo = errors.New("foo")`), so that you can unambiguously handle the error correctly. (People seem to handle io.EOF quite well; emulate that.)

You can describe special cases of your error by wrapping it before returning it, `fmt.Errorf("bar the quux: %w", ErrFoo)`.

Finally, since I talked about logging, please talk about things that DID work in your logs. Your logs are the primary user interface for operators of your software, but often the most neglected interface point. When you see something like "problem connecting to foo\nproblem connecting to foo", you're going to think there's a problem connecting to foo. But if you write "problem connecting to foo (attempt 1/3)\nproblem connecting to foo (attempt 2/3)\nconnected to foo", then the operator knows not to investigate that. It worked, and the program expected it to take 3 attempts. Perfect. (Generally, for any long-running operation a log "starting XXX" and "finished XXX" are great. That way, you can start looking for missing "finished" messages, rather than relying on self-reported errors.)

(And, outside of HN comments, I would make that a structured log, so that someone can easily select(.attempt == .max_attempts) and things like that. It's ugly if you just read the output, but great if you have a tool to pretty-print the logs: https://github.com/jrockway/json-logs/releases/tag/v0.0.3)

Anyway, I guess where this rant goes is -- errors are not an afterthought. They're as much a part of your UI as all the buttons and widgets. They will happen to all software. They will happen to yours. Some poor sap who is not you will be responsible for fixing it. Give them everything you need, and you'll be rewarded with a pull request that makes your program slightly more reliable. Give them "unexpected error: success", and you'll have an interesting bug report to context-switch to over the course of the next month, killing anything cool you wanted to make while you track that down.

Be aware that there is a performance impact compared to using zerolog directly [0] (my uneducated guess is it is likely due to pointer indirection).

[0]: https://github.com/rs/zerolog/issues/571#issuecomment-166202...

Things I can't live without in a new Go project in no particular order:

- https://github.com/golangci/golangci-lint - meta-linter

- https://goreleaser.com - automate release workflows

- https://magefile.org - build tool that can version your tools

- https://github.com/ory/dockertest/v3 - run containers for e2e testing

- https://github.com/ecordell/optgen - generate functional options

- https://golang.org/x/tools/cmd/stringer - generate String()

- https://mvdan.cc/gofumpt - stricter gofmt

- https://github.com/stretchr/testify - test assertion library

- https://github.com/rs/zerolog - logging

- https://github.com/spf13/cobra - CLI framework

FWIW, I just lifted all the tools we use for https://github.com/authzed/spicedb

We've also written some custom linters that might be useful for other folks: https://github.com/authzed/spicedb/tree/main/tools/analyzers

Can you compare it against zerolog?

Hello gophers, I am using https://github.com/uber-go/fx and https://github.com/rs/zerolog for logging.

Hovewer it is not bad to export such a function, if it is done purely for convenience. For example github.com/rs/zerolog works on a logger instances, which can be created manually, but they also provide a github.com/rs/zerolog/blob//log package, which provide you access to the global logger which is more convenient in most cases

IDE: use whatever make you productive. I personally use vscode. VCS: git, as golang communities use github heavily as base for many libraries. AFAIK Linter: use staticcheck for linting as it looks like mostly used linting tool in go, supported by many also. In Vscode it will be recommended once you install go plugin. Libraries/Framework: actually the standard libraries already included many things you need, decent enough for your day-to-day development cycles(e.g. `net/http`). But here are things for extra: - Struct fields validator: validator - Http server lib: chi router , httprouter , fasthttp (for non standard http implementations, but fast) - Web Framework: echo , gin , fiber , beego , etc - Http client lib: most already covered by stdlib(net/http), so you rarely need extra lib for this, but if you really need some are: resty - CLI: cobra - Config: godotenv , viper - DB Drivers: sqlx , postgre , sqlite , mysql - nosql: redis , mongodb , elasticsearch - ORM: gorm , entgo , sqlc(codegen) - JS Transpiler: gopherjs - GUI: fyne - grpc: grpc - logging: zerolog - test: testify , gomock , dockertest - and many others you can find here

I use zerolog myself and have seen it being used in production several times. Also they have a list of who uses zerolog

This would be so awesome if it was extending an awesome logger like https://github.com/rs/zerolog. Personally I love zerolog because of how it handles different data types including structs!

logrus README recommended using other libraries such as Zerolog, Zap, and Apex.