Surprising benchmark allocations

512 views
Skip to first unread message

Francis

unread,
Sep 2, 2016, 9:07:09 AM9/2/16
to golang-nuts
I have been working to reduce allocations in a local cache and found some confusing behaviour around the allocs/op output when benchmarking.

A simplified reproducing version is pasted at bottom.

The behaviour is that setting a value in a single map yields 0 allocations, setting a value in two maps inside the same function yields 1 allocation. Increasing the number of times the Set*() method is called in the benchmark (below I am using b.N*10) doesn't change the number of allocations.

Trying to track down this I have used GOSSAFUNC to inspect both setOne(...) and setTwo(...). I couldn't identify any allocations, although I am not confident in my reading of the SSA output.

I also ran 'go test -bench=.* -memprofile mem.out' which showed 0 allocations.

So I am confused and wanted to ask for clarification on these measurements. It is interesting to me that the setTwo(...) function allocates where the setOne(...) does not, but also that the allocations to the underlying maps don't appear to be recorded by any of the tools I have used here.


package test


type server
struct {
        first  map
[string]string
        second map
[string]string
}


func
new() *server {
       
return &server{
                first
:  make(map[string]string),
                second
: make(map[string]string),
       
}
}


func setOne
(s *server, key string) {
        s
.first[key] = key
}


func setTwo
(s *server, key string) {
        s
.first[key] = key
        s
.second[key] = key
}

with corresponding benchmark



package test


import (
   
"strconv"
   
"testing"
)


func
BenchmarkSetOne(b *testing.B) {
    keyVals
:= make([]string, b.N*10)
   
for i := range keyVals {
            keyVals
[i] = strconv.Itoa(i)
   
}
    s
:= &server{
            first
:  make(map[string]string),
            second
: make(map[string]string),
   
}
    b
.ResetTimer()
    b
.ReportAllocs()
   
for _, key := range keyVals {
            setOne
(s, key)
   
}
}


func
BenchmarkSetTwo(b *testing.B) {
    keyVals
:= make([]string, b.N*10)
   
for i := range keyVals {
            keyVals
[i] = strconv.Itoa(i)
   
}
    s
:= &server{
            first
:  make(map[string]string),
            second
: make(map[string]string),
   
}
    b
.ResetTimer()
    b
.ReportAllocs()
   
for _, key := range keyVals {
            setTwo
(s, key)
   
}
}

peterGo

unread,
Sep 2, 2016, 4:38:35 PM9/2/16
to golang-nuts
Francis,

First, fix any bugs.

For example, "The benchmark function must run the target code b.N times." https://golang.org/pkg/testing/

Therefore,

keyVals := make([]string, b.N*10)
// ...

for _, key := range keyVals {
        setOne(s, key)
}


should be

keyVals := make([]string, b.N)
// ...

for _, key := range keyVals {
        setOne(s, key)
}

or

s /b.N*10/b.N/

Then, as expected,

BenchmarkSetOne-4        1000000          2058 ns/op         159 B/op           0 allocs/op
BenchmarkSetTwo-4        1000000          4648 ns/op         319 B/op           0 allocs/op


Peter

peterGo

unread,
Sep 2, 2016, 4:51:01 PM9/2/16
to golang-nuts
Francis,

And, of course,

keyVals := make([]string, b.N*10)
// ...
for _, key := range keyVals {
        setTwo(s, key)
}


should be

keyVals := make([]string, b.N)
// ...
for _, key := range keyVals {
        setTwo(s, key)
}

or

s /b.N*10/b.N/g

Peter

--
You received this message because you are subscribed to a topic in the Google Groups "golang-nuts" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/golang-nuts/dasvpqes7EU/unsubscribe.
To unsubscribe from this group and all its topics, send an email to golang-nuts+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Francis

unread,
Sep 4, 2016, 3:31:04 PM9/4/16
to golang-nuts
Thanks Peter,

Your observation cracked the mystery for me. There were two things that were causing me confusion.

1: That we were not observing any allocations at all, even though the map/s must be allocating.
2: That one of these tests would allocate anything at all, while the other allocates nothing.

However, given that a hashmap won't necessarily allocate on every set operation some function calls may allocate while others will not. Clearly a function setting in two hashmaps will allocate twice as often as a function setting in one. If the allocs/op is then rounded, or simply stored as an integer, then you have to allocate at a certain rate to get above 0 allocs/op.

We can test this by doubling the number of elements we add inside to the setOne(...) benchmark.

func BenchmarkSetOne(b *testing.B) {
    keyVals
:= make([]string, b.N*20)

   
for i := range keyVals {
            keyVals
[i] = strconv.Itoa(i)
   
}
    s
:= &server{
            first
:  make(map[string]string),
            second
: make(map[string]string),
   
}
    b
.ResetTimer()
    b
.ReportAllocs()
   
for _, key := range keyVals {
            setOne
(s, key)
   
}
}


Gives us

    BenchmarkSetOne-4         200000             14677 ns/op            3192 B/op       1 allocs/op

we can push it further by (naughtily) setting

keyVals := make([]string, b.N*200)

to get

    BenchmarkSetOne-4          10000            159321 ns/op           31921 B/op      11 allocs/op

Your point about observing the 'once per b.N' rule is duly noted :)
To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.

Francis

unread,
Sep 4, 2016, 4:19:40 PM9/4/16
to golang-nuts
Does anyone have any thoughts on whether it would be feasible/desirable to be able to report allocs/op as a decimal in benchmarks? There must be many small functions out there which allocate at uneven, sub b.N, rates. Currently they are hidden/hard to reason about.
Reply all
Reply to author
Forward
0 new messages