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.

Sign up for GitHub

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

Jump to bottom

JDK8 jdk_security3_0_FAILED Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: 0xCE534351 #15663

Open
JasonFengJ9 opened this issue Aug 4, 2022 · 14 comments
Open

JDK8 jdk_security3_0_FAILED Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: 0xCE534351 #15663

JasonFengJ9 opened this issue Aug 4, 2022 · 14 comments
Labels
comp:crypto comp:jclextensions test failure

Comments

@JasonFengJ9
Copy link
Member

Failure link

From an internal build(rhel9x86-rt3-1):

openjdk version "1.8.0_345"
IBM Semeru Runtime Open Edition (build 1.8.0_345-b01)
Eclipse OpenJ9 VM (build openj9-0.33.0-rc1a, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20220804_442 (JIT enabled, AOT enabled)
OpenJ9   - 04a55b45b
OMR      - b58aa2708
JCL      - a0f6d36aea based on jdk8u345-b01)

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

Optional info

Failure output (captured from console output)

[2022-08-04T03:13:32.899Z] variation: Mode150
[2022-08-04T03:13:32.899Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2022-08-04T03:20:47.852Z] TEST: sun/security/pkcs11/Cipher/CancelMultipart.java

[2022-08-04T03:20:47.853Z] STDERR:
[2022-08-04T03:20:47.853Z] java.lang.reflect.InvocationTargetException
[2022-08-04T03:20:47.853Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[2022-08-04T03:20:47.853Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
[2022-08-04T03:20:47.853Z] 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[2022-08-04T03:20:47.853Z] 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[2022-08-04T03:20:47.853Z] 	at PKCS11Test.getSunPKCS11(PKCS11Test.java:108)
[2022-08-04T03:20:47.853Z] 	at PKCS11Test.testNSS(PKCS11Test.java:486)
[2022-08-04T03:20:47.853Z] 	at PKCS11Test.main(PKCS11Test.java:156)
[2022-08-04T03:20:47.853Z] 	at CancelMultipart.main(CancelMultipart.java:113)
[2022-08-04T03:20:47.853Z] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-08-04T03:20:47.853Z] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-08-04T03:20:47.853Z] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-08-04T03:20:47.853Z] 	at java.lang.reflect.Method.invoke(Method.java:498)
[2022-08-04T03:20:47.853Z] 	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-08-04T03:20:47.853Z] 	at java.lang.Thread.run(Thread.java:827)
[2022-08-04T03:20:47.853Z] Caused by: java.security.ProviderException: Initialization failed
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:376)
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:103)
[2022-08-04T03:20:47.853Z] 	... 14 more
[2022-08-04T03:20:47.853Z] Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: 0xCE534351
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.wrapper.PKCS11.C_Initialize(Native Method)
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.wrapper.PKCS11$SynchronizedPKCS11.C_Initialize(PKCS11.java:1627)
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.wrapper.PKCS11.getInstance(PKCS11.java:163)
[2022-08-04T03:20:47.853Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:330)
[2022-08-04T03:20:47.853Z] 	... 15 more

....

[2022-08-04T03:50:26.553Z] Test results: passed: 542; failed: 60
[2022-08-04T03:50:26.553Z] Report written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_x86-64_linux/jvmtest/openjdk/report/html/report.html
[2022-08-04T03:50:26.553Z] Results written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_x86-64_linux/aqa-tests/TKG/output_1659578151249/jdk_security3_0/work
[2022-08-04T03:50:26.553Z] Error: Some tests failed or other problems occurred.
[2022-08-04T03:50:26.553Z] 
[2022-08-04T03:50:26.553Z] jdk_security3_0_FAILED

15x internal grinder - jdk_security3_0
@pshipton
Copy link
Member

pshipton commented Aug 4, 2022

This seems like a machine problem.

@pshipton
Copy link
Member

pshipton commented Aug 4, 2022

In the grinder 4 machines passed (cent7x64-1-9, ub18x64rt1-9, ub20x64rt1-4, cent7x64-1-5), one failed rhel9x86-rt1-1. The original failures were on rhel9x86-rt3-1. Maybe related to rhel9?

Seem to be https://bugs.openjdk.org/browse/JDK-8282538 which is fixed in Java 11.0.17+1, 17.0.5+1, 19, i.e. the next set of releases. We have 17.0.5+1 already, but 11.0.17+1 is blocked on #15664

