Re: [go-nuts] Re: help understanding weird Benchmark results

2020-05-19 Thread Marvin Renich 
* Warren Bare  [200519 13:53]:
> OK, I added a sum of the rand to the demo code and the results are the 
> same.  Since it is displaying the sum, it seems clear that the code is not 
> optimized away.
> 
> Again, I am NOT trying to time each iteration of the loop.  This is a 
> minimal demonstration of a weirdness I was seeing in my own benchmarks.  
> Just pretend the loop is one chunk of code that takes time and is not 
> optimized away.
> 
> Any other ideas?
> 
> func BenchmarkMarshalSample(b *testing.B) {
> var sum int64
> start := time.Now()
> for i := 0; i < 10_000_000; i++ {
> sum += rand.Int63n(0x)
> }
> b.Logf("Sum %e Duration %v", float64(sum), time.Now().Sub(start))
> }

You do not clearly understand how benchmarking in the testing package
works.  In order to get meaningful results, your benchmark function
_must_ iterate b.N times.  The benchmark framework is going to run your
function several times, with different values of b.N until it can get a
meaningful time, and then it does the math to give you "per iteration"
times.  Read carefully the section "Benchmarks" under
https://golang.org/pkg/testing/.

For the above case (given that you are not trying to time one
invocation of rand.Int63n, but a fixed number) you would write your code
like this:

func BenchmarkMarshalSample(b *testing.B) {
var sum int64
start := time.Now()
for j := 0; j < b.N; j++ {
for i := 0; i < 10_000_000; i++ {
sum += rand.Int63n(0x)
}
}
b.Logf("Sum %e Duration %v", float64(sum), time.Now().Sub(start))
}

The benchmark results will give the time for _one_ iteration of the
_outer_ loop, so the "op" in "ns/op" will be 10_000_000 iterations of
the inner loop.

...Marvin

-- 
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/20200519181906.5xvifyyrowbnfzrs%40basil.wdw.

Re: [go-nuts] Re: help understanding weird Benchmark results

2020-05-19 Thread Michael Jones 
as was explained, the loop needs to be "for i:=0; i < b.N; i++"

as was mentioned, the compiler's dead code elimination efforts can
frustrate benchmarking. they way to make sure the test code survives is to
not let it be dead code. for example

// external var dummy

func
for i:=0; i < b.N; i++ {
  dummy += rand.Int63()
}

On Tue, May 19, 2020 at 10:22 AM Warren Bare  wrote:

> >You are supposed to run the loop b.N times, not some fixed constant.
>
> I understand.  This is a simulation of a single bigger task that takes a
> while.  I'm not trying to time the rand function inside the loop.  The loop
> is simply to burn time.  This simple function is a minimal example that
> demonstrates a problem I was having with my own real benchmark test.
>
> I don't know for sure that the compiler is NOT optimizing away this rand
> function, but I can tell you this problem was happening on my own code that
> can not be optimized away.
>
> Thanks.
>
>
>
> On Tuesday, May 19, 2020 at 12:39:33 PM UTC-4, Volker Dobler wrote:
>>
>> You are supposed to run the loop b.N times, not
>> some fixed constant. Also make sure the compiler
>> doesn't optimize away the whole function.
>>
>> V.
>>
>> On Tuesday, 19 May 2020 18:20:43 UTC+2, Warren Bare wrote:
>>>
>>> Hi Folks,
>>>
>>> I'm getting weird results from Benchmark.  Maybe someone can help me
>>> understand this.  I'm running on amd-64 (Threadripper 16 core 32 thread)
>>> Windows 10.  Go 1.14.3
>>>
>>> I have the benchmark below (main_test.go) on a minimum "hello world"
>>> main.go (just like playground).
>>>
>>> When I run the benchmark as it is below, I get the results included just
>>> below here.  Notice it reports 0.135 ns/op but the time is actually 135
>>> *ms* so it is off by a factor of 1 billion.  It is like it trying to
>>> report in seconds but did not change the label from ns to s.
>>>
>>> Further, if I increase the loop 10x from 10_000_000 to 100_000_000, then
>>> it prints Duration 1.349 seconds (good) and now the Benchmark time has
>>> increased by a factor of 10 *billion *and is now correctly reported as
>>> 1349224200 ns/op
>>>
>>> What am I missing here?
>>>
>>>
>>> BenchmarkMarshalSample-32   10   0.135 ns/op   
>>> 0 B/op  0 allocs/op
>>> --- BENCH: BenchmarkMarshalSample-32
>>> main_test.go:14: Duration 136.1221ms
>>> main_test.go:14: Duration 135.1214ms
>>> main_test.go:14: Duration 134.1763ms
>>> main_test.go:14: Duration 135.1217ms
>>> main_test.go:14: Duration 135.1298ms
>>> main_test.go:14: Duration 135.1217ms
>>> main_test.go:14: Duration 135.1218ms
>>> main_test.go:14: Duration 135.1213ms
>>> main_test.go:14: Duration 135.1298ms
>>> main_test.go:14: Duration 135.1216ms
>>> ... [output truncated]
>>> PASS
>>>
>>>
>>>
>>> package main
>>>
>>> import (
>>> "math/rand"
>>> "testing"
>>> "time"
>>> )
>>>
>>> func BenchmarkMarshalSample(b *testing.B) {
>>> start := time.Now()
>>> for i := 0; i < 10_000_000; i++ {
>>> rand.Int63()
>>> }
>>> b.Log("Duration", time.Now().Sub(start))
>>> }
>>>
>>> --
> 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/2abb7390-3c3c-4172-aead-021dbf500bad%40googlegroups.com
> 
> .
>


-- 

*Michael T. jonesmichael.jo...@gmail.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/CALoEmQwN%2Bou8hqYEi5R1RuC%2Bdvbzzemsha35QA5LwK87Q_whVA%40mail.gmail.com.