1

I was trying to process some text files approximately simulating a deterministic finite state automaton. This worked well but the performance was absolutely horrible.

I started investigating and found that the "code size" has a weird and very large effect on the performance. I created a dummy program to illustrate the effect. The following is acceptably fast on my computer (~0.250s):

package com.foo.bar;

import java.io.IOException;
import java.io.Reader;
import java.nio.file.Files;
import java.nio.file.Paths;

public class DummyFileProcessor {

    public static void main(String[] args) throws IOException {
        // `args[0]` is the path to the "citylots.json" file from here:
        // https://github.com/zemirco/sf-city-lots-json (181 MB).
        
        final long startTime = System.currentTimeMillis();
        
        final short stateAlwaysZero = 0; // always 0 in this demo
        
        try (Reader reader = Files.newBufferedReader(Paths.get(args[0]))) {
            final char[] chunk = new char[4096];
            
            for (int chunkLength = reader.read(chunk); chunkLength != -1; chunkLength = reader.read(chunk)) {
                for (int i = 0; i < chunkLength; ++i) {
                    final short triggerAlwaysZero = 0; // always 0 in this demo
                    
                    switch (stateAlwaysZero) {
                    case 0: {
                        switch (triggerAlwaysZero) {
                        case 0: { break; }
                        case 1: { break; }
                        case 2: { break; }
                        case 3: { break; }
                        case 4: { break; }
                        case 5: { break; }
                        case 6: { break; }
                        case 7: { break; }
                        case 8: { break; }
                        case 9: { break; }
                        case 10: { break; }
                        case 11: { break; }
                        case 12: { break; }
                        case 13: { break; }
                        case 14: { break; }
                        case 15: { break; }
                        case 16: { break; }
                        case 17: { break; }
                        case 18: { break; }
                        case 19: { break; }
                        case 20: { break; }
                        case 21: { break; }
                        case 22: { break; }
                        case 23: { break; }
                        case 24: { break; }
                        case 25: { break; }
                        case 26: { break; }
                        case 27: { break; }
                        case 28: { break; }
                        case 29: { break; }
                        }
                        break;
                    }
                    case 1: { break; }
                    case 2: { break; }
                    case 3: { break; }
                    case 4: { break; }
                    case 5: { break; }
                    case 6: { break; }
                    case 7: { break; }
                    case 8: { break; }
                    case 9: { break; }
                    case 10: { break; }
                    case 11: { break; }
                    case 12: { break; }
                    case 13: { break; }
                    case 14: { break; }
                    case 15: { break; }
                    case 16: { break; }
                    case 17: { break; }
                    case 18: { break; }
                    case 19: { break; }
                    case 20: { break; }
                    case 21: { break; }
                    case 22: { break; }
                    case 23: { break; }
                    case 24: { break; }
                    case 25: { break; }
                    case 26: { break; }
                    case 27: { break; }
                    case 28: { break; }
                    case 29: { break; }
                    case 30: { break; }
                    case 31: { break; }
                    case 32: { break; }
                    case 33: { break; }
                    case 34: { break; }
                    case 35: { break; }
                    case 36: { break; }
                    case 37: { break; }
                    case 38: { break; }
                    case 39: { break; }
                    }
                }
            }
        }
        
        final long endTime = System.currentTimeMillis();
        System.out.println("done after " + (((double) (endTime - startTime)) / 1000) + "s");
    }
}

Now I just copy the switch (triggerAlwaysZero) { ... } part into the other cases (1, 2, ...) of switch (stateAlwaysZero) (these cases are never chosen). This makes the code large but it does not have a big impact when done only to the cases 0 to 33. But when I also paste this switch (triggerAlwaysZero) { ... } part to case 34, the processing time suddenly jumps from around 0.250s to around 3.7 seconds.

Does anyone have an idea what is going on here?

$ java -version
openjdk version "11.0.9.1" 2020-11-04
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.9.1+1)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.9.1+1, mixed mode)
jonas
  • 637
  • 1
  • 7
  • 9
  • 4
    I think [this](https://stackoverflow.com/questions/15621083/why-does-java-switch-on-contiguous-ints-appear-to-run-faster-with-added-cases) answers your question. – fuggerjaki61 Feb 25 '21 at 09:49
  • 2
    Subtracting start time from end time in a single run does not provide valid benchmarking values. https://stackoverflow.com/questions/504103/how-do-i-write-a-correct-micro-benchmark-in-java/513259 – daniu Feb 25 '21 at 09:54
  • The way to investigate this properly is to rewrite the code as a valid microbenchmark. Then once you are sure that this is a real effect (and not an artifact of a bad benchmark), you can then get the JIT compiler to print the disassembled native code ... and look at what is really going on. – Stephen C Feb 25 '21 at 10:15
  • 1
    (My guess is that the nested switch has exceeded some threshold that is inhibiting the JIT compilers to detect and eliminate code that does nothing. And that implies that the effect doesn't matter, since you wouldn't write a switch statement with only empty cases in a real application.) – Stephen C Feb 25 '21 at 10:17
  • To simplify the testing / further benchmarks, replacing the file I/O with one loop over large amount will also show this behaviour. – DuncG Feb 25 '21 at 12:09
  • @fuggerjaki61 @StephenC Thanks for pointing me to the JIT. I see a change in the output of `java -XX:+PrintCompilation ...` and when I run the program with `java -XX:-DontCompileHugeMethods ...` it is fast again. The issue seems to be linked to the `HugeMethodLimit` of `8000` (bytes). – jonas Feb 25 '21 at 12:28

0 Answers0