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

JDK8 FIPS cmdLineTester_CryptoTest_0_FAILED Success condition was not found: [Output match: using native crypto library] #16902

Closed
JasonFengJ9 opened this issue Mar 13, 2023 · 37 comments

Comments

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Mar 13, 2023

Failure link

From an internal build(rhel8x64-fips1-1):

openjdk version "1.8.0_372"
IBM Semeru Runtime Open Edition (build 1.8.0_372-b03)
Eclipse OpenJ9 VM (build v0.38.0-release-25af2a240, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20230309_612 (JIT enabled, AOT enabled)
OpenJ9   - 25af2a240
OMR      - 008f97b5c
JCL      - a1cfd8750f based on jdk8u372-b03)

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

Optional info

Failure output (captured from console output)

[2023-03-10T07:26:11.739Z] variation: NoOptions
[2023-03-10T07:26:11.739Z] JVM_OPTIONS:   -Dsemeru.fips=true

[2023-03-10T07:26:11.739Z] TESTING:
[2023-03-10T07:26:12.159Z] *** Starting test suite: OpenSSL Tests ***
[2023-03-10T07:26:12.159Z] Testing: CryptoTest
[2023-03-10T07:26:12.159Z] Test start time: 2023/03/09 23:26:11 Pacific Standard Time
[2023-03-10T07:26:12.159Z] Running command: "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_0/openjdkbinary/j2sdk-image/bin/java"   -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true -cp "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/openssl/"openssltest.jar org.openj9.test.openssl.CryptoTest
[2023-03-10T07:26:12.159Z] Time spent starting: 43 milliseconds
[2023-03-10T07:26:12.598Z] Time spent executing: 324 milliseconds
[2023-03-10T07:26:12.598Z] Test result: FAILED
[2023-03-10T07:26:12.598Z] Output from test:
[2023-03-10T07:26:12.598Z]  [OUT] Crypto test COMPLETED
[2023-03-10T07:26:12.598Z] >> Success condition was not found: [Output match: using native crypto library]
[2023-03-10T07:26:12.598Z] >> Required condition was found: [Output match: Crypto test COMPLETED]
[2023-03-10T07:26:12.598Z] >> Failure condition was not found: [Output match: Native crypto library load failed]
[2023-03-10T07:26:12.598Z] >> Failure condition was not found: [Output match: Crypto test FAILED]
[2023-03-10T07:26:12.599Z] 
[2023-03-10T07:26:12.599Z] 
[2023-03-10T07:26:12.599Z] ---TEST RESULTS---
[2023-03-10T07:26:12.599Z] Number of PASSED tests: 0 out of 1
[2023-03-10T07:26:12.599Z] Number of FAILED tests: 1 out of 1
[2023-03-10T07:26:12.599Z] 
[2023-03-10T07:26:12.599Z] ---SUMMARY OF FAILED TESTS---
[2023-03-10T07:26:12.599Z] CryptoTest
[2023-03-10T07:26:12.599Z] -----------------------------
[2023-03-10T07:26:12.599Z] 
[2023-03-10T07:26:12.599Z] -----------------------------------
[2023-03-10T07:26:12.599Z] cmdLineTester_CryptoTest_0_FAILED

50x internal grinder - all failed

@JasonFengJ9
Copy link
Member Author

JDK 8 x86-64_linux_fips 0.38 m2 build

[2023-03-31T12:12:21.476Z] variation: NoOptions
[2023-03-31T12:12:21.476Z] JVM_OPTIONS:   -Dsemeru.fips=true

