testing: benchmark results are not well aligned

[gopherbot]

by jasonhall@google.com:

What does 'go version' print?
go version go1.3 linux/amd64


What steps reproduce the problem?

1. Run a benchmark ('go test -bench=.') on a suite that has differently-lengthed
benchmark names

What happened?

Output is disjointed and difficult to scan for relative benchmark times, e.g.:

$ go test -bench=.
PASS
BenchmarkSortInt64Reflect             50          45768737 ns/op
BenchmarkSortInt64New         50          48225829 ns/op
BenchmarkSortInt64Old        100          15282155 ns/op
BenchmarkSortInt32Reflect             50          48708838 ns/op
BenchmarkSortInt32New         50          48018021 ns/op
BenchmarkSortInt32Old        100          15299048 ns/op
BenchmarkSortStructReflect            50          49120054 ns/op
BenchmarkSortStructNew        50          49305384 ns/op
BenchmarkSortStructOld       100          18308491 ns/op

It's not immediately apparent that Reflect and New are roughly the same without copying
the output and aligning the values.


What should have happened instead?

Columns line up in an easy-to-read fashion, with ns/op and iterations values
right-aligned across benchmarks.


Please provide any additional information below.

Benchmark outputs are generated using a String() method that doesn't take into account
other benchmark results being printed:
http://golang.org/src/pkg/testing/benchmark.go#L256

An alternative would be to have each BenchmarkResult provide a []byte separating fields
with a \t and using the tabwriter package to align the results, periodically Flushing
the output. We would lose the streamed output that the current behavior provides, but
the columns would be aligned for easier consumption.

[ianlancetaylor]

Comment 1:

Labels changed: added repo-main, release-go1.5.

[dominikh]

Comment 2:

In my opinion this should be solved with external tools, e.g. by piping go test's output
through column(1) -- with the -t flag it produces output that is very close to the
desired format. Alternatively, there's github.com/cespare/prettybench which adds some
other improvements to the output as well as fixing the alignment.
Also I don't understand how "periodically flushing the output" is supposed to work. If
you want all columns to line up properly, you need to buffer the entire output. If you
flush periodically, you will constantly change the alignment.
I feel like streaming output is far more valuable than perfect alignment.

[gopherbot]

Comment 3 by jasonhall@google.com:

Yeah, that makes sense. I hadn't seen prettybench, that's pretty nice, I can use that in
the meantime :)
"Periodically flushing" probably isn't even necessary, like you said it would cause
misalignments between flushed sections. Are there normally enough results being shown
that flushing would even be necessary? Probably not.
It comes down to whether streamed results are more useful than aligned results. What are
the benefits of streamed results?

[josharian]

Comment 4:

I don't think that this necessarily requires giving up streamed results. The test binary
knows up front the names of all the benchmarks that it will run, and it could provide
ample padding to allow for long run times.
However, I'm not sure it is worth the extra code. It is very easy to borrow some code
from benchcmp (http://godoc.org/code.google.com/p/go.tools/cmd/benchcmp) to parse the
output, which you can then reformat to your heart's content, including sorting by
benchmark times to see the relative ordering.
Whatever we do, let's keep streamed results. Streamed results let you see progress as it
happens. For example, the math/big package has 133 benchmarks. It is useful to see that
individual benchmarks are completing in a reasonable time instead of waiting several
minutes to find out what has happened. It is also useful to be able to peek at the first
few results to see whether to let the rest of the benchmarks run.

[osocurioso]

Mailed https://go-review.googlesource.com/2840. This change does an initial round to filter out all the matching benchmarks and simultaneously calculates how to pad the benchmark names in order to align the results.