search

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 721 forks source link

JDK21 jdk_security3_0_FAILED sun/security/pkcs11/sslecc/ClientJSSEServerJSSE.java Exception: Test 'Client JSSE - Server JSSE' failed #18846

Open JasonFengJ9 opened 9 months ago

JasonFengJ9 commented 9 months ago

Failure link

From an internal build(rhel8le-svl-rt6-1):

java version "21.0.2" 2024-01-16 LTS
IBM Semeru Runtime Certified Edition 21.0.2.0-rc3 (build 21.0.2+13-LTS)
Eclipse OpenJ9 VM 21.0.2.0-rc3 (build v0.43.0-release-220e78c65, JRE 21 Linux ppc64le-64-Bit Compressed References 20240116_89 (JIT enabled, AOT enabled)
OpenJ9   - 220e78c65
OMR      - ea8124dbc
JCL      - 9ac3d866bce based on jdk-21.0.2+13)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2024-01-26T01:56:05.524Z] variation: Mode150
[2024-01-26T01:56:05.524Z] JVM_OPTIONS:  -XX:+UseCompressedOops -Xverbosegclog 

[2024-01-26T02:20:59.456Z] TEST: sun/security/pkcs11/sslecc/ClientJSSEServerJSSE.java

[2024-01-26T02:20:59.470Z] STDERR:
[2024-01-26T02:20:59.470Z] WARNING: A terminally deprecated method in java.lang.System has been called
[2024-01-26T02:20:59.470Z] WARNING: System::setSecurityManager has been called by PKCS11Test (file:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_ppc64le_linux/aqa-tests/TKG/output_17062302419784/jdk_security3_0/work/classes/1/sun/security/pkcs11/sslecc/ClientJSSEServerJSSE.d/)
[2024-01-26T02:20:59.470Z] WARNING: Please consider reporting this to the maintainers of PKCS11Test
[2024-01-26T02:20:59.470Z] WARNING: System::setSecurityManager will be removed in a future release
[2024-01-26T02:20:59.470Z] java.io.IOException: Invalid response: HTTP/1.0 200Àï›F)ç¶
[2024-01-26T02:20:59.470Z]  at CipherTest$Client.sendRequest(CipherTest.java:281)
[2024-01-26T02:20:59.470Z]  at JSSEClient.runTest(JSSEClient.java:74)
[2024-01-26T02:20:59.470Z]  at CipherTest$Client.run(CipherTest.java:252)
[2024-01-26T02:20:59.470Z]  at java.base/java.lang.Thread.run(Thread.java:1595)
[2024-01-26T02:20:59.470Z] java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***
[2024-01-26T02:20:59.470Z]  at CipherTest.run(CipherTest.java:209)
[2024-01-26T02:20:59.470Z]  at CipherTest.main(CipherTest.java:337)
[2024-01-26T02:20:59.470Z]  at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:67)
[2024-01-26T02:20:59.470Z]  at PKCS11Test.premain(PKCS11Test.java:870)
[2024-01-26T02:20:59.470Z]  at PKCS11Test.testNSS(PKCS11Test.java:486)
[2024-01-26T02:20:59.470Z]  at PKCS11Test.main(PKCS11Test.java:186)
[2024-01-26T02:20:59.470Z]  at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:57)
[2024-01-26T02:20:59.470Z]  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
[2024-01-26T02:20:59.470Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:586)
[2024-01-26T02:20:59.470Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
[2024-01-26T02:20:59.470Z]  at java.base/java.lang.Thread.run(Thread.java:1595)
[2024-01-26T02:20:59.470Z] 
[2024-01-26T02:20:59.470Z] JavaTest Message: Test threw exception: java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***

[2024-01-26T02:20:59.471Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***
[2024-01-26T02:20:59.471Z] --------------------------------------------------
[2024-01-26T03:16:26.846Z] Test results: passed: 918; failed: 1
[2024-01-26T03:16:39.328Z] Report written to /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_ppc64le_linux/aqa-tests/TKG/output_17062302419784/jdk_security3_0/report/html/report.html
[2024-01-26T03:16:39.328Z] Results written to /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_ppc64le_linux/aqa-tests/TKG/output_17062302419784/jdk_security3_0/work
[2024-01-26T03:16:39.328Z] Error: Some tests failed or other problems occurred.
[2024-01-26T03:16:39.328Z] -----------------------------------
[2024-01-26T03:16:39.328Z] jdk_security3_0_FAILED

50x internal grinder - 20/50 failed

JasonFengJ9 commented 9 months ago

50x internal grinder - 20/50 failed

Reproduced the initial IOException: Invalid response:.

22:04:08  STDERR:
22:04:08  java.io.IOException: Invalid response: HTPj’ÜС“O÷ƒ³H;
22:04:08    at CipherTest$Client.sendRequest(CipherTest.java:281)
22:04:08    at JSSEClient.runTest(JSSEClient.java:74)
22:04:08    at CipherTest$Client.run(CipherTest.java:252)
22:04:08    at java.base/java.lang.Thread.run(Thread.java:1595)
22:04:08  java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***
22:04:08    at CipherTest.run(CipherTest.java:209)
22:04:08    at CipherTest.main(CipherTest.java:337)
22:04:08    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:67)
22:04:08    at PKCS11Test.premain(PKCS11Test.java:870)
22:04:08    at PKCS11Test.testNSS(PKCS11Test.java:486)
22:04:08    at PKCS11Test.main(PKCS11Test.java:186)
22:04:08    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:57)
22:04:08    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
22:04:08    at java.base/java.lang.reflect.Method.invoke(Method.java:586)
22:04:08    at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
22:04:08    at java.base/java.lang.Thread.run(Thread.java:1595)

