Verbose and JSON Test Output in Go for CI Tools to Parse

go test prints text meant for people. A dashboard, a CI annotation tool or a flaky test tracker wants structure, and parsing the text with regular expressions breaks the first time the format shifts. The toolchain already has the answer: go test -json.

package main

func main() {}

package main

import "testing"

func TestPass(t *testing.T) { t.Log("hello") }

func TestFail(t *testing.T) { t.Error("broken") }

func TestSkip(t *testing.T) { t.Skip("later") }

echo "# go test -json: one event per line"
go test -count=1 -json . 2>&1 | sed -E 's/"Time":"[^"]+"/"Time":"T"/; s/"Elapsed":[0-9.]+/"Elapsed":E/; s/example.test\/lab\t[0-9.]+s/example.test\/lab\tS/; s/\\t[0-9.]+s/\\tS/' | head -14
echo
echo "# actions seen, counted"
go test -count=1 -json . 2>&1 | grep -o '"Action":"[a-z]*"' | sort | uniq -c
echo
echo "# test2json on plain -v output"
go test -count=1 -v . 2>&1 | go tool test2json | grep -c Action

# go test -json: one event per line
{"Time":"T","Action":"start","Package":"example.test/lab"}
{"Time":"T","Action":"run","Package":"example.test/lab","Test":"TestPass"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestPass","Output":"=== RUN   TestPass\n"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestPass","Output":"    a_test.go:5: hello\n"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestPass","Output":"--- PASS: TestPass (0.00s)\n"}
{"Time":"T","Action":"pass","Package":"example.test/lab","Test":"TestPass","Elapsed":E}
{"Time":"T","Action":"run","Package":"example.test/lab","Test":"TestFail"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestFail","Output":"=== RUN   TestFail\n"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestFail","Output":"    a_test.go:7: broken\n"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestFail","Output":"--- FAIL: TestFail (0.00s)\n"}
{"Time":"T","Action":"fail","Package":"example.test/lab","Test":"TestFail","Elapsed":E}
{"Time":"T","Action":"run","Package":"example.test/lab","Test":"TestSkip"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestSkip","Output":"=== RUN   TestSkip\n"}
{"Time":"T","Action":"output","Package":"example.test/lab","Test":"TestSkip","Output":"    a_test.go:9: later\n"}

# actions seen, counted
   2 "Action":"fail"
  11 "Action":"output"
   1 "Action":"pass"
   3 "Action":"run"
   1 "Action":"skip"
   1 "Action":"start"

# test2json on plain -v output
20

One event per line

Each line is a complete JSON object, so a consumer can process the stream while the tests run. The fields are Time, Action, Package, Test (absent for package level events), Output and Elapsed (seconds, on terminal events). The lab replaces the timestamps and durations so the output is stable.

The actions in this run were start for the package, run for each test as it began, output for every line printed, and one of pass, fail or skip for each test. The counts show the shape: three tests, three run events, one pass, one skip and two fail, one of which is the package itself. The eleven output events are the === RUN and --- PASS lines plus anything logged with t.Log, one event per line.

Two details matter when you write a consumer. The Output field includes the trailing newline, so concatenate in order to rebuild the text. And a failing test's output may arrive after a fail event for a parent, so key everything by Package and Test, and finalise a package when its own terminal event arrives, not when the stream ends.

Converting text you already have

go tool test2json reads the -v text from standard input and writes the same events. The last block of the lab did that and counted 20 Action fields. It is the tool to use when the test binary was run somewhere else, for example ./pkg.test -test.v, or when a log file is all you have. Pass -t to add timestamps, and -p pkgname to label the package.

Reading the stream in Go

A consumer needs very little code. Decode each line into a struct with the six fields, keep a map from Package and Test to the lines of output seen so far, and print that buffer only when the test's fail event arrives. Passing tests then cost nothing and failing ones show their complete output, grouped, even when parallel tests interleave in the raw stream. That grouping is the main reason to use the JSON form: plain -v output from parallel tests is interleaved line by line, and reading it by eye is hard.

The -json flag changes how output is produced but not what runs. It combines with every other flag, including -race, -cover and -run, and the exit status is the same. Build output and compiler errors also arrive as JSON events in recent versions, with Action set to build-output and build-fail, so a consumer should ignore actions it does not know.

Uses

• A CI step that turns fail events into annotations with the test name and its output.
• Slow test reports: sort pass events by Elapsed, which is the input for the approach in speeding up a slow suite.
• A history of flaky tests, built from the stream of every run.

The format is documented in the test2json reference, and the flag is described with the others in the flags reference.