Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[quarkus-integration-test-jaxb] and others fail with GraalVM master (GraalVM for JDK 22) #37657

Closed
jerboaa opened this issue Dec 11, 2023 · 22 comments
Labels

Comments

@jerboaa
Copy link
Contributor

jerboaa commented Dec 11, 2023

Describe the bug

We see some native integration tests failing in our CI. For example IT main, jaxb or spring-web. All of them have a NPE in common:

Exception java.lang.NullPointerException [in thread "main"]
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.getRecognizedProperties(XMLDocumentFragmentScannerImpl.java:764)
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.getRecognizedProperties(XMLDocumentScannerImpl.java:449)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addRecognizedParamsAndSetDefaults(XML11Configuration.java:1518)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addComponent(XML11Configuration.java:1462)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.<init>(XML11Configuration.java:612)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:136)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:93)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.SAXParser.<init>(SAXParser.java:121)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.<init>(SAXParserImpl.java:405)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:137)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:124)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.newSAXParserImpl(SAXParserFactoryImpl.java:104)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.setFeature(SAXParserFactoryImpl.java:144)
	at java.xml/javax.xml.catalog.CatalogImpl.getParser(CatalogImpl.java:312)
	at java.xml/javax.xml.catalog.CatalogImpl.parse(CatalogImpl.java:290)
	at java.xml/javax.xml.catalog.CatalogImpl.load(CatalogImpl.java:171)
	at java.xml/javax.xml.catalog.CatalogManager.catalog(CatalogManager.java:73)
	at java.xml/jdk.xml.internal.JdkCatalog.init(JdkCatalog.java:43)
	at java.xml/jdk.xml.internal.XMLSecurityManager.prepareCatalog(XMLSecurityManager.java:305)
	at java.xml/jdk.xml.internal.XMLSecurityManager.<init>(XMLSecurityManager.java:290)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.<init>(SAXParserFactoryImpl.java:72)
	at java.xml/jdk.xml.internal.JdkXmlUtils.getSAXFactory(JdkXmlUtils.java:441)
	at java.xml/jdk.xml.internal.JdkXmlUtils.<clinit>(JdkXmlUtils.java:97)
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.<clinit>(XMLDocumentFragmentScannerImpl.java:193)
	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized0(Native Method)
	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized(Unsafe.java:1160)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.ensureClassInitialized(ClassInitializationSupport.java:177)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:191)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:160)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:160)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:129)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:161)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:150)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.SVMHost.isInitialized(SVMHost.java:323)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.meta.AnalysisType.isInitialized(AnalysisType.java:920)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.maybeEagerlyInitialize(BytecodeParser.java:4488)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4694)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4683)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4678)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.processBytecode(BytecodeParser.java:5488)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.iterateBytecodesForBlock(BytecodeParser.java:3470)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.iterateBytecodesForBlock(SharedGraphBuilderPhase.java:790)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.handleBytecodeBlock(BytecodeParser.java:3430)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.processBlock(BytecodeParser.java:3272)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.build(BytecodeParser.java:1136)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.build(SharedGraphBuilderPhase.java:202)
	at jdk.graal.compiler/jdk.graal.compiler.java.BytecodeParser.buildRootMethod(BytecodeParser.java:1028)
	at jdk.graal.compiler/jdk.graal.compiler.java.GraphBuilderPhase$Instance.run(GraphBuilderPhase.java:102)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.phases.SharedGraphBuilderPhase.run(SharedGraphBuilderPhase.java:154)
	at jdk.graal.compiler/jdk.graal.compiler.phases.Phase.run(Phase.java:49)
	at jdk.graal.compiler/jdk.graal.compiler.phases.BasePhase.apply(BasePhase.java:435)
	at jdk.graal.compiler/jdk.graal.compiler.phases.Phase.apply(Phase.java:42)
	at jdk.graal.compiler/jdk.graal.compiler.phases.Phase.apply(Phase.java:38)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.AnalysisParsedGraph.parseBytecode(AnalysisParsedGraph.java:144)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.meta.AnalysisMethod.parseGraph(AnalysisMethod.java:888)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsedHelper(AnalysisMethod.java:853)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsed(AnalysisMethod.java:836)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.lookupEncodedGraph(InlineBeforeAnalysisGraphDecoder.java:175)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.doInline(PEGraphDecoder.java:1215)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.tryInline(PEGraphDecoder.java:1198)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.trySimplifyInvoke(PEGraphDecoder.java:1053)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.handleInvokeWithCallTarget(PEGraphDecoder.java:1005)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.handleInvoke(PEGraphDecoder.java:991)
	at jdk.graal.compiler/jdk.graal.compiler.nodes.GraphDecoder.processNextNode(GraphDecoder.java:930)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.processNextNode(InlineBeforeAnalysisGraphDecoder.java:343)
	at jdk.graal.compiler/jdk.graal.compiler.nodes.GraphDecoder.decode(GraphDecoder.java:658)
	at jdk.graal.compiler/jdk.graal.compiler.replacements.PEGraphDecoder.decode(PEGraphDecoder.java:895)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.phases.InlineBeforeAnalysis.decodeGraph(InlineBeforeAnalysis.java:73)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.parse(MethodTypeFlowBuilder.java:198)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.apply(MethodTypeFlowBuilder.java:608)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.MethodTypeFlow.createFlowsGraph(MethodTypeFlow.java:167)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.MethodTypeFlow.ensureFlowsGraphCreated(MethodTypeFlow.java:152)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.MethodTypeFlow.getOrCreateMethodFlowsGraphInfo(MethodTypeFlow.java:110)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.typestate.DefaultVirtualInvokeTypeFlow.onObservedUpdate(DefaultVirtualInvokeTypeFlow.java:114)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.flow.TypeFlow.update(TypeFlow.java:628)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.PointsToAnalysis$1.run(PointsToAnalysis.java:538)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.util.CompletionExecutor.executeCommand(CompletionExecutor.java:169)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.util.CompletionExecutor.lambda$executeService$0(CompletionExecutor.java:154)
	at java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1726)
	at java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1717)
	at java.base/java.util.concurrent.ForkJoinTask$InterruptibleTask.exec(ForkJoinTask.java:1641)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:507)
	at java.base/java.util.concurrent.ForkJoinPool.externalHelpQuiesce(ForkJoinPool.java:2519)
	at java.base/java.util.concurrent.ForkJoinPool.helpQuiescePool(ForkJoinPool.java:2553)
	at java.base/java.util.concurrent.ForkJoinPool.awaitQuiescence(ForkJoinPool.java:3784)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.util.CompletionExecutor.complete(CompletionExecutor.java:210)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.PointsToAnalysis.doTypeflow(PointsToAnalysis.java:576)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.PointsToAnalysis.finish(PointsToAnalysis.java:564)
	at org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.AbstractAnalysisEngine.runAnalysis(AbstractAnalysisEngine.java:153)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:795)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:573)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:538)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:524)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:699)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.start(NativeImageGeneratorRunner.java:139)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:94)

