Current master fails ec-check-privkey test

[mouse07410]

macOS Big Sur 11.4, Xcode-12.5.1, OpenSSL-3.0 dev (current master), OpenSC (current master), libp11 (current master).

FAIL: ec-check-privkey.softhsm
==============================

Current directory: /Users/ur20980/src/libp11/tests
Source directory: .
Output directory: output.80297
* Initializing smart card... ok
Using slot 0 with a present token (0x71615760)
Using slot 0 with a present token (0x71615760)
***************
Listing objects
***************
Using slot 0 with a present token (0x71615760)
Private Key Object; EC
  label:      server-key
  ID:         01020304
  Usage:      decrypt, sign, unwrap
  Access:     sensitive
Certificate Object; type = X.509 cert
  label:      server-key
  subject:    DN: CN=ec
  ID:         01020304
PKCS#11: Initializing the engine
Found 2 slots
Looking in slot -1 for private key: id=01020304 label=server-key
[1902204768] SoftHSM slot ID 0x7161576  login             (libp11-test)
[1] SoftHSM slot ID 0x1        uninitialized, login  (no label)
Found slot:  SoftHSM slot ID 0x71615760
Found token: libp11-test
Looking in slot -1 for private key: id=01020304 label=server-key
[1902204768] SoftHSM slot ID 0x7161576  login             (libp11-test)
[1] SoftHSM slot ID 0x1        uninitialized, login  (no label)
Found slot:  SoftHSM slot ID 0x71615760
Found token: libp11-test
Found 1 private key:
   1 P  id=01020304 label=server-key
At main.c:186:
- SSL error:05800075:x509 certificate routines::unknown key type: crypto/x509/x509_cmp.c:410
check-privkey.c:185 Could not check private key
The private key loading couln't get the public key from the certificate
FAIL ec-check-privkey.softhsm (exit status: 1)

[dengert]

Your libp11 line numbers don't match what is in master. But I question why in https://github.com/OpenSC/libp11/blob/master/tests/check-privkey.c#L162-L181 is ENGINE_finish(engine); called so early, I would expect it should be called at L179.

[mouse07410]

Your libp11 line numbers don't match what is in master

Patching my fork, I #if 0-ed the removed lines instead of completely deleting them from the file src/back_eng.c.

Regardless, the observed problem did not occur until the latest patch.

ENGINE_finish(engine); called so early . . .

Strange - in the file I see in my repo:

.  .  .  .  .
    printf("Key and certificate matched\n");
    ret = 0;

    CONF_modules_unload(1);
end:
    X509_free(cert);
    EVP_PKEY_free(pkey);

    ENGINE_finish(engine);

    return ret;
}

[dengert]

Yes, the location of the ENGINE_finish(engine); is strange. I was looking at https://github.com/OpenSC/libp11/blob/master/tests/check-privkey.c#L162-L181 that has not been modified in in 2 years.

Did you move it? git blame should show something.

[dengert]

Have a look at 9bc75aacaee2e42118a40262acee5b46ef006c6f from a few days ago. Did this drop a reference that is need for a public key?

[mouse07410]

Have a look at 9bc75aa from a few days ago. Did this drop a reference that is need for a public key?

I'm not sure.

It does look like this comparison https://github.com/openssl/openssl/blob/5fc0992fc748ec182ef5a8191807a18ecccbb4ce/crypto/evp/p_lib.c#L349 fails, which causes this https://github.com/openssl/openssl/blob/5fc0992fc748ec182ef5a8191807a18ecccbb4ce/crypto/x509/x509_cmp.c#L396 to return -2.

[mtrojnar]

@mouse07410 I confirmed that X509_get0_pubkey(cert)->ameth is indeed NULL in https://github.com/OpenSC/libp11/blob/9bc75aacaee2e42118a40262acee5b46ef006c6f/tests/check-privkey.c#L164 regardless of whether the certificate was loaded from a pem file or from our engine. It looks to me like an error in OpenSSL 3.0.

[mtrojnar]

Yes, the location of the ENGINE_finish(engine); is strange.

Not really. OpenSSL's object management is based on reference counting. The engine is not finished until its functional reference count reaches zero: https://github.com/openssl/openssl/blob/5fc0992fc748ec182ef5a8191807a18ecccbb4ce/crypto/engine/eng_init.c#L59-L61 Each EVP_PKEY object holds a functional reference to its engine: https://github.com/openssl/openssl/blob/5fc0992fc748ec182ef5a8191807a18ecccbb4ce/crypto/evp/p_lib.c#L684 Consequently, the engine is only finished after its last key is removed: https://github.com/openssl/openssl/blob/5fc0992fc748ec182ef5a8191807a18ecccbb4ce/crypto/evp/p_lib.c#L1722

[levitte]

I may have solved the issue: https://github.com/openssl/openssl/issues/15927#issuecomment-873993664

But, when looking more closely into this, I'm surprised to see that you only check this for EC keys... might I suggest adding a similar test for RSA?

[mouse07410]

I may have solved the issue: openssl/openssl#15927 (comment)

Thank you! Let me test.

But, when looking more closely into this, I'm surprised to see that you only check this for EC keys... might I suggest adding a similar test for RSA?

It's up to @mtrojnar to decide - but the suggestion makes perfect sense to me. I may try to create something like that myself too...

[mtrojnar]

I'm surprised to see that you only check this for EC keys... might I suggest adding a similar test for RSA?

It's up to @mtrojnar to decide - but the suggestion makes perfect sense to me. I may try to create something like that myself too...

Good idea. Please submit the test as a PR.

[mouse07410]

Addressing via PR https://github.com/OpenSC/libp11/pull/421