ArrayIndexOutOfBoundsException during native image build

[wenqiglantz]

Hi, I am running into issue with my app (built on Boot 3.0.0-M5, Spring Cloud 2022.0.0-M4) during native image build phase (I used tracing agent to generate the config json files). Error details: https://github.com/wenqiglantz/spring-native-feign-reactive/actions/runs/3143616106/jobs/5108561598. Any advice on how to fix it is appreciated!

Steps to reproduce the issue

1. git clone https://github.com/wenqiglantz/spring-native-feign-reactive.git
2. mvn -ntp clean package -Pnative -e -X

Describe GraalVM and your environment:

• GraalVM version: GraalVM CE 22.2.0 (build 17.0.4+8-jvmci-22.2-b06, mixed mode, sharing)
• JDK major version: 17
• OS: ubuntu
• Architecture: [e.g.: AMD64]

OpenJDK 64-Bit Server VM GraalVM CE 22.2.0 (build 17.0.4+8-jvmci-22.2-b06, mixed mode, sharing)

More details
Stack trace, see below, also attaching screenshot from github actions workflow to build native image. For full native image build debugging details including the full stack trace, warning, etc, please refer to https://github.com/wenqiglantz/spring-native-feign-reactive/actions/runs/3143616106/jobs/5108561598.

[2/7] Performing analysis...  [*]                                                                       (36.5s @ 2.12GB)
   7,238 (86.93%) of  8,326 classes reachable
   9,314 (62.23%) of 14,966 fields reachable
  28,938 (79.49%) of 36,406 methods reachable
     826 classes,   230 fields, and     0 methods registered for reflection

------------------------------------------------------------------------------------------------------------------------
Fatal error: java.lang.ArrayIndexOutOfBoundsException: Index -1 out of bounds for length 1
	at java.base/java.lang.invoke.VarHandle$1.apply(VarHandle.java:2187)
	at java.base/java.lang.invoke.VarHandle$1.apply(VarHandle.java:2184)
	at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:177)
	at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:174)
	at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:62)
	at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
	at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:266)
	at java.base/java.lang.invoke.VarHandleReferences$Array.getVolatile(VarHandleReferences.java:602)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.heap.TypeData.getFieldValue(TypeData.java:83)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.heap.ImageHeapScanner.onFieldRead(ImageHeapScanner.java:116)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.meta.AnalysisField.registerAsAccessed(AnalysisField.java:268)
	at org.graalvm.nativeimage.builder/com.oracle.svm.reflect.hosted.ReflectionDataBuilder.registerTypesForField(ReflectionDataBuilder.java:446)
	at org.graalvm.nativeimage.builder/com.oracle.svm.reflect.hosted.ReflectionDataBuilder.processMethodMetadata(ReflectionDataBuilder.java:275)
	at org.graalvm.nativeimage.builder/com.oracle.svm.reflect.hosted.ReflectionDataBuilder.duringAnalysis(ReflectionDataBuilder.java:187)
	at org.graalvm.nativeimage.builder/com.oracle.svm.reflect.hosted.ReflectionFeature.duringAnalysis(ReflectionFeature.java:238)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.lambda$runPointsToAnalysis$10(NativeImageGenerator.java:734)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.FeatureHandler.forEachFeature(FeatureHandler.java:78)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.lambda$runPointsToAnalysis$11(NativeImageGenerator.java:734)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.PointsToAnalysis.runAnalysis(PointsToAnalysis.java:755)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:731)
                        2.1s (4.3% of total time) in 23 GCs | Peak RSS: 2.75GB | CPU load: 1.94
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:564)
========================================================================================================================
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:521)
Failed generating 'demo' after 48.8s.
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:407)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:585)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:128)
Error: Image build request failed with exit status 1

[wirthi]

Thanks for your report, we are looking into that.

Any chance you can provide a small reproducer?

[snicoll]

@wirthi there are steps to reproduce the issue in the description. Isn't that enough or are you looking for a minimal project that reproduces the problem?

[wirthi]

Hi,

sorry, missed that, asked for the reproducer out of a habit.

Christian

[wirthi]

(internally tracked as GR-41450)

[cstancu]

The error message is not very helpful, but what is happening is that we try to snapshot the value of an AnalysisField whose position field is not yet computed, it is -1. The field that is missing a position is DefaultFormattingConversionService.jsr354Present. If you look at the log carefully you can see that spring does some special processing for it: Field org.springframework.format.support.DefaultFormattingConversionService#jsr354Present set to false at build time.

In debug mode I can see that this field is represented as an org.springframework.aot.graalvm.ConstantReadableJavaField, which is a spring specific class that seems to implement field substition. It looks like there are two instances of ConstantReadableJavaField for the same java.lang.ReflectField, hence multiple AnalysisFields, and only one of them has the position set. The ConstantReadableJavaField objects are generated by the org.springframework.aot.graalvm.ConstantFieldSubstitutionProcessor which doesn't seem to do any caching. ConstantFieldSubstitutionProcessor.lookup() can be, and it is, called multiple times for the same field. This is a Spring bug. cc: @sdeleuze

I'll try to improve the error message to be more defensive against this type of errors.

[sdeleuze]

Thanks for the detailed feedback, I will implement per field caching on Spring side and let you know if that fixes the issue.

[sdeleuze]

Fixed via spring-projects/spring-framework#29250.

[cstancu]

@sdeleuze that's a step in the right direction but is not enough. The cache needs to be thread safe as the substitution mechanism can be invoked concurrently. You probably want to use a ConcurrentHashMap.