eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 722 forks source link

BruteArgumentMoverHandle.permuteArguments NullPointerException #8972

Closed pshipton closed 9 months ago

pshipton commented 4 years ago

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.system_x86-64_linux_xl_Nightly/319 TestIBMJlmRemoteMemoryNoAuth_0

CL1 stderr Exception in thread "main" java.lang.BootstrapMethodError: java.lang.invoke.StringConcatException: Generator failed
CL1 stderr  at net.openj9.test.extensions.MemoryPoolExtensionCommand.execute(MemoryPoolExtensionCommand.java:97)
CL1 stderr  at net.openj9.test.jlm.resources.VMData.invokeIBMMemoryPoolBeanTest(VMData.java:179)
CL1 stderr  at net.openj9.test.jlm.resources.MemoryData.writeData(MemoryData.java:112)
CL1 stderr  at net.openj9.test.jlm.remote.MemoryProfiler.getStatsViaProxy(MemoryProfiler.java:192)
CL1 stderr  at net.openj9.test.jlm.remote.MemoryProfiler.main(MemoryProfiler.java:119)
CL1 stderr Caused by: java.lang.invoke.StringConcatException: Generator failed
CL1 stderr  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:764)
CL1 stderr  at java.base/java.lang.invoke.StringConcatFactory.doStringConcat(StringConcatFactory.java:665)
CL1 stderr  at java.base/java.lang.invoke.StringConcatFactory.makeConcatWithConstants(StringConcatFactory.java:581)
CL1 stderr  at java.base/java.lang.invoke.DirectHandle.invokeExact_thunkArchetype_L(DirectHandle.java:302)
CL1 stderr  at java.base/java.lang.invoke.CollectHandle.invokeExact_thunkArchetype_X(CollectHandle.java:130)
CL1 stderr  at java.base/java.lang.invoke.AsTypeHandle.invokeExact_thunkArchetype_X(AsTypeHandle.java:49)
CL1 stderr  at java.base/java.lang.invoke.MethodHandle.invokeBsm(MethodHandle.java:963)
CL1 stderr  at java.base/java.lang.invoke.MethodHandle.resolveInvokeDynamic(MethodHandle.java:1093)
CL1 stderr  ... 5 more
CL1 stderr Caused by: java.lang.NullPointerException
CL1 stderr  at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
CL1 stderr  at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2911)
CL1 stderr  at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2928)
CL1 stderr  at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
CL1 stderr  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
CL1 stderr  ... 12 more
pshipton commented 1 year ago

@tajila @0xdaryl for diagnosis do you think it would be worth modifying the OpenJDK code to catch the exception and create a core file when these conditions occur? We've had the problem for a long time, it occurs fairly frequently, but we aren't making any efforts to fix it, in particular since we put it into the backlog. What can we do to help figure out it?

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.system_x86-64_windows_Nightly_testList_2/545 TestIBMJlmRemoteMemoryNoAuth_1

05:13:48  CL2 stderr Caused by: java.lang.NullPointerException
05:13:48  CL2 stderr    at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
05:13:48  CL2 stderr    at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
05:13:48  CL2 stderr    at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
05:13:48  CL2 stderr    at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
05:13:48  CL2 stderr    at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
05:13:48  CL2 stderr    ... 9 more
tajila commented 1 year ago

We've had the problem for a long time, it occurs fairly frequently, but we aren't making any efforts to fix it, in particular since we put it into the backlog. What can we do to help figure out it?

The long term plan is to backport ojdk Mh into JDK11. AFIAK this issue doesn't occur there

tajila commented 1 year ago

@babsingh FYI

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/4 jdk_lang_0 java/lang/reflect/DefaultMethodMembers/FilterNotMostSpecific.java java/lang/reflect/Proxy/ProxyRace.java

22:29:20  Caused by: java.lang.NullPointerException
22:29:20    at java.lang.invoke.InnerClassLambdaMetafactory.buildCallSite(InnerClassLambdaMetafactory.java:226)
22:29:20    at java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:304)
22:29:20    at java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:115)
22:29:20    at java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:166)
22:29:20    ... 30 more
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_x86-64_mac_OMR_testList_0/3 jdk_lang_0 java/lang/Thread/StopThrowable.java.StopThrowable java/lang/reflect/DefaultMethodMembers/FilterNotMostSpecific.java.FilterNotMostSpecific jdk/lambda/ArrayCtorRefTest.java.ArrayCtorRefTest jdk/lambda/LambdaTranslationCompoundSamTest.java.LambdaTranslationCompoundSamTest jdk/lambda/LambdaTranslationInnerConstructor.java.LambdaTranslationInnerConstructor jdk/lambda/LambdaTranslationTest1.java.LambdaTranslationTest1 jdk/lambda/LambdaTranslationTest2.java.LambdaTranslationTest2 jdk/lambda/MethodReferenceTestSuper.java.MethodReferenceTestSuper jdk/lambda/MethodReferenceTestVarArgsSuperDefault.java.MethodReferenceTestVarArgsSuperDefault jdk/lambda/TestPrivateCtorRef.java.TestPrivateCtorRef jdk/lambda/separate/TestHarness.java.TestHarness jdk/lambda/vm/InterfaceAccessFlagsTest.java.InterfaceAccessFlagsTest

