0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

Goのベンチマークが想定と違う話の作業メモ

Posted at

「【調査中】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 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

結果変わらずです。

0
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?