Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

testing: benchmark cleanup causes inconsistent and slower benchmark time #38314

Closed
cuonglm opened this issue Apr 8, 2020 · 6 comments
Closed
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@cuonglm
Copy link
Member

cuonglm commented Apr 8, 2020

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
Copy link
Contributor

cc also @ianlancetaylor @bcmills

@gopherbot
Copy link

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

gopherbot pushed a commit that referenced this issue Apr 9, 2020
For map with hint larger than BUCKETSIZE, makemap ignore allocated
bucket and allocate buckets itself. So do not allocate bucket in
this case, save us the cost of zeroing+assignment to the bucket.

name                            old time/op    new time/op    delta
NewEmptyMap-12                    3.89ns ± 4%    3.88ns ± 2%    ~     (p=0.939 n=19+20)
NewSmallMap-12                    23.3ns ± 3%    23.1ns ± 2%    ~     (p=0.307 n=18+17)
NewEmptyMapHintLessThan8-12       6.43ns ± 3%    6.31ns ± 2%  -1.72%  (p=0.000 n=19+18)
NewEmptyMapHintGreaterThan8-12     159ns ± 2%     150ns ± 1%  -5.79%  (p=0.000 n=20+18)

Benchmark run with commit ab7c174 reverted, see #38314.

Fixes #20184

Change-Id: Ic021f57454c3a0dd50601d73bbd77b8faf8d93b6
Reviewed-on: https://go-review.googlesource.com/c/go/+/227458
Run-TryBot: Cuong Manh Le <cuong.manhle.vn@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Keith Randall <khr@golang.org>
@andybons andybons added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 10, 2020
@andybons andybons added this to the Unplanned milestone Apr 10, 2020
@cuonglm
Copy link
Member Author

cuonglm commented Aug 15, 2020

@ianlancetaylor @bcmills any idea on this?

@ianlancetaylor
Copy link
Contributor

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

@cuonglm
Copy link
Member Author

cuonglm commented Aug 18, 2020

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
Copy link
Contributor

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.

@golang golang locked and limited conversation to collaborators Aug 18, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

5 participants