[2023-03-31T12:12:21.476Z] TESTING:
[2023-03-31T12:12:21.896Z] *** Starting test suite: OpenSSL Tests ***
[2023-03-31T12:12:21.896Z] Testing: CryptoTest
[2023-03-31T12:12:21.896Z] Test start time: 2023/03/31 05:12:21 Pacific Standard Time
[2023-03-31T12:12:21.896Z] Running command: "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_0/openjdkbinary/j2sdk-image/bin/java"   -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true -cp "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/openssl/"openssltest.jar org.openj9.test.openssl.CryptoTest
[2023-03-31T12:12:21.896Z] Time spent starting: 51 milliseconds
[2023-03-31T12:12:22.328Z] Time spent executing: 362 milliseconds
[2023-03-31T12:12:22.328Z] Test result: FAILED
[2023-03-31T12:12:22.328Z] Output from test:
[2023-03-31T12:12:22.328Z]  [OUT] Crypto test COMPLETED
[2023-03-31T12:12:22.328Z] >> Success condition was not found: [Output match: using native crypto library]
[2023-03-31T12:12:22.328Z] >> Required condition was found: [Output match: Crypto test COMPLETED]
[2023-03-31T12:12:22.328Z] >> Failure condition was not found: [Output match: Native crypto library load failed]
[2023-03-31T12:12:22.328Z] >> Failure condition was not found: [Output match: Crypto test FAILED]

@pshipton
Copy link
Member

pshipton commented Apr 3, 2023

@jasonkatonica this test does some simple crypto [1] with -Djdk.nativeCryptoTrace=true and expects to see using native crypto library in the output due to openssl being used [2]. Does using FIPS change the use of openssl? Do you know what changed in 0.38 to cause this test to start failing? I see it's failing the same in jdk11, but it passed for jdk17.

[1] https://github.com/eclipse-openj9/openj9/blob/master/test/functional/cmdLineTests/openssl/src/org/openj9/test/openssl/CryptoTest.java
[2] https://github.com/ibmruntimes/openj9-openjdk-jdk8/blob/openj9/closed/adds/jdk/src/share/classes/jdk/crypto/jniprovider/NativeCrypto.java#L138

@jasonkatonica
Copy link
Contributor

Hello @pshipton, When executing with the flag -Dsemeru.fips=true set the SunJCE provider, and its associated algorithms, are all currently disabled. This is because the crypto code in SunJCE, and some potential OpenSSL paths in SunJCE, are not FIPS certified.

I do not expect OpenSSL to be called at all in FIPS mode with the M2 build.

  • If tests are coded to explicitly call the SunJCE provider algorithms I would expect errors such as AlgorithmNotFound errors.
  • In the above case for CryptoTest.java, the code is using the default provider list for instantiation of the cipher. In this case I would expect the code to drive down into NSS libraries when running in FIPS mode to perform AES/GCM/NoPadding. If the system was not setup at all for PKCS11 FIPS testing I would expect other PKCS11 related errors since NSS would not be available and or configured.

@taoliult and @WilburZjh , let us know if you have thoughts otherwise :)

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

So the conclusion is the failure is expected. I'm not sure why we didn't see it in previous releases, but not sure it's worth trying to figure it out. My remaining question is why it's passing on jdk17.

Internal build - rhel8x64-fips3-1

[2023-04-03T17:46:37.015Z] Testing: CryptoTest
[2023-04-03T17:46:37.015Z] Test start time: 2023/04/03 10:46:31 Pacific Standard Time
[2023-04-03T17:46:37.015Z] Running command: "/home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_fips_testList_0/openjdkbinary/j2sdk-image/bin/java"   -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true -cp "/home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_fips_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/openssl/"openssltest.jar org.openj9.test.openssl.CryptoTest
[2023-04-03T17:46:37.015Z] Time spent starting: 67 milliseconds
[2023-04-03T17:46:37.015Z] Time spent executing: 873 milliseconds
[2023-04-03T17:46:37.015Z] Test result: PASSED

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

If you are not familiar with cmdlinetester, the conditions for passing/failing are

Passing if both using native crypto library and Crypto test COMPLETED are in the output.
Failing if it doesn't pass or Native crypto library load failed or Crypto test FAILED is in the output.

@WilburZjh
Copy link
Contributor

Hi @pshipton , Im investigating the exceptions, i will update shortly.

@jasonkatonica
Copy link
Contributor

It is worrisome that the Java 17 build is passing here. I would not expect OpenSSL to be driven there either in FIPS mode.

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

For reference, this is the output when running the test on a non-FIPS machine.