06:00:45  Caused by: java.lang.NullPointerException
06:00:45    at java.lang.invoke.InnerClassLambdaMetafactory.buildCallSite(InnerClassLambdaMetafactory.java:226)
06:00:45    at java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:304)
06:00:45    at java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:115)
06:00:45    at java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:166)
06:00:45    ... 30 more
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_Nightly_testList_2/9 jdk_security2_1 com/sun/crypto/provider/Cipher/DES/PaddingTest.java.PaddingTest com/sun/crypto/provider/Cipher/DES/TestCipherDES.java.TestCipherDES com/sun/crypto/provider/Cipher/KeyWrap/NISTWrapKAT.java.NISTWrapKAT com/sun/crypto/provider/Cipher/KeyWrap/XMLEncKAT.java.XMLEncKAT com/sun/crypto/provider/Cipher/PBE/CheckPBEKeySize.java.CheckPBEKeySize com/sun/crypto/provider/Cipher/PBE/NegativeLength.java.NegativeLength com/sun/crypto/provider/Cipher/PBE/PBEInvalidParamsTest.java.PBEInvalidParamsTest com/sun/crypto/provider/Cipher/PBE/PBEKeysAlgorithmNames.java.PBEKeysAlgorithmNames com/sun/crypto/provider/Cipher/PBE/PBEParametersTest.java.PBEParametersTest com/sun/crypto/provider/Cipher/PBE/PBES2Test.java.PBES2Test com/sun/crypto/provider/Cipher/PBE/PBESameBuffer/PBESameBuffer.java.PBESameBuffer com/sun/crypto/provider/Cipher/PBE/PBESealedObject.java.PBESealedObject com/sun/crypto/provider/Cipher/PBE/PBKDF2Translate.java.PBKDF2Translate com/sun/crypto/provider/Cipher/PBE/PBMacDoFinalVsUpdate.java.PBMacDoFinalVsUpdate com/sun/crypto/provider/Cipher/PBE/PKCS12Cipher.java.PKCS12Cipher com/sun/crypto/provider/Cipher/PBE/PKCS12Oid.java.PKCS12Oid com/sun/crypto/provider/Cipher/PBE/TestCipherPBE.java.TestCipherPBE com/sun/crypto/provider/Cipher/PBE/TestCipherPBECons.java.TestCipherPBECons com/sun/crypto/provider/Cipher/RSA/TestOAEPPadding.java.TestOAEPPadding com/sun/crypto/provider/Cipher/RSA/TestOAEPParameterSpec.java.TestOAEPParameterSpec com/sun/crypto/provider/Cipher/RSA/TestOAEPWithParams.java.TestOAEPWithParams com/sun/crypto/provider/Cipher/RSA/TestOAEP_KAT.java.TestOAEP_KAT com/sun/crypto/provider/Cipher/TextLength/TestCipherTextLength.java.TestCipherTextLength com/sun/crypto/provider/KeyAgreement/DHKeyAgreement3.java.DHKeyAgreement3 com/sun/crypto/provider/KeyAgreement/SupportedDHKeys.java.SupportedDHKeys com/sun/crypto/provider/KeyAgreement/SupportedDHParamGens.java.SupportedDHParamGens com/sun/crypto/provider/KeyAgreement/SupportedDHParamGensLongKey.java.SupportedDHParamGensLongKey com/sun/crypto/provider/KeyAgreement/TestExponentSize.java.TestExponentSize com/sun/crypto/provider/KeyAgreement/UnsupportedDHKeys.java.UnsupportedDHKeys com/sun/crypto/provider/KeyFactory/PBKDF2HmacSHA1FactoryTest.java.PBKDF2HmacSHA1FactoryTest

JasonFengJ9 commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_s390x_linux_Nightly/583/tapResults/

variation: Mode610
JVM_OPTIONS:  -Xcompressedrefs -Xjit -Xgcpolicy:gencon 

