On Tuesday, 24 March 2020 20:27:39 UTC, Adrian Ratnapala wrote:
>
> ...

So that sounds like the use-case is to call Stop-, StartTimer once 
> before you enter the main loop of the benchmark.  They not efficient 
> enough for a tight inner loop. 
>

Thanks for the input and I think that you are probably correct. It would be 
nice if the docs said that though.

The code that I'm profiling wasn't written by me. It's fast but it modifies 
its input data so it needs new data on each iteration. The implementation 
is non-trivial and it might be a maintenance headache. I've been asked to 
benchmark it along with less complicated implementations. It was whilst 
trying to set up per-iteration test data that I came across this issue.







 

>
> On Wed, 25 Mar 2020 at 06:51, Jake Montgomery <jake...@gmail.com 
> <javascript:>> wrote: 
> > 
> > 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 golan...@googlegroups.com <javascript:>. 
> > To view this discussion on the web visit 
> https://groups.google.com/d/msgid/golang-nuts/feda7e38-5d1f-43cf-b0cd-98db0a94d3c9%40googlegroups.com.
>  
>
>
>
>
> -- 
> Adrian Ratnapala 
>

-- 
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/291af5de-8a01-4c30-98bb-d4765e3a5333%40googlegroups.com.

Reply via email to