0

I was playing around with a TreeMap and decided to do a simple performance test by comparing System.currentTimeMillis(). The results were quite unexpected: after some more testing I found out that a TreeMap with a Comparator took very long to be created. I have the following code:

public static void main(String[] args) {
    final long millis1 = System.currentTimeMillis();
    final TreeMap<Integer,Integer> natural = new TreeMap<>();
    final long millis2 = System.currentTimeMillis();
    System.out.println(millis2 - millis1);
    final TreeMap<Integer,Integer> compare = new TreeMap<>(Integer::compare);
    System.out.println(System.currentTimeMillis() - millis2);
}

Output:

0
114

Is this normal? Why does this happen?

Priv
  • 812
  • 2
  • 9
  • 23
  • 4
    You may want to look into microbench marking e.g. warming up the JVM. – Darren Forsythe Apr 15 '18 at 14:44
  • Interesting question. I checked the source code for `TreeMap`, and the constructor you are calling simply stores a reference to the customer comparator, and nothing more. I wonder if all collections with custom comparators would behave this way. – Tim Biegeleisen Apr 15 '18 at 14:46
  • Those milliseconds are probably once-only setup costs, and therefore mean nothing within a real application, where most of the time is spent executing certain bits of code over and over (and *those* are where the just-in-time compiler really tries to optimize the resulting code). Run-once code is not too interesting from a performance standpoint. – tucuxi Apr 15 '18 at 14:49
  • Try more times, such as create them in a loop `Integer.MAX_VALUE` times, I believe the results will be much closer. – xingbin Apr 15 '18 at 14:50
  • 1
    @TimBiegeleisen No they wouldn't, as what the OP sees has zero relation with the fact that a comparator was passed. The first time you do a call that creates a methodhandle, there's a lot of initialization and classloading going on. Which you can see in two ways: if you do `new TreeMap<>(Integer::compare)` twice, it takes as much time (in milliseconds) as doing it once. And also, if you replace `Integer::compare` with an anonymous Comparator implementation that does the same, it also takes less than a millisecond. And thirdly, the OP is measuring `System.out.println` as well. – Erwin Bolwidt Apr 15 '18 at 14:51
  • @ErwinBolwidt Boo. This ended badly. – Tim Biegeleisen Apr 15 '18 at 15:06
  • @TimBiegeleisen ? – Erwin Bolwidt Apr 15 '18 at 15:10
  • @ErwinBolwidt I did a test before where I didn't measure `System.out.println` which gave me the same result. – Priv Apr 15 '18 at 16:03
  • I just found out creating a second `TreeMap` with a `Comparator` just takes one millisecond. Despite that I still do not understand why the first thing I am doing takes zero ms while I am still initializing a `TreeMap`. – Priv Apr 15 '18 at 16:07
  • @Priv You're not getting it. Java starts very slowly as it 1. loads all the needed classes, 2. first interprets the bytecode and gather some performance stats, 3. then compiles the critical parts and gathers more stats, 4. then compiles the most critical parts again with heavy optimizations, 5. the initial processing of lamdas and method references is especially heavy. `+++` Java is designed for long-running processes, anything below one second is meaningless. `+++` The phases from my above description overlap, new classes can be loaded anytime, code gets interpreted and compiled all the time. – maaartinus Apr 15 '18 at 22:13
  • 1
    @Priv It's not the comparator, it's the `Integer::compare` method reference which requires the initialization of the complicated method handle machinery. Read the comment by Erwin Bolwidt, especially the "anonymous Comparator" part. – maaartinus Apr 15 '18 at 22:16

0 Answers0