STF 08:46:54.247 - Monitoring processes: MCL1 MCL2 MCL3 MCL4 MCL5
MCL5 stderr Exception in thread "main" java.lang.BootstrapMethodError: java.lang.invoke.StringConcatException: Generator failed
MCL5 stderr     at net.openj9.sc.classes.Test_Init_0112.stringOperations(Test_Init_0112.java:20)
MCL5 stderr     at net.openj9.sc.classes.Test_Init_0112.getName(Test_Init_0112.java:7)
MCL5 stderr     at net.openj9.test.sc.LoaderSlaveMultiCL.run(LoaderSlaveMultiCL.java:115)
MCL5 stderr     at net.openj9.test.sc.LoaderSlaveMultiCL.main(LoaderSlaveMultiCL.java:52)
MCL5 stderr Caused by: java.lang.invoke.StringConcatException: Generator failed
MCL5 stderr     at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:764)
MCL5 stderr     at java.base/java.lang.invoke.StringConcatFactory.doStringConcat(StringConcatFactory.java:665)
MCL5 stderr     at java.base/java.lang.invoke.StringConcatFactory.makeConcatWithConstants(StringConcatFactory.java:581)
MCL5 stderr     at java.base/java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:178)
MCL5 stderr     at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:240)
MCL5 stderr     ... 4 more
MCL5 stderr Caused by: java.lang.NullPointerException
MCL5 stderr     at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
MCL5 stderr     at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
MCL5 stderr     at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
MCL5 stderr     at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
MCL5 stderr     at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
MCL5 stderr     ... 8 more
STF 08:47:01.913 - **FAILED** Process MCL5 ended with exit code (1) and not the expected exit code/s (0)

SharedClasses.SCM01.MultiCL_1_FAILED
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.system_s390x_linux_Nightly_testList_0/587 TestJlmRemoteThreadNoAuth_1

CL2 stderr Caused by: java.lang.NullPointerException
CL2 stderr  at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
CL2 stderr  at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
CL2 stderr  at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
CL2 stderr  ... 10 more

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_s390x_linux_Nightly_testList_2/590 SharedClasses.SCM01.MultiCL_1

MCL2 stderr Caused by: java.lang.NullPointerException
MCL2 stderr     at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
MCL2 stderr     at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
MCL2 stderr     at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
MCL2 stderr     at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
MCL2 stderr     at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
MCL2 stderr     ... 8 more
JamesKingdon commented 1 year ago

I have a customer case for this problem on Java 8. Is the cause known?

nbhuiyan commented 1 year ago

@JamesKingdon I don't think a cause for this has been established yet given the failed attempts to reproduce this with dump agent configured in the past. This problem only happens when using the older MH implementation which is still being used in JDK8 and 11.

JamesKingdon commented 1 year ago

Ok, so the good news is I have data to look at, I'll see if it makes any sense.

JamesKingdon commented 1 year ago

It appears to have thrown the NPE while running in the interpreter for method {java/lang/invoke/BruteArgumentMoverHandle.permuteArguments}. I'm not used to debugging the interpreter, but it looks like the NPE was triggered at bytecode +46 which is:

