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

OpenJDK jdk_security1 timeout in java.math.BigInteger doing RSAKeyPairGenerator.generateKeyPair #20986

Open
pshipton opened this issue Jan 21, 2025 · 4 comments

Comments

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/399 - ub20-390-1
jdk_security1_1
java/security/SignedObject/Chain.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/399/openjdk_test_output.tar.gz

19:33:44  Running jstack on process 2230411
19:33:44  2025-01-21T00:33:40.086298695
19:33:44  Virtual machine: 2230411 JVM information:
19:33:44  JRE 21 Linux s390x-64-Bit 20250120_415 (JIT enabled, AOT enabled)
19:33:44  OpenJ9   - a61d849ea72
19:33:44  OMR      - 6bfb20f781c
19:33:44  JCL      - fe541c56c5a based on jdk-21.0.6+6
19:33:44  
19:33:44  "main" prio=5 Id=2 WAITING
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.waitImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:255)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:221)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.join(Thread.java:2110)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.join(Thread.java:2186)
19:33:44  	at app//com.sun.javatest.regtest.agent.MainActionHelper.runClass(MainActionHelper.java:219)
19:33:44  	at app//com.sun.javatest.regtest.agent.AgentServer.doMain(AgentServer.java:317)
19:33:44  	at app//com.sun.javatest.regtest.agent.AgentServer.run(AgentServer.java:242)
19:33:44  	at app//com.sun.javatest.regtest.agent.AgentServer.main(AgentServer.java:71)
19:33:44  
19:33:44  "JIT Compilation Thread-000" prio=10 Id=4 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-001 Suspended" prio=10 Id=5 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-002 Suspended" prio=10 Id=6 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-003 Suspended" prio=10 Id=7 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-004 Suspended" prio=10 Id=8 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-005 Suspended" prio=10 Id=9 RUNNABLE
19:33:44  
19:33:44  "JIT Compilation Thread-006 Suspended" prio=10 Id=10 RUNNABLE
19:33:44  
19:33:44  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=11 RUNNABLE
19:33:44  
19:33:44  "JIT-SamplerThread" prio=10 Id=12 TIMED_WAITING
19:33:44  
19:33:44  "IProfiler" prio=5 Id=13 RUNNABLE
19:33:44  
19:33:44  "Common-Cleaner" prio=8 Id=3 TIMED_WAITING
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.waitImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:255)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:221)
19:33:44  	at java.base@21.0.6-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:141)
19:33:44  	at java.base@21.0.6-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.run(Thread.java:1595)
19:33:44  	at java.base@21.0.6-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
19:33:44  
19:33:44  "Finalizer thread" prio=5 Id=14 RUNNABLE
19:33:44  
19:33:44  "Concurrent Mark Helper" prio=1 Id=15 RUNNABLE
19:33:44  
19:33:44  "GC Worker" prio=5 Id=16 RUNNABLE
19:33:44  
19:33:44  "GC Worker" prio=5 Id=17 RUNNABLE
19:33:44  
19:33:44  "GC Worker" prio=5 Id=18 RUNNABLE
19:33:44  
19:33:44  "Attach API update file access time" prio=5 Id=21 TIMED_WAITING
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.sleepImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.sleep(Thread.java:516)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.AttachHandler$1.run(AttachHandler.java:348)
19:33:44  
19:33:44  "Attach API wait loop" prio=10 Id=22 RUNNABLE
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
19:33:44  
19:33:44  "pool-1-thread-1" prio=5 Id=23 TIMED_WAITING
19:33:44  	at java.base@21.0.6-internal/jdk.internal.misc.Unsafe.park(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:269)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1763)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1070)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
19:33:44  	at java.base@21.0.6-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.run(Thread.java:1595)
19:33:44  
19:33:44  "AgentVMThread" prio=5 Id=250 RUNNABLE
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.addOne(BigInteger.java:3345)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.montReduce(BigInteger.java:3244)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.implMontgomerySquare(BigInteger.java:2990)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.montgomerySquare(BigInteger.java:2946)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.oddModPow(BigInteger.java:3216)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.modPow(BigInteger.java:2877)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.passesMillerRabin(BigInteger.java:1129)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.primeToCertainty(BigInteger.java:985)
19:33:44  	at java.base@21.0.6-internal/java.math.BitSieve.retrieve(BitSieve.java:203)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.largePrime(BigInteger.java:858)
19:33:44  	at java.base@21.0.6-internal/java.math.BigInteger.probablePrime(BigInteger.java:788)
19:33:44  	at java.base@21.0.6-internal/sun.security.rsa.RSAKeyPairGenerator.generateKeyPair(RSAKeyPairGenerator.java:185)
19:33:44  	at java.base@21.0.6-internal/sun.security.rsa.RSAKeyPairGenerator$Legacy.generateKeyPair(RSAKeyPairGenerator.java:277)
19:33:44  	at java.base@21.0.6-internal/java.security.KeyPairGenerator$Delegate.generateKeyPair(KeyPairGenerator.java:722)
19:33:44  	at java.base@21.0.6-internal/java.security.KeyPairGenerator.genKeyPair(KeyPairGenerator.java:496)
19:33:44  	at Chain.runTest(Chain.java:238)
19:33:44  	at Chain.runTestPSS(Chain.java:198)
19:33:44  	at Chain.main(Chain.java:184)
19:33:44  	at java.base@21.0.6-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
19:33:44  	at java.base@21.0.6-internal/java.lang.reflect.Method.invoke(Method.java:586)
19:33:44  	at app//com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.run(Thread.java:1595)
19:33:44  
19:33:44  "ClassByNameCache Reaper" prio=5 Id=251 WAITING
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.waitImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:255)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:221)
19:33:44  	at java.base@21.0.6-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:141)
19:33:44  	at java.base@21.0.6-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:113)
19:33:44  	at java.base@21.0.6-internal/java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:232)
19:33:44  	at java.base@21.0.6-internal/java.lang.Thread.run(Thread.java:1595)
19:33:44  
19:33:44  "file lock watchdog" prio=10 Id=253 TIMED_WAITING
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.waitImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:255)
19:33:44  	at java.base@21.0.6-internal/java.lang.Object.wait(Object.java:221)
19:33:44  	at java.base@21.0.6-internal/java.util.TimerThread.mainLoop(Timer.java:602)
19:33:44  	at java.base@21.0.6-internal/java.util.TimerThread.run(Timer.java:543)
19:33:44  
19:33:44  "Attachment portNumber: 42767" prio=10 Id=256 RUNNABLE
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:250)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:186)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:252)
19:33:44  	at java.base@21.0.6-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:162)
19:33:44  
19:33:44  
19:33:44  --- Timeout information end.
@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Nightly_testList_2/403