@JasonFengJ9
Copy link
Member Author

A similar internal failure (rhel9s390xrt-2) - another rhel9

openjdk version "1.8.0_352"
IBM Semeru Runtime Open Edition (build 1.8.0_352-b01)
Eclipse OpenJ9 VM (build master-1719d2e01, JRE 1.8.0 Linux s390x-64-Bit Compressed References 20220826_434 (JIT enabled, AOT enabled)
OpenJ9   - 1719d2e01
OMR      - 938f0686f
JCL      - f2a9dfa9c based on jdk8u352-b01)

[2022-08-28T13:13:59.148Z] variation: Mode150
[2022-08-28T13:13:59.148Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2022-08-28T13:52:52.573Z] TEST: sun/security/tools/keytool/autotest.sh

[2022-08-28T13:52:52.573Z] ERR is:
[2022-08-28T13:52:52.573Z] 
[2022-08-28T13:52:52.573Z] OUT is:
[2022-08-28T13:52:52.573Z] keytool error: java.io.IOException: load failed
[2022-08-28T13:52:52.573Z] 
[2022-08-28T13:52:52.573Z] Exception in thread "main" java.io.IOException: load failed
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.P11KeyStore.engineLoad(P11KeyStore.java:764)
[2022-08-28T13:52:52.573Z] 	at java.security.KeyStore.load(KeyStore.java:1445)
[2022-08-28T13:52:52.573Z] 	at sun.security.tools.keytool.Main.doCommands(Main.java:869)
[2022-08-28T13:52:52.573Z] 	at sun.security.tools.keytool.Main.run(Main.java:378)
[2022-08-28T13:52:52.573Z] 	at sun.security.tools.keytool.Main.main(Main.java:371)
[2022-08-28T13:52:52.573Z] 	at KeyToolTest.test(KeyToolTest.java:159)
[2022-08-28T13:52:52.573Z] 	at KeyToolTest.test(KeyToolTest.java:127)
[2022-08-28T13:52:52.573Z] 	at KeyToolTest.testOK(KeyToolTest.java:182)
[2022-08-28T13:52:52.573Z] 	at KeyToolTest.testPKCS11(KeyToolTest.java:525)
[2022-08-28T13:52:52.573Z] 	at KeyToolTest.main(KeyToolTest.java:1345)
[2022-08-28T13:52:52.573Z] Caused by: javax.security.auth.login.LoginException
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.SunPKCS11.login(SunPKCS11.java:1466)
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.P11KeyStore.login(P11KeyStore.java:864)
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.P11KeyStore.engineLoad(P11KeyStore.java:751)
[2022-08-28T13:52:52.573Z] 	... 9 more
[2022-08-28T13:52:52.573Z] Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_USER_TYPE_INVALID
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.wrapper.PKCS11.C_Login(Native Method)
[2022-08-28T13:52:52.573Z] 	at sun.security.pkcs11.SunPKCS11.login(SunPKCS11.java:1450)
[2022-08-28T13:52:52.573Z] 	... 11 more

[2022-08-28T13:52:52.574Z] TEST RESULT: Failed. Execution failed: exit code 1
[2022-08-28T13:52:52.574Z] --------------------------------------------------
[2022-08-28T13:58:35.640Z] Test results: passed: 601; failed: 1
[2022-08-28T13:58:35.640Z] Report written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_s390x_linux/aqa-tests/TKG/output_16616889022357/jdk_security3_0/report/html/report.html
[2022-08-28T13:58:35.640Z] Results written to /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_s390x_linux/aqa-tests/TKG/output_16616889022357/jdk_security3_0/work
[2022-08-28T13:58:35.640Z] Error: Some tests failed or other problems occurred.
[2022-08-28T13:58:35.640Z] 
[2022-08-28T13:58:35.640Z] jdk_security3_0_FAILED

@pshipton
Copy link
Member

We probably need to backport https://bugs.openjdk.org/browse/JDK-8282538 to jdk8.

@pshipton
Copy link
Member

pshipton commented Aug 30, 2022 •
edited
Loading

Seems it should already be backported via https://bugs.openjdk.org/browse/JDK-8290076, but we don't have this change as of jdk8u352-b04

@pshipton
Copy link
Member

pshipton commented Sep 13, 2022 •
edited
Loading