+46 invokespecial 34 {java/lang/invoke/BruteArgumentMoverHandle.<init>(Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodHandle;[I[Ljava/lang/Object;Ljava/lang/invoke/MethodHandle;)V} I think this could only trigger an NPE if the earlier newdup instruction failed to allocate storage for the object and yet didn't throw an OOM (or any other exception)

+11 newdup 24 java/lang/invoke/BruteArgumentMoverHandle <<< +6 This seems strange and unlikely, so I'll pass the case to the VM team for further investigation.

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_x86-64_windows_Nightly_testList_0/37 jdk/lambda/LambdaTranslationCompoundSamTest.java.LambdaTranslationCompoundSamTest jdk/lambda/LambdaTranslationInnerConstructor.java.LambdaTranslationInnerConstructor jdk/lambda/LambdaTranslationTest1.java.LambdaTranslationTest1 jdk/lambda/LambdaTranslationTest2.java.LambdaTranslationTest2 jdk/lambda/MethodReferenceTestInnerDefault.java.MethodReferenceTestInnerDefault jdk/lambda/MethodReferenceTestInnerInstance.java.MethodReferenceTestInnerInstance jdk/lambda/MethodReferenceTestInnerVarArgsThis.java.MethodReferenceTestInnerVarArgsThis jdk/lambda/MethodReferenceTestInstance.java.MethodReferenceTestInstance jdk/lambda/MethodReferenceTestKinds.java.MethodReferenceTestKinds jdk/lambda/MethodReferenceTestNewInner.java.MethodReferenceTestNewInner jdk/lambda/MethodReferenceTestSuper.java.MethodReferenceTestSuper jdk/lambda/MethodReferenceTestSuperDefault.java.MethodReferenceTestSuperDefault jdk/lambda/MethodReferenceTestTypeConversion.java.MethodReferenceTestTypeConversion jdk/lambda/MethodReferenceTestVarArgsExt.java.MethodReferenceTestVarArgsExt jdk/lambda/MethodReferenceTestVarArgsSuper.java.MethodReferenceTestVarArgsSuper jdk/lambda/MethodReferenceTestVarArgsSuperDefault.java.MethodReferenceTestVarArgsSuperDefault jdk/lambda/MethodReferenceTestVarArgsThis.java.MethodReferenceTestVarArgsThis jdk/lambda/TestPrivateCtorRef.java.TestPrivateCtorRef jdk/lambda/vm/InterfaceAccessFlagsTest.java.InterfaceAccessFlagsTest sun/misc/URLClassPath/ClassnameCharTest.java.ClassnameCharTest

02:21:12  Caused by: java.lang.NullPointerException
02:21:12    at java.lang.invoke.InnerClassLambdaMetafactory.buildCallSite(InnerClassLambdaMetafactory.java:226)
02:21:12    at java.lang.invoke.LambdaMetafactory.metafactory(LambdaMetafactory.java:304)
02:21:12    at java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:115)
02:21:12    at java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:166)
02:21:12    ... 19 more
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_OMR_testList_1/21/ jdk_lang_1 java/lang/String/concat/ImplicitStringConcatShapes.java

