「【調査中】Goのbenchmarkを使うと環境ごとに結果がバラバラになってしまったので、誰か知恵を貸して欲しい」の作業メモです。結果は本記事に反映されます。

dockerで試してみた

mac上のdockerです。

FROM golang:1.9.2

ADD . /go/const/

WORKDIR /go/const/
CMD go test --bench .

結果

$ docker run const:latest
goos: linux
goarch: amd64
BenchmarkCase0-2   	    5000	    327356 ns/op
BenchmarkCase1-2   	    2000	    619763 ns/op
BenchmarkCase2-2   	    5000	    323818 ns/op
BenchmarkCase3-2   	    2000	    660053 ns/op

？？？遅いケースが違うぞ

bench結果で遅いのはmac場では、case2のみだったのに、　docker上ではcase1とcase3が遅いパターンになりました。
ちなみに、遅いものは何度試しても遅いです。つまり、ローカルでやると常に　case2が遅く、docker上では常にcase1とcase3が遅いです。

今度はalpineでやった

$ docker run const:alpine
goos: linux
goarch: amd64
BenchmarkCase0-2   	    5000	    314101 ns/op
BenchmarkCase1-2   	    5000	    317110 ns/op
BenchmarkCase2-2   	    5000	    322272 ns/op
BenchmarkCase3-2   	    5000	    321220 ns/op

alpineでは同じくらいになるようです。

メモリを制限してみた

$ docker run -m 100mb const:latest
goos: linux
goarch: amd64
BenchmarkCase0-2   	    5000	    321531 ns/op
BenchmarkCase1-2   	    2000	    647952 ns/op
BenchmarkCase2-2   	    5000	    317249 ns/op
BenchmarkCase3-2   	    2000	    645457 ns/op

alpine

$ docker run -m 100mb const:alpine
goos: linux
goarch: amd64
BenchmarkCase0-2   	    5000	    321483 ns/op
BenchmarkCase1-2   	    5000	    319432 ns/op
BenchmarkCase2-2   	    5000	    316911 ns/op
BenchmarkCase3-2   	    5000	    312556 ns/op

CPUのコア数を制限してみた

cpu1core

$ docker run --cpuset-cpus 0 const:latest
goos: linux
goarch: amd64
BenchmarkCase0 	    5000	    321715 ns/op
BenchmarkCase1 	    2000	    639052 ns/op
BenchmarkCase2 	    5000	    319538 ns/op
BenchmarkCase3 	    2000	    627908 ns/op

cpu2core

$ docker run --cpuset-cpus 0-1 const:latest
goos: linux
goarch: amd64
BenchmarkCase0-2   	    5000	    320463 ns/op
BenchmarkCase1-2   	    2000	    645313 ns/op
BenchmarkCase2-2   	    5000	    321973 ns/op
BenchmarkCase3-2   	    2000	    648644 ns/op

まとめ

go testのベンチマークがおかしい！
状況によって一部のテストに二倍の時間がかかる
どのテストに二倍の時間がかかるかは端末ごとに違い、何度繰り返しても同一環境なら同じものが遅い
コードが誤っている可能性はある

誰か助けて

追記その1

助言に従ってassemblyを出力してみました。

これは問題のcase2とcase3

"".BenchmarkCase2 t=1 size=85 args=0x8 locals=0x18
	0x0000 00000 (main_test.go:17)	TEXT	"".BenchmarkCase2(SB), $24-8
	0x0000 00000 (main_test.go:17)	MOVQ	(TLS), CX
	0x0009 00009 (main_test.go:17)	CMPQ	SP, 16(CX)
	0x000d 00013 (main_test.go:17)	JLS	78
	0x000f 00015 (main_test.go:17)	SUBQ	$24, SP
	0x0013 00019 (main_test.go:17)	MOVQ	BP, 16(SP)
	0x0018 00024 (main_test.go:17)	LEAQ	16(SP), BP
	0x001d 00029 (main_test.go:17)	FUNCDATA	$0, gclocals·a36216b97439c93dafebe03e7f0808b5(SB)
	0x001d 00029 (main_test.go:17)	FUNCDATA	$1, gclocals·33cdeccccebe80329f1fdbee7f5874cb(SB)
	0x001d 00029 (main_test.go:18)	MOVQ	$0, AX
	0x001f 00031 (main_test.go:18)	MOVQ	AX, "".i+8(SP)
	0x0024 00036 (main_test.go:18)	MOVQ	"".b+32(FP), CX
	0x0029 00041 (main_test.go:18)	MOVQ	200(CX), DX
	0x0030 00048 (main_test.go:18)	CMPQ	AX, DX
	0x0033 00051 (main_test.go:18)	JGE	$0, 68
	0x0035 00053 (main_test.go:19)	PCDATA	$0, $0
	0x0035 00053 (main_test.go:19)	CALL	"".case2(SB)
	0x003a 00058 (main_test.go:18)	MOVQ	"".i+8(SP), AX
	0x003f 00063 (main_test.go:18)	INCQ	AX
	0x0042 00066 (main_test.go:18)	JMP	31
	0x0044 00068 (main_test.go:21)	MOVQ	16(SP), BP
	0x0049 00073 (main_test.go:21)	ADDQ	$24, SP
	0x004d 00077 (main_test.go:21)	RET
	0x004e 00078 (main_test.go:21)	NOP
	0x004e 00078 (main_test.go:17)	PCDATA	$0, $-1
	0x004e 00078 (main_test.go:17)	CALL	runtime.morestack_noctxt(SB)
	0x0053 00083 (main_test.go:17)	JMP	0
	0x0000 65 48 8b 0c 25 00 00 00 00 48 3b 61 10 76 3f 48  eH..%....H;a.v?H
	0x0010 83 ec 18 48 89 6c 24 10 48 8d 6c 24 10 31 c0 48  ...H.l$.H.l$.1.H
	0x0020 89 44 24 08 48 8b 4c 24 20 48 8b 91 c8 00 00 00  .D$.H.L$ H......
	0x0030 48 39 d0 7d 0f e8 00 00 00 00 48 8b 44 24 08 48  H9.}......H.D$.H
	0x0040 ff c0 eb db 48 8b 6c 24 10 48 83 c4 18 c3 e8 00  ....H.l$.H......
	0x0050 00 00 00 eb ab                                   .....
	rel 5+4 t=16 TLS+0
	rel 54+4 t=8 "".case2+0
	rel 79+4 t=8 runtime.morestack_noctxt+0
