openssl pkcs11 engine: a newly created key cannot be used if one with the same url was used before

[sbrandt-aixtrusion]

We have the following issue:

We use openssl 3.0.13 to OP-TEE (arm embedded) via the PKCS11 engine (libp11 0.4.12)
We can create keys via pkcs11, use them from openssl, everything is okay.
But we also need to create new keys, when we create a new certificate enrollment.

Now, it appears that the openssl pkey is "cached" inside the engine. If we create a new pkcs11 key, the public part of the pkey is still cached and thus, the old key, while the private part is passed through pkcs11 to the op-tee implementation and uses, of course, the new key.
This makes the following workflow impossible:

• start the program
• use the pkcs11 key as EVP_PKEY
• works without issue
• free all instances of that EVP_PKEY
• create a new pkcs11 key (same name/url/id) via pkcs11-interface
• get a reference to the new pkcs11 key as EVP_PKEY
  That EVP_PKEY is no longer able to verify its own signatures, as the public part is still the old key, while the private part is the new key.
  An application restart fixes that problem, but that is not a solution that can be implemented in our project.

Looking into the code of the pkcs11 engine, I found that the created EVP_PKEY gets an EVP_PKEY_up_ref, and is returned with a reference count of 2, not of 1. So, when the user program frees "all references" of that EVP_PKEY, it is not actually freed. This of course explains why the new key still has the old public information, instead of retrieving the new public information from the new pkcs11 key. This is quite obviously not just a bug (very old code), but "by design", though not visibly explained.

When calling another EVP_PKEY_free, the key reference is of course freed completely. But it is no longer possible to get an EVP_PKEY reference. This reason for this is unclear, I have not yet debugged that far.

So, there are two "broken" flows.

1. during the runtime of a program, a pkcs11 engine key cannot be re-created and then used successfully by openssl, due to EVP_PKEY reference counting being used for caching the openssl/pkcs11 key "bridge". An application restart is needed.
2. without that key bridge, retrieving the same key again is impossible.

When we set up the project, Providers for PKCS11 where not yet sufficiently mature to be used. Switching everything to that would only make sense if we can be sure that this problem is not present there.

The issue cannot be easily reproduced in minimal sample code, as it requires a step outside of the application to create the new key.

The attached sample code should reproduce the problem, assuming you have a working pkcs11 setup.

Output is like:

$ PIN=0000 /usr/bin/pkcs11-problem
pkcs11-lib: No object with label testkey found
pkcs11-lib: No object with label testkey found
Private and public key 'testkey' have been deleted.
Do: generate PKCS11 key with label 'testkey', and press return.
PIN=...
pkcs11-tool --pin $PIN --module /usr/lib/libckteec.so.0 --login --label testkey --id 1150 --keypairgen --key-type EC:secp384r1 --usage-sign

Got key 0xaaaaedd49980
Public key:
-----BEGIN PUBLIC KEY-----
MHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEMFCavXi2/p6yaL6peLAiJaYDoI8gt0gP
yDKrAPgs8lYbpyKf9s1oQ77wCP2c2CDeCgSpNmnkM6FfthFOWH/HlGmOwAo7ExaK
5hwHyryxgHvXOSa8cPgtG6XwhA7uvMTv
-----END PUBLIC KEY-----

Signature created
Signature verified
First PKCS11 key is valid, and has been freed.
pkcs11-lib: No object with label testkey found
pkcs11-lib: No object with label testkey found
Private and public key 'testkey' have been deleted (again).
Do: generate PKCS11 key with label 'testkey' (again), and press return.

Got key 0xaaaaedd49980
Public key:
-----BEGIN PUBLIC KEY-----
MHYwEAYHKoZIzj0CAQYFK4EEACIDYgAEMFCavXi2/p6yaL6peLAiJaYDoI8gt0gP
yDKrAPgs8lYbpyKf9s1oQ77wCP2c2CDeCgSpNmnkM6FfthFOWH/HlGmOwAo7ExaK
5hwHyryxgHvXOSa8cPgtG6XwhA7uvMTv
-----END PUBLIC KEY-----

Signature created
Verification failed
At /home/developer/cosy/workspace-imx8mpcosy/build/workspace/sources/security-manager/src/rctest/pkcs11-problem.cc:173:

As you can see, the public key as PEM that is printed is unchanged even though deleted and re-created. Also, the EVP_PKEY has the same pointer address.

Note that the problem does not appear if the keys are deleted in an external process using pkcs11-tool. Then, when getting the key after re-generation, the EVP_PKEY is "korrekt".

If EVP_PKEY_free is called twice, the can't be loaded afterwards:

The private key was not found at: pkcs11:object=testkey
PKCS11_get_private_key returned NULL
Error: failed loading private key pkcs11:object=testkey
Got key (nil)

#include <stdio.h>

#include <openssl/err.h>
#include <openssl/evp.h>
#include <openssl/engine.h>
#include <pkcs11_session.h>

static const char *KEYNAME{"testkey"};

static void display_openssl_errors(int l);
static bool checkKeyValidity(EVP_PKEY *pkey, ENGINE *engine);
static ENGINE *loadEngine();
static EVP_PKEY *getKeyFromEngine(ENGINE *engine, const char *keyname);

int main(int, char **)
{

    CK_SESSION_HANDLE session{};
    pkcs11_initialize_session(&session);

    ENGINE *engine = loadEngine();
    if (!engine)
    {
        return 1;
    }

    pkcs11_destroy_object(session, (CK_BYTE_PTR)KEYNAME, CKO_PUBLIC_KEY);
    pkcs11_destroy_object(session, (CK_BYTE_PTR)KEYNAME, CKO_PRIVATE_KEY);

    printf("Private and public key '%s' have been deleted.\n", KEYNAME);
    printf("Do: generate PKCS11 key with label '%s', and press return.\n", KEYNAME);
    printf("PIN=...\n"
    //    "pkcs11-tool --pin $PIN --module /usr/lib/libckteec.so.0 --login --label testkey --delete-object --type pubkey\n"
    //    "pkcs11-tool --pin $PIN --module /usr/lib/libckteec.so.0 --login --label testkey --delete-object --type privkey\n"
        "pkcs11-tool --pin $PIN --module /usr/lib/libckteec.so.0 --login --label testkey --id 1150 --keypairgen --key-type EC:secp384r1 --usage-sign\n");
    char buffer[1024];
    (void)fgets(buffer, sizeof(buffer), stdin);
    {
        EVP_PKEY *pkey = getKeyFromEngine(engine, KEYNAME);
        printf("Got key %p\n", (void*)pkey);
        if (!pkey)
        {
            return 1;
        }
        if (!checkKeyValidity(pkey, engine))
        {
            return 1;
        }
        EVP_PKEY_free(pkey);
    }
    printf("First PKCS11 key is valid, and has been freed.\n");

    pkcs11_destroy_object(session, (CK_BYTE_PTR)KEYNAME, CKO_PUBLIC_KEY);
    pkcs11_destroy_object(session, (CK_BYTE_PTR)KEYNAME, CKO_PRIVATE_KEY);
    printf("Private and public key '%s' have been deleted (again).\n", KEYNAME);
    printf("Do: generate PKCS11 key with label '%s' (again), and press return.\n", KEYNAME);
    (void)fgets(buffer, sizeof(buffer), stdin);
    {
        EVP_PKEY *pkey = getKeyFromEngine(engine, KEYNAME);
        printf("Got key %p\n", (void*)pkey);
        if (!pkey)
        {
            return 1;
        }
        if (!checkKeyValidity(pkey, engine))
        {
            return 1;
        }
        EVP_PKEY_free(pkey);
    }
    ENGINE_free(engine);
    ENGINE_cleanup();

    return 0;
}


static void display_openssl_errors(int l)
{
    fprintf(stderr, "At %s:%d:\n", __FILE__, l);

    unsigned long e{};
    while ((e = ERR_get_error()))
    {
        fprintf(stderr, "- SSL %s\n", ERR_error_string(e, nullptr));
    }
}

