Throwing an Exception is 2.5 times slower on native-image

[SergejIsbrecht]

Describe the issue
During a benchmark I noticed high numbers for a slow path within our code. It uses Enum#valueOf, and if an Exception is thrown, something different will be done. I was intrigued and looked a little bit closer into this issue.

OpenJDK 17 amd64

Benchmark                                             Mode  Cnt     Score    Error   Units
FromStringBench.valueOf                               avgt    5     4.729 ±  0.234   ns/op
FromStringBench.valueOf:·gc.alloc.rate                avgt    5    ≈ 10⁻⁴           MB/sec
FromStringBench.valueOf:·gc.alloc.rate.norm           avgt    5    ≈ 10⁻⁷             B/op
FromStringBench.valueOf:·gc.count                     avgt    5       ≈ 0           counts
FromStringBench.valueOfException                      avgt    5  1195.178 ± 65.872   ns/op
FromStringBench.valueOfException:·gc.alloc.rate       avgt    5   766.129 ± 41.666  MB/sec
FromStringBench.valueOfException:·gc.alloc.rate.norm  avgt    5   960.000 ±  0.001    B/op
FromStringBench.valueOfException:·gc.count            avgt    5   129.000           counts
FromStringBench.valueOfException:·gc.time             avgt    5    84.000               ms

native-image JDK17 amd64

Benchmark                                        Mode  Cnt     Score    Error   Units
FromStringBench.valueOf                          avgt    5     7.475 ±  0.187   ns/op
FromStringBench.valueOf:·gc.alloc.rate           avgt    5       ≈ 0           MB/sec
FromStringBench.valueOf:·gc.count                avgt    5       ≈ 0           counts
FromStringBench.valueOfException                 avgt    5  2988.646 ± 23.550   ns/op
FromStringBench.valueOfException:·gc.alloc.rate  avgt    5       ≈ 0           MB/sec
FromStringBench.valueOfException:·gc.count       avgt    5   437.000           counts
FromStringBench.valueOfException:·gc.time        avgt    5   898.000               ms

(The OpenJDK 17 version on hotspot is 2.5 times faster than the native-image one for valueOfException)

Calling Enum#valueOf seems to be equally fast, but calling Enum#valueOf with a value not in the enumeration results in an Exception. To me, it looks like unwinding the stack is quite costly. See

According to taken flamegraph (-F 499; callgraph dwarf) 50% of time is spend in CodeInfoTable::lookupCodeInfoQueryResult. In absolute terms de-compression costs 37% (absolute) FrameInfoDecoder::decodeFrameInfo.

To me it looks like CompressedOops, but for Codeinformation. Am I right?

Steps to reproduce the issue
Please include both build steps as well as run steps

1. git clone https://github.com/SergejIsbrecht/Bench2.git
2. see README.md to build and run on OpenJDK and native-image

Describe GraalVM and your environment:

• GraalVM version GraalVM CE 23.1.0-dev-20230414_0206
• JDK major version: JDK17
• OS: Ubuntu 20.04 - 5.x
• Architecture: AMD64

More details

See build.gradke.kts -> graalvmNative for used native-image command line options:

            buildArgs.add("--verbose")
            buildArgs.add("--no-fallback")
            // buildArgs.add("-g")
            // buildArgs.add("-H:-DeleteLocalSymbols")
            buildArgs.add("-H:IncludeResources=.*/BenchmarkList")
            buildArgs.add("-H:Log=registerResource:verbose")
            buildArgs.add("--initialize-at-build-time=org.openjdk.jmh.infra,org.openjdk.jmh.util.Utils,org.openjdk.jmh.runner.InfraControl,org.openjdk.jmh.runner.InfraControlL0,org.openjdk.jmh.runner.InfraControlL1,org.openjdk.jmh.runner.InfraControlL2,org.openjdk.jmh.runner.InfraControlL3,org.openjdk.jmh.runner.InfraControlL4")
            buildArgs.add("-H:-SpawnIsolates")
            buildArgs.add("-H:+UseSerialGC")
            buildArgs.add("-H:InitialCollectionPolicy=BySpaceAndTime")
            buildArgs.add("-H:AlignedHeapChunkSize=524288")
            buildArgs.add("-H:+ReportExceptionStackTraces")
            buildArgs.add("--enable-monitoring=all")
            buildArgs.add("-J-Xmx20g")
            buildArgs.add("-march=native")