jdk-17/bin/java -Djdk.nativeCryptoTrace=true CryptoTest
MessageDigest native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Using OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021 (/lib64)
Native crypto library load succeeded - using native crypto library.
SunEC native crypto implementation enabled.
NativeChaCha20Cipher native crypto implementation enabled.
NativeGaloisCounterMode native crypto implementation enabled.
Crypto test COMPLETED

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

I enabled FIPS on my own machine and get the following in FIPS mode.

jdk-17/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Crypto test COMPLETED

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

I should have mentioned the previous was with an older open source head stream build.

Eclipse OpenJ9 VM (build master-13f9b4c3525, JRE 17 Linux amd64-64-Bit Compressed References 20230321_449 (JIT enabled, AOT enabled)
OpenJ9   - 13f9b4c3525
OMR      - 1a20c5d2b24
JCL      - 7c20b2891d2 based on jdk-17.0.7+5)

Using Semeru M2 I get the following.

jdk-17.0.7+5/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Using OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021 (/lib64)
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED
openjdk version "17.0.7" 2023-04-18
IBM Semeru Runtime Open Edition 17.0.7.0-m2 (build 17.0.7+5)
Eclipse OpenJ9 VM 17.0.7.0-m2 (build v0.38.0-release-353bdb06f, JRE 17 Linux amd64-64-Bit Compressed References 20230418_436 (JIT enabled, AOT enabled)
OpenJ9   - 353bdb06f
OMR      - 855813495
JCL      - 267a5a72c4a based on jdk-17.0.7+5)

ibmruntimes/openj9-openjdk-jdk17@7c20b28...267a5a7

One difference is the Java Restricted Security Mode
ibmruntimes/openj9-openjdk-jdk17#194

The Milestone 1 build seems fine.

jdk-17.0.7+2/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Crypto test COMPLETED

@taoliult
Copy link
Contributor

taoliult commented Apr 4, 2023

@pshipton
Looking at it, and will update soon.

@taoliult
Copy link
Contributor

taoliult commented Apr 4, 2023

This CryptoTest is quite simple, just get the cipher, initialize it using the secret key spec.

public class CryptoTest {
    public static void main(String[] args) {
        try {
            Cipher cipher = Cipher.getInstance("AES/GCM/NoPadding");
            Random r = new Random(10);
            byte[] skey_bytes = new byte[16];
            r.nextBytes(skey_bytes);
            SecretKeySpec skey = new SecretKeySpec(skey_bytes, "AES");
            cipher.init(Cipher.ENCRYPT_MODE, skey);
            System.out.println("Crypto test COMPLETED");
        } catch (Exception e) {
            System.out.println("Crypto test FAILED");
            e.printStackTrace();
        }
    }
}

The different between the FIPS and non-FIPS is, in FIPS mode, all above come from the FIPS provider SunPKCS11-NSS-FIPS. In non-FIPS mode, all the above come from the provider SunJCE or SunJSSE.

For using the native library, I searched the keyword “NativeCrypto.isAlgorithmEnabled” in OpenJDK codes, we can see, the CipherCore.java, PKCS12PBECipherCore.java, SunJCE.java, SunEntries.java, RSACore.java and SunEC.java, are using the Native library.

And in the FIPS mode, we limit the providers, only allow SunEntries.java, SunPKCS11.java, SunJSSE.java and SunEC.java.

So, when running the above tests, if the first provider get by Cipher.getInstance() from the provider list, is the SunPKCS11, then the above code will run without initialize provider Sun or SunEC. Then in the output, you won’t see any debug output, saying “using native crypto library”. But, if the first provider get from the provider list, is not SunPKCS11, for example, the first one get is SunEC, and then SunPKCS11, but since SunEC returned, so it will be initialized, and due to SunEC can use Native library, so, in the debug output, we will see “using native crypto library”. Following are the example, when I run the same command using the same JDK11, but different output.

This one, SunEC be returned from the provider list before SunPKCS11. So SunEC static final variable will be initialized, code below. And then, even the above test code will using the SunPKCS11 provider, but we will still see the following “using native crypto library” from the output, because those are the output when initializing provider SunEC.