The change is actually in jdk8u352-b01, but this is the build that failed. We should try again on the latest (b05) to see if it's still failing.
ibmruntimes/openj9-openjdk-jdk8@612208ee2ba

sun/security/pkcs11/Cipher/CancelMultipart.java on rhel9x86-rt2-1 grinder (head) - passed
sun/security/tools/keytool/autotest.sh on rhel9x86-rt2-1 grinder (head) - still fails, but passed on another machine (ub18x64rt1-1)

@pshipton pshipton mentioned this issue Sep 15, 2022
Open
@pshipton
Copy link
Member

Created #15902 for #15663 (comment), closing this one as resolved.

@JasonFengJ9
Copy link
Member Author

JDK8 x86-64_linux 0.41 milestone 1(rhel9x86-svl-rt5-1)

openjdk version "1.8.0_392"
IBM Semeru Runtime Open Edition (build 1.8.0_392-b03)
Eclipse OpenJ9 VM (build v0.41.0-release-87d042a68, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20230906_749 (JIT enabled, AOT enabled)
OpenJ9   - 87d042a68
OMR      - fa7b6ddc7
JCL      - 04ddaa8f70 based on jdk8u392-b03)

[2023-09-06T20:49:57.497Z] variation: Mode150
[2023-09-06T20:49:57.497Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2023-09-06T21:00:47.712Z] TEST: sun/security/pkcs11/Provider/Login.sh

[2023-09-06T21:00:47.712Z] Exception in thread "main" java.lang.reflect.InvocationTargetException
[2023-09-06T21:00:47.712Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[2023-09-06T21:00:47.712Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
[2023-09-06T21:00:47.712Z] 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[2023-09-06T21:00:47.712Z] 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[2023-09-06T21:00:47.712Z] 	at PKCS11Test.getSunPKCS11(PKCS11Test.java:108)
[2023-09-06T21:00:47.712Z] 	at PKCS11Test.testNSS(PKCS11Test.java:486)
[2023-09-06T21:00:47.712Z] 	at PKCS11Test.main(PKCS11Test.java:156)
[2023-09-06T21:00:47.712Z] 	at PKCS11Test.main(PKCS11Test.java:137)
[2023-09-06T21:00:47.712Z] 	at Login.main(Login.java:39)
[2023-09-06T21:00:47.712Z] Caused by: java.security.ProviderException: Initialization failed
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:427)
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:131)
[2023-09-06T21:00:47.712Z] 	... 9 more
[2023-09-06T21:00:47.712Z] Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: 0xCE534351
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.wrapper.PKCS11.C_Initialize(Native Method)
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.wrapper.PKCS11$SynchronizedPKCS11.C_Initialize(PKCS11.java:1693)
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.wrapper.PKCS11.getInstance(PKCS11.java:229)
[2023-09-06T21:00:47.712Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:358)
[2023-09-06T21:00:47.712Z] 	... 10 more

[2023-09-06T21:40:06.631Z] jdk_security3_0_FAILED

50x jdk_security3_0 internal grinder

@JasonFengJ9 JasonFengJ9 reopened this Sep 8, 2023
@pshipton
Copy link
Member

pshipton commented Sep 8, 2023

Failing on rhel9, the grinder failed on rhel9x86-svl-rt4-1. Not an OpenJ9 issue, either JCL or machine setup.

@ThanHenderson ThanHenderson mentioned this issue Dec 4, 2023
Merged
@JasonFengJ9
Copy link
Member Author

JasonFengJ9 commented Mar 25, 2024 •
edited
Loading

JDK8 ppc64le_linux(rhel9lert-2)

openjdk version "1.8.0_412"
IBM Semeru Runtime Open Edition (build 1.8.0_412-b06)
Eclipse OpenJ9 VM (build v0.44.0-release-218cf6016, JRE 1.8.0 Linux ppc64le-64-Bit Compressed References 20240321_874 (JIT enabled, AOT enabled)
OpenJ9   - 218cf6016
OMR      - 254af5a04
JCL      - 27b33e9312 based on jdk8u412-b06)

[2024-03-21T21:20:18.096Z] variation: Mode150
[2024-03-21T21:20:18.096Z] JVM_OPTIONS:  -XX:+UseCompressedOops -Xverbosegclog 

[2024-03-21T21:25:39.812Z] TEST: sun/security/pkcs11/Provider/Login.sh

