Client certificate not sent by SSL_connect()

[rmuehl]

I'm using openssl-3.0.8 and main branch of the pkcs11_provider.
When i do openssl s_client -provider pkcs11 -cert "pkcs11:" -connect 127.0.0.1:8443, I can see the transmitted client certificate on the servers side.

Now I'm trying to get this to work in C. I can load key and cert from provider, and both got printed out:

X509_check_private_key(cert, privkey)
SSL_CTX_use_cert_and_key(mySSLCTX, cert, privkey, NULL, 0);
X509_print_fp(stdout, SSL_CTX_get0_certificate(mySSLCTX));
EVP_PKEY_print_private_fp(stdout, SSL_CTX_get0_privatekey(mySSLCTX), 0, NULL);

but on SSL_connect()

mySSL = SSL_new(mySSLCTX);
SSL_connect(mySSL)

there's no certificate sent:

Header:
Version = TLS 1.2 (0x303)
Content Type = ApplicationData (23)
Length = 25
Inner Content Type = Handshake (22)
Certificate, Length=4
context (len=0):
certificate_list, length=0`

40679E910B7F0000:error:0A0000C7:SSL routines:tls_process_client_certificate:peer did not return a certificate:ssl/statem/statem_srvr.c:3511:

I'm completely out if ideas. Maybe someone got this to work?

[simo5]

Have you tried printing out the error stack from OpenSSL to see if there is any clue?

[rmuehl]

Yes, i did. Every step is checked if something's got wrong. But everything is OK, the code runs flawless to the end. It is completely silently ignored. Even openssl in DEBUG mode dont give me a clue.

[rmuehl]

This is what I do to load the cert/key from store:

X509 *cert = NULL;
EVP_PKEY *privkey = NULL;
OSSL_STORE_CTX *store = NULL;
const char *uri = "pkcs11:";

store = OSSL_STORE_open(uri, UI_OpenSSL(), NULL, NULL, NULL);
while (!OSSL_STORE_eof(store)) {
	OSSL_STORE_INFO *info = OSSL_STORE_load(store);

	switch (OSSL_STORE_INFO_get_type(info)) {
		case OSSL_STORE_INFO_CERT:
			if (!cert)
				cert = OSSL_STORE_INFO_get1_CERT(info);
			break;

		case OSSL_STORE_INFO_PKEY:
			if (!privkey)
			privkey = OSSL_STORE_INFO_get1_PKEY(info);

		default:
			break;
	}	
	OSSL_STORE_INFO_free(info);
}
OSSL_STORE_close(store);

[simo5]

And you have exactly 1 cert and 1 key in the token ?

[simo5]

You may want to try to enable pkcs11-provider's debug log to see if it gives any clue ...

[rmuehl]

Yes, I load only the first cert/key - and it's only this pair on the token. And the printout show that its the right one.
pkcs11-provider's debug log also gives my no hint.

[simo5]

Does the same code work fine if you pass in in a pem file as the uri?
(Let's try to rule out anything that is not pkcs11 related)

[rmuehl]

What I'm trying to do is to migrate from ENGINE to PROVIDER.
The token works fine with the engine code.

When I use key and cert PEM files, the code works.
When i use the cert PEM (fetched from token) and the key form the provider, it doesn't work.

[simo5]

Do you see the pkcs11 being invoked to make a signature, after the certificate and key have been looked up?
And do you see both cert and key being returned on lookup?

[rmuehl]

I'm not sure about that.
But I get asked for the PIN, and after that, the key and cert seems to get loaded correctly.

X509_print_fp(stdout, SSL_CTX_get0_certificate(mySSLCTX));

shows the cert data

EVP_PKEY_print_private_fp(stdout, SSL_CTX_get0_privatekey(mySSLCTX), 0, NULL);

shows the public part of the key

[Can't export and print private key data]
PKCS11 RSA Public Key (2048 bits)
Modulus:
00:c5:ee:bf:fa:a9:01:37:9e:eb:25:0c:e3:07:07:
aa:d4:fb:7a:85:99:a5:32:7a:cb:e4:b4:a0:55:ed:
......

When I disable the default privider in the openssl.cnf I get
ERROR: SSL_CTX_new: error:0A0000A1:SSL routines::library has no ciphers

[simo5]

So you get the PIN asked interactively?
In that case I think you would need to either set callbacks to ask for the PIN again at time of signing.
Or you can try with setting "pkcs11-module-cache-pins = cache"

See https://github.com/latchset/pkcs11-provider/wiki#pkcs11-module-cache-pins

[rmuehl]

This was one of my first thougts. This is my openssl.cfg section:

[pkcs11_sect]
activate = 1
module = /usr/lib64/ossl-modules/pkcs11.so
pkcs11-module-path = /usr/lib64/opensc-pkcs11.so
pkcs11-module-cache-pins = cache

[simo5]

what version of opensc is this?
In a bug report we just found out a potential regression in the github tree.
See #234

[rmuehl]

I'm using an older version of opensc. I can sign and verify succesfully with openssl:
openssl dgst -sign "pkcs11:" -out test.sig -sha384 test.data
openssl dgst -verify "pkcs11:" -signature test.sig -sha384 test.data
Verified OK

[rmuehl]

So, IMO opensc-pkcs11 and libp11kit are working as expected.

[simo5]

@rmuehl do public and private key, or at least cert and private key have the same CKA_ID ?
That is what is used to do certain fallbacks when openssl code assume a private key also provides a public key

[rmuehl]

On a Yubikey there is no id=....

p11tool --list-token-urls pkcs11:
pkcs11:model=PKCS%2315%20emulated;manufacturer=piv_II;serial=00112233445566778899;token=something

[simo5]

I am trying to see if I can write a minimal reproducer, but I assume I need a TLS server willing to accept client certs?
Perhaps I can test with openssl s_server ?

What do you use to test?

[simo5]

Ok I used the following code:

int main(int argc, char *argv[]) {
    X509 *cert = NULL;
    EVP_PKEY *privkey = NULL;
    OSSL_STORE_CTX *store = NULL;
    const char *uri = "pkcs11:id=%db%1f%e6%00%94%9f%45%81%aa%23%37%8d%2c%e0%c1%a3%b6%d1%60%1c";
    SSL_CTX *mySSLCTX;
    SSL *mySSL;
    BIO *myBIO;
    int ret;

    store = OSSL_STORE_open(uri, UI_OpenSSL(), NULL, NULL, NULL);
    while (!OSSL_STORE_eof(store)) {
	OSSL_STORE_INFO *info = OSSL_STORE_load(store);

	switch (OSSL_STORE_INFO_get_type(info)) {
		case OSSL_STORE_INFO_CERT:
			if (!cert)
				cert = OSSL_STORE_INFO_get1_CERT(info);
			break;

		case OSSL_STORE_INFO_PKEY:
			if (!privkey)
			privkey = OSSL_STORE_INFO_get1_PKEY(info);

		default:
			break;
	}
	OSSL_STORE_INFO_free(info);
    }
    OSSL_STORE_close(store);

    mySSLCTX = SSL_CTX_new(TLS_client_method());

    ret = X509_check_private_key(cert, privkey);
    if (ret != 1) {
        ERR_print_errors_fp(stderr);
        exit(1);
    }

    SSL_CTX_use_cert_and_key(mySSLCTX, cert, privkey, NULL, 0);
    X509_print_fp(stdout, SSL_CTX_get0_certificate(mySSLCTX));
    EVP_PKEY_print_private_fp(stdout, SSL_CTX_get0_privatekey(mySSLCTX), 0, NULL);

    myBIO = BIO_new_ssl_connect(mySSLCTX);
    BIO_set_conn_hostname(myBIO, "localhost:8443");
    BIO_get_ssl(myBIO, &mySSL);
    SSL_set_tlsext_host_name(mySSL, "localhost");
    printf("Connecting:\n");
    ret = SSL_connect(mySSL);
    if (ret != 1) {
        ERR_print_errors_fp(stderr);
        exit(1);
    }

    BIO_puts(myBIO, "GET / HTTP/1.1\r\n"
              "Host: sec-crypto.users.ipa.redhat.com\r\n"
              "Connection: close\r\n\r\n");
    int len = 0;
    do {
        char buf[4096] = {};
        len = BIO_read(myBIO, buf, sizeof(buf));
        if (len > 0) {
            printf("< %*s", len, buf);
        }
    } while(len > 0 || BIO_should_retry(myBIO));
}

[simo5]

And this command as a server:
openssl s_server -verify 1 -accept 8443 -www -cert $ECBASEURI

And I see that the server receives a certificate:

depth=0 O = PKCS11 Provider, CN = My Test Cert
verify error:num=20:unable to get local issuer certificate
verify return:1
depth=0 O = PKCS11 Provider, CN = My Test Cert
verify error:num=21:unable to verify the first certificate
verify return:1
depth=0 O = PKCS11 Provider, CN = My Test Cert
verify return:1

[simo5]

O = PKCS11 Provider, CN = My Test Cert is the cert found when using the pkcs11 URI I pass in the client:

$ openssl storeutl -certs -text $BASEURI
[..]
        Subject: O=PKCS11 Provider, CN=My Test Cert
        Subject Public Key Info:
            Public Key Algorithm: rsaEncryption
                Public-Key: (2048 bit)
[..]

[simo5]

While the server uses:

$ openssl storeutl -certs -text $ECBASEURI
[..]
        Subject: O=PKCS11 Provider, CN=My EC Cert
        Subject Public Key Info:
            Public Key Algorithm: id-ecPublicKey
                Public-Key: (256 bit)
[..]

[simo5]

The $BASEURI and $ECBASEURI are variable set by the pkcs11 test suite:

$ cat tests/tmp.softokn/testvars 
[..]
export BASEURI="pkcs11:id=%db%1f%e6%00%94%9f%45%81%aa%23%37%8d%2c%e0%c1%a3%b6%d1%60%1c"
export PUBURI="pkcs11:type=public;id=%db%1f%e6%00%94%9f%45%81%aa%23%37%8d%2c%e0%c1%a3%b6%d1%60%1c"
export PRIURI="pkcs11:type=private;id=%db%1f%e6%00%94%9f%45%81%aa%23%37%8d%2c%e0%c1%a3%b6%d1%60%1c"
export CRTURI="pkcs11:type=cert;object=testCert"

export ECBASEURIWITHPIN="pkcs11:id=%1c%72%e7%2a%4f%32%11%81%1e%41%73%82%ec%7e%cd%0b%0e%21%40%e1;pin-value=12345678"
export ECBASEURI="pkcs11:id=%1c%72%e7%2a%4f%32%11%81%1e%41%73%82%ec%7e%cd%0b%0e%21%40%e1"
[..]

[rmuehl]

Basically I'm doing the same, but using a Yubikey Hardware Token.

I compared the provider debug log with opesnssl s_client (which is working). I found, that the digest lines are completely missing:

[digests.c:378] p11prov_digest_get_params(): digest get params: digest=220, params=0x7ffe39f2aad0
[digests.c:393] p11prov_digest_get_params(): block_size = 64
[digests.c:408] p11prov_digest_get_params(): digest_size = 20
[digests.c:378] p11prov_digest_get_params(): digest get params: digest=255, params=0x7ffe39f2aad0
[digests.c:393] p11prov_digest_get_params(): block_size = 64
[digests.c:408] p11prov_digest_get_params(): digest_size = 28
[digests.c:378] p11prov_digest_get_params(): digest get params: digest=250, params=0x7ffe39f2aad0
[digests.c:393] p11prov_digest_get_params(): block_size = 64
[digests.c:408] p11prov_digest_get_params(): digest_size = 32
[digests.c:378] p11prov_digest_get_params(): digest get params: digest=260, params=0x7ffe39f2aad0
[digests.c:393] p11prov_digest_get_params(): block_size = 128
[digests.c:408] p11prov_digest_get_params(): digest_size = 48
[digests.c:378] p11prov_digest_get_params(): digest get params: digest=270, params=0x7ffe39f2aad0
[digests.c:393] p11prov_digest_get_params(): block_size = 128
[digests.c:408] p11prov_digest_get_params(): digest_size = 64

The only difference at store loading is, that p11prov_store_set_ctx_params() is not being called:

[session.c:252] session_new(): Creating new P11PROV_SESSION session on pool 0x6e15d0
[session.c:286] session_new(): Total sessions: 1
[interface.gen.c:215] p11prov_OpenSession(): Calling C_OpenSession
[session.c:72] token_session_open(): C_OpenSession ret:0 (session: 18)
[interface.gen.c:884] p11prov_GenerateRandom(): Calling C_GenerateRandom
[util.c:554] p11prov_parse_uri(): ctx=0x689e00 uri=pkcs11:)
[store.c:472] p11prov_store_set_ctx_params(): set ctx params (0x6e1f70, 0x7ffe39f2ad70)

[rmuehl]

On a Yubikey there is no id=....

p11tool --list-token-urls pkcs11:
pkcs11:model=PKCS%2315%20emulated;manufacturer=piv_II;serial=00112233445566778899;token=something

[simo5]

If a key returns no CKA_ID, none is printed.

[rmuehl]

I can't find a string "CKA_ID" in the provider debug log. Neither in the working one nor in the not working one.

But as the openssl s_client is working with the provider, something must be missing in my SSL_somewhat.