00:19:46  "AgentVMThread" Id=128 RUNNABLE
00:19:46  	at java.math.BigInteger.implMulAdd(BigInteger.java:3050)
00:19:46  	at java.math.BigInteger.mulAdd(BigInteger.java:3020)
00:19:46  	at java.math.BigInteger.implSquareToLen(BigInteger.java:2093)
00:19:46  	at java.math.BigInteger.squareToLen(BigInteger.java:2014)
00:19:46  	at java.math.BigInteger.implMontgomerySquare(BigInteger.java:2715)
00:19:46  	at java.math.BigInteger.montgomerySquare(BigInteger.java:2674)
00:19:46  	at java.math.BigInteger.oddModPow(BigInteger.java:2942)
00:19:46  	at java.math.BigInteger.modPow(BigInteger.java:2605)
00:19:46  	at java.math.BigInteger.passesMillerRabin(BigInteger.java:1038)
00:19:46  	at java.math.BigInteger.primeToCertainty(BigInteger.java:894)
00:19:46  	at java.math.BitSieve.retrieve(BitSieve.java:203)
00:19:46  	at java.math.BigInteger.largePrime(BigInteger.java:771)
00:19:46  	at java.math.BigInteger.probablePrime(BigInteger.java:701)
00:19:46  	at sun.security.rsa.RSAKeyPairGenerator.generateKeyPair(RSAKeyPairGenerator.java:137)
00:19:46  	at java.security.KeyPairGenerator$Delegate.generateKeyPair(KeyPairGenerator.java:697)
00:19:46  	at java.security.KeyPairGenerator.genKeyPair(KeyPairGenerator.java:470)
00:19:46  	at Chain.runTest(Chain.java:214)
00:19:46  	at Chain.runTestPSS(Chain.java:181)
00:19:46  	at Chain.main(Chain.java:167)

@pshipton
Copy link
Member Author

