Better Go test output
- Author: Stephen Ball
- Published:
-
Tags:
- Permalink: /blog/better-go-test-output
Improving the default `go test` output
The go test
command is alright and props to Go for being like a real modern language with built-in support for testing. But its output is decidedly unfriendly.
$ go test
PASS
ok pragprog.com/rggo/interacting/todo 0.100s
(Aside: I’m going through Powerful Command-Line Applications in Go and it’s quite excellent)
We can make it a little nicer with -v
$ go test -v
=== RUN TestAdd
--- PASS: TestAdd (0.00s)
=== RUN TestComplete
--- PASS: TestComplete (0.00s)
=== RUN TestDelete
--- PASS: TestDelete (0.00s)
=== RUN TestSaveGet
--- PASS: TestSaveGet (0.00s)
PASS
ok pragprog.com/rggo/interacting/todo 0.211s
But still not very human friendly.
There’s a gotestfmt
tool out there which has pretty great results! Provided you pass it the json output of go test
$ go test -v -json | gotestfmt
📦 pragprog.com/rggo/interacting/todo
✅ TestAdd (0s)
✅ TestComplete (0s)
✅ TestDelete (0s)
✅ TestSaveGet (0s)
But if you have stderr output from your tests as part of the setup/teardown process then gotestfmt
will let you down. For some reason it outputs all of those outputs before any of the test results.
$ go test -v -json | gotestfmt
📦 pragprog.com/rggo/interacting/todo/cmd/todo
Building tool...
Running tests...
Cleaning up...
✅ TestTodoCLI (240ms)
✅ TestTodoCLI/AddNewTaskFromArguments (220ms)
✅ TestTodoCLI/AddNewTaskFromSTDIN (10ms)
✅ TestTodoCLI/CompleteTask (10ms)
✅ TestTodoCLI/ListTasks (0s)
vs
$ go test -v
Building tool...
Running tests...
=== RUN TestTodoCLI
=== RUN TestTodoCLI/AddNewTaskFromArguments
=== RUN TestTodoCLI/AddNewTaskFromSTDIN
=== RUN TestTodoCLI/ListTasks
=== RUN TestTodoCLI/CompleteTask
--- PASS: TestTodoCLI (0.08s)
--- PASS: TestTodoCLI/AddNewTaskFromArguments (0.07s)
--- PASS: TestTodoCLI/AddNewTaskFromSTDIN (0.00s)
--- PASS: TestTodoCLI/ListTasks (0.00s)
--- PASS: TestTodoCLI/CompleteTask (0.00s)
PASS
Cleaning up...
ok pragprog.com/rggo/interacting/todo/cmd/todo 0.314s
A minor quibble absolutely; but one that annoyed me enough to want to do something about it.
Since go test
very nicely provides json output what about using it directly?
$ go test -v -json
{"Time":"2022-03-16T13:50:18.170841-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Output":"Building tool...\n"}
{"Time":"2022-03-16T13:50:18.334313-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Output":"Running tests...\n"}
{"Time":"2022-03-16T13:50:18.334414-04:00","Action":"run","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI"}
{"Time":"2022-03-16T13:50:18.334422-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI","Output":"=== RUN TestTodoCLI\n"}
{"Time":"2022-03-16T13:50:18.334473-04:00","Action":"run","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromArguments"}
{"Time":"2022-03-16T13:50:18.33448-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromArguments","Output":"=== RUN TestTodoCLI/AddNewTaskFromArguments\n"}
{"Time":"2022-03-16T13:50:18.495296-04:00","Action":"run","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromSTDIN"}
{"Time":"2022-03-16T13:50:18.495322-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromSTDIN","Output":"=== RUN TestTodoCLI/AddNewTaskFromSTDIN\n"}
{"Time":"2022-03-16T13:50:18.499036-04:00","Action":"run","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/ListTasks"}
{"Time":"2022-03-16T13:50:18.499055-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/ListTasks","Output":"=== RUN TestTodoCLI/ListTasks\n"}
{"Time":"2022-03-16T13:50:18.50366-04:00","Action":"run","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/CompleteTask"}
{"Time":"2022-03-16T13:50:18.503676-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/CompleteTask","Output":"=== RUN TestTodoCLI/CompleteTask\n"}
{"Time":"2022-03-16T13:50:18.513055-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI","Output":"--- PASS: TestTodoCLI (0.18s)\n"}
{"Time":"2022-03-16T13:50:18.513088-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromArguments","Output":" --- PASS: TestTodoCLI/AddNewTaskFromArguments (0.16s)\n"}
{"Time":"2022-03-16T13:50:18.513097-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromArguments","Elapsed":0.16}
{"Time":"2022-03-16T13:50:18.513105-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromSTDIN","Output":" --- PASS: TestTodoCLI/AddNewTaskFromSTDIN (0.00s)\n"}
{"Time":"2022-03-16T13:50:18.513109-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/AddNewTaskFromSTDIN","Elapsed":0}
{"Time":"2022-03-16T13:50:18.513113-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/ListTasks","Output":" --- PASS: TestTodoCLI/ListTasks (0.00s)\n"}
{"Time":"2022-03-16T13:50:18.51313-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/ListTasks","Elapsed":0}
{"Time":"2022-03-16T13:50:18.513134-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/CompleteTask","Output":" --- PASS: TestTodoCLI/CompleteTask (0.01s)\n"}
{"Time":"2022-03-16T13:50:18.513139-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI/CompleteTask","Elapsed":0.01}
{"Time":"2022-03-16T13:50:18.513142-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Test":"TestTodoCLI","Elapsed":0.18}
{"Time":"2022-03-16T13:50:18.513146-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Output":"PASS\n"}
{"Time":"2022-03-16T13:50:18.51315-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Output":"Cleaning up...\n"}
{"Time":"2022-03-16T13:50:18.513938-04:00","Action":"output","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Output":"ok \tpragprog.com/rggo/interacting/todo/cmd/todo\t0.696s\n"}
{"Time":"2022-03-16T13:50:18.513983-04:00","Action":"pass","Package":"pragprog.com/rggo/interacting/todo/cmd/todo","Elapsed":0.696}
Definitely usable! And the outputs are ordered correctly so it’s even weirder that gotestfmt
groups them.
A gotestfmt
replacement using jq
jq-go-tests
is a gotestfmt
replacement using jq
and sed
to get something human friendly but still ordered correctly. It’s not as fancy as gotestfmt
pulling out the package and formatting but it’s certainly good enough for me.
$ go test -v -json | jq-go-tests
Building tool...
Running tests...
✅ TestTodoCLI (0.24s)
✅ TestTodoCLI/AddNewTaskFromArguments (0.22s)
✅ TestTodoCLI/AddNewTaskFromSTDIN (0.00s)
✅ TestTodoCLI/ListTasks (0.00s)
✅ TestTodoCLI/CompleteTask (0.01s)
PASS
Cleaning up...
ok pragprog.com/rggo/interacting/todo/cmd/todo 0.822s
If you don’t want to click through to the code jq-go-tests
is simply
#!/usr/bin/env bash
jq -r '.Output // ""' | rg -v "=== RUN" | sed -e '/^$/d' -e "s/--- PASS/✅/" -e "s/--- FAIL/❌/"
I could spend some time making jq
do more of the lifting and formatting but this is definitely already good enough that I’m already using it as my default Go test output.