Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
On Tuesday, 24 March 2020 18:50:32 UTC, Michael Jones wrote:
>
> yes
>
...and that is exactly the scenario that I believe is yielding inconsistent
results:
Given the following function to be benchmarked:
func foo() []string{
testData := []string{}
for i:= 0; i < 8; i++ {
testData = append(testData, strconv.Itoa(i))
}
return testData
}
On my hardware this takes either 454 ns/op or 1322 ns/op depending on how
it's called:
1st case:
func Benchmark(b *testing.B) {
for i := 0; i < b.N; i++{
Foo1 = foo()// this reports 454 ns/op on my hardware
}
}
2nd case:
func Benchmark(b *testing.B) {
for i := 0; i < b.N; i++{
b.StopTimer()
Foo1 = foo() // This shouldn't be charged against the benchmark. Ignore the
fact that it's a call to foo, I'm just using it as a means of elapsing some
time
b.StartTimer()
Foo2 = foo()// this reports a whopping 1322 ns/op on my hardware
}
}
So a call to foo takes over three times more time if *within the loop* we
stop the timer, do something that takes time and then start the timer
before calling foo. That's definitely violating the law of least surprise
for me.
For StopTimer and StartTimer to be of any use I have to believe that they
actually do stop and start the timer reliably. From those timings I'd say
that this isn't the case.
As always I may be wrong. I'd just like someone to explain how and I'll be
a happy chappie :)
>
> On Tue, Mar 24, 2020 at 11:48 AM Orson Cart > wrote:
>
>> On Tuesday, 24 March 2020 18:31:29 UTC, Michael Jones wrote:
>>>
>>> You use them to stop the time charged against your benchmark.
>>>
>>> For example:
>>>
>>> bench:
>>> stop timer
>>> generate initial data
>>> start timer
>>> do test
>>>
>>
>> Thanks Michael. What if the initial data has to be generated from scratch
>> on each iteration? Is the following expected to work?
>>
>> bench:
>> b.N Loop
>> stop timer
>> generate new data
>> start timer
>> do test
>>
>>
>>
>>
>>>
>>> On Tue, Mar 24, 2020 at 10:47 AM Orson Cart
>>> wrote:
>>>
On Tuesday, 24 March 2020 16:49:55 UTC, Robert Engels wrote:
>
> Can you please succinctly explain the problem?
>
Let's see. Benchmarks can yield incorrect results when b.StopTimer and
b.StartTimer are used.
My reasoning:
1/ I have a benchmark that calls a single function. The reported
duration is T.
2/ I have another benchmark which invokes the same function twice. I'd
expect the reported duration for this to be nominally 2T and within reason
it appears to be the case.
3/ I have yet another benchmark which also invokes the same function
twice but it stops the benchmark timer before the first call and then
starts it after the the first call has completed. I'd expect the reported
duration to be nominally T again. It isn't. It's closer to 3T on my
hardware and I've seen much worse correlation on other hardware - almost 5T
Now it's entirely possible that I'm misunderstanding something about
how b.StopTimer and b.StartTimer are intended to be used, hence my post
here :)
>
>
> On Mar 24, 2020, at 11:24 AM, 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
Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
yes
On Tue, Mar 24, 2020 at 11:48 AM Orson Cart
wrote:
> On Tuesday, 24 March 2020 18:31:29 UTC, Michael Jones wrote:
>>
>> You use them to stop the time charged against your benchmark.
>>
>> For example:
>>
>> bench:
>> stop timer
>> generate initial data
>> start timer
>> do test
>>
>
> Thanks Michael. What if the initial data has to be generated from scratch
> on each iteration? Is the following expected to work?
>
> bench:
> b.N Loop
> stop timer
> generate new data
> start timer
> do test
>
>
>
>
>>
>> On Tue, Mar 24, 2020 at 10:47 AM Orson Cart
>> wrote:
>>
>>>
>>> On Tuesday, 24 March 2020 16:49:55 UTC, Robert Engels wrote:
Can you please succinctly explain the problem?
>>>
>>> Let's see. Benchmarks can yield incorrect results when b.StopTimer and
>>> b.StartTimer are used.
>>>
>>> My reasoning:
>>>
>>> 1/ I have a benchmark that calls a single function. The reported
>>> duration is T.
>>> 2/ I have another benchmark which invokes the same function twice. I'd
>>> expect the reported duration for this to be nominally 2T and within reason
>>> it appears to be the case.
>>> 3/ I have yet another benchmark which also invokes the same function
>>> twice but it stops the benchmark timer before the first call and then
>>> starts it after the the first call has completed. I'd expect the reported
>>> duration to be nominally T again. It isn't. It's closer to 3T on my
>>> hardware and I've seen much worse correlation on other hardware - almost 5T
>>>
>>> Now it's entirely possible that I'm misunderstanding something about how
>>> b.StopTimer and b.StartTimer are intended to be used, hence my post here :)
>>>
>>>
>>>
>>>
>>>
>>>
>>>
On Mar 24, 2020, at 11:24 AM, 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.
Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
On Tuesday, 24 March 2020 18:31:29 UTC, Michael Jones wrote:
>
> You use them to stop the time charged against your benchmark.
>
> For example:
>
> bench:
> stop timer
> generate initial data
> start timer
> do test
>
Thanks Michael. What if the initial data has to be generated from scratch
on each iteration? Is the following expected to work?
bench:
b.N Loop
stop timer
generate new data
start timer
do test
>
> On Tue, Mar 24, 2020 at 10:47 AM Orson Cart > wrote:
>
>>
>> On Tuesday, 24 March 2020 16:49:55 UTC, Robert Engels wrote:
>>>
>>> Can you please succinctly explain the problem?
>>>
>>
>> Let's see. Benchmarks can yield incorrect results when b.StopTimer and
>> b.StartTimer are used.
>>
>> My reasoning:
>>
>> 1/ I have a benchmark that calls a single function. The reported duration
>> is T.
>> 2/ I have another benchmark which invokes the same function twice. I'd
>> expect the reported duration for this to be nominally 2T and within reason
>> it appears to be the case.
>> 3/ I have yet another benchmark which also invokes the same function
>> twice but it stops the benchmark timer before the first call and then
>> starts it after the the first call has completed. I'd expect the reported
>> duration to be nominally T again. It isn't. It's closer to 3T on my
>> hardware and I've seen much worse correlation on other hardware - almost 5T
>>
>> Now it's entirely possible that I'm misunderstanding something about how
>> b.StopTimer and b.StartTimer are intended to be used, hence my post here :)
>>
>>
>>
>>
>>
>>
>>
>>>
>>>
>>> On Mar 24, 2020, at 11:24 AM, 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.
>>> To view this discussion on the web visit
>>> https://groups.google.com/d/msgid/golang-nuts/38f10940-a770-4fc5-86a9-19cc1371152a%40googlegroups.com
>>>
>>>
Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
You use them to stop the time charged against your benchmark.
For example:
bench:
stop timer
generate initial data
start timer
do test
On Tue, Mar 24, 2020 at 10:47 AM Orson Cart
wrote:
>
> On Tuesday, 24 March 2020 16:49:55 UTC, Robert Engels wrote:
>>
>> Can you please succinctly explain the problem?
>>
>
> Let's see. Benchmarks can yield incorrect results when b.StopTimer and
> b.StartTimer are used.
>
> My reasoning:
>
> 1/ I have a benchmark that calls a single function. The reported duration
> is T.
> 2/ I have another benchmark which invokes the same function twice. I'd
> expect the reported duration for this to be nominally 2T and within reason
> it appears to be the case.
> 3/ I have yet another benchmark which also invokes the same function twice
> but it stops the benchmark timer before the first call and then starts it
> after the the first call has completed. I'd expect the reported duration to
> be nominally T again. It isn't. It's closer to 3T on my hardware and I've
> seen much worse correlation on other hardware - almost 5T
>
> Now it's entirely possible that I'm misunderstanding something about how
> b.StopTimer and b.StartTimer are intended to be used, hence my post here :)
>
>
>
>
>
>
>
>>
>>
>> On Mar 24, 2020, at 11:24 AM, 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.
>> To view this discussion on the web visit
>> https://groups.google.com/d/msgid/golang-nuts/38f10940-a770-4fc5-86a9-19cc1371152a%40googlegroups.com
>>
>> .
>>
>> --
> 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/1d291cef-420a-4f80-b719-e0654585c25d%40googlegroups.com
>
Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
On Tuesday, 24 March 2020 16:49:55 UTC, Robert Engels wrote:
>
> Can you please succinctly explain the problem?
>
Let's see. Benchmarks can yield incorrect results when b.StopTimer and
b.StartTimer are used.
My reasoning:
1/ I have a benchmark that calls a single function. The reported duration
is T.
2/ I have another benchmark which invokes the same function twice. I'd
expect the reported duration for this to be nominally 2T and within reason
it appears to be the case.
3/ I have yet another benchmark which also invokes the same function twice
but it stops the benchmark timer before the first call and then starts it
after the the first call has completed. I'd expect the reported duration to
be nominally T again. It isn't. It's closer to 3T on my hardware and I've
seen much worse correlation on other hardware - almost 5T
Now it's entirely possible that I'm misunderstanding something about how
b.StopTimer and b.StartTimer are intended to be used, hence my post here :)
>
>
> On Mar 24, 2020, at 11:24 AM, 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 .
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/golang-nuts/38f10940-a770-4fc5-86a9-19cc1371152a%40googlegroups.com
>
>
> .
>
>
--
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/1d291cef-420a-4f80-b719-e0654585c25d%40googlegroups.com.
Re: [go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
Can you please succinctly explain the problem?
> On Mar 24, 2020, at 11:24 AM, 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/38f10940-a770-4fc5-86a9-19cc1371152a%40googlegroups.com.
--
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/B3D08334-348B-4A0E-919D-3260E37D0345%40ix.netcom.com.
[go-nuts] Bencharking issue with b.StartTimer and b.StopTimer. Was: Benchmark using b.StopTimer and b.StartTimer has unexpected behaviour - to me at least
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/38f10940-a770-4fc5-86a9-19cc1371152a%40googlegroups.com.