14:54:28  Caused by: java.lang.NullPointerException
14:54:28    at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
14:54:28    at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
14:54:28    at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
14:54:28    at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
14:54:28    at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
14:54:28    ... 13 more
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_x86-64_windows_Nightly_testList_2/40/ com/sun/crypto/provider/Cipher/AES/TestKATForECB_VT.java.TestKATForECB_VT com/sun/crypto/provider/Cipher/AES/TestKATForGCM.java.TestKATForGCM com/sun/crypto/provider/Cipher/AES/TestNonexpanding.java.TestNonexpanding com/sun/crypto/provider/Cipher/AES/TestSameBuffer.java.TestSameBuffer com/sun/crypto/provider/Cipher/AES/TestShortBuffer.java.TestShortBuffer com/sun/crypto/provider/Cipher/Blowfish/TestCipherBlowfish.java.TestCipherBlowfish com/sun/crypto/provider/Cipher/CTR/CounterMode.java.CounterMode com/sun/crypto/provider/Cipher/CTS/CTSMode.java.CTSMode com/sun/crypto/provider/Cipher/ChaCha20/ChaCha20KAT.java.ChaCha20KAT com/sun/crypto/provider/Cipher/ChaCha20/ChaCha20KeyGeneratorTest.java.ChaCha20KeyGeneratorTest com/sun/crypto/provider/Cipher/ChaCha20/ChaCha20NoReuse.java.ChaCha20NoReuse com/sun/crypto/provider/Cipher/ChaCha20/ChaCha20Poly1305ParamTest.java.ChaCha20Poly1305ParamTest com/sun/crypto/provider/Cipher/ChaCha20/OutputSizeTest.java.OutputSizeTest com/sun/crypto/provider/Cipher/ChaCha20/unittest/ChaCha20CipherUnitTest.java.ChaCha20CipherUnitTest com/sun/crypto/provider/Cipher/ChaCha20/unittest/ChaCha20Poly1305ParametersUnitTest.java.ChaCha20Poly1305ParametersUnitTest com/sun/crypto/provider/Cipher/DES/DesAPITest.java.DesAPITest com/sun/crypto/provider/Cipher/DES/DoFinalReturnLen.java.DoFinalReturnLen com/sun/crypto/provider/Cipher/DES/FlushBug.java.FlushBug com/sun/crypto/provider/Cipher/DES/PaddingTest.java.PaddingTest com/sun/crypto/provider/Cipher/DES/TestCipherDES.java.TestCipherDES com/sun/crypto/provider/Cipher/DES/TestCipherDESede.java.TestCipherDESede com/sun/crypto/provider/Cipher/KeyWrap/NISTWrapKAT.java.NISTWrapKAT com/sun/crypto/provider/Cipher/KeyWrap/TestCipherKeyWrapperTest.java.TestCipherKeyWrapperTest com/sun/crypto/provider/Cipher/KeyWrap/XMLEncKAT.java.XMLEncKAT com/sun/crypto/provider/Cipher/PBE/CheckPBEKeySize.java.CheckPBEKeySize com/sun/crypto/provider/Cipher/PBE/NegativeLength.java.NegativeLength com/sun/crypto/provider/Cipher/PBE/PBEInvalidParamsTest.java.PBEInvalidParamsTest com/sun/crypto/provider/Cipher/PBE/PBEKeysAlgorithmNames.java.PBEKeysAlgorithmNames com/sun/crypto/provider/Cipher/PBE/PBEParametersTest.java.PBEParametersTest com/sun/crypto/provider/Cipher/PBE/PBES2Test.java.PBES2Test com/sun/crypto/provider/Cipher/PBE/PBESameBuffer/PBESameBuffer.java.PBESameBuffer com/sun/crypto/provider/Cipher/PBE/PBESealedObject.java.PBESealedObject com/sun/crypto/provider/Cipher/PBE/PBKDF2Translate.java.PBKDF2Translate com/sun/crypto/provider/Cipher/PBE/PBMacBuffer.java.PBMacBuffer com/sun/crypto/provider/Cipher/PBE/PBMacDoFinalVsUpdate.java.PBMacDoFinalVsUpdate com/sun/crypto/provider/Cipher/PBE/PKCS12Cipher.java.PKCS12Cipher com/sun/crypto/provider/Cipher/PBE/PKCS12CipherKAT.java.PKCS12CipherKAT com/sun/crypto/provider/Cipher/PBE/PKCS12Oid.java.PKCS12Oid com/sun/crypto/provider/Cipher/PBE/TestCipherKeyWrapperPBEKey.java.TestCipherKeyWrapperPBEKey com/sun/crypto/provider/Cipher/PBE/TestCipherPBE.java.TestCipherPBE com/sun/crypto/provider/Cipher/PBE/TestCipherPBECons.java.TestCipherPBECons com/sun/crypto/provider/Cipher/RC2ArcFour/CipherKAT.java.CipherKAT com/sun/crypto/provider/Cipher/RSA/TestOAEP.java.TestOAEP com/sun/crypto/provider/Cipher/RSA/TestOAEPPadding.java.TestOAEPPadding com/sun/crypto/provider/Cipher/RSA/TestOAEPParameterSpec.java.TestOAEPParameterSpec com/sun/crypto/provider/Cipher/RSA/TestOAEPWithParams.java.TestOAEPWithParams com/sun/crypto/provider/Cipher/RSA/TestOAEP_KAT.java.TestOAEP_KAT com/sun/crypto/provider/Cipher/RSA/TestRSA.java.TestRSA com/sun/crypto/provider/Cipher/TextLength/TestCipherTextLength.java.TestCipherTextLength com/sun/crypto/provider/KeyAgreement/DHGenSharedSecret.java.DHGenSharedSecret com/sun/crypto/provider/KeyAgreement/DHKeyAgreement3.java.DHKeyAgreement3 com/sun/crypto/provider/KeyAgreement/SupportedDHKeys.java.SupportedDHKeys com/sun/crypto/provider/KeyAgreement/SupportedDHParamGens.java.SupportedDHParamGens com/sun/crypto/provider/KeyAgreement/SupportedDHParamGensLongKey.java.SupportedDHParamGensLongKey com/sun/crypto/provider/KeyAgreement/TestExponentSize.java.TestExponentSize com/sun/crypto/provider/KeyAgreement/UnsupportedDHKeys.java.UnsupportedDHKeys com/sun/crypto/provider/KeyFactory/PBKDF2HmacSHA1FactoryTest.java.PBKDF2HmacSHA1FactoryTest com/sun/crypto/provider/Mac/EmptyByteBufferTest.java.EmptyByteBufferTest com/sun/crypto/provider/Mac/HmacPBESHA1.java.HmacPBESHA1 com/sun/crypto/provider/Mac/HmacSaltLengths.java.HmacSaltLengths com/sun/crypto/provider/Mac/LargeByteBufferTest.java.LargeByteBufferTest com/sun/crypto/provider/Mac/MacKAT.java.MacKAT com/sun/crypto/provider/Mac/MacSameTest.java.MacSameTest com/sun/crypto/provider/TLS/TestLeadingZeroes.java.TestLeadingZeroes com/sun/crypto/provider/TLS/TestMasterSecret.java.TestMasterSecret com/sun/crypto/provider/TLS/TestPRF.java.TestPRF javax/crypto/CipherSpi/DirectBBRemaining.java.DirectBBRemaining javax/crypto/Cipher/ByteBuffersNull.java.ByteBuffersNull javax/crypto/Cipher/EmptyFinalBuffer.java.EmptyFinalBuffer javax/crypto/CryptoPermission/AllPermCheck.java.AllPermCheck javax/crypto/CryptoPermission/RC2PermCheck.java.RC2PermCheck javax/crypto/CryptoPermission/RSANoLimit.java.RSANoLimit javax/crypto/CryptoPermissions/TestExemption.java.TestExemption javax/xml/crypto/dsig/GetInstanceTests.java.GetInstanceTests javax/xml/crypto/dsig/keyinfo/KeyInfoFactory/UnknownProvider.java.UnknownProvider

