go seems to slow down functions passed as arguments? or maybe it’s just optimising my test code …

Hello everybody!

I’m just writing a post in which I mention that go supports multiple return arguments and I came up with a very simple example of where you could use this:

func divide(divisor, dividend int) (quotient, remainder int) {
    quotient = divisor/dividend
    remainder = divisor - dividend*quotient
    return
}

This sort of made sense to me because the % operation is quite expensive. However, the div operation in x86–64 returns the divisor in one register and the dividend in the other, so I imagine go might well take advantage of this to only do the operation once. It is of course also possible that an integer division on x86–64 may actually be faster than an integer multiplication and subtraction.

So in order to compare the time I wrote the following:

package main
import (
    "log"
    "time"
)
func divide(divisor, dividend int) (quotient, remainder int) {
    quotient = divisor/dividend
    remainder = divisor - dividend*quotient
    return
}
func divide2(divisor, dividend int) (quotient, remainder int) {
    quotient = divisor/dividend
    remainder = divisor%dividend
    return
}
func main() {
    t := time.Now()
    for i:=100; i<100000; i++ {
        for j:=10; j<100; j++ {
            divide(i, j)
        }
    }
    log.Printf("time passed: %v\n", time.Now().Sub(t))
    t = time.Now()
    for i:=100; i<100000; i++ {
        for j:=10; j<100; j++ {
            divide2(i, j)
        }
    }
    log.Printf("time passed: %v\n", time.Now().Sub(t))
}   

This resulted in:

2017/07/15 21:59:06 time passed: 6.039273ms
2017/07/15 21:59:06 time passed: 4.400625ms

So divide2 (the function using %) is faster.

Then the functional programmer in me took over, because I didn’t like the repeated code, so I changed it to be like this:

package main
import (
    "log"
    "time"
)
func divide(divisor, dividend int) (quotient, remainder int) {
    quotient = divisor/dividend
    remainder = divisor - dividend*quotient
    return
}
func divide2(divisor, dividend int) (quotient, remainder int) {
    quotient = divisor/dividend
    remainder = divisor%dividend
    return
}
type IntIntToIntInt func(Int, Int) (Int, Int)
func Loop(f IntIntToIntInt) {
    for i:=100; i<100000; i++ {
        for j:=10; j<100; j++ {
            f(i,j)
        }
    }
}
func main() {
    t := time.Now()
    Loop(divide)
    log.Printf("time passed: %v\n", time.Now().Sub(t))
    t = time.Now()
    log.Printf("time passed: %v\n", time.Now().Sub(t))
}

Which resulted in:

2017/07/15 22:03:02 time passed: 154.627646ms
2017/07/15 22:03:02 time passed: 122.988259ms

Which is a whole lot slower. Maybe there’s some secret boxing/unboxing going on here. I can’t find anything on Google about this at the moment. Maybe a more experienced go programmer knows what’s going on here :) Certainly the go runtime seems to be working a lot harder than when the function is called directly without being passed.

— edit —

I think I’ve worked out what’s going on. I’ve changed my main function to look like this:

var foo int
for i:=100; i<100000; i++ {
    for j:=10; j<100; j++ {
        foo, _ = divide(i, j)
    }
}
log.Print(foo) // need to use variable

Now it takes 100ms, which is much closer to 150ms. I imagine the compiler was optimising out the divide(i,j) call. This doesn’t explain why function passing is 50% slower.

Of course, that also doesn’t explain why when divide(i,j) is optimised out it runs slower than when divide2(i,j) is optimised out.

I’ve just written similar code in C and found that all methods (using % and using function pointers) take about 80ms on my machine. Go is pretty competitive.

Meanwhile in news that may not surprise many, scala returns from between 60ms (using % and for comprehensions) up to 350ms (using % and function passing).