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.27k stars 721 forks source link

jdk_security3_0_FAILED InvalidKeyException: Key must not be null & KeyStoreException: Cannot store non-PrivateKeys #15221

Open JasonFengJ9 opened 2 years ago

JasonFengJ9 commented 2 years ago

Failure link

From an internal build (ub20x64rt1-3):

openjdk version "1.8.0_342"
IBM Semeru Runtime Open Edition (build 1.8.0_342-b03)
Eclipse OpenJ9 VM (build v0.33.0-release-bf978d503, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20220602_396 (JIT enabled, AOT enabled)
OpenJ9   - bf978d503
OMR      - e7d85499b
JCL      - b43a04972a based on jdk8u342-b03)

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

Optional info

Failure output (captured from console output)

[2022-06-02T20:13:58.406Z] Running test jdk_security3_0 ...
[2022-06-02T20:13:58.406Z] ===============================================
[2022-06-02T20:13:58.406Z] jdk_security3_0 Start Time: Thu Jun  2 13:13:58 2022 Epoch Time (ms): 1654200838176

[2022-06-02T20:13:58.406Z] variation: Mode150
[2022-06-02T20:13:58.406Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2022-06-02T20:22:59.925Z] TEST: sun/security/pkcs11/Secmod/GetPrivateKey.java

