testing: benchmark cleanup causes inconsistent and slower benchmark time

[cuonglm]

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

$ go version
go version devel +0dfb0513ec Wed Apr 8 14:51:58 2020 +0000 darwin/amd64

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
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/cuonglm/Library/Caches/go-build"
GOENV="/Users/cuonglm/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/cuonglm/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/Users/cuonglm/sources/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/Users/cuonglm/sources/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/cuonglm/sources/go/src/go.mod"
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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/y4/hs76ltbn7sb66lw_6934kq4m0000gn/T/go-build861617789=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

$ cd "$(go env GOROOT)/src/runtime"
$ go test -run=NONE -bench='BenchmarkNewEmptyMap$' -count=20
goos: darwin
goarch: amd64
pkg: runtime
BenchmarkNewEmptyMap-12    	227090132	         5.17 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	265820960	         4.65 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	247291054	         4.60 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	254193786	         6.40 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	261036198	         4.88 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	277105014	         5.33 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	231302805	         6.38 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	231796490	         5.77 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	226394065	         5.19 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	250847887	         5.26 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	254218030	         5.33 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	243212448	         6.78 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	201041560	         6.21 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	220739622	         4.70 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	219490611	         5.94 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	242538295	         5.33 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	226324015	         5.32 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	244244470	         5.28 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	237576693	         5.28 ns/op	       0 B/op	       0 allocs/op
BenchmarkNewEmptyMap-12    	227848381	         5.13 ns/op	       0 B/op	       0 allocs/op
PASS
ok  	runtime	38.543s

What did you expect to see?

Low variance in benchmark.

What did you see instead?

Benchmark result has high variance, also benchmark time is higher than go1.13:

$ benchstat master cl-20184 go1.14.1 go1.13.9
name \ time/op    master       cl-20184     go1.14.1     go1.13.9
NewEmptyMap-12    5.31ns ±40%  5.22ns ±33%  5.23ns ±20%  3.86ns ± 2%

git bisect points to ab7c174

cc @rogpeppe

[josharian]

cc also @ianlancetaylor @bcmills

[gopherbot]

Change https://golang.org/cl/227458 mentions this issue: cmd/compile: do not allocate bucket for non-escaping map

[cuonglm]

@ianlancetaylor @bcmills any idea on this?

[ianlancetaylor]

When we are talking about numbers like 5 nanoseconds, variance is normal and expected. I don't see a problem here.

[cuonglm]

When we are talking about numbers like 5 nanoseconds, variance is normal and expected. I don't see a problem here.

I think it's only an issue if we compare result from go1.13 vs higher version, there you can see go1.13 produce consistent result + low variance. Starting from go1.14, the result has higher variance. If you comparing go1.14 result and higher, it makes much more sense, because both of them has higher variance.

Since go1.15 is released, I think we can close this, though I'm still curious whether the high variance after go1.13 is intentional.

[ianlancetaylor]

The higher variance is not intentional. I just don't think it matters. If you want to investigate what is causing it, by all means go ahead. But I predict that the answer will not lead to doing anything differently.