private static final boolean useNativeEC = NativeCrypto.isAlgorithmEnabled("jdk.nativeEC", "SunEC");

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

And the below one, SunPKCS11 return as the first provider and this provider can be used for the Cipher, then the above test code will be executed, and no SunEC needed, so SunEC won’t be initialized. So, we won’t see any "using native crypto library" output.

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Crypto test COMPLETED

I run the same command using the same JDK11 couple of times, the output below:

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# /root/tao/JDKs/OpenJ9-JDK11-x86-64_linux-20230330-165936/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Crypto test COMPLETED

[root@unbolts1 openj9-crypto-tao]# 

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

The inconsistent behavior is not caused by AOT (shared classes) or the JIT because I can duplicate it with -Xshareclasses:none and -Xint. Perhaps something is intermittently failing so it's falling back to non-FIPS?

@taoliult
Copy link
Contributor

taoliult commented Apr 4, 2023

@pshipton

I don't think it related to AOT (shared classes) or the JIT.

Currently, FIPS mode doesn't use the native crypto library. But sometime, if we see the below output, that is because, when initialized the provider SunEC, its static final variable "useNativeEC" will be initialized. And then, the debug trace from "NativeCrypto.java" will be printed out due to "jdk.nativeCryptoTrace" is true.

private static final boolean useNativeEC = NativeCrypto.isAlgorithmEnabled("jdk.nativeEC", "SunEC");

SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.

But, even the "useNativeEC" is true and native crypto library is used in SunEC, the algorithms FIPS mode allowed in SunEC, are still not using the native crypto.

@pshipton
Copy link
Member

pshipton commented Apr 4, 2023

We should figure out why the behavior differs from run to run. We do have Attach API which initializes itself in another thread, but using -Dcom.ibm.tools.attach.enable=no to disable it the behavior still differs from run to run.

@taoliult
Copy link
Contributor

taoliult commented Apr 5, 2023

@pshipton

About the behaviour, sometime when running the CryptoTest, both SunEC and SunPKCS11 are loaded, and because the SunEC will check the native library, so the “using native crypto library” will be printed out. Sometime when running the CryptoTest, only SunPKCS11 is loaded, SunEC is not loaded, so there is no “using native crypto library” printed out.

The root cause is due to, loading the non java.based provider using ServiceLoader.

When loading the provider using ProviderConfig.java getProvider() method, the java.base provider, like Sun, SunRsaSign, SunJCE, etc. will be loaded directly by calling their constructor, so the order defined in the java.security file will be the order when actually loading them.

All the other non java.base providers, like SunPKCS11, SunEC, etc. will be loaded by the ServiceLoader.java. And in this service loader, it will iterator over the provider class from the class loader, by calling the provider class constructor and then return the provider name. If the provider name matches the needed one, then return it. But before return the needed one, other providers class constructor maybe invoked for the purpose of getting the provider name, for comparing with the needed provider name. And if the provider class constructor is invoked, that mean, that provider is initialized/loaded.

In the case of CryptoTest, due to the FIPS mode crypto provider is limited to SunPKCS11. So, when trying to load the SunPKCS11 using ServiceLoader. The providers class return from the class loader will be initialized one by one(without any order) to get the provider name, until the provider name matches the name “SunPKCS11”.

So, from the below two examples, we can see, the first example. Before get the “sun.security.pkcs11.SunPKCS11”, 4 other non java.based providers be initialized, which are SunProvider, JdkSASL, SunPCSC and XMLDSigRI. And due to they are not using the native crypto, so no “using native crypto library” printed out.

[root@unbolts1 openj9-crypto-tao]# /root/tao/mkJDK/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ServiceLoader loading provider: sun.security.jgss.SunProvider
Tao Debug - In ServiceLoader loading provider: com.sun.security.sasl.gsskerb.JdkSASL
Tao Debug - In ServiceLoader loading provider: sun.security.smartcardio.SunPCSC
Tao Debug - In ServiceLoader loading provider: org.jcp.xml.dsig.internal.dom.XMLDSigRI
Tao Debug - In ServiceLoader loading provider: sun.security.pkcs11.SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Crypto test COMPLETED