Also PKCS11Exception: CKR_ENCRYPTED_DATA_INVALID

18:48:17  Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ENCRYPTED_DATA_INVALID
18:48:17    at jdk.crypto.cryptoki/sun.security.pkcs11.P11AEADCipher.implDoFinal(P11AEADCipher.java:770)
18:48:17    ... 15 more
18:48:17    at jdk.crypto.cryptoki/sun.security.pkcs11.P11AEADCipher.implDoFinal(P11AEADCipher.java:785)
18:48:17    at jdk.crypto.cryptoki/sun.security.pkcs11.P11AEADCipher.engineDoFinal(P11AEADCipher.java:605)
18:48:17    at java.base/javax.crypto.Cipher.doFinal(Cipher.java:2543)
18:48:17    at java.base/sun.security.ssl.SSLCipher$T12CC20P1305ReadCipherGenerator$CC20P1305ReadCipher.decrypt(SSLCipher.java:2169)
18:48:17    at java.base/sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(SSLSocketInputRecord.java:264)
18:48:17    at java.base/sun.security.ssl.SSLSocketInputRecord.decode(SSLSocketInputRecord.java:181)
18:48:17    at java.base/sun.security.ssl.SSLTransport.decode(SSLTransport.java:111)
18:48:17    ... 9 more
18:48:17  Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ENCRYPTED_DATA_INVALID
18:48:17  java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***
18:48:17    at jdk.crypto.cryptoki/sun.security.pkcs11.P11AEADCipher.implDoFinal(P11AEADCipher.java:770)
18:48:17    ... 15 more
18:48:17    at CipherTest.run(CipherTest.java:209)
18:48:17    at CipherTest.main(CipherTest.java:337)
18:48:17    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:67)
18:48:17    at PKCS11Test.premain(PKCS11Test.java:870)
18:48:17    at PKCS11Test.testNSS(PKCS11Test.java:486)
18:48:17    at PKCS11Test.main(PKCS11Test.java:186)
18:48:17    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:57)
18:48:17    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
18:48:17    at java.base/java.lang.reflect.Method.invoke(Method.java:586)
18:48:17    at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
18:48:17    at java.base/java.lang.Thread.run(Thread.java:1595)
18:48:17  
18:48:17  JavaTest Message: Test threw exception: java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***

SocketException: Socket is closed

20:14:36  javax.net.ssl|WARNING|A1|Client 2|2024-01-29 17:14:22.713 PST|SSLSocketImpl.java:576|SSLSocket duplex close failed. Debug info only. Exception details: (
20:14:36  "throwable" : {
20:14:36    java.net.SocketException: Socket is closed
20:14:36        at java.base/java.net.Socket.shutdownInput(Socket.java:1756)
20:14:36        at java.base/sun.security.ssl.BaseSSLSocketImpl.shutdownInput(BaseSSLSocketImpl.java:224)
20:14:36        at java.base/sun.security.ssl.SSLSocketImpl.shutdownInput(SSLSocketImpl.java:850)
20:14:36        at java.base/sun.security.ssl.SSLSocketImpl.bruteForceCloseInput(SSLSocketImpl.java:799)
20:14:36        at java.base/sun.security.ssl.SSLSocketImpl.duplexCloseOutput(SSLSocketImpl.java:664)
20:14:36        at java.base/sun.security.ssl.SSLSocketImpl.close(SSLSocketImpl.java:584)
20:14:36        at JSSEClient.runTest(JSSEClient.java:108)
20:14:36        at CipherTest$Client.run(CipherTest.java:252)
20:14:36        at java.base/java.lang.Thread.run(Thread.java:1595)}
20:14:36  
20:14:36  )
20:14:36  java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***

50x grinder w/ RI

JasonFengJ9 commented 9 months ago

Similar failures occurred w/ RI

09:11:43  openjdk version "21.0.2" 2024-01-16 LTS
09:11:43  OpenJDK Runtime Environment Temurin-21.0.2+13 (build 21.0.2+13-LTS)
09:11:43  OpenJDK 64-Bit Server VM Temurin-21.0.2+13 (build 21.0.2+13-LTS, mixed mode, sharing)

09:01:55  Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ENCRYPTED_DATA_INVALID
09:01:55    at jdk.crypto.cryptoki/sun.security.pkcs11.wrapper.PKCS11.C_Decrypt(Native Method)
09:01:55    at jdk.crypto.cryptoki/sun.security.pkcs11.P11AEADCipher.implDoFinal(P11AEADCipher.java:770)
09:01:55    ... 14 more
09:01:55  java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***
09:01:55    at CipherTest.run(CipherTest.java:209)
09:01:55    at CipherTest.main(CipherTest.java:337)
09:01:55    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:67)
09:01:55    at PKCS11Test.premain(PKCS11Test.java:870)
09:01:55    at PKCS11Test.testNSS(PKCS11Test.java:486)
09:01:55    at PKCS11Test.main(PKCS11Test.java:186)
09:01:55    at ClientJSSEServerJSSE.main(ClientJSSEServerJSSE.java:57)
09:01:55    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
09:01:55    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
09:01:55    at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
09:01:55    at java.base/java.lang.Thread.run(Thread.java:1583)
09:01:55  
09:01:55  JavaTest Message: Test threw exception: java.lang.Exception: *** Test 'Client JSSE - Server JSSE' failed ***

This is not an OpenJ9 JVM issue.