go testでベンチマークを取ってpprofで時間がかかっている箇所を調べる
golangこの関数のベンチマークを取る。
package cal
import (
"math/big"
)
var cache = map[int]*big.Int{}
func resetCache() {
cache = map[int]*big.Int{}
}
func Fibonacci(n int) *big.Int {
if c := cache[n]; c != nil {
return c
}
ret := new(big.Int)
before := big.NewInt(1)
for i := 1; i < n; i++ {
tmp := new(big.Int).Add(ret, before)
before = ret
ret = tmp
cache[i] = ret
}
cache[n] = ret
return ret
}
引数にtesting.Bを取る、Benchmarkから始まる関数を書いて、b.N回ループさせる。
package cal
import (
"math/big"
"testing"
)
func TestFibonacci(t *testing.T) {
if f := Fibonacci(10); f.String() != big.NewInt(34).String() {
t.Errorf("%d != %d (expected)", f, big.NewInt(34))
}
}
func BenchmarkFibonacci(b *testing.B) {
for i := 0; i < b.N; i++ {
b.StopTimer()
resetCache()
b.StartTimer()
Fibonacci(100)
}
}
これをgo test -benchで実行するとベンチマークが取れる。さらに-benchmemを付けるとメモリアロケーションの情報も出る。
また、-cpuprofileでCPUのプロファイルを出力し、pprofに渡すことでどの部分で時間がかかっているかを調べることができる。
https://golang.org/cmd/go/#hdr-Description_of_testing_flags
$ go test -bench Fibonacci -benchmem -o pprof/test.bin -cpuprofile pprof/cpu.out ./cal
BenchmarkFibonacci-4 50000 32788 ns/op 13344 B/op 211 allocs/op
PASS
ok github.com/sambaiz/try-pprof/cal 3.406s
$ go tool pprof --text pprof/test.bin pprof/cpu.out
3.80s of 3.83s total (99.22%)
Dropped 17 nodes (cum <= 0.02s)
flat flat% sum% cum cum%
2.31s 60.31% 60.31% 2.31s 60.31% runtime.mach_semaphore_signal
0.38s 9.92% 70.23% 0.38s 9.92% runtime.mach_semaphore_timedwait
0.32s 8.36% 78.59% 0.32s 8.36% runtime.mach_semaphore_wait
0.27s 7.05% 85.64% 0.27s 7.05% runtime.usleep
0.14s 3.66% 89.30% 0.14s 3.66% runtime.deductSweepCredit
0.09s 2.35% 91.64% 0.28s 7.31% runtime.mallocgc
0.04s 1.04% 92.69% 0.14s 3.66% runtime.mapassign1
0.04s 1.04% 93.73% 0.05s 1.31% runtime.updatememstats
0.03s 0.78% 94.52% 0.13s 3.39% math/big.nat.add
0.03s 0.78% 95.30% 0.03s 0.78% runtime.aeshash64
...
graphvizをインストールすることでsvgのグラフを出すこともできる。
$ brew install graphviz
$ go tool pprof --svg pprof/test.bin pprof/cpu.out > pprof/test.svg