[2024-03-21T21:25:39.812Z] STDERR:
[2024-03-21T21:25:39.812Z] Note: /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_ppc64le_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/jdk/test/sun/security/pkcs11/Provider/Login.java uses or overrides a deprecated API.
[2024-03-21T21:25:39.812Z] Note: Recompile with -Xlint:deprecation for details.
[2024-03-21T21:25:39.812Z] Note: /home/jenkins/workspace/Test_openjdk8_j9_extended.openjdk_ppc64le_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/jdk/test/sun/security/pkcs11/Provider/../PKCS11Test.java uses unchecked or unsafe operations.
[2024-03-21T21:25:39.812Z] Note: Recompile with -Xlint:unchecked for details.
[2024-03-21T21:25:39.812Z] Exception in thread "main" java.lang.reflect.InvocationTargetException
[2024-03-21T21:25:39.812Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[2024-03-21T21:25:39.812Z] 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
[2024-03-21T21:25:39.812Z] 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[2024-03-21T21:25:39.812Z] 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[2024-03-21T21:25:39.812Z] 	at PKCS11Test.getSunPKCS11(PKCS11Test.java:108)
[2024-03-21T21:25:39.812Z] 	at PKCS11Test.testNSS(PKCS11Test.java:486)
[2024-03-21T21:25:39.812Z] 	at PKCS11Test.main(PKCS11Test.java:156)
[2024-03-21T21:25:39.812Z] 	at PKCS11Test.main(PKCS11Test.java:137)
[2024-03-21T21:25:39.812Z] 	at Login.main(Login.java:39)
[2024-03-21T21:25:39.812Z] Caused by: java.security.ProviderException: Initialization failed
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:427)
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:131)
[2024-03-21T21:25:39.812Z] 	... 9 more
[2024-03-21T21:25:39.812Z] Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: 0xCE534351
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.wrapper.PKCS11.C_Initialize(Native Method)
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.wrapper.PKCS11$SynchronizedPKCS11.C_Initialize(PKCS11.java:1693)
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.wrapper.PKCS11.getInstance(PKCS11.java:229)
[2024-03-21T21:25:39.812Z] 	at sun.security.pkcs11.SunPKCS11.<init>(SunPKCS11.java:358)
[2024-03-21T21:25:39.812Z] 	... 10 more

[2024-03-21T21:25:39.813Z] TEST RESULT: Failed. Execution failed: exit code 1

[2024-03-21T21:42:02.337Z] jdk_security3_0_FAILED

50x internal grinder - #15663 (comment)

@pshipton
Copy link
Member

@jasonkatonica fyi

@taoliult
Copy link
Contributor

taoliult commented Apr 1, 2024

At line 486 of PKCS11Test.java, as below:

[2024-03-21T21:25:39.812Z] at PKCS11Test.testNSS(PKCS11Test.java:486)

        String customConfig = System.getProperty("CUSTOM_P11_CONFIG");
        String customConfigName = System.getProperty("CUSTOM_P11_CONFIG_NAME", "p11-nss.txt");
        String p11config = (customConfig != null) ?
                                customConfig :
                                base + SEP + "nss" + SEP + customConfigName;

        System.setProperty("pkcs11test.nss.lib", libfile);
        System.setProperty("pkcs11test.nss.db", dbdir);
        Provider p = getSunPKCS11(p11config);                --- Line 486

It tried to initialize the SunPKCS11 using the configure file. If the test failed during FIPS testing, that is expected, because in FIPS mode, SunPKCS11 will be initialized using the FIPS nss.fips.cfg. And it can't be initialized again in the tests. So, the Initialization failed will happen.

If the test failed but not in FIPS testing, does this failure happens all the time, or failed intermittently?

@pshipton
Copy link
Member

pshipton commented Apr 1, 2024

non-FIPS testing. The most recent failure is in a test run that doesn't have any TEST_FLAG set. It's likely intermittent or specific to a machine. @JasonFengJ9 pls run a grinder.

@JasonFengJ9
Copy link
Member Author

50x internal grinder

Passed at ubu20le-rtp-rt7-1, sles15le-svl-rt5-1, and sles15le-svl-rt8-1.
Failed at rhel8le-svl-rt7-1 and cent8le-rtp-rt3-1 with a known failure

The original error PKCS11Exception: 0xCE534351 wasn't reproduced.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
comp:crypto comp:jclextensions test failure
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@JasonFengJ9 @pshipton @taoliult