Resolution

Either improve the frame-info de-compression or provide the ability to build an native-image without compression. Am I right in the assumption, that not using some kind of pointer compression results in way bigger binaries?

[SergejIsbrecht]

According to the FlameGraph 6.25% (absolute) are spend in growing the ArrayList

class BuildStackTraceVisitor extends JavaStackFrameVisitor {
    private final boolean filterExceptions;
    final ArrayList<StackTraceElement> trace;
    final int limit;

    BuildStackTraceVisitor(boolean filterExceptions, int limit) {
        this.filterExceptions = filterExceptions;
        this.trace = new ArrayList<>();
        this.limit = limit;
    }

I do not know how big the limit is , but maybe we could init the ArrayList with a different size (10) than the default one. Maybe use limit to safe the array-copy, but this also could to lead to a slow path allocating it, if the TLAB threshold is exceeded.

[oubidar-Abderrahim]

Thank you for reporting this, it's tracked internally on GR 45871

[zapster]

Hi @SergejIsbrecht! Thanks for the report and for the benchmark. It came in just in time as we were already working on improving the performance of Throwable.fillInStackTrace, which is, as your analysis clearly shows, the root of the performance issue. The optimization was already merged with #6533 and should be included in the next release. Local benchmarking shows about 4x speed-up for valueOfException. Thanks again for your investigations.

[SergejIsbrecht]

Hi @zapster,

thank you for keeping me in the loop. Do I get it correctly, that instead of resolving each StackFrame information (FrameInfo) on fillInStackTrace, you just store all IPs. This reduces the work to be done, when an Exception is thrown. Resolving FrameInfos will be done, when for example the StackTrace is printed?

Are there any plans to improve the Performance of resolving the FrameInfos? In large applications on native-image Exception will be printed due to logging/ tracing. Therefore, it would be great to improve the performance of resolving the FrameInfos as well.

Anyhow, thank you for improving the default behavior of actually creating an Exception!

Are there any plans to port this to 23.0?

Update:

I did a quick bench for actually resolving an exception on OpenJDK 17 and native-image JDK17

  @Benchmark
  @OutputTimeUnit(TimeUnit.NANOSECONDS)
  @BenchmarkMode(Mode.AverageTime)
  public void valueOfException(Blackhole blackhole) throws Exception {
    EnumPrev value;
    try {
      value = EnumPrev.valueOf("ENUM^VALUE^1");
    } catch (Exception ex) {
      blackhole.consume(ex.getStackTrace());
      return;
    }
    blackhole.consume(value);
  }

And it seems native-image JDK17 is already way faster

OpenJDK 17

FromStringBench.valueOfException                      avgt    5  5701.232 ± 62.578   ns/op

native-image JDK17

FromStringBench.valueOfException                 avgt    5  3345.853 ± 227.313   ns/op

[zapster]

Do I get it correctly, that instead of resolving each StackFrame information (FrameInfo) on fillInStackTrace, you just store all IPs. This reduces the work to be done, when an Exception is thrown. Resolving FrameInfos will be done, when for example the StackTrace is printed?

Correct.

Are there any plans to improve the Performance of resolving the FrameInfos? In large applications on native-image Exception will be printed due to logging/ tracing. Therefore, it would be great to improve the performance of resolving the FrameInfos as well.

No concrete plans. Also not sure whether there is lot to gain in this area.

Are there any plans to port this to 23.0?

Unless there are compelling reasons, we usually do not backport features to older versions. Is there a reason why you would want to stick with 23.0?

And it seems native-image JDK17 is already way faster

Cool.

[SergejIsbrecht]

Unless there are compelling reasons, we usually do not backport features to older versions.

I would probably see it as a bug instead of a feature :)

Is there a reason why you would want to stick with 23.0?

We are targeting 23.0 for a release, therefore every improvement helps on hardware with limited resources. We do not experience a bottleneck with exceptions, but using less CPU cycles always helps the overall system. Therefore, we do not need it, but it would be a nice to have.

Thank you for looking into this issue and fixing it.