See: https://github.com/graalvm/mandrel/actions/runs/7154825726/job/19483074935#step:12:1688

In some cases it looks like this:

java.lang.NullPointerException: Cannot invoke "[Ljava.lang.String;.clone()" because "com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.RECOGNIZED_PROPERTIES" is null
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.getRecognizedProperties(XMLDocumentFragmentScannerImpl.java:764)
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.getRecognizedProperties(XMLDocumentScannerImpl.java:449)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addRecognizedParamsAndSetDefaults(XML11Configuration.java:1518)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addComponent(XML11Configuration.java:1462)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.<init>(XML11Configuration.java:612)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:136)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:93)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.SAXParser.<init>(SAXParser.java:121)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.<init>(SAXParserImpl.java:405)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:137)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:124)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.newSAXParserImpl(SAXParserFactoryImpl.java:104)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.setFeature(SAXParserFactoryImpl.java:144)
	at java.xml/javax.xml.catalog.CatalogImpl.getParser(CatalogImpl.java:312)
	at java.xml/javax.xml.catalog.CatalogImpl.parse(CatalogImpl.java:290)
	at java.xml/javax.xml.catalog.CatalogImpl.load(CatalogImpl.java:171)
	at java.xml/javax.xml.catalog.CatalogManager.catalog(CatalogManager.java:73)
	at java.xml/jdk.xml.internal.JdkCatalog.init(JdkCatalog.java:43)
	at java.xml/jdk.xml.internal.XMLSecurityManager.prepareCatalog(XMLSecurityManager.java:305)
	at java.xml/jdk.xml.internal.XMLSecurityManager.<init>(XMLSecurityManager.java:290)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.<init>(SAXParserFactoryImpl.java:72)
	at java.xml/jdk.xml.internal.JdkXmlUtils.getSAXFactory(JdkXmlUtils.java:441)
	at java.xml/jdk.xml.internal.JdkXmlUtils.<clinit>(JdkXmlUtils.java:97)

See: https://github.com/graalvm/mandrel/actions/runs/7161773572/job/19498392690#step:12:2306

@jerboaa jerboaa added the kind/bug Something isn't working label Dec 11, 2023
Copy link

quarkus-bot bot commented Dec 11, 2023

/cc @Karm (mandrel), @galderz (mandrel), @gsmet (jaxb), @zakkak (mandrel)

@zakkak
Copy link
Contributor

zakkak commented Dec 13, 2023

Looking at the stack trace it looks like there is a circular dependency.

While initializing XMLDocumentFragmentScannerImpl the initialization of JdkXmlUtils is triggered, which then leads to the invocation of
XMLDocumentFragmentScannerImpl.getRecognizedProperties which reads the not yet initialized RECOGNIZED_PROPERTIES:

Caused by: java.lang.ExceptionInInitializerError
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.<clinit>(XMLDocumentFragmentScannerImpl.java:193)
	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized0(Native Method)
	at java.base/jdk.internal.misc.Unsafe.ensureClassInitialized(Unsafe.java:1160)
	at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.ensureClassInitialized(ClassInitializationSupport.java:177)
	... 59 more
Caused by: java.lang.NullPointerException: Cannot invoke "[Ljava.lang.String;.clone()" because "com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.RECOGNIZED_PROPERTIES" is null
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.getRecognizedProperties(XMLDocumentFragmentScannerImpl.java:764)
	at java.xml/com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.getRecognizedProperties(XMLDocumentScannerImpl.java:449)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addRecognizedParamsAndSetDefaults(XML11Configuration.java:1518)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.addComponent(XML11Configuration.java:1462)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XML11Configuration.<init>(XML11Configuration.java:612)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:136)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:93)
	at java.xml/com.sun.org.apache.xerces.internal.parsers.SAXParser.<init>(SAXParser.java:121)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.<init>(SAXParserImpl.java:405)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:137)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:124)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.newSAXParserImpl(SAXParserFactoryImpl.java:104)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.setFeature(SAXParserFactoryImpl.java:144)
	at java.xml/javax.xml.catalog.CatalogImpl.getParser(CatalogImpl.java:312)
	at java.xml/javax.xml.catalog.CatalogImpl.parse(CatalogImpl.java:290)
	at java.xml/javax.xml.catalog.CatalogImpl.load(CatalogImpl.java:171)
	at java.xml/javax.xml.catalog.CatalogManager.catalog(CatalogManager.java:73)
	at java.xml/jdk.xml.internal.JdkCatalog.init(JdkCatalog.java:43)
	at java.xml/jdk.xml.internal.XMLSecurityManager.prepareCatalog(XMLSecurityManager.java:305)
	at java.xml/jdk.xml.internal.XMLSecurityManager.<init>(XMLSecurityManager.java:290)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.<init>(SAXParserFactoryImpl.java:72)
	at java.xml/jdk.xml.internal.JdkXmlUtils.getSAXFactory(JdkXmlUtils.java:441)
	at java.xml/jdk.xml.internal.JdkXmlUtils.<clinit>(JdkXmlUtils.java:97)