static bool checkKeyValidity(EVP_PKEY *pkey, ENGINE *engine)
{
    auto digest_algo = EVP_get_digestbyname("sha256");
    unsigned char sig[4096]{};
    size_t sig_len{};
    unsigned char md[128]{};
    size_t md_len{};

    {
        BIO* bio {BIO_new(BIO_s_mem())};
        if (PEM_write_bio_PUBKEY(bio, pkey) >= 0)
        {
            char* bioData{nullptr};
            long bioLen = BIO_get_mem_data(bio, &bioData);
            if (bioLen > 0 && bioData)
            {
                printf("Public key:\n%s\n", bioData);
            }
        }
        BIO_free(bio);
    }

    {
        auto pkey_ctx = EVP_PKEY_CTX_new(pkey, engine);
        if (pkey_ctx == NULL)
        {
            fprintf(stderr, "Could not create context\n");
            display_openssl_errors(__LINE__);
            exit(1);
        }

        if (EVP_PKEY_sign_init(pkey_ctx) <= 0)
        {
            fprintf(stderr, "Could not init signature\n");
            display_openssl_errors(__LINE__);
            exit(1);
        }

        if (EVP_PKEY_CTX_set_signature_md(pkey_ctx, digest_algo) <= 0)
        {
            fprintf(stderr, "Could not set message digest algorithm\n");
            display_openssl_errors(__LINE__);
            exit(1);
        }

        sig_len = sizeof(sig);
        if (EVP_PKEY_sign(pkey_ctx, sig, &sig_len, md, static_cast<size_t>(EVP_MD_size(digest_algo))) <= 0)
        {
            display_openssl_errors(__LINE__);
            exit(1);
        }
        EVP_PKEY_CTX_free(pkey_ctx);
    }

    printf("Signature created\n");

    {
        auto pkey_ctx = EVP_PKEY_CTX_new(pkey, engine);

        if (EVP_PKEY_verify_init(pkey_ctx) <= 0)
        {
            fprintf(stderr, "Could not init verify\n");
            display_openssl_errors(__LINE__);
            exit(1);
        }

        if (EVP_PKEY_CTX_set_signature_md(pkey_ctx, digest_algo) <= 0)
        {
            fprintf(stderr, "Could not set message digest algorithm\n");
            display_openssl_errors(__LINE__);
            exit(1);
        }

        auto ret = EVP_PKEY_verify(pkey_ctx, sig, sig_len, md, md_len);
        if (ret < 0)
        {
            printf("EVP_PKEY_verify() failed with  %d\n", ret);
            display_openssl_errors(__LINE__);
            exit(1);
        }

        if (ret != 1)
        {
            printf("Verification failed\n");
            display_openssl_errors(__LINE__);
            return false;
        }
        EVP_PKEY_CTX_free(pkey_ctx);
    }
    printf("Signature verified\n");
    return true;
}

static ENGINE *loadEngine()
{
    ENGINE_load_builtin_engines();
    auto eng = ENGINE_by_id("pkcs11");
    if (!eng)
    {
        printf("Error: Load PKCS#11 ENGINE\n");
        return nullptr;
    }

    if (!ENGINE_init(eng))
    {
        printf("Error: ENGINE_init\n");
        ENGINE_free(eng);
        return nullptr;
    }

    if (!ENGINE_ctrl_cmd(eng, "MODULE_PATH", 0, (void *)("/usr/lib/libckteec.so.0"), NULL, 1))
    {
        printf("Error: MODULE_PATH\n");
        ENGINE_free(eng);
        return nullptr;
    }

    auto pin = getenv("PIN");
    if (!ENGINE_ctrl_cmd_string(eng, "PIN", pin, 0))
    {
        printf("Error: ENGINE set pin\n");
        ENGINE_free(eng);
        return nullptr;
    }
    return eng;
}

static EVP_PKEY *getKeyFromEngine(ENGINE *engine, const char *keyname)
{
    char buffer[1024]{};
    snprintf(buffer, sizeof(buffer), "pkcs11:object=%s", keyname);
    auto private_key = ENGINE_load_private_key(engine, buffer, NULL, NULL);

    if (!private_key)
    {
        printf("Error: failed loading private key %s\n", buffer);
    }
    return private_key;
}

[etienne-lms]

Hello @sbrandt-aixtrusion,

I was able to reproduce the issue using OP-TEE's pkcs11 TA token implementation. I use a client application that creates/destroys token key pairs using straight calls to Cryptoki (pkcs#11) API functions and that uses OpenSSL (with libp11 pkcs11 engine) to load the key and sign some data. Indeed, when I destroy an object and create a new one, my pkcs11 token (that is OP-TEE's pkcs11 TA) may assign the value of the previous key handle as handle value for the newly created key. This ends with libp11 pkcs11 engine to confuse object due to its cache when loading the private key reference.

I considered changing OP-TEE's pkcs11 TA implementation to lower cases where the pkcs11 object handle value of a destroyed key is re-assigned to a newly created object, but I think such change is fragile unless the implementation ensures an old object handle is never reused. I think such change would be to much of a constraint in OP-TEE's pkcs11 TA implementation considering a long term execution.

I tried another approach, changing libp11 implementation to reload object attributes when an object is initialized and its handle is found in the engine cache. I've created P-R #552 for that. Feedback is welcome.

[etienne-lms]

@sbrandt-aixtrusion, have a look at @mtrojnar feedback in #552, I hope it may help.

[sbrandt-aixtrusion]

Thanks a lot!
The bug is gone in the test program, it will take some more time to verify in the real life implementation.

I only noticed later that some of the functions I used were written by a colleague, and not public, but their names were meaningful enough, it seems.

[sbrandt-aixtrusion]

About unloading the engine - I tried that, we unload the engine when we don't use it. I will have to look into that in more detail. Might be that we don't call ENGINE_remove(), only ENGINE_free and ENGINE_cleanup(). But we do that after fetching the keys, before using them, so, ENGINE_remove might break our usage pattern.

So, at least for use, the "no caching" is a much better solution.