OpenPGP card v3.4 pkcs15-init reports not supported private key

[msetina]

While running:

pkcs15-init --delete-objects privkey,pubkey,cert --id 3 --store-private-key MihaSetina2024_new.p12 --format pkcs12 --auth-id 3 --verify-pin

I got:

Using reader with a card: Alcor Micro AU9540 00 00
User PIN required.
Please enter User PIN [Admin PIN]: 
Deleted 3 objects
error:11800071:PKCS12 routines::mac verify failure
Please enter passphrase to unlock secret key: 
Importing 3 certificates:
  0: 
  1: 
  2: 
Failed to store private key: Not supported

When ran with -vvvv it reports:

P:5738; T:0x140604670091904 18:17:28.090 [pkcs15-init] card-openpgp.c:3469:pgp_store_key: Update card algorithms
P:5738; T:0x140604670091904 18:17:28.090 [pkcs15-init] card-openpgp.c:2964:pgp_update_card_algorithms: called
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] card-openpgp.c:2993:pgp_update_card_algorithms: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] card-openpgp.c:3474:pgp_store_key: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] card-openpgp.c:3584:pgp_card_ctl: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] card.c:1129:sc_card_ctl: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] pkcs15-openpgp.c:190:openpgp_store_key: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.091 [pkcs15-init] pkcs15-lib.c:1211:sc_pkcs15init_encode_prvkey_content: called
P:5738; T:0x140604670091904 18:17:28.092 [pkcs15-init] pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
P:5738; T:0x140604670091904 18:17:28.092 [pkcs15-init] pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.092 [pkcs15-init] pkcs15-lib.c:1223:sc_pkcs15init_encode_prvkey_content: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.092 [pkcs15-init] pkcs15-lib.c:3330:sc_pkcs15init_add_object: called
P:5738; T:0x140604670091904 18:17:28.092 [pkcs15-init] pkcs15-lib.c:3331:sc_pkcs15init_add_object: add object 0x55f758b23dc0 to DF of type 0
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-lib.c:3355:sc_pkcs15init_add_object: Append object
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-openpgp.c:405:openpgp_emu_update_any_df: called
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-openpgp.c:408:openpgp_emu_update_any_df: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-lib.c:3374:sc_pkcs15init_add_object: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-openpgp.c:433:openpgp_store_data: called
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-openpgp.c:524:openpgp_store_data: returning with: 0 (Success)
P:5738; T:0x140604670091904 18:17:28.093 [pkcs15-init] pkcs15-lib.c:1843:sc_pkcs15init_store_private_key: returning with: 0 (Success)
P:5738; T:0x140604670091904free(): double free detected in tcache 2
Aborted (core dumped)

pkcs11-tool reports private key, public key and cert written on the card.

opensc-tool info is:

OpenSC 0.25.0 

[Jakuje]

Can you run the code under valgrind to get a backtrace of the double-free?

[msetina]

Do you need any special parameters for valgrind?

[Jakuje]

No, the default memcheck should catch double free and print backtraces.

[msetina]

@Jakuje here it is:
valgrind-out.txt

[frankmorgner]

errors reported by pgp_set_blob are often ignored, but that doesn't seem to be the problem here.

I think your code is en par with 0.25.0. Here, card-openpgp.c:2551 calls pgp_put_data with algo_blob->data. It seems that this very algo_blob is found as existing blob and modified by pgp_put_data, which invalidates the pointer when the underlying pgp_set_blob does its cleanup. I think you can fix this with the following change:

diff --git a/src/libopensc/card-openpgp.c b/src/libopensc/card-openpgp.c
index 0e8015053..c7b067bdf 100644
--- a/src/libopensc/card-openpgp.c
+++ b/src/libopensc/card-openpgp.c
@@ -2547,8 +2547,8 @@ pgp_update_new_algo_attr(sc_card_t *card, sc_cardctl_openpgp_keygen_info_t *key_
                }
 
                pgp_set_blob(algo_blob, data, data_len);
+               r = pgp_put_data(card, tag, data, data_len);
                free(data);
-               r = pgp_put_data(card, tag, algo_blob->data, data_len);
                /* Note: Don't use pgp_set_blob to set data, because it won't touch the real DO */
                LOG_TEST_RET(card->ctx, r, "Cannot set new algorithm attributes");
        } else {

However, I'm not too deep into that code to check whether there is some logical problem that should be fixed first.

[Jakuje]

@msetina did you try with the changed code proposed by Frank?

[msetina]

By the words around I did not bite, but now I tried it and there is no change from user side. It still says unsupported, but I think now it does not write certificate.

[msetina]

I've reverted and I can confirm that after the mentioned change certificate is not written. Reverting I get Private key and certificate on the card.

[frankmorgner]

thanks for the feedback. I created a pull request with the fix.

[msetina]

@frankmorgner I am sorry for the confusion, but the proposed change did not fix the issue. It added a problem of not writing a certificate.
The original code wrote the private key, public key and the certificate to the card, but reported the unsupported private key because of the problem with releasing memory.
I did revert your change on my side to confirm that original code did write the certificate.

[msetina]

I've made a test case that prepares as private key and a certificate and tries to write it to the card. In one case it core dumped, when running in a separate process it said it has a corrupted double-linked list in another malloc_consolidate(): unaligned fastbin chunk detected.
In the last case I got it to run over pkcs11-spy and in debug mode:
opensc-debug.txt
logfile.txt

[dengert]

I would suggest that you build OpenSC and add to CPPFLAGS and LDGLAGS -g
Then run under debugger (gdb for example) and when it crashes, get a back trace and look at the some of the parameters.

[msetina]

I would do that if I was not running in python over PyKCS11. It would be easy for me to help you if I was capable of CPP or C.
Thanks anyway. I've done what I could.
The problem started with pkcs15-init and I see the same with PKCS11.