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

2020-05-19 Thread Warren Bare
OK, I got it.  You were trying to change the code I was benchmarking, and I 
did not realize you were trying to say a benchmark must have the ability to 
run b.N times.

Yes, that was the problem.  This fixed it:

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


On Tuesday, May 19, 2020 at 1:53:19 PM UTC-4, Warren Bare wrote:
>
> 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))
> }
>
>
>
> On Tuesday, May 19, 2020 at 12:20:43 PM UTC-4, 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/1f6e43a6-3c62-4c0f-99af-f277ba8cba55%40googlegroups.com.


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

2020-05-19 Thread Warren Bare
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))
}



On Tuesday, May 19, 2020 at 12:20:43 PM UTC-4, 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/c0775f1f-9eeb-4ac4-8615-027caa02f1ed%40googlegroups.com.


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

2020-05-19 Thread Warren Bare
>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.


[go-nuts] help understanding weird Benchmark results

2020-05-19 Thread Warren Bare
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/33c4ab46-18ae-46c2-99e9-e467d6f3e184%40googlegroups.com.