@jerboaa this looks like an OpenJDK issue to me introduced by https://bugs.openjdk.org/browse/JDK-8306055 (openjdk/jdk@93bdc2a) in JDK 22+26. Could you please create an issue in the OpenJDK project to track it?

Reproducer without Mandrel, Quarkus etc.:

❯ ~/jvms/jdk-22+26/bin/jshell --add-exports java.xml/com.sun.org.apache.xerces.internal.impl=ALL-UNNAMED 
|  Welcome to JShell -- Version 22-beta
|  For an introduction type: /help intro

jshell> var scanner = new com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl()
|  Exception java.lang.ExceptionInInitializerError
|        at XMLDocumentFragmentScannerImpl.<clinit> (XMLDocumentFragmentScannerImpl.java:193)
|        at do_it$Aux (#1:1)
|        at (#1:1)
|  Caused by: java.lang.NullPointerException: Cannot invoke "[Ljava.lang.String;.clone()" because "com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.RECOGNIZED_PROPERTIES" is null
|        at XMLDocumentFragmentScannerImpl.getRecognizedProperties (XMLDocumentFragmentScannerImpl.java:764)
|        at XMLDocumentScannerImpl.getRecognizedProperties (XMLDocumentScannerImpl.java:449)
|        at XML11Configuration.addRecognizedParamsAndSetDefaults (XML11Configuration.java:1518)
|        at XML11Configuration.addComponent (XML11Configuration.java:1462)
|        at XML11Configuration.<init> (XML11Configuration.java:612)
|        at XIncludeAwareParserConfiguration.<init> (XIncludeAwareParserConfiguration.java:136)
|        at XIncludeAwareParserConfiguration.<init> (XIncludeAwareParserConfiguration.java:93)
|        at SAXParser.<init> (SAXParser.java:121)
|        at SAXParserImpl$JAXPSAXParser.<init> (SAXParserImpl.java:405)
|        at SAXParserImpl.<init> (SAXParserImpl.java:137)
|        at SAXParserImpl.<init> (SAXParserImpl.java:124)
|        at SAXParserFactoryImpl.newSAXParserImpl (SAXParserFactoryImpl.java:104)
|        at SAXParserFactoryImpl.setFeature (SAXParserFactoryImpl.java:144)
|        at CatalogImpl.getParser (CatalogImpl.java:312)
|        at CatalogImpl.parse (CatalogImpl.java:290)
|        at CatalogImpl.load (CatalogImpl.java:171)
|        at CatalogManager.catalog (CatalogManager.java:73)
|        at JdkCatalog.init (JdkCatalog.java:43)
|        at XMLSecurityManager.prepareCatalog (XMLSecurityManager.java:305)
|        at XMLSecurityManager.<init> (XMLSecurityManager.java:290)
|        at SAXParserFactoryImpl.<init> (SAXParserFactoryImpl.java:72)
|        at JdkXmlUtils.getSAXFactory (JdkXmlUtils.java:441)
|        at JdkXmlUtils.<clinit> (JdkXmlUtils.java:97)
|        ...

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 13, 2023

@zakkak Thanks for taking a look. I'll do some more investigation and create an upstream OpenJDK issue once confirmed.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 14, 2023

@zakkak This seems to be an issue with class init order. When I force initialization of JdkXmlUtils first and use XMLDocumentFragmentScannerImpl later it works.

$ /disk/openjdk/builds/jdk-22+26/bin/jshell --add-exports java.xml/com.sun.org.apache.xerces.internal.impl=ALL-UNNAMED --add-exports java.xml/jdk.xml.internal
|  Welcome to JShell -- Version 22-beta
|  For an introduction type: /help intro

jshell> jdk.xml.internal.JdkXmlUtils.CATALOG_RESOLVE
$1 ==> "javax.xml.catalog.resolve"

jshell> var scanner = new com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl()
scanner ==> com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl@71dac704

jshell> 

I'm mentioning this, because something like that is hard to reproduce using only supported java xml APIs. So I wonder if graalvm should enforce this init order as well.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 15, 2023

Since this seems a class load ordering issue I'd prefer we fix that on the Quarkus/Mandrel side.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 15, 2023

FWIW, this program also loads the affected XMLDocumentFragmentScannerImpl class, but after JdkXmlUtils is being loaded.

$ ./mandrelvm/bin/java --version
openjdk 22-beta 2024-03-19
OpenJDK Runtime Environment Temurin-22+26-202312041405 (build 22-beta+26-ea)
OpenJDK 64-Bit Server VM Temurin-22+26-202312041405 (build 22-beta+26-ea, mixed mode, sharing)
$ cat TestXML.java 
import java.nio.file.Path;
import java.nio.file.Files;
import javax.xml.parsers.DocumentBuilderFactory;
import org.w3c.dom.Document;

public class TestXML {
    public static void main(String[] args) throws Exception {
        var xmlPath = Path.of(args[0]);
        var dbf = DocumentBuilderFactory.newInstance();
        var db = dbf.newDocumentBuilder();
        Document doc;
        try (var is = Files.newInputStream(xmlPath)) {
            doc = db.parse(is);
        }
    }
}
$ cat ./demo-xslt-native/test.xml
<point>
<x>1</x>
<y>y</y>
</point>
$ ./mandrelvm/bin/java -Xlog:class+load=info TestXML ./demo-xslt-native/test.xml  | grep -E 'com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl|JdkXmlUtils'
[0.047s][info][class,load] jdk.xml.internal.JdkXmlUtils source: jrt:/java.xml
[0.056s][info][class,load] com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl source: jrt:/java.xml
[0.057s][info][class,load] com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$ElementStack source: jrt:/java.xml
[0.057s][info][class,load] com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$ElementStack2 source: jrt:/java.xml
[0.057s][info][class,load] com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$Driver source: jrt:/java.xml
[0.057s][info][class,load] com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl$FragmentContentDriver source: jrt:/java.xml

@zakkak
Copy link
Contributor

zakkak commented Dec 15, 2023

Since this seems a class load ordering issue I'd prefer we fix that on the Quarkus/Mandrel side.

Sure, I started looking at how/why this happens in Mandrel/GraalVM, but didn't have the time to complete the analysis. I hope I will be able to get to it tonight.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 15, 2023

Since this seems a class load ordering issue I'd prefer we fix that on the Quarkus/Mandrel side.

Sure, I started looking at how/why this happens in Mandrel/GraalVM, but didn't have the time to complete the analysis. I hope I will be able to get to it tonight.

Same here. I keep looking as I failed to reliably reproduce yet. Will keep you posted should I find anything.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 15, 2023

FWIW, the case we seem to be running into here is described in this piece of code of ProvenSafeClassInitializationSupport:

           /*
             * Unfortunately, the computation of canInitializeWithoutSideEffects is not completely
             * deterministic: Consider a class A whose class initializer depends on class B. Assume
             * class B has no other dependencies and can therefore be initialized at build time.
             * When class A is analyzed after class B has been initialized, it can also be
             * initialized at build time. But when class A is analyzed before class B has been
             * initialized, it cannot. Since two threads can analyze class A at the same time (there
             * is no per-class locking) and another thread can initialize B at the same time, we can
             * have a conflicting initialization status. In that case, BUILD_TIME must win over
             * RUN_TIME because one thread has already initialized class A.
             */

See: https://github.com/oracle/graal/blob/a43123982961881e39ebc82321639ba2119f500c/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/classinitialization/ProvenSafeClassInitializationSupport.java#L352-L362

It's the non-determinism of class loading order and inline-before-analysis which seems to make this issue difficult to reproduce reliably. One needs to have the following condition satisfied:

InlineBeforeAnalysis encounters bytecode for XMLDocumentFragmentScannerImpl before any thread that loads JdkXmlUtils.

So far I haven't seen it happening locally for any of the mentioned tests and the same mandrel build as produced from that CI build.

@zakkak
Copy link
Contributor

zakkak commented Dec 15, 2023

So far I haven't seen it happening locally for any of the mentioned tests and the same mandrel build as produced from that CI build.

FWIW I have had the "luck" to reproduce it, not in the debugger though.

It looks like the GraalVM team has done some work to deal with JDK-8306055 in the JDK 22+26 version bump ( 🤦 should have seen this earlier), trying to understand whether that's what's causing the issue.

Update: When the issue happens the work-around in oracle/graal@2a8653f does not trigger (so it can't be the one causing the issue). Does this mean that there is some other path we need to work-around in a similar manner? Looking...

Update 2: Although I have still not managed to reproduce the NPE in the debugger I have managed to get it to freeze in the following state.

Thread A (initialization triggered by registration of com.sun.org.apache.xerces.internal.impl.PropertyManager.<init>(int) for reflection):

"ForkJoinPool.commonPool-worker-16@3199" tid=0x45 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	 blocks ForkJoinPool.commonPool-worker-1@3147
	  at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.<init>(XML11Configuration.java:610)
	  at com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:136)
	  at com.sun.org.apache.xerces.internal.parsers.XIncludeAwareParserConfiguration.<init>(XIncludeAwareParserConfiguration.java:93)
	  at com.sun.org.apache.xerces.internal.parsers.SAXParser.<init>(SAXParser.java:121)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.<init>(SAXParserImpl.java:405)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:137)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.<init>(SAXParserImpl.java:124)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.newSAXParserImpl(SAXParserFactoryImpl.java:104)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.setFeature(SAXParserFactoryImpl.java:144)
	  at javax.xml.catalog.CatalogImpl.getParser(CatalogImpl.java:312)
	  at javax.xml.catalog.CatalogImpl.parse(CatalogImpl.java:290)
	  at javax.xml.catalog.CatalogImpl.load(CatalogImpl.java:171)
	  at javax.xml.catalog.CatalogManager.catalog(CatalogManager.java:73)
	  at jdk.xml.internal.JdkCatalog.init(JdkCatalog.java:43)
	  at jdk.xml.internal.XMLSecurityManager.prepareCatalog(XMLSecurityManager.java:305)
	  - locked <0x74fb> (a java.lang.Object)
	  at jdk.xml.internal.XMLSecurityManager.<init>(XMLSecurityManager.java:290)
	  at com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl.<init>(SAXParserFactoryImpl.java:72)
	  at jdk.xml.internal.JdkXmlUtils.getSAXFactory(JdkXmlUtils.java:441)
	  at jdk.xml.internal.JdkXmlUtils.<clinit>(JdkXmlUtils.java:97)
	  at jdk.internal.misc.Unsafe.ensureClassInitialized0(Unsafe.java:-1)
	  at jdk.internal.misc.Unsafe.ensureClassInitialized(Unsafe.java:1160)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.ensureClassInitialized(ClassInitializationSupport.java:177)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:191)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:129)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:161)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:150)
	  at com.oracle.svm.hosted.SVMHost.onTypeReachable(SVMHost.java:315)
	  at com.oracle.graal.pointsto.meta.AnalysisUniverse.onTypeReachable(AnalysisUniverse.java:735)
	  at com.oracle.graal.pointsto.meta.AnalysisType.lambda$new$0(AnalysisType.java:318)
	  at com.oracle.graal.pointsto.meta.AnalysisType$$Lambda/0x000000000f2de9e0.run(Unknown Source:-1)
	  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	  at java.util.concurrent.FutureTask.run(FutureTask.java:317)
	  at com.oracle.graal.pointsto.util.AnalysisFuture.ensureDone(AnalysisFuture.java:69)
	  at com.oracle.graal.pointsto.meta.AnalysisType.ensureOnTypeReachableTaskDone(AnalysisType.java:705)
	  at com.oracle.graal.pointsto.meta.AnalysisType.onReachable(AnalysisType.java:599)
	  at com.oracle.graal.pointsto.meta.AnalysisType$$Lambda/0x000000000f2df270.run(Unknown Source:-1)
	  at com.oracle.graal.pointsto.util.AtomicUtils.atomicSetAndRun(AtomicUtils.java:49)
	  at com.oracle.graal.pointsto.meta.AnalysisType.lambda$registerAsReachable$8(AnalysisType.java:571)
	  at com.oracle.graal.pointsto.meta.AnalysisType$$Lambda/0x000000000f2df040.accept(Unknown Source:-1)
	  at com.oracle.graal.pointsto.meta.AnalysisType.forAllSuperTypes(AnalysisType.java:685)
	  at com.oracle.graal.pointsto.meta.AnalysisType.forAllSuperTypes(AnalysisType.java:668)
	  at com.oracle.graal.pointsto.meta.AnalysisType.forAllSuperTypes(AnalysisType.java:664)
	  at com.oracle.graal.pointsto.meta.AnalysisType.registerAsReachable(AnalysisType.java:571)
	  at com.oracle.graal.pointsto.meta.AnalysisUniverse.lookupAllowUnresolved(AnalysisUniverse.java:370)
	  at com.oracle.graal.pointsto.infrastructure.AnalysisConstantPool.lookupField(AnalysisConstantPool.java:42)
	  at jdk.graal.compiler.java.BytecodeParser.lookupField(BytecodeParser.java:4408)
	  at jdk.graal.compiler.java.BytecodeParser.genGetStatic(BytecodeParser.java:4968)
	  at jdk.graal.compiler.java.BytecodeParser.processBytecode(BytecodeParser.java:5479)
	  at jdk.graal.compiler.java.BytecodeParser.iterateBytecodesForBlock(BytecodeParser.java:3470)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.iterateBytecodesForBlock(SharedGraphBuilderPhase.java:790)
	  at jdk.graal.compiler.java.BytecodeParser.handleBytecodeBlock(BytecodeParser.java:3430)
	  at jdk.graal.compiler.java.BytecodeParser.processBlock(BytecodeParser.java:3272)
	  at jdk.graal.compiler.java.BytecodeParser.build(BytecodeParser.java:1136)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.build(SharedGraphBuilderPhase.java:202)
	  at jdk.graal.compiler.java.BytecodeParser.buildRootMethod(BytecodeParser.java:1028)
	  at jdk.graal.compiler.java.GraphBuilderPhase$Instance.run(GraphBuilderPhase.java:102)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase.run(SharedGraphBuilderPhase.java:154)
	  at jdk.graal.compiler.phases.Phase.run(Phase.java:49)
	  at jdk.graal.compiler.phases.BasePhase.apply(BasePhase.java:435)
	  at jdk.graal.compiler.phases.Phase.apply(Phase.java:42)
	  at jdk.graal.compiler.phases.Phase.apply(Phase.java:38)
	  at com.oracle.graal.pointsto.flow.AnalysisParsedGraph.parseBytecode(AnalysisParsedGraph.java:144)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.parseGraph(AnalysisMethod.java:888)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsedHelper(AnalysisMethod.java:853)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsed(AnalysisMethod.java:836)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.lookupEncodedGraph(InlineBeforeAnalysisGraphDecoder.java:175)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.doInline(PEGraphDecoder.java:1215)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.tryInline(PEGraphDecoder.java:1198)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.trySimplifyInvoke(PEGraphDecoder.java:1053)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.handleInvokeWithCallTarget(PEGraphDecoder.java:1005)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.handleInvoke(PEGraphDecoder.java:991)
	  at jdk.graal.compiler.nodes.GraphDecoder.processNextNode(GraphDecoder.java:930)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.processNextNode(InlineBeforeAnalysisGraphDecoder.java:343)
	  at jdk.graal.compiler.nodes.GraphDecoder.decode(GraphDecoder.java:658)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.decode(PEGraphDecoder.java:895)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysis.decodeGraph(InlineBeforeAnalysis.java:73)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.parse(MethodTypeFlowBuilder.java:198)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.apply(MethodTypeFlowBuilder.java:608)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.createFlowsGraph(MethodTypeFlow.java:167)
	  - locked <0x74ca> (a com.oracle.graal.pointsto.flow.MethodTypeFlow)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.ensureFlowsGraphCreated(MethodTypeFlow.java:152)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.getOrCreateMethodFlowsGraphInfo(MethodTypeFlow.java:110)
	  at com.oracle.graal.pointsto.typestate.DefaultSpecialInvokeTypeFlow.lambda$onObservedUpdate$0(DefaultSpecialInvokeTypeFlow.java:88)
	  at com.oracle.graal.pointsto.typestate.DefaultSpecialInvokeTypeFlow$$Lambda/0x000000000f497a70.accept(Unknown Source:-1)
	  at com.oracle.graal.pointsto.util.LightImmutableCollection.forEach(LightImmutableCollection.java:90)
	  at com.oracle.graal.pointsto.typestate.DefaultSpecialInvokeTypeFlow.onObservedUpdate(DefaultSpecialInvokeTypeFlow.java:87)
	  at com.oracle.graal.pointsto.flow.TypeFlow.update(TypeFlow.java:628)
	  at com.oracle.graal.pointsto.PointsToAnalysis$1.run(PointsToAnalysis.java:538)
	  at com.oracle.graal.pointsto.util.CompletionExecutor.executeCommand(CompletionExecutor.java:169)
	  at com.oracle.graal.pointsto.util.CompletionExecutor.lambda$executeService$0(CompletionExecutor.java:154)
	  at com.oracle.graal.pointsto.util.CompletionExecutor$$Lambda/0x000000000f41bcf0.run(Unknown Source:-1)
	  at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1726)
	  at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1717)
	  at java.util.concurrent.ForkJoinTask$InterruptibleTask.exec(ForkJoinTask.java:1641)
	  at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:507)
	  at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1491)
	  at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:2073)
	  at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2035)
	  at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)

