jetty / jetty.project

Eclipse Jetty® - Web Container & Clients - supports HTTP/2, HTTP/1.1, HTTP/1.0, websocket, servlets, and more
https://eclipse.dev/jetty
Other
3.82k stars 1.91k forks source link

SslContextFactory$Server stops working when using PKCS11-keystores and some idle time passes #8157

Closed kimmerin closed 2 months ago

kimmerin commented 2 years ago

Jetty version(s) 10.0.9

Java version/vendor (use: 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)

OS type/version Microsoft Windows [Version 10.0.19044.1706]

Description I've set up a TLS-connector using a SslContextFactory where I set an explicit KeyStore that "comes from" a PKCS#11-provider of an HSM:

<New id="utimacoSslContextFactory" class="org.eclipse.jetty.util.ssl.SslContextFactory$Server">
    <Set name="keyStore"><Call class="mypackage.CryptoTools" name="getKeyStore">
        <Arg>utimaco</Arg>
    </Call></Set>
    <Set name="CertAlias">testhsmcert</Set>
    [...]
</New>

The HSM in question is a "cloud-based HSM", i.e. you have network connections in order to access the HSM. This all works but if the connector stays idle for some time a new TLS-handshake will fail and the browser (here, Firefox) will report a "PR_END_OF_FILE_ERROR". The server log doesn't show anything unless you enable debug-level. Then you'll get an exception:

2022-06-10 20:18:29,595 DEBUG [qtp705913731-178] SslConnection: DecryptedEndPoint@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)
    at org.eclipse.jetty.server.HttpConnection.fillRequestBuffer(HttpConnection.java:368)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:265)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:530)
    at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:379)
    at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:146)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:412)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:381)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:268)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produce(AdaptiveExecutionStrategy.java:190)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038)
    at java.base/java.lang.Thread.run(Thread.java:829)
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
2022-06-10 20:18:29,595 DEBUG [qtp705913731-178] SslConnection: handshake failed SslConnection@1dbf9b9d::SocketChannelEndPoint@326a86d4[{l=/127.0.0.1:4433,r=/127.0.0.1:3254,OPEN,fill=-,flush=-,to=6/180000}{io=0/0,kio=0,kro=1}]->[SslConnection@1dbf9b9d{NEED_WRAP,eio=0/0,di=-1,fill=IDLE,flush=IDLE}~>{l=/127.0.0.1:4433,r=/127.0.0.1:3254,OPEN,fill=-,flush=-,to=24/180000}=>HttpConnection@4ca7fe38[p=HttpParser{s=START,0 of -1},g=HttpGenerator@56d2af39{s=START}]=>HttpChannelOverHttp@3892eda4{s=HttpChannelState@7d9064d2{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}] {}
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)
    at org.eclipse.jetty.server.HttpConnection.fillRequestBuffer(HttpConnection.java:368)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:265)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:319)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:530)
    at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:379)
    at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:146)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)
    at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:412)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:381)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:268)
    at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produce(AdaptiveExecutionStrategy.java:190)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:894)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1038)
    at java.base/java.lang.Thread.run(Thread.java:829)
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

You have to restart Jetty in order to get this working again. I'm assuming that Jetty is retrieving the private key once and caches it. The long idle time leads to some timeout within the Provider or on the HSM side, so the session "behind" the key becomes invalid. Subsequent attempts to use the key then leads to the mentioned error.

To verify my theory I've created a test-class that - I think - confirms it:

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.InvalidKeyException;
import java.security.KeyStore;
import java.security.NoSuchAlgorithmException;
import java.security.PrivateKey;
import java.security.Provider;
import java.security.Security;
import java.security.Signature;
import java.security.SignatureException;
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 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);
            System.out.println(ks.aliases().nextElement());

            PrivateKey key = (PrivateKey) ks.getKey("testcert", null);
            for (long wait = 16 * 60000; wait < 3600000; ) {
//                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));
//                    }
//                });
                performSign(prov, key);
                System.out.println("wait " + (wait / 60000) + " mins");
                Thread.sleep(wait);
            }
        }
        finally {
            tempConfig.delete();
        }

    }

    private static void performSign(AuthProvider prov, PrivateKey key)
            throws NoSuchAlgorithmException, InvalidKeyException, SignatureException, UnsupportedEncodingException {
        Signature sig = Signature.getInstance("SHA1WithRSA", prov);
        sig.initSign(key);
        sig.update("signdata".getBytes("8859_1"));

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

In the version shown above, the whole thing breaks after 16 or 32 minutes:

testcert
Fri Jun 10 19:55:00 CEST 2022: a8726a4ed3c3f7[...]1368b16
wait 16 mins
Fri Jun 10 20:11:00 CEST 2022: a8726a4ed3c3f7[...]1368b16
wait 16 mins
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:74)
    at HSMAccessTest.main(HSMAccessTest.java:60)
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

When putting the key-retrieval within the for-loop, no error occurred and - because I haven't seen this effect in Jetty 9.4 - I assume that this was the way it was done in previous versions of Jetty (i.e. get the key every time it's needed).

"Activating" the commented out block would solve the problem as well but that doesn't help "here", because Jetty isn't able to do this call (keystore.getProvider()exists but the password is unknown so you can't call login).

How to reproduce?

Set up a Jetty instance with TLS connector using a network-based HSM (I had to deal with Utimaco but there might be others with similar effects). Go to your browser of choice and try to connect to the connector. Wait. Try again.

sbordet commented 2 years ago

I'm not sure I understand this, as all seems unrelated to Jetty? Why it is a Jetty bug if the HSM times out?

kimmerin commented 2 years ago

It seems to me that Jetty calls keystore.getKey() once and keeps the returned key forever. If it's not used for some time, the underlying session to the HSM becomes invalid and using that key leads to an error. The KeyStore itself can still be used, i.e. getting the same key again by calling getKey() again returns a usable key.

Assuming that a key-instance is valid "forever" is a bug in my eyes. If it is not, I don't see, how to configure Jetty to use KeyStores of HSM-providers in a way that this problem can't occur. As said, as soon as this problem occurs, you need to restart Jetty, which is something you don't want in production-environments.

sbordet commented 2 years ago

Jetty does not call KeyStore.getKey().

Jetty just uses the KeyStore from the JDK implementation to set values to configure it, and then the JDK implementation does the rest, which may or may not call getKey() or cache it.

Assuming that a key-instance is valid "forever" is a bug in my eyes.

You should then file an issue to the JDK, not us.

I think it's wrong to assume that a class like KeyStore which was designed to support file-system resources to load cryptographic material will behave the same when used over the network with HSMs that time out.

I don't think we can solve this from Jetty. We certainly don't want to trigger a "refresh" of the KeyStore usage and have all other use cases to pay this cost, just to support your use case.

I think you should implement your own workaround for your own use case.

kimmerin commented 2 years ago

I think it's wrong to assume that a class like KeyStore which was designed to support file-system resources to load cryptographic material will behave the same when used over the network with HSMs that time out.

I'm not assuming anything and using a network accessed HSM (every time I write this, my head explodes) isn't a choice of mine but an external requirement. As well, the way KeyStores were designed in the past and the caveats that produces now in these IT-cloudy times is not my fault ;-)

If Jetty is just passing the KeyStore to the JVM, you're right that the JVM's issue tracker is the right place. Thanks. But it might be considered to log this particular error with level error and not debug because it's something that leads to the inoperation of Jetty, so the reason for this should show up in a log with a level-setting that is common on production systems.

sbordet commented 2 years ago

But it might be considered to log this particular error with level error and not debug because it's something that leads to the inoperation of Jetty, so the reason for this should show up in a log with a level-setting that is common on production systems.

No, because your error is indistinguishable from a client error such as the client abruptly closing the connection. These client-side errors are so common that we cannot even log them at INFO level, never mind at ERROR level.

Your use case is very particular.

You can try to add a SslHandshakeListener, see for example here. In that listener you can try to inspect the exception you get, and try to figure out if it's due to your HSM problems.

If it is, you can try to reload the SslContextFactory, see https://github.com/eclipse/jetty.project/blob/jetty-10.0.9/jetty-server/src/test/java/org/eclipse/jetty/server/ssl/SslContextFactoryReloadTest.java, so you don't restart the whole server.

kimmerin commented 2 years ago

I'll check the test class but

No, because your error is indistinguishable from a client error such as the client abruptly closing the connection.

A client closing a connection is leading to a ProviderException?

sbordet commented 2 years ago

A client closing a connection is leading to a ProviderException?

A client can cause a large number of different exceptions, and we rarely differentiate -- it's a bad client and we don't bother.

For your unique case, see what I suggest above, or configure your HSM to not timeout, or poll periodically your HSM so it does not timeout.

Really, this is not a Jetty issue.

github-actions[bot] commented 1 year ago

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.

github-actions[bot] commented 2 months ago

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.