1

I was measuring the performance of inline functions when I encountered this really weird behavior.

fun normalFunction(block: () -> Unit) = block()

inline fun inlineFunction(block: () -> Unit) = block()

The following piece of code produces the output 0.315988524.

var x = 0

println(measureNanoTime {
    repeat(1_000_000_000) {
        normalFunction {
            x += it
        }
    }
} / 1E9)

Replacing normalFunction by inlineFunction produces the output 0.307185642; slightly faster as one might expect.

Now to the weird part. If I run both pieces of code directly in the same function (renaming x to y in one instance or encapsulating both blocks with run { ... }) then the produced output varies drastically depending on which block is run first:

  • normalFunction then inlineFunction produces the output 0.320697598 and 0.310288507
  • inineFunction then normalFunction produces the output 0.310213495 and 5.515626813

The weirdness ends when the two pieces of code are extracted to individual functions. The only thing that comes to my mind is GC but the inline function shouldn't really have any overhead memory wise. Does someone have an idea why this might happen? Should I file a bug report?

Here are the two complete versions for clarity:

fun main() {
    run {
        var x = 0

        println(measureNanoTime {
            repeat(1_000_000_000) {
                normalFunction {
                    x += it
                }
            }
        } / 1E9)
    }

    run {
        var x = 0

        println(measureNanoTime {
            repeat(1_000_000_000) {
                inlineFunction {
                    x += it
                }
            }
        } / 1E9)
    }
}
fun main() {
    run {
        var x = 0

        println(measureNanoTime {
            repeat(1_000_000_000) {
                inlineFunction {
                    x += it
                }
            }
        } / 1E9)
    }

    run {
        var x = 0

        println(measureNanoTime {
            repeat(1_000_000_000) {
                normalFunction {
                    x += it
                }
            }
        } / 1E9)
    }
}
Marvin
  • 1,832
  • 2
  • 13
  • 22
  • This is 100% normal for any JVM code. The JVM optimizes code as it runs more, so of course later code will run faster than earlier code. – Louis Wasserman Jun 21 '21 at 19:17
  • I'm not sure if you got my question right. Performance varies depending on executing order of two slightly different and independent pieces of code and only as long as they are placed directly in the same function. – Marvin Jun 21 '21 at 19:21
  • 1
    It does not happen on my machine with Java 14. They both take around 0.32-0.35, no matter the order. And I think @LouisWasserman could be right. It is hard to measure the performance of Java code, because quite a lot of things happen under the hood. It is discouraged to write such simple tests as yours as results may be misleading. You should use JMH or similar tool to see if you will reproduce your results. – broot Jun 21 '21 at 19:24

0 Answers0