cmd/go: go test running bench twice with -benchtime=1x

[vitesse-ftian]

What version of Go are you using (go version)?

1.12.5

Does this issue reproduce with the latest release?

yes

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/ftian/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/ftian/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build598447146=/tmp/go-build -gno-record-gcc-switches"

What did you do?

ftian@ftian-xps:~/tmp/x$ cat xxx_test.go
package x

import (
"fmt"
"testing"
)

func BenchmarkOnce(b *testing.B) {
fmt.Printf("Calling me once.\n")
}

ftian@ftian-xps:~/tmp/x$ go test -run=NONONO -bench=Once -benchtime=1x
Calling me once.
goos: linux
goarch: amd64
BenchmarkOnce-12 Calling me once.
1 17290 ns/op
PASS
ok _/home/ftian/tmp/x 0.002s

What did you expect to see?

The BencharkOnce should be run only once. The line should be printed once.

What did you see instead?

Calling me once. printed twice.

[robpike]

Working as intended. The benchmark support code calls each benchmark function as many times as necessary to establish a reliable performance figure.

[robpike]

By the way, you're using the benchtime flag incorrectly. I'm surprised you didn't see an error. Its argument is a duration.

[cespare]

By the way, you're using the benchtime flag incorrectly. I'm surprised you didn't see an error. Its argument is a duration.

As of Go 1.12 (https://golang.org/doc/go1.12#testing):

The -benchtime flag now supports setting an explicit iteration count instead of a time when the value ends with an "x". For example, -benchtime=100x runs the benchmark 100 times.

[vitesse-ftian]

benchtime=1x is a new feature in 1.12. According to doc, 100x means 100 times.

BTW, before benchtime=1x, I used to use -benchtime=0s to trick go test to only run my test case once. 1.12 will error, stating 0s is not a valid duration.

-benchtime=1ns still does the trick.

[cespare]

Looking at the code, it looks like we always call the benchmark once to initialize things (for example, to discover sub-benchmarks). Then we run it n times after that.

Perhaps we just need to subtract 1 from n.

In any case, it does seem confusing that 1x runs it twice. (And I suspect that 1 is the most common number to use with -benchtime=Nx. We use it in CI to verify that our benchmarks aren't broken, for example.)

[andybons]

@rsc for a decision on behavior.

[robpike]

Well, benchtime needs some documentation then. The testing package doesn't mention it in the comment with the other flags.

Not a fan of this hack, but I obviously missed it when it went in.

[cespare]

#24735 has the context for the -benchtime=Nx syntax.

Well, benchtime needs some documentation then. The testing package doesn't mention it in the comment with the other flags.

As far as I can see, the testing package documentation only mentions three of the testing flags: -run, -bench, and -cpu. There are more than 20 other flags not mentioned. If we're going to describe -benchtime there, we should consider including some other important ones such as -v, -timeout, -count, and -short. (The testing package docs do already link to https://golang.org/cmd/go/#hdr-Testing_flags, though.)

[robpike]

Maybe that's enough, but I must say that 'go doc testing' is a lot easier to handle than the output of the go command's own documentation.