「【調査中】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
結果変わらずです。