The below second example, before get the “sun.security.pkcs11.SunPKCS11”, 2 other non java.based providers be initialized, which are XMLDSigRI and SunEC. And due to the SunEC is using the native crypto, so there is “using native crypto library” printed out.

[root@unbolts1 openj9-crypto-tao]# /root/tao/mkJDK/openj9-openjdk-jdk11/build/linux-x86_64-normal-server-release/images/jdk/bin/java -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true CryptoTest
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ServiceLoader loading provider: org.jcp.xml.dsig.internal.dom.XMLDSigRI
Tao Debug - In ServiceLoader loading provider: sun.security.ec.SunEC
SunEC native crypto implementation enabled.
Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
Native crypto library load succeeded - using native crypto library.
Tao Debug - In ServiceLoader loading provider: sun.security.pkcs11.SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Tao Debug - In ProviderConfig loading provider: SunPKCS11
Crypto test COMPLETED

So, this explained, why when running the CryptoTest, sometime we can see “SunEC native crypto implementation enabled”, and sometime, there is no such output. Because, before getting this non java.based provider "SunPKCS11” in ServiceLoader from the class loader, there is no order about which provider class will be initialized before the provider class "SunPKCS11”.

This is working as design and currently FIPS mode doesn’t use the native crypto.

@jasonkatonica @WilburZjh FYI.

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

Thanks for the explanation. It seems the best solution is to exclude the test. I also finally realized why we haven't seen this problem before, because I believe we just started running functional testing in FIPS mode.

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

I believe we just started running functional testing in FIPS mode

Nope, I checked and we were running sanity.functional before. I guess we were just getting lucky?

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

I ran the test with an older version 11.018, and while SunEC is still initialized sometimes, there are no messages Native crypto library load succeeded - using native crypto library.

Attempt to load OpenSSL /lib64/libcrypto.so.1.1
Supported OpenSSL version: OpenSSL 1.1.1k  FIPS 25 Mar 2021
SunEC - using native crypto library.
Crypto test COMPLETED

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

Seems we changed the verbose output? While it used to output SunEC - using native crypto library, with the latest version it outputs SunEC native crypto implementation enabled. instead.

@taoliult
Copy link
Contributor

taoliult commented Apr 5, 2023

@pshipton

Yes, there is a PR "Lazily initialize native crypto libraries" (ibmruntimes/openj9-openjdk-jdk11@fc9cdcb) changed the message in the debug trace from JDK11 and above, but I did not see this PR in JDK8.

@JasonFengJ9
Copy link
Member Author

Yes, there is a PR "Lazily initialize native crypto libraries" (ibmruntimes/openj9-openjdk-jdk11@fc9cdcb) changed the message in the debug trace from JDK11 and above, but I did not see this PR in JDK8.

The PR in question was for a CRIU issue which is not supported in JDK8 yet.

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

It appears jdk8 should have always failed the test. Since it doesn't use service providers it never seems to initialize SunEC. While with jdk11+ the results vary from run to run as we have seen.

@taoliult
Copy link
Contributor

taoliult commented Apr 5, 2023

@pshipton
let me take a look at the jdk8 behaviour and will update shortly.

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

I'm not concerned about the failure any more. I still think we should just exclude the test for FIPS.

@taoliult
Copy link
Contributor

taoliult commented Apr 5, 2023

@pshipton

Yes, when running the cmdLineTester_CryptoTest in JDK8, the test will always failed. From the output below, the failure reason is not because lack of output "Crypto test COMPLETED", it is because no "using native crypto library" output. So it can not meet the success conditions, which are both "using native crypto library" and "Crypto test COMPLETED" are in the output.

[2023-03-10T07:26:12.598Z] Output from test:
[2023-03-10T07:26:12.598Z]  [OUT] Crypto test COMPLETED
[2023-03-10T07:26:12.598Z] >> Success condition was not found: [Output match: using native crypto library]
[2023-03-10T07:26:12.598Z] >> Required condition was found: [Output match: Crypto test COMPLETED]
[2023-03-10T07:26:12.598Z] >> Failure condition was not found: [Output match: Native crypto library load failed]
[2023-03-10T07:26:12.598Z] >> Failure condition was not found: [Output match: Crypto test FAILED]