16:22:59  ACTION: main -- Failed. Execution failed: `main' threw exception: java.security.InvalidKeyException: Key must not be null
16:22:59  REASON: User specified action: run main/othervm GetPrivateKey 
16:22:59  TIME:   0.295 seconds
16:22:59  messages:
16:22:59  command: main GetPrivateKey
16:22:59  reason: User specified action: run main/othervm GetPrivateKey 
16:22:59  Mode: othervm [/othervm specified]
16:22:59  elapsed time (seconds): 0.295
16:22:59  configuration:
16:22:59  STDOUT:
16:22:59  libsoftokn3 version = 3.491.  ECC Basic.
16:22:59  SunPKCS11-NSSKeyStore version 1.8
16:22:59  entries: 0
16:22:59  []
16:22:59  null
16:22:59  Signing...
[2022-06-02T20:22:59.926Z] STDERR:
[2022-06-02T20:22:59.926Z] java.security.InvalidKeyException: Key must not be null
[2022-06-02T20:22:59.926Z]  at sun.security.rsa.RSAKeyFactory.toRSAKey(RSAKeyFactory.java:119)
[2022-06-02T20:22:59.926Z]  at sun.security.rsa.RSASignature.engineInitSign(RSASignature.java:111)
[2022-06-02T20:22:59.926Z]  at sun.security.rsa.RSASignature.engineInitSign(RSASignature.java:103)
[2022-06-02T20:22:59.926Z]  at java.security.Signature$Delegate.tryOperation(Signature.java:1286)
[2022-06-02T20:22:59.926Z]  at java.security.Signature$Delegate.chooseProvider(Signature.java:1234)
[2022-06-02T20:22:59.926Z]  at java.security.Signature$Delegate.engineInitSign(Signature.java:1332)
[2022-06-02T20:22:59.926Z]  at java.security.Signature.initSign(Signature.java:621)
[2022-06-02T20:22:59.926Z]  at GetPrivateKey.main(GetPrivateKey.java:79)
[2022-06-02T20:22:59.926Z]  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-06-02T20:22:59.926Z]  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-06-02T20:22:59.926Z]  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-06-02T20:22:59.926Z]  at java.lang.reflect.Method.invoke(Method.java:498)
[2022-06-02T20:22:59.926Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-06-02T20:22:59.926Z]  at java.lang.Thread.run(Thread.java:827)
[2022-06-02T20:22:59.926Z] 
[2022-06-02T20:22:59.926Z] JavaTest Message: Test threw exception: java.security.InvalidKeyException: Key must not be null

[2022-06-02T20:22:59.926Z] TEST: sun/security/pkcs11/Secmod/JksSetPrivateKey.java

16:22:59  ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.IllegalArgumentException: Private key must be accompanied by certificate chain
16:22:59  REASON: User specified action: run main/othervm JksSetPrivateKey 
16:22:59  TIME:   0.273 seconds
16:22:59  messages:
16:22:59  command: main JksSetPrivateKey
16:22:59  reason: User specified action: run main/othervm JksSetPrivateKey 
16:22:59  Mode: othervm [/othervm specified]
16:22:59  elapsed time (seconds): 0.273
16:22:59  configuration:
16:22:59  STDOUT:
16:22:59  libsoftokn3 version = 3.491.  ECC Basic.
16:22:59  SunPKCS11-NSSKeyStore version 1.8
16:22:59  entries: 0
16:22:59  []
16:22:59  null
[2022-06-02T20:22:59.927Z] STDERR:
[2022-06-02T20:22:59.927Z] java.security.KeyStoreException: Cannot store non-PrivateKeys
[2022-06-02T20:22:59.927Z] java.lang.IllegalArgumentException: Private key must be accompanied by certificate chain
[2022-06-02T20:22:59.927Z]  at java.security.KeyStore.setKeyEntry(KeyStore.java:1136)
[2022-06-02T20:22:59.927Z]  at JksSetPrivateKey.main(JksSetPrivateKey.java:86)
[2022-06-02T20:22:59.927Z]  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-06-02T20:22:59.927Z]  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-06-02T20:22:59.927Z]  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-06-02T20:22:59.927Z]  at java.lang.reflect.Method.invoke(Method.java:498)
[2022-06-02T20:22:59.927Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-06-02T20:22:59.927Z]  at java.lang.Thread.run(Thread.java:827)
[2022-06-02T20:22:59.927Z] 
[2022-06-02T20:22:59.927Z] JavaTest Message: Test threw exception: java.lang.IllegalArgumentException: Private key must be accompanied by certificate chain

[2022-06-02T21:07:52.131Z] Test results: passed: 603; failed: 2
[2022-06-02T21:07:52.131Z] Report written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_x86-64_linux/jvmtest/openjdk/report/html/report.html
[2022-06-02T21:07:52.131Z] Results written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_x86-64_linux/aqa-tests/TKG/output_16541956331725/jdk_security3_0/work
[2022-06-02T21:07:52.131Z] Error: Some tests failed or other problems occurred.
[2022-06-02T21:07:52.131Z] 
[2022-06-02T21:07:52.131Z] jdk_security3_0_FAILED

50x grinder - job/Grinder/24536/ & job/Grinder/24537/ - all passed

pshipton commented 2 years ago

These failures are occurring in the 0.33 M2 build, in both jdk_security3_0 and jdk_security3_1, on the same machine ub20x64rt1-3. /job/Test_openjdk8_j9_extended.openjdk_x86-64_linux/70/

Trying a single re-run of jdk_security3_0 in a grinder /job/Grinder/25726 (ubu22x86-rt2-1), which failed the same way.

Also this failure sun/security/pkcs11/KeyStore/SecretKeysBasic.sh

08:57:26  Running test with provider SunPKCS11-nss (security manager disabled) ...
08:57:26  softkey> javax.crypto.spec.SecretKeySpec@fffe81a3
08:57:26    ALGO=AES
08:57:26    [RAW] VALUE=6845FA82B7369647DCA94D80CB385FC3
08:57:26  skey1> SunPKCS11-nss DESede secret key, 168 bitssession object, not sensitive, extractable)
08:57:26    ALGO=DESede
08:57:26    [RAW] VALUE=341F51AD29704A7AA252C2C4A7583B315886DC34F264C2A8
08:57:26  skey2> SunPKCS11-nss DESede secret key, 168 bitssession object, not sensitive, extractable)
08:57:26    ALGO=DESede
08:57:26    [RAW] VALUE=790161028CDA9EE0919EB0B32A765D0D6BB6A82620D9C892
08:57:26  libsoftokn3 version not found, set to 0.0: /usr/lib/x86_64-linux-gnu/nss/libsoftokn3.so
08:57:26  libnss3 version not found, set to 0.0: /usr/lib/x86_64-linux-gnu/nss/libnss3.so
08:57:26  Number of entries: 0
08:57:26  Test against  nss  Failed!
08:57:26  STDERR:
08:57:26  java.io.FileNotFoundException: /usr/lib/x86_64-linux-gnu/nss/libnss3.so (No such file or directory)
08:57:26    at java.io.FileInputStream.open(FileInputStream.java:195)
08:57:26    at java.io.FileInputStream.<init>(FileInputStream.java:138)
08:57:26    at java.io.FileInputStream.<init>(FileInputStream.java:93)
08:57:26    at PKCS11Test.getNSSInfo(PKCS11Test.java:363)
08:57:26    at PKCS11Test.getLibnss3Version(PKCS11Test.java:329)
08:57:26    at SecretKeysBasic.doTest(SecretKeysBasic.java:144)
08:57:26    at SecretKeysBasic.main(SecretKeysBasic.java:84)
08:57:26    at PKCS11Test.premain(PKCS11Test.java:125)
08:57:26    at PKCS11Test.testNSS(PKCS11Test.java:487)
08:57:26    at PKCS11Test.main(PKCS11Test.java:156)
08:57:26    at PKCS11Test.main(PKCS11Test.java:137)
08:57:26    at SecretKeysBasic.main(SecretKeysBasic.java:47)
08:57:26  Exception in thread "main" java.security.ProviderException: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ATTRIBUTE_SENSITIVE
08:57:26    at sun.security.pkcs11.P11Key$P11SecretKey.getEncodedInternal(P11Key.java:470)
08:57:26    at sun.security.pkcs11.P11Key.getEncoded(P11Key.java:163)
08:57:26    at SecretKeysBasic.checkSecretKeyEntry(SecretKeysBasic.java:121)
08:57:26    at SecretKeysBasic.doTest(SecretKeysBasic.java:167)
08:57:26    at SecretKeysBasic.main(SecretKeysBasic.java:84)
08:57:26    at PKCS11Test.premain(PKCS11Test.java:125)
08:57:26    at PKCS11Test.testNSS(PKCS11Test.java:487)
08:57:26    at PKCS11Test.main(PKCS11Test.java:156)
08:57:26    at PKCS11Test.main(PKCS11Test.java:137)
08:57:26    at SecretKeysBasic.main(SecretKeysBasic.java:47)
08:57:26  Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ATTRIBUTE_SENSITIVE
08:57:26    at sun.security.pkcs11.P11Key$P11SecretKey.getEncodedInternal(P11Key.java:467)
08:57:26    ... 9 more
pshipton commented 2 years ago

Ran sun/security/pkcs11/Secmod/GetPrivateKey.java by itself (/job/Grinder/25729 - ub20x64rt1-5, /job/Grinder/25730 - ub20x64rt1-3) which passed.

pshipton commented 2 years ago

Running jdk_security3_0 using the 0.32 release build. GetPrivateKey.java & JksSetPrivateKey.java are still failing the same way. /job/Grinder/25731 - ub20x64rt3-8

pshipton commented 2 years ago

@alon-sh any ideas about these failures? They only seem to fail when the entire group jdk_security3 is run.

pshipton commented 2 years ago

Trying with -Djdk.nativeCrypto=false /job/Grinder/25737 - cent7x64-1-9 - passed /job/Grinder/25738 - ub18x64cudavm2 - passed /job/Grinder/25739 - ub20x64rt4-2 - failed

JasonFengJ9 commented 2 years ago

sun/security/pkcs11/KeyStore/SecretKeysBasic.sh failed with "PKCS11Exception: CKR_ATTRIBUTE_SENSITIVE" This test has been excluded for RI JDK8 - https://github.com/adoptium/aqa-tests/blob/55ffc854ffd54cd3ecca6b838a6d4ba3aea0440e/openjdk/excludes/ProblemList_openjdk8.txt#L295

RI JDK8 failed sun/security/pkcs11/Secmod/GetPrivateKey.java & sun/security/pkcs11/Secmod/JksSetPrivateKey.java as well - job/Grinder/25733/console - ub20x64rt3-9

Will create exclude PR.

alon-sh commented 2 years ago

@pshipton looks like nss cryptographic library is not installed properly on the machine. it cant find the shared lib.

rpm nss-3.67.0-7.el8_5.x86_64 or similar should be installed on the system. and yeah @JasonFengJ9 is right, the other tests should be excluded.

pshipton commented 2 years ago

Created infrastructure/issues/7098