Weird benchmark results for seemingly identical functions

[Yonatan Ben-Nes]

Hi,

I'm encountering a weird issue which I fail to explain. It boils down to 2 almost identical functions which give wildly different benchmark results.

The difference between the functions is that at the slow func there is a for loop like this:

for pos := 0; pos < suffixLen && pos < previousSuffixLen; pos++ {
}

While at the fast func the loop is like this:

for pos := 0; true; pos++ {
   if pos < suffixLen && pos < previousSuffixLen {
     break
   }
}

* do note that the check at both versions is the same.

Other than that the functions are identical but when I benchmark them I get:

$ go test -bench=Weird .
goos: linux
goarch: amd64
BenchmarkWeirdFast-4 280394 3602 ns/op
BenchmarkWeirdSlow-4 1866 618953 ns/op

It's extra weird since getting the condition check into the loop should be the slower form, or at least that what I intuitively thought.

Also, the extra time cost is divided between the loop section and an append function call which run immediately at the start of the function and is not connected in any way to the for loop.

And it's extra weird as the append cost also get smaller if instead of reading the test text from a file I just declare a string variable with the same text for the benchmark (mind you that I b.ResetTimer() after doing either of those options).

I attached the files to this message as they will make everything more clear and I also added comments describing what happen at the right points.

I'm using Ubuntu 18.04 and go is version 1.14.2, and I also checked it on a GCP compute engine and got the same results.

Any thoughts will be much appreciated as I'm totally confused here! :)

[Bakul Shah]

They are not equivalent. You want if !(pos < suffixLen && pos < previousSuffixLen) {  break } in the second case.

--
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...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/3cf40b00-96ec-42a6-8093-7f1c27bfd93fn%40googlegroups.com.

[Martin Schnabel]

Let me quickly point out that your logic is inverted in the second code
snippet because you break on the condition. That is most likely the
reason for the difference. I guess the second example exits on the first
iteration.

for pos := 0; true; pos++ {
if pos < suffixLen && pos < previousSuffixLen {

continue
}
break

> --
> 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...@googlegroups.com

> <mailto:golang-nuts...@googlegroups.com>.

> To view this discussion on the web visit
> https://groups.google.com/d/msgid/golang-nuts/3cf40b00-96ec-42a6-8093-7f1c27bfd93fn%40googlegroups.com

> <https://groups.google.com/d/msgid/golang-nuts/3cf40b00-96ec-42a6-8093-7f1c27bfd93fn%40googlegroups.com?utm_medium=email&utm_source=footer>.

[Nimrod Yonatan Ben-Nes]

Oh the shame!!!!

Thank you for pointing that out :)

[Yonatan Ben-Nes]

So I'm probably missing something obvious again but the fact that the loops were checking different/inverse conditions should not have cause the append line to cost 300k ns/op.

I'm referring to the line `lcp = append(lcp, 0)` which appear at the start of both of the functions, when I'm running the "slow" function as-is I get timing of about 600k ns/op, but when I comment out the above append line I get timing of about 300k ns/op, which mean that calling append took around 300k ns (or maybe it doesn't mean that?).

This is weird since the loops do not refer in any way with the lcp array which is just returned later (both functions just do the aforementioned append and at the end return the lcp slice which contain just 1 element with 0 value).

I actually even pinpointed the code which make the append become slower and it's part of the check of the inner for loop, its the "pos < previousSuffixLen" part, removing this part make the code speed be roughly the same with or without the append line.

just to be sure that this is not a sane speed for an append function, I also benchmarked the function below, it got 21 ns/op.

func timeAppend(suffixArray []string) (lcp []int) {
  lcp = append(lcp, 0)
   return lcp
}

Thanks again in advance :)