Strange. I hope someone has a real answer for you. In the meantime, you can simplify your example to demonstrate the issue:
package demo_test import ( "testing" ) var Foo1 []string var Count int = 8 func Benchmark1(b *testing.B) { for i := 0; i < b.N; i++ { Foo1 = foo(Count) } } func Benchmark2(b *testing.B) { b.StopTimer() for i := 0; i < b.N; i++ { // Hypothetical setup here b.StartTimer() Foo1 = foo(Count) b.StopTimer() } } func foo(count int) []string { testData := []string{} for i := 0; i < count; i++ { testData = append(testData, "a") } return testData } I get: goos: windows goarch: amd64 Benchmark1-4 2101567 584 ns/op Benchmark2-4 1000000 1668 ns/op PASS So it appears that StopTimer() and StartTimer() are introducing some overhead. I am surprised that it is this large. Good Luck On Tuesday, March 24, 2020 at 12:24:08 PM UTC-4, Orson Cart wrote: > > I posted this earlier but I realised that the code had a fundamental error > in it. I've corrected here it but the underlying problem still exists. > > I've recently started using go test's benchmarks support and I'm > particularly interested in understanding the benchmark timer functions. > I've been getting results that I found surprising and I was wondering if > anyone could explain what's going on here. > > The code below has three benchmarks that each invoke a single function > (foo). The implementation of foo isn't important, it's just there to > consume some time: > - foo is called once per iteration in Benchmark1. > - It's called twice per iteration in Benchmark2 so I'd expect Benchmark2's > duration to be nominally twice that of Benchmark1. > - It's also called twice per iteration in Benchmark3 but the first call is > wrapped in b.StopTimer and b.startTimer calls. Because of this I'd have > expected Benchmark3 to be about the same duration as Benchmark1 > > Apologies for the length of the example but I didn't think it fair to ask > the question and leave anything out. > > package demo_test > > import ( > "strconv" > "testing" > ) > > var Foo1 []string > var Foo2 []string > var Count int = 32767 > > func Benchmark1(b *testing.B) { > for i := 0; i < b.N; i++{ > Foo1 = foo(Count) > } > } > > func Benchmark2(b *testing.B) { > for i := 0; i < b.N; i++{ > Foo1 = foo(Count) > Foo2 = foo(Count) > } > } > > func Benchmark3(b *testing.B) { > for i := 0; i < b.N; i++{ > b.StopTimer() > Foo1 = foo(Count) > b.StartTimer() > Foo2 = foo(Count) > } > } > > func foo(count int) []string{ > testData := []string{} > for i:= 0; i < count; i++ { > testData = append(testData, strconv.Itoa(i)) > } > > return testData > } > > > When the benchmarks are run the results are as follows: > > Benchmark1-4 351 3345215 ns/op > Benchmark2-4 166 7206582 ns/op > Benchmark3-4 334 3457907 ns/op > PASS > ok bar.com/benchmarks 6.881s > > OK benchmark3 is a little slower than Benchmark1 but that's not what's > bothering me. It's this: if I now change Count to something much smaller > the results are a surprise, at least to me. Here are the results when Count > = 8: > > Benchmark1-4 2706196 442 ns/op > Benchmark2-4 1357482 873 ns/op > Benchmark3-4 840729 1387 ns/op > PASS > ok bar.com/benchmarks 23.547s > > The ratio of timings for Benchmark1 and Benchmark2 are roughly in line > with expectations but I was surprised to see that the timings for > Benchmark3 are now larger than those for Benchmark2. > > Can anyone explain this? > > TIA > Orson > -- You received this message because you are subscribed to the Google Groups "golang-nuts" group. To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/feda7e38-5d1f-43cf-b0cd-98db0a94d3c9%40googlegroups.com.