Thread B (initialization also triggered by the registration of com.sun.xml.internal.stream.XMLInputFactoryImpl.createXMLStreamReader(javax.xml.transform.Source) for reflection)

"ForkJoinPool.commonPool-worker-23@3299" tid=0x4c nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	 blocks ForkJoinPool.commonPool-worker-4@3152
	 blocks ForkJoinPool.commonPool-worker-24@3306
	  at com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl.<clinit>(XMLDocumentFragmentScannerImpl.java:193)
	  at jdk.internal.misc.Unsafe.ensureClassInitialized0(Unsafe.java:-1)
	  at jdk.internal.misc.Unsafe.ensureClassInitialized(Unsafe.java:1160)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.ensureClassInitialized(ClassInitializationSupport.java:177)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:191)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:160)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:160)
	  at com.oracle.svm.hosted.classinitialization.AllowAllHostedUsagesClassInitializationSupport.computeInitKindAndMaybeInitializeClass(AllowAllHostedUsagesClassInitializationSupport.java:129)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:161)
	  at com.oracle.svm.hosted.classinitialization.ClassInitializationSupport.maybeInitializeAtBuildTime(ClassInitializationSupport.java:150)
	  at com.oracle.svm.hosted.SVMHost.isInitialized(SVMHost.java:323)
	  at com.oracle.graal.pointsto.meta.AnalysisType.isInitialized(AnalysisType.java:920)
	  at jdk.graal.compiler.java.BytecodeParser.maybeEagerlyInitialize(BytecodeParser.java:4488)
	  at jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4694)
	  at jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4683)
	  at jdk.graal.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4678)
	  at jdk.graal.compiler.java.BytecodeParser.processBytecode(BytecodeParser.java:5488)
	  at jdk.graal.compiler.java.BytecodeParser.iterateBytecodesForBlock(BytecodeParser.java:3470)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.iterateBytecodesForBlock(SharedGraphBuilderPhase.java:790)
	  at jdk.graal.compiler.java.BytecodeParser.handleBytecodeBlock(BytecodeParser.java:3430)
	  at jdk.graal.compiler.java.BytecodeParser.processBlock(BytecodeParser.java:3272)
	  at jdk.graal.compiler.java.BytecodeParser.build(BytecodeParser.java:1136)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase$SharedBytecodeParser.build(SharedGraphBuilderPhase.java:202)
	  at jdk.graal.compiler.java.BytecodeParser.buildRootMethod(BytecodeParser.java:1028)
	  at jdk.graal.compiler.java.GraphBuilderPhase$Instance.run(GraphBuilderPhase.java:102)
	  at com.oracle.svm.hosted.phases.SharedGraphBuilderPhase.run(SharedGraphBuilderPhase.java:154)
	  at jdk.graal.compiler.phases.Phase.run(Phase.java:49)
	  at jdk.graal.compiler.phases.BasePhase.apply(BasePhase.java:435)
	  at jdk.graal.compiler.phases.Phase.apply(Phase.java:42)
	  at jdk.graal.compiler.phases.Phase.apply(Phase.java:38)
	  at com.oracle.graal.pointsto.flow.AnalysisParsedGraph.parseBytecode(AnalysisParsedGraph.java:144)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.parseGraph(AnalysisMethod.java:888)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsedHelper(AnalysisMethod.java:853)
	  at com.oracle.graal.pointsto.meta.AnalysisMethod.ensureGraphParsed(AnalysisMethod.java:836)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.lookupEncodedGraph(InlineBeforeAnalysisGraphDecoder.java:175)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.doInline(PEGraphDecoder.java:1215)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.tryInline(PEGraphDecoder.java:1198)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.trySimplifyInvoke(PEGraphDecoder.java:1053)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.handleInvokeWithCallTarget(PEGraphDecoder.java:1005)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.handleInvoke(PEGraphDecoder.java:991)
	  at jdk.graal.compiler.nodes.GraphDecoder.processNextNode(GraphDecoder.java:930)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysisGraphDecoder.processNextNode(InlineBeforeAnalysisGraphDecoder.java:343)
	  at jdk.graal.compiler.nodes.GraphDecoder.decode(GraphDecoder.java:658)
	  at jdk.graal.compiler.replacements.PEGraphDecoder.decode(PEGraphDecoder.java:895)
	  at com.oracle.graal.pointsto.phases.InlineBeforeAnalysis.decodeGraph(InlineBeforeAnalysis.java:73)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.parse(MethodTypeFlowBuilder.java:198)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.apply(MethodTypeFlowBuilder.java:608)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.createFlowsGraph(MethodTypeFlow.java:167)
	  - locked <0x74fa> (a com.oracle.graal.pointsto.flow.MethodTypeFlow)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.ensureFlowsGraphCreated(MethodTypeFlow.java:152)
	  at com.oracle.graal.pointsto.flow.MethodTypeFlow.getOrCreateMethodFlowsGraphInfo(MethodTypeFlow.java:110)
	  at com.oracle.graal.pointsto.typestate.DefaultVirtualInvokeTypeFlow.onObservedUpdate(DefaultVirtualInvokeTypeFlow.java:114)
	  at com.oracle.graal.pointsto.flow.TypeFlow.lambda$addObserver$0(TypeFlow.java:475)
	  at com.oracle.graal.pointsto.flow.TypeFlow$$Lambda/0x000000000f49b678.run(Unknown Source:-1)
	  at com.oracle.graal.pointsto.util.CompletionExecutor.executeCommand(CompletionExecutor.java:169)
	  at com.oracle.graal.pointsto.util.CompletionExecutor.lambda$executeService$0(CompletionExecutor.java:154)
	  at com.oracle.graal.pointsto.util.CompletionExecutor$$Lambda/0x000000000f41bcf0.run(Unknown Source:-1)
	  at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1726)
	  at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1717)
	  at java.util.concurrent.ForkJoinTask$InterruptibleTask.exec(ForkJoinTask.java:1641)
	  at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:507)
	  at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1491)
	  at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:2073)
	  at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2035)
	  at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)

