Private Keys are cached "forever" leading to inop HTTP-TLS-servers

Wed Jun 15 09:15:27 UTC 2022

Hi,

I first thought this to be a bug in Jetty[1] but it seems to be within the JVM.

I have the situation that the Jetty HTTP server is configured to use a
cloud-based HSM as KeyStore for Private Keys. This works but if the
connector stays idle for some time, subsequent handshakes fail with
a ProviderException:

2022-06-10 20:18:29,595 DEBUG [qtp705913731-178] SslConnection: DecryptedEndPoint at 1b2a1192[{l=/127.0.0.1:4433,r=/127.0.0.1:3254,OPEN,fill=-,flush=-,to=24/180000}] stored flush exception
java.security.ProviderException: Initialization failed
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11PSSSignature.initialize(P11PSSSignature.java:310)
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11PSSSignature.ensureInitialized(P11PSSSignature.java:216)
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11PSSSignature.engineUpdate(P11PSSSignature.java:507)
	at java.base/java.security.Signature$Delegate.engineUpdate(Signature.java:1394)
	at java.base/java.security.Signature.update(Signature.java:903)
	at java.base/java.security.Signature.update(Signature.java:872)
	at java.base/sun.security.ssl.ECDHServerKeyExchange$ECDHServerKeyExchangeMessage.updateSignature(ECDHServerKeyExchange.java:462)
	at java.base/sun.security.ssl.ECDHServerKeyExchange$ECDHServerKeyExchangeMessage.<init>(ECDHServerKeyExchange.java:173)
	at java.base/sun.security.ssl.ECDHServerKeyExchange$ECDHServerKeyExchangeProducer.produce(ECDHServerKeyExchange.java:488)
	at java.base/sun.security.ssl.ClientHello$T12ClientHelloConsumer.consume(ClientHello.java:1091)
	at java.base/sun.security.ssl.ClientHello$ClientHelloConsumer.onClientHello(ClientHello.java:843)
	at java.base/sun.security.ssl.ClientHello$ClientHelloConsumer.consume(ClientHello.java:802)
	at java.base/sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392)
	at java.base/sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:443)
	at java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1074)
	at java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1061)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask.run(SSLEngineImpl.java:1008)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:629)
[...]
Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_USER_NOT_LOGGED_IN
	at jdk.crypto.cryptoki/sun.security.pkcs11.wrapper.PKCS11.C_SignInit(Native Method)
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11PSSSignature.initialize(P11PSSSignature.java:303)
	... 34 common frames omitted

Used Java: java -version
openjdk version "11.0.14" 2022-01-18 LTS
OpenJDK Runtime Environment Zulu11.54+23-CA (build 11.0.14+9-LTS)
OpenJDK 64-Bit Server VM Zulu11.54+23-CA (build 11.0.14+9-LTS, mixed mode)

I assume that the driver or the HSM-server is running into a timeout invalidating
some session and thus make the key no longer usable. The KeyStore itself can
still be used. If the same key is retrieved by "getKey" somewhere else the
returned key doesn't get "invalidated", either. I've created a test class where
this can be seen:

------------------- snip
import java.io.File;
import java.io.FileWriter;
import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.nio.charset.StandardCharsets;
import java.security.AuthProvider;
import java.security.GeneralSecurityException;
import java.security.KeyStore;
import java.security.PrivateKey;
import java.security.Provider;
import java.security.Security;
import java.security.Signature;
import java.util.Arrays;
import java.util.Date;

import javax.security.auth.callback.Callback;
import javax.security.auth.callback.CallbackHandler;
import javax.security.auth.callback.PasswordCallback;
import javax.security.auth.callback.UnsupportedCallbackException;
import javax.security.auth.login.LoginException;

import com.ebd.util.text.TextTools;

public class HSMAccessTest {

     public final static void main(String[] args) throws Exception {
         String config =
                 "name = TestUtimaco\r\n" +
                 "library = D:/Program Files/Utimaco/CryptoServer/Lib/cs_pkcs11_R2.dll\r\n" +
                 "";

         File tempConfig = File.createTempFile("hsmconfig_", ".properties");
         try {
             try (FileWriter fw = new FileWriter(tempConfig, StandardCharsets.ISO_8859_1)) {
                 fw.write(config);
                 fw.flush();
             }

             Provider p = Security.getProvider("SunPKCS11");
             AuthProvider prov = (AuthProvider) p.configure(tempConfig.getAbsolutePath());
             KeyStore ks = KeyStore.getInstance("PKCS11", prov);
             char[] pswd = "654321".toCharArray();
             ks.load(null, pswd);
             String certAlias = ks.aliases().nextElement();
             System.out.println(certAlias);

             PrivateKey key = (PrivateKey) ks.getKey(certAlias, null);
             for (long wait = 16 * 60000; wait < 3600000; ) {
//                performWorkaround(prov, pswd);
                 performSign(prov, key);
                 System.out.println("wait " + (wait / 60000) + " mins");
                 Thread.sleep(wait);
             }
         }
         finally {
             tempConfig.delete();
         }

     }

     static void performSign(AuthProvider prov, PrivateKey key) throws GeneralSecurityException, UnsupportedEncodingException {
         System.out.println(new Date() + ": Sign data. Key is destroyed: " + key.isDestroyed());
         Signature sig = Signature.getInstance("SHA1WithRSA", prov);
         sig.initSign(key);
         sig.update("signdata".getBytes("8859_1"));

         System.out.println(new Date() + ": " + TextTools.join(sig.sign(), ""));
     }

     static void performWorkaround(AuthProvider prov, char[] pswd) throws LoginException {
         prov.login(null, new CallbackHandler() {
             @Override
             public void handle(Callback[] callbacks) throws IOException, UnsupportedCallbackException {
                 Arrays.stream(callbacks)
                     .filter(cb -> cb instanceof PasswordCallback)
                     .map(cb -> (PasswordCallback) cb)
                     .forEach(cb -> cb.setPassword(pswd));
             }
         });
     }
}
------------------- snip

The class in this version will run into an error after 16 minutes (32 minutes at the latest)

------------------- snip
testcert
Mon Jun 13 17:01:33 CEST 2022: Sign data. Key is destroyed: false
Mon Jun 13 17:01:33 CEST 2022: a8726a4ed3c3f77aced24b078931167214a7f64b1dac2e7774874aec7ec973d289bf72920b342b52c6b799ebee793332332f531994f1fd9ec77a986ac253e54771d410acc4c3dc71ca97b8c5ac445262b9da1177db0eaedb66b9a0af5dfc2f5c761ab514dde5ab90afc53aa7bcd54edfb93f247855794c127e6cff86562652ab5a3493c7e49756cc0d309495b5d365bbfc8eeeb30d46e4419727421c4eec5011560fe17fa6894ea967280470ec62366d56839ece086502471bb537a27a708a4654df2ba0a0234bd20f0d80519843e7ed4ca5beb76af5d66e886977a07092e20e73478c4bbdf1742475092b79b53c9a202d072a70ee112ef405138df7c1368b16
wait 16 mins
Mon Jun 13 17:17:33 CEST 2022: Sign data. Key is destroyed: false
Mon Jun 13 17:17:33 CEST 2022: a8726a4ed3c3f77aced24b078931167214a7f64b1dac2e7774874aec7ec973d289bf72920b342b52c6b799ebee793332332f531994f1fd9ec77a986ac253e54771d410acc4c3dc71ca97b8c5ac445262b9da1177db0eaedb66b9a0af5dfc2f5c761ab514dde5ab90afc53aa7bcd54edfb93f247855794c127e6cff86562652ab5a3493c7e49756cc0d309495b5d365bbfc8eeeb30d46e4419727421c4eec5011560fe17fa6894ea967280470ec62366d56839ece086502471bb537a27a708a4654df2ba0a0234bd20f0d80519843e7ed4ca5beb76af5d66e886977a07092e20e73478c4bbdf1742475092b79b53c9a202d072a70ee112ef405138df7c1368b16
wait 16 mins
Mon Jun 13 17:33:33 CEST 2022: Sign data. Key is destroyed: false
Exception in thread "main" java.security.ProviderException: Initialization failed
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11Signature.initialize(P11Signature.java:375)
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11Signature.engineInitSign(P11Signature.java:502)
	at java.base/java.security.Signature$Delegate.engineInitSign(Signature.java:1351)
	at java.base/java.security.Signature.initSign(Signature.java:636)
	at HSMAccessTest.performSign(HSMAccessTest.java:76)
	at HSMAccessTest.main(HSMAccessTest.java:50)
Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_USER_NOT_LOGGED_IN
	at jdk.crypto.cryptoki/sun.security.pkcs11.wrapper.PKCS11.C_SignInit(Native Method)
	at jdk.crypto.cryptoki/sun.security.pkcs11.P11Signature.initialize(P11Signature.java:366)
	... 5 more
------------------- snip

Putting the getKey-call inside the for-loop solves the problem. A workaround is
regularily calling authprovider.login. This can be seen if the commented-line
in the for-loop is activated.

Not sure if this should be considered a bug in the PKCS#11-DLL of the HSM-provider
but if a key-instance must be valid forever, shouldn't that be mentioned in the
interface's Javadoc?

Thanks and best regards,

Lothar Kimmeringer

[1] https://github.com/eclipse/jetty.project/issues/8157