8010309 : PlatformLogger: isLoggable performance / waste due to HashMap<Integer, Level> leads to Integer allocations (boxing)

[Laurent Bourgès]

Hi Peter,

thanks for your microbench tool !
It works well and avoid me to do my own (caliper is a well known one)

I do not know what MethodHandle is but its performance is impressive !

Here are my results (Oracle jdk 1.7_13 vs OpenJDK 8 patched):

java -Xms8m -Xmx8m

JDK 1.7_13

run:
>> JVM START
#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =      1,75 ns/op (σ =   0,00 ns/op) [     1,75]
           1 threads, Tavg =      1,75 ns/op (σ =   0,00 ns/op) [     1,75]
# Measure:
           1 threads, Tavg =      1,80 ns/op (σ =   0,00 ns/op) [     1,80]
           2 threads, Tavg =      1,99 ns/op (σ =   0,01 ns/op) [
2,00,      1,98]


>> java.util.logging enabled

#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =     26,41 ns/op (σ =   0,00 ns/op) [    26,41]
           1 threads, Tavg =     25,86 ns/op (σ =   0,00 ns/op) [    25,86]
# Measure:
           1 threads, Tavg =     26,90 ns/op (σ =   0,00 ns/op) [    26,90]
           2 threads, Tavg =     30,07 ns/op (σ =   0,20 ns/op) [
30,27,     29,87]

<< JVM END
BUILD SUCCESSFUL (total time: 40 seconds)

jdk 1.8 patched

run:
>> JVM START
#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =      1,77 ns/op (σ =   0,00 ns/op) [     1,77]
           1 threads, Tavg =      1,77 ns/op (σ =   0,00 ns/op) [     1,77]
# Measure:
           1 threads, Tavg =      1,75 ns/op (σ =   0,00 ns/op) [     1,75]
           2 threads, Tavg =      2,01 ns/op (σ =   0,01 ns/op) [
2,00,      2,01]


>> java.util.logging enabled

#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =      7,64 ns/op (σ =   0,00 ns/op) [     7,64]
           1 threads, Tavg =      7,57 ns/op (σ =   0,00 ns/op) [     7,57]
# Measure:
           1 threads, Tavg =      7,62 ns/op (σ =   0,00 ns/op) [     7,62]
           2 threads, Tavg =      9,92 ns/op (σ =   0,58 ns/op) [
10,53,      9,37]

<< JVM END
BUILD SUCCESSFUL (total time: 40 seconds)


JUL started before PlatformLogger:

run:
mars 23, 2013 9:09:00 PM PlatformLoggerBenchmark <clinit>
Infos: JUL started
mars 23, 2013 9:09:00 PM PlatformLoggerBenchmark <clinit>
>> JVM START
Grave: PlatformLogger started
#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =      3,51 ns/op (σ =   0,00 ns/op) [     3,51]
           1 threads, Tavg =      3,49 ns/op (σ =   0,00 ns/op) [     3,49]
# Measure:
           1 threads, Tavg =      3,50 ns/op (σ =   0,00 ns/op) [     3,50]
           2 threads, Tavg =      3,83 ns/op (σ =   0,02 ns/op) [
3,82,      3,85]


>> java.util.logging enabled

#
# isLoggableFinest: run duration:  5 000 ms, #of logical CPUS: 4
#
# Warm up:
           1 threads, Tavg =      3,50 ns/op (σ =   0,00 ns/op) [     3,50]
           1 threads, Tavg =      3,50 ns/op (σ =   0,00 ns/op) [     3,50]
# Measure:
           1 threads, Tavg =      3,50 ns/op (σ =   0,00 ns/op) [     3,50]
           2 threads, Tavg =      3,90 ns/op (σ =   0,03 ns/op) [
3,87,      3,93]

<< JVM END
BUILD SUCCESSFUL (total time: 40 seconds)

I will test on OpenJDK8 (no patch) to see the impact on my machine (slower
than yours).

Laurent