@pshipton
Copy link
Member

pshipton commented Apr 5, 2023

I think I finally figured out why we haven't seen this failure previously. Although we were running sanity.functional testing for past releases, it was only running a single test cmdLineTester_fips. All the other testing is being run for this release for the first time.

paritkum added a commit to paritkum/openj9 that referenced this issue Jun 6, 2023
Excluded cmdLineTester_CryptoTest in FIPS mode, as per the conversation found in issue eclipse-openj9#16902.

Signed-off-by: Paritosh Kumar <[email protected]>
@paritkum
Copy link
Contributor

paritkum commented Jun 7, 2023

Testcase is excluded from FIPS mode as part of PR #17533. This issue can be closed.

@JasonFengJ9
Copy link
Member Author

JDK8 x86-64_linux_fips

[2023-06-08T16:54:01.478Z] variation: NoOptions
[2023-06-08T16:54:01.478Z] JVM_OPTIONS:   -Dsemeru.fips=true

[2023-06-08T16:54:01.478Z] TESTING:
[2023-06-08T16:54:01.478Z] *** Starting test suite: OpenSSL Tests ***
[2023-06-08T16:54:01.478Z] Testing: CryptoTest
[2023-06-08T16:54:01.478Z] Test start time: 2023/06/08 09:53:57 Pacific Standard Time
[2023-06-08T16:54:01.478Z] Running command: "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_1/openjdkbinary/j2sdk-image/bin/java"   -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true -cp "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/openssl/"openssltest.jar org.openj9.test.openssl.CryptoTest
[2023-06-08T16:54:01.478Z] Time spent starting: 27 milliseconds
[2023-06-08T16:54:01.478Z] Time spent executing: 543 milliseconds
[2023-06-08T16:54:01.478Z] Test result: FAILED
[2023-06-08T16:54:01.478Z] Output from test:
[2023-06-08T16:54:01.478Z]  [OUT] Crypto test COMPLETED
[2023-06-08T16:54:01.478Z] >> Success condition was not found: [Output match: using native crypto library]
[2023-06-08T16:54:01.478Z] >> Required condition was found: [Output match: Crypto test COMPLETED]
[2023-06-08T16:54:01.478Z] >> Failure condition was not found: [Output match: Native crypto library load failed]
[2023-06-08T16:54:01.478Z] >> Failure condition was not found: [Output match: Crypto test FAILED]
[2023-06-08T16:54:01.478Z] 
[2023-06-08T16:54:01.478Z] 
[2023-06-08T16:54:01.478Z] ---TEST RESULTS---
[2023-06-08T16:54:01.478Z] Number of PASSED tests: 0 out of 1
[2023-06-08T16:54:01.478Z] Number of FAILED tests: 1 out of 1
[2023-06-08T16:54:01.478Z] 
[2023-06-08T16:54:01.478Z] ---SUMMARY OF FAILED TESTS---
[2023-06-08T16:54:01.478Z] CryptoTest
[2023-06-08T16:54:01.478Z] -----------------------------
[2023-06-08T16:54:01.478Z] 
[2023-06-08T16:54:01.478Z] -----------------------------------
[2023-06-08T16:54:01.478Z] cmdLineTester_CryptoTest_0_FAILED

@pshipton
Copy link
Member

Reopening since the failure still occurs on jdk8.

@pshipton pshipton reopened this Jun 12, 2023
@paritkum
Copy link
Contributor

I have checked the failing built it's run again openj9 v0.40.0-release branch.
The PR was only merged into master branch. It's not merged in v0.40.0-release

Shall I ask to get it merged in v0.40.0-release?

@pshipton
Copy link
Member

Shall I ask to get it merged in v0.40.0-release?

Yes, pls open a PR against the v0.40.0-release branch.

@JasonFengJ9
Copy link
Member Author

JasonFengJ9 commented Sep 8, 2023

