Benchmarking

[kawasin73]

• Set()
• timer diff

[kawasin73]

golang でパフォーマンスチューニングする際に気を付けるべきこと

https://godoc.org/golang.org/x/perf/cmd/benchstat

go get -u golang.org/x/perf/cmd/...

[kawasin73]

Created latency tool
362acf0

bench command

go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=0
go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=1000

go run cmd/latency/main.go -interval=100000 -n 100000 -worker=0
go run cmd/latency/main.go -interval=100000 -n 100000 -worker=1000

go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=0
go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=1000

[kawasin73]

Performance v0.4.0

$ go version
go version go1.10.1 darwin/amd64

$ system_profiler SPHardwareDataType
Hardware:

    Hardware Overview:

      Model Name: MacBook Pro
      Model Identifier: MacBookPro12,1
      Processor Name: Intel Core i7
      Processor Speed: 3.1 GHz
      Number of Processors: 1
      Total Number of Cores: 2
      L2 Cache (per Core): 256 KB
      L3 Cache: 4 MB
      Memory: 16 GB

$ go test -bench=. -count=10 > bench.txt && benchstat bench.txt
name             time/op
Scheduler_Set-4  1.52µs ± 4%

$ go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=0
set 1000000 tasks in 2.883528886s. interval = 1µs, total=1s, workers=0
all task have executed in 2.695712349s.
task executed latency : mean=848.03613ms, min=1.280555ms, max=1.695715713s
executed min index=0, max index=999994
$ go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=1000
set 1000000 tasks in 2.943881676s. interval = 1µs, total=1s, workers=1000
all task have executed in 6.010413861s.
task executed latency : mean=2.480499799s, min=1.265004ms, max=5.010415861s
executed min index=0, max index=999999

$ go run cmd/latency/main.go -interval=100000 -n 100000 -worker=0
set 100000 tasks in 253.059688ms. interval = 100µs, total=10s, workers=0
all task have executed in 9.999921139s.
task executed latency : mean=27.708µs, min=7.635µs, max=1.081832ms
executed min index=66497, max index=66507
$ go run cmd/latency/main.go -interval=100000 -n 100000 -worker=1000
set 100000 tasks in 302.308732ms. interval = 100µs, total=10s, workers=1000
all task have executed in 9.999922568s.
task executed latency : mean=28.193µs, min=11.186µs, max=2.244994ms
executed min index=8435, max index=8411

$ go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=0
set 10000 tasks in 34.668009ms. interval = 1ms, total=10s, workers=0
all task have executed in 9.999255193s.
task executed latency : mean=241.131µs, min=32.719µs, max=1.414843ms
executed min index=3594, max index=5644
$ go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=1000
set 10000 tasks in 40.431829ms. interval = 1ms, total=10s, workers=1000
all task have executed in 9.999212943s.
task executed latency : mean=246.485µs, min=24.315µs, max=1.225857ms
executed min index=371, max index=0

[kawasin73]

Performance v0.4.1

$ go test -bench=. -count=10 > bench.txt && benchstat bench.txt
name             time/op
Scheduler_Set-4  1.52µs ± 1%

$ go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=0
set 1000000 tasks in 2.995069909s. interval = 1µs, total=1s, workers=0
all task have executed in 1.187109126s.
task executed latency : mean=89.401961ms, min=825.441µs, max=187.529808ms
executed min index=0, max index=995060
$ go run cmd/latency/main.go -interval=1000 -n 1000000 -worker=1000
set 1000000 tasks in 2.920602839s. interval = 1µs, total=1s, workers=1000
all task have executed in 3.780219339s.
task executed latency : mean=1.398613812s, min=1.245229ms, max=2.782968339s
executed min index=0, max index=999999

$ go run cmd/latency/main.go -interval=100000 -n 100000 -worker=0
set 100000 tasks in 292.649906ms. interval = 100µs, total=10s, workers=0
all task have executed in 9.99992153s.
task executed latency : mean=27.207µs, min=12.938µs, max=1.195354ms
executed min index=74683, max index=0
$ go run cmd/latency/main.go -interval=100000 -n 100000 -worker=1000
set 100000 tasks in 305.584522ms. interval = 100µs, total=10s, workers=1000
all task have executed in 9.999922502s.
task executed latency : mean=27.717µs, min=13.109µs, max=1.475327ms
executed min index=40074, max index=40046

$ go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=0
set 10000 tasks in 28.64034ms. interval = 1ms, total=10s, workers=0
all task have executed in 9.999248894s.
task executed latency : mean=270.313µs, min=30.631µs, max=5.821627ms
executed min index=9118, max index=6563
$ go run cmd/latency/main.go -interval=1000000 -n 10000 -worker=1000
set 10000 tasks in 40.446178ms. interval = 1ms, total=10s, workers=1000
all task have executed in 9.999250249s.
task executed latency : mean=234.137µs, min=29.701µs, max=2.699203ms
executed min index=4262, max index=243

[kawasin73]

TODO

• チャネルを使わずに計測する
• high resolution timer
  • http://jjy.nict.go.jp/tsp/research/labo3/gettime.html
  • https://github.com/ScaleFT/monotime