@jasonkatonica do you think is this of concern, or just slow machines?

@jasonkatonica
Copy link
Contributor

jasonkatonica commented Jan 28, 2025

I did see this in the log posted above for the failing testcase:

java.security.SignatureException: Could not sign data
	at java.base/sun.security.rsa.RSASignature.engineSign(RSASignature.java:196)
	at java.base/java.security.Signature$Delegate.engineSign(Signature.java:1410)
	at java.base/java.security.Signature.sign(Signature.java:713)
	at java.base/java.security.SignedObject.sign(SignedObject.java:252)
	at java.base/java.security.SignedObject.<init>(SignedObject.java:168)
	at Chain.runTest(Chain.java:256)
	at Chain.lambda$main$0(Chain.java:183)
	at java.base/java.util.stream.MatchOps$1MatchSink.accept(MatchOps.java:90)
	at java.base/java.util.Spliterators$ArraySpliterator.tryAdvance(Spliterators.java:1034)
	at java.base/java.util.stream.ReferencePipeline.forEachWithCancel(ReferencePipeline.java:129)
	at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:540)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:526)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:512)
	at java.base/java.util.stream.MatchOps$MatchOp.evaluateSequential(MatchOps.java:230)
	at java.base/java.util.stream.MatchOps$MatchOp.evaluateSequential(MatchOps.java:196)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:239)
	at java.base/java.util.stream.ReferencePipeline.allMatch(ReferencePipeline.java:637)
	at Chain.main(Chain.java:183)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:586)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.Thread.run(Thread.java:1595)
Caused by: javax.crypto.BadPaddingException: RSA private key operation failed
	at java.base/sun.security.rsa.NativeRSACore.crtCrypt_Native(NativeRSACore.java:149)
	at java.base/sun.security.rsa.NativeRSACore.rsa(NativeRSACore.java:91)
	at java.base/sun.security.rsa.RSACore.rsa(RSACore.java:150)
	at java.base/sun.security.rsa.RSASignature.engineSign(RSASignature.java:193)
	... 21 more

This seem similar to the issue reported at #20915

It seems that there is some sort of issue prevalent on s390x for RSA signatures.

@JinhangZhang has attempted to recreate issue #20915 on failing machines and also on various other linux on z machines without any luck so far. We did see that timeout occur but it wasnt clear to me if we hit the timeout or if we are randomly receiving signature failures from the RSA signature code on this platform.

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_s390x_linux_Nightly_testList_2/422 - rh8-390-2
jdk_security1_0
java/security/SignedObject/Chain.java

07:43:35  "AgentVMThread" Id=148 RUNNABLE
07:43:35  	at java.math.BigInteger.addOne(BigInteger.java:3070)
07:43:35  	at java.math.BigInteger.implSquareToLen(BigInteger.java:2094)
07:43:35  	at java.math.BigInteger.squareToLen(BigInteger.java:2014)
07:43:35  	at java.math.BigInteger.implMontgomerySquare(BigInteger.java:2715)
07:43:35  	at java.math.BigInteger.montgomerySquare(BigInteger.java:2674)
07:43:35  	at java.math.BigInteger.oddModPow(BigInteger.java:2942)
07:43:35  	at java.math.BigInteger.modPow(BigInteger.java:2605)
07:43:35  	at java.math.BigInteger.passesMillerRabin(BigInteger.java:1038)
07:43:35  	at java.math.BigInteger.primeToCertainty(BigInteger.java:894)
07:43:35  	at java.math.BitSieve.retrieve(BitSieve.java:203)
07:43:35  	at java.math.BigInteger.largePrime(BigInteger.java:771)
07:43:35  	at java.math.BigInteger.probablePrime(BigInteger.java:701)
07:43:35  	at sun.security.rsa.RSAKeyPairGenerator.generateKeyPair(RSAKeyPairGenerator.java:140)
07:43:35  	at java.security.KeyPairGenerator$Delegate.generateKeyPair(KeyPairGenerator.java:697)
07:43:35  	at java.security.KeyPairGenerator.genKeyPair(KeyPairGenerator.java:470)
07:43:35  	at Chain.runTest(Chain.java:215)
07:43:35  	at Chain.runTestPSS(Chain.java:181)
07:43:35  	at Chain.main(Chain.java:167)

Chain.jtr.txt

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

No branches or pull requests

2 participants