01:22:48  Caused by: java.lang.NullPointerException
01:22:48    at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
01:22:48    at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
01:22:48    at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
01:22:48    at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
01:22:48    at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
01:22:48    ... 11 more
JamesKingdon commented 1 year ago

Currently it looks like we're failing to rebuild the stack during OSR. In the corefiles I've looked at so far, dropArgumentsUnsafe is a jit'd method body compiled at hot that we OSR out of prior to calling MethodHandle.computeThunks. BruteArgumentMoverHandle.permuteArguments was inlined into dropArgumentsUnsafe, and it's likely that the first part of the method ran in the jit'd body and we failed to recreate all the state before the interpreter took over. In particular, I can't find where we constructed the new object that the interpreter NPEs over. It's possible we optimised it away from the hot method and failed to recreate it during OSR.

The relevant inlining in dropArgumentsUnsafe:

-1:126   invokevirtual 118 {java/lang/invoke/MethodHandle.permuteArguments(Ljava/lang/invoke/MethodType;[I)Ljava/lang/invoke/MethodHandle;}
{  //Inlined #6 0x00000000062d6b00 {java/lang/invoke/BruteArgumentMoverHandle.permuteArguments}
   6:43    invokespecial 33 {java/lang/invoke/PermuteHandle.<init>(Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodHandle;[I)V}
   {  //Inlined #19 0x0000000000082c20 {java/lang/invoke/PermuteHandle.<init>}
      19:5     invokespecial 2 {java/lang/invoke/MethodHandle.<init>(Ljava/lang/invoke/MethodType;BLjava/lang/Object;)V}
      {  //Inlined #20 0x0000000000055948 {java/lang/invoke/MethodHandle.<init>}
         20:25    invokevirtual 42 {java/lang/invoke/MethodHandle.computeThunks(Ljava/lang/Object;)Ljava/lang/invoke/ThunkTuple;}
JamesKingdon commented 1 year ago

Further to the previous comment, it appears that the OSR is not the root cause of the problem but something of an innocent bystander. The newly created BruteArgumentMoverHandle instance should be the return value from dropArgumentsUnsafe. In the warm method body this is clearly true, but in the hot body the object is neither created nor returned, even in the absence of OSR. It looks like the hot method body incorrectly optimised away the creation of the new object. We will need to get a compilation log for {java/lang/invoke/MethodHandles.dropArgumentsUnsafe(Ljava/lang/invoke/MethodHandle;I[Ljava/lang/Class;)Ljava/lang/invoke/MethodHandle; from a failing run to see what happened.

JamesKingdon commented 1 year ago

The problem is being caused when dropArgumentsUnsafe is compiled at hot, and we have a log capturing the compilation. Devin kindly provided me with extensive help looking at the log and we discovered an unfortunate sequence of events with possible performance and functional consequences:

I'll do some more work to capture specific opt ids next week and pass the info to Henry for consideration.

hzongaro commented 1 year ago

I'm investigating whether pull request #14074 fixes this problem. . . .

hzongaro commented 1 year ago

I think this issue should be fixed by pull request #14074, but I'd like to leave it open for now to see whether we see any recurrences of the intermittent failure in BruteArgumentMoverHandle.permuteArguments.

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.system_s390x_linux_Release_testList_2/76/ TestJlmRemoteThreadNoAuth_0

CL2 stderr Exception in thread "main" java.lang.BootstrapMethodError: java.lang.invoke.StringConcatException: Generator failed
CL2 stderr  at net.adoptopenjdk.test.jlm.resources.ThreadData.writeData(ThreadData.java:618)
CL2 stderr  at net.adoptopenjdk.test.jlm.remote.ThreadProfiler.getStatsViaServer(ThreadProfiler.java:199)
CL2 stderr  at net.adoptopenjdk.test.jlm.remote.ThreadProfiler.main(ThreadProfiler.java:99)
CL2 stderr Caused by: java.lang.invoke.StringConcatException: Generator failed
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:764)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory.doStringConcat(StringConcatFactory.java:665)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory.makeConcatWithConstants(StringConcatFactory.java:581)
CL2 stderr  at java.base/java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:178)
CL2 stderr  at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:240)
CL2 stderr  ... 3 more
CL2 stderr Caused by: java.lang.NullPointerException
CL2 stderr  at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
CL2 stderr  at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
CL2 stderr  at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
CL2 stderr  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
CL2 stderr  ... 7 more

@hzongaro

hzongaro commented 1 year ago

Pull request #18315 fixes another case that can exhibit similar symptoms if JIT-compiled code induces OSR. Again, once that pull request has been reviewed and merged, I would like to leave this issue open for a few months just to watch for any new occurrences.

JasonFengJ9 commented 11 months ago

JDK11 aarch64_linux(rhel9-aarch64-1)

java version "11.0.21" 2023-10-17
IBM Semeru Runtime Certified Edition 11.0.21.0-rc2 (build 11.0.21+9)
Eclipse OpenJ9 VM 11.0.21.0-rc2 (build v0.41.0-release-a803f004b, JRE 11 Linux aarch64-64-Bit Compressed References 20231116_458 (JIT enabled, AOT enabled)
OpenJ9   - a803f004b
OMR      - 5eee6ad9d
JCL      - 6f4cc08025 based on jdk-11.0.21+9)

[2023-11-16T05:16:20.491Z] variation: Mode650
[2023-11-16T05:16:20.491Z] JVM_OPTIONS:  -XX:-UseCompressedOops 

[2023-11-16T05:17:03.019Z] TEST: com/sun/jndi/dns/AttributeTests/GetRRs.java

[2023-11-16T05:17:03.022Z] STDERR:
[2023-11-16T05:17:03.022Z] java.lang.BootstrapMethodError: java.lang.invoke.StringConcatException: Generator failed
[2023-11-16T05:17:03.022Z]  at DNSTestUtils.getCaptureFile(DNSTestUtils.java:243)
[2023-11-16T05:17:03.022Z]  at DNSTestUtils.createDNSServer(DNSTestUtils.java:220)
[2023-11-16T05:17:03.022Z]  at DNSTestUtils.initEnv(DNSTestUtils.java:143)
[2023-11-16T05:17:03.022Z]  at DNSTestBase.initTest(DNSTestBase.java:48)
[2023-11-16T05:17:03.022Z]  at TestBase.run(TestBase.java:48)
[2023-11-16T05:17:03.022Z]  at GetRRs.main(GetRRs.java:40)
[2023-11-16T05:17:03.022Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-11-16T05:17:03.022Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2023-11-16T05:17:03.022Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2023-11-16T05:17:03.022Z]  at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.Thread.run(Thread.java:839)
[2023-11-16T05:17:03.022Z] Caused by: java.lang.invoke.StringConcatException: Generator failed
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:764)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.StringConcatFactory.doStringConcat(StringConcatFactory.java:665)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.StringConcatFactory.makeConcatWithConstants(StringConcatFactory.java:581)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:178)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:240)
[2023-11-16T05:17:03.022Z]  ... 12 more
[2023-11-16T05:17:03.022Z] Caused by: java.lang.NullPointerException
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
[2023-11-16T05:17:03.022Z]  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
[2023-11-16T05:17:03.022Z]  ... 16 more
[2023-11-16T05:17:03.022Z] 
[2023-11-16T05:17:03.022Z] JavaTest Message: Test threw exception: java.lang.BootstrapMethodError

[2023-11-16T05:17:03.022Z] TEST: com/sun/jndi/dns/ConfigTests/AuthTest.java

[2023-11-16T05:17:03.025Z] TEST: com/sun/jndi/dns/ConfigTests/PortUnreachable.java

[2023-11-16T05:17:03.029Z] TEST: com/sun/jndi/dns/ConfigTests/RecursiveTest.java

[2023-11-16T05:17:11.789Z] TEST: com/sun/jndi/dns/ConfigTests/Timeout.java

[2023-11-16T05:20:09.274Z] STDERR:
[2023-11-16T05:20:09.274Z] java.lang.BootstrapMethodError: java.lang.invoke.StringConcatException: Generator failed
[2023-11-16T05:20:09.274Z]  at BalancedParentheses.doClientSide(BalancedParentheses.java:109)
[2023-11-16T05:20:09.274Z]  at BalancedParentheses.startClient(BalancedParentheses.java:214)
[2023-11-16T05:20:09.274Z]  at BalancedParentheses.<init>(BalancedParentheses.java:222)
[2023-11-16T05:20:09.274Z]  at BalancedParentheses.main(BalancedParentheses.java:256)
[2023-11-16T05:20:09.274Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2023-11-16T05:20:09.274Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2023-11-16T05:20:09.274Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2023-11-16T05:20:09.274Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2023-11-16T05:20:09.274Z]  at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
[2023-11-16T05:20:09.274Z]  at java.base/java.lang.Thread.run(Thread.java:839)
[2023-11-16T05:20:09.274Z] Caused by: java.lang.invoke.StringConcatException: Generator failed
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:764)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.StringConcatFactory.doStringConcat(StringConcatFactory.java:665)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.StringConcatFactory.makeConcatWithConstants(StringConcatFactory.java:581)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.MethodHandleResolver.invokeBsm(MethodHandleResolver.java:178)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.MethodHandleResolver.resolveInvokeDynamic(MethodHandleResolver.java:240)
[2023-11-16T05:20:09.275Z]  ... 10 more
[2023-11-16T05:20:09.275Z] Caused by: java.lang.NullPointerException
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.BruteArgumentMoverHandle.permuteArguments(BruteArgumentMoverHandle.java:286)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.MethodHandles.dropArgumentsUnsafe(MethodHandles.java:2961)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.MethodHandles.dropArguments(MethodHandles.java:2978)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.StringConcatFactory$MethodHandleInlineCopyStrategy.generate(StringConcatFactory.java:1536)
[2023-11-16T05:20:09.275Z]  at java.base/java.lang.invoke.StringConcatFactory.generate(StringConcatFactory.java:756)
[2023-11-16T05:20:09.275Z]  ... 14 more
[2023-11-16T05:20:09.275Z] 
[2023-11-16T05:20:09.275Z] JavaTest Message: Test threw exception: java.lang.BootstrapMethodError
[2023-11-16T05:20:09.275Z] JavaTest Message: shutting down test
[2023-11-16T05:20:09.275Z] 
[2023-11-16T05:20:09.275Z] 
[2023-11-16T05:20:09.275Z] JavaTest Message: Problem cleaning up the following threads:
[2023-11-16T05:20:09.275Z] Thread-10
[2023-11-16T05:20:09.275Z]   at java.base/java.net.PlainSocketImpl.socketAccept(Native Method)
[2023-11-16T05:20:09.275Z]   at java.base/java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:474)
[2023-11-16T05:20:09.275Z]   at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:565)
[2023-11-16T05:20:09.275Z]   at java.base/java.net.ServerSocket.accept(ServerSocket.java:533)
[2023-11-16T05:20:09.275Z]   at BalancedParentheses.doServerSide(BalancedParentheses.java:64)
[2023-11-16T05:20:09.275Z]   at BalancedParentheses$1.run(BalancedParentheses.java:177)
[2023-11-16T05:20:09.275Z] 
[2023-11-16T05:20:09.275Z] 
[2023-11-16T05:20:09.275Z] TEST RESULT: Error. Error while cleaning up threads after test
[2023-11-16T05:20:09.275Z] --------------------------------------------------
[2023-11-16T05:29:16.960Z] Test results: passed: 239; failed: 22; error: 1
[2023-11-16T05:29:31.389Z] Report written to /home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_aarch64_linux/aqa-tests/TKG/output_17001105225457/jdk_other_1/report/html/report.html
[2023-11-16T05:29:31.389Z] Results written to /home/jenkins/workspace/Test_openjdk11_j9_extended.openjdk_aarch64_linux/aqa-tests/TKG/output_17001105225457/jdk_other_1/work
[2023-11-16T05:29:31.389Z] Error: Some tests failed or other problems occurred.
[2023-11-16T05:29:31.389Z] -----------------------------------
[2023-11-16T05:29:31.389Z] jdk_other_1_FAILED

50x internal grinder - passed

hzongaro commented 11 months ago

@JasonFengJ9, regarding the failure you reported in the previous comment, the fix in pull request #18135 didn't make it into release-0.41. It will be part of release-0.43.

java version "11.0.21" 2023-10-17
IBM Semeru Runtime Certified Edition 11.0.21.0-rc2 (build 11.0.21+9)
Eclipse OpenJ9 VM 11.0.21.0-rc2 (build v0.41.0-release-a803f004b, JRE 11 Linux aarch64-64-Bit Compressed References 20231116_458 (JIT enabled, AOT enabled)
OpenJ9   - a803f004b
OMR      - 5eee6ad9d
JCL      - 6f4cc08025 based on jdk-11.0.21+9)
hzongaro commented 9 months ago

I don't think we've seen any further occurrences of this problem in the past few months, so I will close it.