JDK8 x86-64_linux_fips140_2 0.41 milestone 1(rhel8x64-fips8-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-06T19:50:21.112Z] variation: NoOptions
[2023-09-06T19:50:21.112Z] JVM_OPTIONS:   -Dsemeru.fips=true

[2023-09-06T19:50:21.112Z] TESTING:
[2023-09-06T19:50:21.112Z] *** Starting test suite: OpenSSL Tests ***
[2023-09-06T19:50:21.112Z] Testing: CryptoTest
[2023-09-06T19:50:21.112Z] Test start time: 2023/09/06 12:50:17 Pacific Standard Time
[2023-09-06T19:50:21.112Z] Running command: "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/openjdkbinary/j2sdk-image/bin/java"   -Dsemeru.fips=true -Djdk.nativeCryptoTrace=true -cp "/home/jenkins/workspace/Test_openjdk8_j9_sanity.functional_x86-64_linux_fips140_2_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/openssl/"openssltest.jar org.openj9.test.openssl.CryptoTest
[2023-09-06T19:50:21.112Z] Time spent starting: 32 milliseconds
[2023-09-06T19:50:21.112Z] Time spent executing: 584 milliseconds
[2023-09-06T19:50:21.112Z] Test result: FAILED
[2023-09-06T19:50:21.112Z] Output from test:
[2023-09-06T19:50:21.112Z]  [OUT] Crypto test COMPLETED
[2023-09-06T19:50:21.112Z] >> Success condition was not found: [Output match: using native crypto library]
[2023-09-06T19:50:21.112Z] >> Required condition was found: [Output match: Crypto test COMPLETED]
[2023-09-06T19:50:21.112Z] >> Failure condition was not found: [Output match: Native crypto library load failed]
[2023-09-06T19:50:21.112Z] >> Failure condition was not found: [Output match: Crypto test FAILED]
[2023-09-06T19:50:21.112Z] 
[2023-09-06T19:50:21.112Z] 
[2023-09-06T19:50:21.112Z] ---TEST RESULTS---
[2023-09-06T19:50:21.112Z] Number of PASSED tests: 0 out of 1
[2023-09-06T19:50:21.112Z] Number of FAILED tests: 1 out of 1
[2023-09-06T19:50:21.112Z] 
[2023-09-06T19:50:21.112Z] ---SUMMARY OF FAILED TESTS---
[2023-09-06T19:50:21.112Z] CryptoTest
[2023-09-06T19:50:21.112Z] -----------------------------
[2023-09-06T19:50:21.112Z] 
[2023-09-06T19:50:21.112Z] -----------------------------------
[2023-09-06T19:50:21.112Z] cmdLineTester_CryptoTest_0_FAILED

50x internal grinder - all passed

@JasonFengJ9 JasonFengJ9 reopened this Sep 8, 2023
@llxia
Copy link
Contributor

llxia commented Sep 11, 2023

It seems that <feature>FIPS140_2:nonapplicable</feature> does not work as expected. @renfeiw can you take a look?
https://github.com/eclipse-openj9/openj9/blob/master/test/functional/cmdLineTests/openssl/playlist.xml#L42C4-L42C46

@llxia
Copy link
Contributor

llxia commented Sep 11, 2023

We are using test material from v0.41.0-release branch, which still uses FIPS.
https://github.com/eclipse-openj9/openj9/blob/v0.41.0-release/test/functional/cmdLineTests/openssl/playlist.xml#L42

@renfeiw could you back port cd4ce67 into v0.41.0-release branch?

@renfeiw
Copy link
Contributor

renfeiw commented Sep 11, 2023

We are using test material from v0.41.0-release branch, which still uses FIPS. https://github.com/eclipse-openj9/openj9/blob/v0.41.0-release/test/functional/cmdLineTests/openssl/playlist.xml#L42

@renfeiw could you back port cd4ce67 into v0.41.0-release branch?

PR created: #18112

@llxia
Copy link
Contributor

llxia commented Sep 11, 2023

Thanks @renfeiw . #18112 is merged.

@llxia llxia closed this as completed Sep 11, 2023
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

8 participants