"".BenchmarkCase3 t=1 size=85 args=0x8 locals=0x18
	0x0000 00000 (main_test.go:23)	TEXT	"".BenchmarkCase3(SB), $24-8
	0x0000 00000 (main_test.go:23)	MOVQ	(TLS), CX
	0x0009 00009 (main_test.go:23)	CMPQ	SP, 16(CX)
	0x000d 00013 (main_test.go:23)	JLS	78
	0x000f 00015 (main_test.go:23)	SUBQ	$24, SP
	0x0013 00019 (main_test.go:23)	MOVQ	BP, 16(SP)
	0x0018 00024 (main_test.go:23)	LEAQ	16(SP), BP
	0x001d 00029 (main_test.go:23)	FUNCDATA	$0, gclocals·a36216b97439c93dafebe03e7f0808b5(SB)
	0x001d 00029 (main_test.go:23)	FUNCDATA	$1, gclocals·33cdeccccebe80329f1fdbee7f5874cb(SB)
	0x001d 00029 (main_test.go:24)	MOVQ	$0, AX
	0x001f 00031 (main_test.go:24)	MOVQ	AX, "".i+8(SP)
	0x0024 00036 (main_test.go:24)	MOVQ	"".b+32(FP), CX
	0x0029 00041 (main_test.go:24)	MOVQ	200(CX), DX
	0x0030 00048 (main_test.go:24)	CMPQ	AX, DX
	0x0033 00051 (main_test.go:24)	JGE	$0, 68
	0x0035 00053 (main_test.go:25)	PCDATA	$0, $0
	0x0035 00053 (main_test.go:25)	CALL	"".case3(SB)
	0x003a 00058 (main_test.go:24)	MOVQ	"".i+8(SP), AX
	0x003f 00063 (main_test.go:24)	INCQ	AX
	0x0042 00066 (main_test.go:24)	JMP	31
	0x0044 00068 (main_test.go:27)	MOVQ	16(SP), BP
	0x0049 00073 (main_test.go:27)	ADDQ	$24, SP
	0x004d 00077 (main_test.go:27)	RET
	0x004e 00078 (main_test.go:27)	NOP
	0x004e 00078 (main_test.go:23)	PCDATA	$0, $-1
	0x004e 00078 (main_test.go:23)	CALL	runtime.morestack_noctxt(SB)
	0x0053 00083 (main_test.go:23)	JMP	0
	0x0000 65 48 8b 0c 25 00 00 00 00 48 3b 61 10 76 3f 48  eH..%....H;a.v?H
	0x0010 83 ec 18 48 89 6c 24 10 48 8d 6c 24 10 31 c0 48  ...H.l$.H.l$.1.H
	0x0020 89 44 24 08 48 8b 4c 24 20 48 8b 91 c8 00 00 00  .D$.H.L$ H......
	0x0030 48 39 d0 7d 0f e8 00 00 00 00 48 8b 44 24 08 48  H9.}......H.D$.H
	0x0040 ff c0 eb db 48 8b 6c 24 10 48 83 c4 18 c3 e8 00  ....H.l$.H......
	0x0050 00 00 00 eb ab                                   .....
	rel 5+4 t=16 TLS+0
	rel 54+4 t=8 "".case3+0
	rel 79+4 t=8 runtime.morestack_noctxt+0

どうも全く同じように見える……。Benchmark側の問題も考慮してタイマーのリセットを行います。

　## タイマーのリセット

package main

import "testing"

func BenchmarkCase0(b *testing.B) {
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		case0()
	}
}

func BenchmarkCase1(b *testing.B) {
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		case1()
	}
}

func BenchmarkCase2(b *testing.B) {
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		case2()
	}
}

func BenchmarkCase3(b *testing.B) {
	b.ResetTimer()
	for i := 0; i < b.N; i++ {
		case3()
	}
}

$ go test -bench . -benchmem
BenchmarkCase0-4   	    5000	    316630 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase1-4   	    5000	    317177 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase2-4   	    2000	    629405 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase3-4   	    5000	    317769 ns/op	       0 B/op	       0 allocs/op

変わらないことを確認

このベンチマークをやるには回数が少ない気がする。(つまり誤差?) / “【調査中】Goのbenchmarkを使うと環境ごとに結果がバラバラになってしまったので、誰か知恵を貸して欲しい - Qiita” https://t.co/U4QzP6FUyW
— mattn (@mattn_jp) 2017年12月8日

このようなご指摘をいただいたため、回数を増やしたのですが、

$ go test -bench . -benchmem -benchtime 20s
BenchmarkCase0-4   	  100000	    314117 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase1-4   	  100000	    316989 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase2-4   	   50000	    624479 ns/op	       0 B/op	       0 allocs/op
BenchmarkCase3-4   	  100000	    332317 ns/op	       0 B/op	       0 allocs/op

結果変わらずです。