Thread A is already in jdk.xml.internal.JdkXmlUtils.<clinit> while Thread B tries to initialize XMLDocumentFragmentScannerImpl and depends on JdkXmlUtils being initialized. I would expect the JVM to be able to handle this by stalling Thread B till Thread A completes the initialization of JdkXmlUtils but the debugger shows both threads running while nothing happens.

Update 3: I am able to get it to freeze even outside the debugger.

The freeze (and probably the NPE as well, I can't reproduce it anymore :/ ) seem to happen due to the registrations in

reflectiveClass
.produce(ReflectiveClassBuildItem.builder("com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl",
"com.sun.org.apache.xerces.internal.jaxp.datatype.DatatypeFactoryImpl",
"com.sun.org.apache.xalan.internal.xsltc.trax.TransformerFactoryImpl",
"com.sun.org.apache.xerces.internal.jaxp.SAXParserFactoryImpl",
"com.sun.org.apache.xerces.internal.parsers.SAXParser",
"com.sun.org.apache.xml.internal.utils.FastStringBuffer").build());
reflectiveClass.produce(ReflectiveClassBuildItem.builder("com.sun.xml.internal.stream.XMLInputFactoryImpl",
"com.sun.xml.internal.stream.XMLOutputFactoryImpl",
"com.sun.org.apache.xpath.internal.functions.FuncNot",
"com.sun.org.apache.xerces.internal.impl.dv.xs.SchemaDVFactoryImpl",
"javax.xml.namespace.QName").methods().build());

and

addReflectiveClass(reflectiveClass, true, false, "com.sun.xml.internal.stream.XMLInputFactoryImpl");
addReflectiveClass(reflectiveClass, true, false, "com.sun.xml.internal.stream.XMLOutputFactoryImpl");

which are the ones that trigger the transformation in https://github.com/oracle/graal/blob/a43123982961881e39ebc82321639ba2119f500c/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/xml/Target_jdk_xml_internal_JdkCatalog.java in our case.

The freezes seem to happen before the transformation gets in effect hinting that they are independent of it!?

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 19, 2023

The best thing I can think of is to eagerly load jdk.xml.internal.JdkXmlUtils in a feature in beforeAnalysis. By doing that the InlineBeforeAnalysis optimization isn't yet triggered which might cause the class initializer of XMLDocumentFragmentScannerImpl to run. The issue seems to be hosted class loading order.

So something like this should work:

    @Override
     public void beforeAnalysis(BeforeAnalysisAccess access) {
        // Ensure that class loading of xml related classes work
        // com.sun.org.apache.xerces.internal.impl.XMLDocumentFragmentScannerImpl
        // implicitly depends on jdk.xml.internal.JdkXmlUtils. So initialization
        // order needs to happen in the reverse order.
        Class<?> jdkUtil = access.findClassByName("jdk.xml.internal.JdkXmlUtils");
        if (jdkUtil != null) {
            ReflectionUtil.newInstance(jdkUtil);
        }

     }

I wonder if there would be a better way to do this in GraalVM or if this could be added to GraalVM itself unconditionally to avoid the ExceptionInInitializerError, yet not adding (m)any classes to the universe unnecessarily.

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 20, 2023

Update 2: Although I have still not managed to reproduce the NPE in the debugger I have managed to get it to freeze in the following state.

It appears CI managed to reproduce one deadlock too yesterday trying to build jaxb native it test:
https://github.com/graalvm/mandrel/actions/runs/7269633674/job/19808115290#step:12:2245

@zakkak
Copy link
Contributor

zakkak commented Dec 20, 2023

The best thing I can think of is to eagerly load jdk.xml.internal.JdkXmlUtils in a feature in beforeAnalysis.

That's inline with what I was thinking as well.

I wonder if there would be a better way to do this in GraalVM

I don't know but this looks good enough to me.

I also thought about abusing the "typeReachable" condition to only register the classes causing the issue when JdkXmlUtils is reachable, and in the process of checking force the initialization before the registration:

diff --git a/extensions/jaxb/deployment/src/main/java/io/quarkus/jaxb/deployment/JaxbProcessor.java b/extensions/jaxb/deployment/src/main/java/io/quarkus/jaxb/deployment/JaxbProcessor.java
index 17768f6d8e6..8d74a8c74d3 100644
--- a/extensions/jaxb/deployment/src/main/java/io/quarkus/jaxb/deployment/JaxbProcessor.java
+++ b/extensions/jaxb/deployment/src/main/java/io/quarkus/jaxb/deployment/JaxbProcessor.java
@@ -70,6 +70,7 @@
 import io.quarkus.deployment.builditem.nativeimage.NativeImageResourceBundleBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.NativeImageSystemPropertyBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.ReflectiveClassBuildItem;
+import io.quarkus.deployment.builditem.nativeimage.ReflectiveClassConditionBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.ReflectiveHierarchyIgnoreWarningBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.RuntimeInitializedClassBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.ServiceProviderBuildItem;
@@ -275,6 +276,7 @@ void registerClasses(
             BuildProducer<NativeImageSystemPropertyBuildItem> nativeImageProps,
             BuildProducer<ServiceProviderBuildItem> providerItem,
             BuildProducer<ReflectiveClassBuildItem> reflectiveClass,
+            BuildProducer<ReflectiveClassConditionBuildItem> reflectiveClassCondition,
             BuildProducer<NativeImageResourceBundleBuildItem> resourceBundle) {
         addReflectiveClass(reflectiveClass, true, false, "org.glassfish.jaxb.runtime.v2.ContextFactory");
         addReflectiveClass(reflectiveClass, true, false, "com.sun.xml.internal.stream.XMLInputFactoryImpl");
@@ -282,6 +284,13 @@ void registerClasses(
         addReflectiveClass(reflectiveClass, true, false, "com.sun.org.apache.xpath.internal.functions.FuncNot");
         addReflectiveClass(reflectiveClass, true, false, "com.sun.org.apache.xerces.internal.impl.dv.xs.SchemaDVFactoryImpl");
 
+        reflectiveClassCondition
+                .produce(new ReflectiveClassConditionBuildItem("com.sun.xml.internal.stream.XMLInputFactoryImpl",
+                        "jdk.xml.internal.JdkXmlUtils"));
+        reflectiveClassCondition
+                .produce(new ReflectiveClassConditionBuildItem("com.sun.xml.internal.stream.XMLOutputFactoryImpl",
+                        "jdk.xml.internal.JdkXmlUtils"));
+
         addResourceBundle(resourceBundle, "jakarta.xml.bind.Messages");
         addResourceBundle(resourceBundle, "jakarta.xml.bind.helpers.Messages");
 
diff --git a/extensions/jaxp/deployment/src/main/java/io/quarkus/jaxp/deployment/JaxpProcessor.java b/extensions/jaxp/deployment/src/main/java/io/quarkus/jaxp/deployment/JaxpProcessor.java
index b7b06fe00cd..f05000ad03d 100644
--- a/extensions/jaxp/deployment/src/main/java/io/quarkus/jaxp/deployment/JaxpProcessor.java
+++ b/extensions/jaxp/deployment/src/main/java/io/quarkus/jaxp/deployment/JaxpProcessor.java
@@ -8,11 +8,13 @@
 import io.quarkus.deployment.builditem.nativeimage.NativeImageResourceBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.NativeImageResourceBundleBuildItem;
 import io.quarkus.deployment.builditem.nativeimage.ReflectiveClassBuildItem;
+import io.quarkus.deployment.builditem.nativeimage.ReflectiveClassConditionBuildItem;
 
 class JaxpProcessor {
 
     @BuildStep
-    void reflectiveClasses(BuildProducer<ReflectiveClassBuildItem> reflectiveClass) {
+    void reflectiveClasses(BuildProducer<ReflectiveClassBuildItem> reflectiveClass,
+            BuildProducer<ReflectiveClassConditionBuildItem> reflectiveClassConditional) {
         reflectiveClass
                 .produce(ReflectiveClassBuildItem.builder("com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl",
                         "com.sun.org.apache.xerces.internal.jaxp.datatype.DatatypeFactoryImpl",
@@ -26,6 +28,10 @@ void reflectiveClasses(BuildProducer<ReflectiveClassBuildItem> reflectiveClass)
                 "com.sun.org.apache.xpath.internal.functions.FuncNot",
                 "com.sun.org.apache.xerces.internal.impl.dv.xs.SchemaDVFactoryImpl",
                 "javax.xml.namespace.QName").methods().build());
+
+        reflectiveClassConditional
+                .produce(new ReflectiveClassConditionBuildItem("com.sun.org.apache.xerces.internal.parsers.SAXParser",
+                        "jdk.xml.internal.JdkXmlUtils"));
     }
 
     @BuildStep

I believe the Feature approach is less fragile.

or if this could be added to GraalVM itself unconditionally to avoid the ExceptionInInitializerError, yet not adding (m)any classes to the universe unnecessarily.

It's probably worth an upstream discussion. To my understanding the only reason upstream doesn't face the same issue (if they actually don't) is due to using the typeReachable condition. The issue doesn't seem to be Quarkus specific to me (I believe it would manifest even with run-time initialization, but I haven't tried reproducing it in that context).

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 20, 2023

FWIW, I've got this commit with a tiny patch for upstream discussion. I'll try to create an upstream issue with a proposed PR later today or tomorrow.

Two test runs with this (it also passes a very opinionated custom reproducer):
https://github.com/graalvm/mandrel/actions/runs/7273652011
https://github.com/graalvm/mandrel/actions/runs/7266712957

@jerboaa
Copy link
Contributor Author

jerboaa commented Dec 21, 2023

I'll try to create an upstream issue with a proposed PR later today or tomorrow.

Upstream issue: oracle/graal#8075

@jerboaa
Copy link
Contributor Author

jerboaa commented Jan 17, 2024

Update: The current expectation would be that this should be fixed (as in, not see any more random XML related initializer errors in any CI run) once oracle/graal#8185 oracle/graal#8193 merges.

@zakkak
Copy link
Contributor

zakkak commented Jan 19, 2024

oracle/graal#8193 is now merged.

@jerboaa I have cherry picked oracle/graal@944f5d1 (the cherry-pick will be dropped once backported on upstream) in https://github.com/graalvm/mandrel/tree/mandrel/24.0 to work around oracle/graal#8195 and see if oracle/graal#8193 resolves the issue.

@jerboaa
Copy link
Contributor Author

jerboaa commented Jan 22, 2024

oracle/graal#8193 is now merged.

Yes. We'll see if we will see failures again on the JDK 23 based trees going forward.

@jerboaa I have cherry picked oracle/graal@944f5d1 (the cherry-pick will be dropped once backported on upstream) in https://github.com/graalvm/mandrel/tree/mandrel/24.0 to work around oracle/graal#8195 and see if oracle/graal#8193 resolves the issue.

oracle/graal#8193 needs a backport to the 24.0 release train before we can say anything about the JDK 22-base release train. FWIW, we just had a failure on JDK 22 two days ago here:
https://github.com/graalvm/mandrel/actions/runs/7591232948/job/20679453988#step:12:2252

See: graalvm/mandrel#644 (comment)

@zakkak
Copy link
Contributor

zakkak commented Jan 23, 2024

oracle/graal#8193 needs a backport to the 24.0 release train before we can say anything about the JDK 22-base release train.

Right. I openned graalvm/mandrel#667 to keep track of this.

@jerboaa
Copy link
Contributor Author

jerboaa commented Jan 24, 2024

oracle/graal#8193 is now merged.

Yes. We'll see if we will see failures again on the JDK 23 based trees going forward.

We've just had two failures again related to this issue:

So it looks like oracle/graal#8193 didn't fix the issue after all for JDK 23.

@jerboaa
Copy link
Contributor Author

jerboaa commented Jan 30, 2024

oracle/graal#8256 fixed this for master (24.1), but CI is bust for JDK 23 builds[1] so we don't have good test coverage (yet).

[1] graalvm/mandrel#676

@jerboaa
Copy link
Contributor Author

jerboaa commented Feb 8, 2024

We have fixes for this in Graal master and the 24.0 tree and CI has run for a while without seeing this issue crop up again. I'm closing this issue as fixed.

Master fix: oracle/graal#8256
24.0 fix: oracle/graal@df761b6

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants