C_FindObjects does not find keys generated by C_GenerateKeyPair without reinserting

[arrowd]

In my program I read the public part of the keypair stored on token, then generate a new keypair and read the public key again. I'm getting the same key until I reinsert the token or restart my program.

In #3018 (comment) I was suggested to additionally call C_DestroyObject before generating a new keypair. This caused my program to report "no keys generated" after C_GenerateKeyPair finishes, which is again fixed by reinserting/restarting.

Here are the logs I gathered while reproducing the issue:

I. GetPublicKey() for a previosly generated key pair

card.c:471:sc_lock: called
reader-pcsc.c:690:pcsc_lock: called
card-openpgp.c:3745:pgp_card_reader_lock_obtained: called
card-openpgp.c:3772:pgp_card_reader_lock_obtained: returning with: 0 (Success)
card.c:513:sc_lock: returning with: 0 (Success)
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_ENCRYPT = TRUE
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b240
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456252992: Attribute 0x104 does NOT match.
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b1e0
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:435:C_FindObjectsInit: Object 0/34456252896 matches
pkcs11-object.c:439:C_FindObjectsInit: realloc for 32 handles
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456350800: Attribute 0x104 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 1 matching objects
misc.c:289:session_get_operation: called
misc.c:289:session_get_operation: called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456252896: CKA_MODULUS = <size inquiry>
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011150, hObject=0x805c0b1e0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456252896: CKA_MODULUS = DBA8735B108923E7BB3F266107C542A6634A73435650015CF587573C36B664B1
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011150, hObject=0x805c0b1e0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456252896: CKA_PUBLIC_EXPONENT = <size inquiry>
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011150, hObject=0x805c0b1e0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456252896: CKA_PUBLIC_EXPONENT = 010001
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011150, hObject=0x805c0b1e0) = CKR_OK
card.c:523:sc_unlock: called
reader-pcsc.c:742:pcsc_unlock: called

II. FindObjects + DeleteObject

card.c:471:sc_lock: called
reader-pcsc.c:690:pcsc_lock: called
card-openpgp.c:3745:pgp_card_reader_lock_obtained: called
card-openpgp.c:3772:pgp_card_reader_lock_obtained: returning with: 0 (Success)
card.c:513:sc_lock: returning with: 0 (Success)
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = CKO_PUBLIC_KEY
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b240
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456252992: Attribute 0x0 does NOT match.
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b1e0
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:435:C_FindObjectsInit: Object 0/34456252896 matches
pkcs11-object.c:439:C_FindObjectsInit: realloc for 32 handles
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456350800: Attribute 0x0 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 1 matching objects
misc.c:289:session_get_operation: called
pkcs11-object.c:190:C_DestroyObject: C_DestroyObject(hSession=0x806011150, hObject=0x805c0b1e0)
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
pkcs15-lib.c:321:sc_pkcs15init_bind: called
card.c:1119:sc_card_ctl: called
card-openpgp.c:3584:pgp_card_ctl: called
card-openpgp.c:3611:pgp_card_ctl: returning with: -1408 (Not supported)
card.c:1126:sc_card_ctl: card_ctl(4) not supported
card.c:850:sc_select_file: called; type=2, path=3f0050154946
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1510:pgp_select_file: returning with: -1201 (File not found)
card.c:872:sc_select_file: 'SELECT' error: -1201 (File not found)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/pkcs15.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/pkcs15.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/openpgp.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/openpgp.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:428:sc_pkcs15init_bind: returning with: 0 (Success)
pkcs15-lib.c:761:sc_pkcs15init_finalize_profile: called
pkcs15-lib.c:776:sc_pkcs15init_finalize_profile: Finalize profile with application 'default'
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:779:sc_pkcs15init_finalize_profile: sc_pkcs15init_finalize_profile() returns 0
pkcs15-lib.c:780:sc_pkcs15init_finalize_profile: returning with: 0 (Success)
pkcs15-lib.c:3568:sc_pkcs15init_delete_object: called
pkcs15-lib.c:3572:sc_pkcs15init_delete_object: delete object(type:201) with path(type:2,a401)
card.c:850:sc_select_file: called; type=2, path=a401
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card.c:885:sc_select_file: returning with: 0 (Success)
pkcs15-lib.c:580:sc_pkcs15init_delete_by_path: called
pkcs15-lib.c:581:sc_pkcs15init_delete_by_path: trying to delete 'a401'
card.c:850:sc_select_file: called; type=2, path=a401
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card.c:885:sc_select_file: returning with: 0 (Success)
pkcs15-lib.c:601:sc_pkcs15init_delete_by_path: Found 'DELETE' acl
pkcs15-lib.c:4026:sc_pkcs15init_authenticate: called
pkcs15-lib.c:4028:sc_pkcs15init_authenticate: path 'a401', op=2
pkcs15-lib.c:4044:sc_pkcs15init_authenticate: acl 0x806000640
pkcs15-lib.c:4059:sc_pkcs15init_authenticate: verify acl(method:1,reference:3)
pkcs15-lib.c:3855:sc_pkcs15init_verify_secret: called
pkcs15-lib.c:3859:sc_pkcs15init_verify_secret: get and verify PIN('PIN',type:0x1,reference:0x3)
pkcs15-lib.c:2327:sc_pkcs15init_get_pin_reference: called
pkcs15-lib.c:2337:sc_pkcs15init_get_pin_reference: found 3 auth objects; looking for AUTH object(auth_method:1,reference:3)
pkcs15-lib.c:2344:sc_pkcs15init_get_pin_reference: check PIN(User PIN,auth_method:1,type:2,reference:2,flags:13)
pkcs15-lib.c:2344:sc_pkcs15init_get_pin_reference: check PIN(User PIN (sig),auth_method:1,type:2,reference:1,flags:13)
pkcs15-lib.c:2344:sc_pkcs15init_get_pin_reference: check PIN(Admin PIN,auth_method:1,type:2,reference:3,flags:9B)
pkcs15-lib.c:2347:sc_pkcs15init_get_pin_reference: returning with: 3
pkcs15-lib.c:3879:sc_pkcs15init_verify_secret: found PIN reference 3
pkcs15-lib.c:3904:sc_pkcs15init_verify_secret: found PIN object 'Admin PIN'
pkcs15-lib.c:3911:sc_pkcs15init_verify_secret: PIN object 'Admin PIN'; pin_obj->content.len:9
pkcs15-lib.c:3917:sc_pkcs15init_verify_secret: 've got 'PIN' value from cache
pkcs15-pin.c:304:sc_pkcs15_verify_pin: called
pkcs15-pin.c:351:sc_pkcs15_verify_pin_with_session_pin: called
pkcs15-pin.c:355:sc_pkcs15_verify_pin_with_session_pin: PIN(type:0; method:1; value(0x7fffdf3f6aa0:9)
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
card.c:850:sc_select_file: called; type=2, path=3f00
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card.c:885:sc_select_file: returning with: 0 (Success)
sec.c:203:sc_pin_cmd: called
sec.c:259:sc_pin_cmd: returning with: 0 (Success)
pkcs15-pin.c:443:sc_pkcs15_verify_pin_with_session_pin: PIN cmd result 0
pkcs15-pin.c:749:sc_pkcs15_pincache_add: called
pkcs15-pin.c:793:sc_pkcs15_pincache_add: PIN(Admin PIN) cached
card.c:523:sc_unlock: called
pkcs15-pin.c:465:sc_pkcs15_verify_pin_with_session_pin: returning with: 0 (Success)
pkcs15-pin.c:749:sc_pkcs15_pincache_add: called
pkcs15-pin.c:793:sc_pkcs15_pincache_add: PIN(Admin PIN) cached
pkcs15-pin.c:321:sc_pkcs15_verify_pin: returning with: 0 (Success)
card.c:850:sc_select_file: called; type=2, path=a401
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card.c:885:sc_select_file: returning with: 0 (Success)
pkcs15-lib.c:4000:sc_pkcs15init_verify_secret: returning with: 0 (Success)
pkcs15-lib.c:4065:sc_pkcs15init_authenticate: returning with: 0 (Success)
card.c:850:sc_select_file: called; type=2, path=a401
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card.c:885:sc_select_file: returning with: 0 (Success)
pkcs15-lib.c:652:sc_pkcs15init_delete_by_path: Now really delete file
card.c:611:sc_delete_file: called; type=0, path=a401
card-openpgp.c:3667:pgp_delete_file: called
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1520:pgp_select_file: returning with: 0 (Success)
card-openpgp.c:3705:pgp_delete_file: returning with: 0 (Success)
card.c:616:sc_delete_file: returning with: 0 (Success)
pkcs15-lib.c:655:sc_pkcs15init_delete_by_path: returning with: 0 (Success)
pkcs15-openpgp.c:405:openpgp_emu_update_any_df: called
pkcs15-openpgp.c:408:openpgp_emu_update_any_df: returning with: 0 (Success)
pkcs15-lib.c:3617:sc_pkcs15init_delete_object: returning with: 0 (Success)
pkcs15-lib.c:438:sc_pkcs15init_unbind: called
pkcs15-lib.c:439:sc_pkcs15init_unbind: Pksc15init Unbind: 1:0x0:1
card.c:523:sc_unlock: called
misc.c:289:session_get_operation: called
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = CKO_PRIVATE_KEY
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b240
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
pkcs11-object.c:435:C_FindObjectsInit: Object 0/34456252992 matches
pkcs11-object.c:439:C_FindObjectsInit: realloc for 32 handles
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456350800: Attribute 0x0 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 1 matching objects
misc.c:289:session_get_operation: called
pkcs11-object.c:190:C_DestroyObject: C_DestroyObject(hSession=0x806011150, hObject=0x805c0b240)
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
pkcs15-lib.c:321:sc_pkcs15init_bind: called
card.c:1119:sc_card_ctl: called
card-openpgp.c:3584:pgp_card_ctl: called
card-openpgp.c:3611:pgp_card_ctl: returning with: -1408 (Not supported)
card.c:1126:sc_card_ctl: card_ctl(4) not supported
card.c:850:sc_select_file: called; type=2, path=3f0050154946
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1510:pgp_select_file: returning with: -1201 (File not found)
card.c:872:sc_select_file: 'SELECT' error: -1201 (File not found)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/pkcs15.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/pkcs15.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/openpgp.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/openpgp.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:428:sc_pkcs15init_bind: returning with: 0 (Success)
pkcs15-lib.c:761:sc_pkcs15init_finalize_profile: called
pkcs15-lib.c:776:sc_pkcs15init_finalize_profile: Finalize profile with application 'default'
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:779:sc_pkcs15init_finalize_profile: sc_pkcs15init_finalize_profile() returns 0
pkcs15-lib.c:780:sc_pkcs15init_finalize_profile: returning with: 0 (Success)
pkcs15-lib.c:3568:sc_pkcs15init_delete_object: called
pkcs15-lib.c:3572:sc_pkcs15init_delete_object: delete object(type:101) with path(type:0,)
pkcs15-openpgp.c:405:openpgp_emu_update_any_df: called
pkcs15-openpgp.c:408:openpgp_emu_update_any_df: returning with: 0 (Success)
pkcs15-lib.c:3617:sc_pkcs15init_delete_object: returning with: 0 (Success)
pkcs15-lib.c:438:sc_pkcs15init_unbind: called
pkcs15-lib.c:439:sc_pkcs15init_unbind: Pksc15init Unbind: 1:0x0:1
card.c:523:sc_unlock: called
misc.c:289:session_get_operation: called
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = 0x9
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:435:C_FindObjectsInit: Object 0/34456350800 matches
pkcs11-object.c:439:C_FindObjectsInit: realloc for 32 handles
pkcs11-object.c:452:C_FindObjectsInit: 1 matching objects
misc.c:289:session_get_operation: called
pkcs11-object.c:190:C_DestroyObject: C_DestroyObject(hSession=0x806011150, hObject=0x805c23050)
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
pkcs15-lib.c:321:sc_pkcs15init_bind: called
card.c:1119:sc_card_ctl: called
card-openpgp.c:3584:pgp_card_ctl: called
card-openpgp.c:3611:pgp_card_ctl: returning with: -1408 (Not supported)
card.c:1126:sc_card_ctl: card_ctl(4) not supported
card.c:850:sc_select_file: called; type=2, path=3f0050154946
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1510:pgp_select_file: returning with: -1201 (File not found)
card.c:872:sc_select_file: 'SELECT' error: -1201 (File not found)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/pkcs15.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/pkcs15.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/openpgp.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/openpgp.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:428:sc_pkcs15init_bind: returning with: 0 (Success)
pkcs15-lib.c:761:sc_pkcs15init_finalize_profile: called
pkcs15-lib.c:776:sc_pkcs15init_finalize_profile: Finalize profile with application 'default'
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:779:sc_pkcs15init_finalize_profile: sc_pkcs15init_finalize_profile() returns 0
pkcs15-lib.c:780:sc_pkcs15init_finalize_profile: returning with: 0 (Success)
pkcs15-lib.c:3568:sc_pkcs15init_delete_object: called
pkcs15-lib.c:3570:sc_pkcs15init_delete_object: Failed to get object path: -1408 (Not supported)
pkcs15-lib.c:438:sc_pkcs15init_unbind: called
pkcs15-lib.c:439:sc_pkcs15init_unbind: Pksc15init Unbind: 0:0x0:1
card.c:523:sc_unlock: called
misc.c:71:sc_to_cryptoki_error_common: libopensc return value: -1408 (Not supported)
misc.c:289:session_get_operation: called
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = CKO_CERTIFICATE
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456350800: Attribute 0x0 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 0 matching objects
misc.c:289:session_get_operation: called
misc.c:289:session_get_operation: called

III. GenerateKeyPair

pkcs11-object.c:1161:C_GenerateKeyPair: C_GenerateKeyPair(), PrivKey attrs: CKA_CLASS = CKO_PRIVATE_KEY
pkcs11-object.c:1161:C_GenerateKeyPair: C_GenerateKeyPair(), PrivKey attrs: CKA_TOKEN = TRUE
pkcs11-object.c:1161:C_GenerateKeyPair: C_GenerateKeyPair(), PrivKey attrs: CKA_PRIVATE = TRUE
pkcs11-object.c:1161:C_GenerateKeyPair: C_GenerateKeyPair(), PrivKey attrs: CKA_SENSITIVE = TRUE
pkcs11-object.c:1162:C_GenerateKeyPair: C_GenerateKeyPair(), PubKey attrs: CKA_CLASS = CKO_PUBLIC_KEY
pkcs11-object.c:1162:C_GenerateKeyPair: C_GenerateKeyPair(), PubKey attrs: CKA_TOKEN = TRUE
pkcs11-object.c:1162:C_GenerateKeyPair: C_GenerateKeyPair(), PubKey attrs: CKA_PRIVATE = FALSE
pkcs11-object.c:1162:C_GenerateKeyPair: C_GenerateKeyPair(), PubKey attrs: CKA_MODULUS_BITS = 0x800
framework-pkcs15.c:3282:pkcs15_gen_keypair: Key pair generation, mech = 0x0
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
pkcs15-lib.c:321:sc_pkcs15init_bind: called
card.c:1119:sc_card_ctl: called
card-openpgp.c:3584:pgp_card_ctl: called
card-openpgp.c:3611:pgp_card_ctl: returning with: -1408 (Not supported)
card.c:1126:sc_card_ctl: card_ctl(4) not supported
card.c:850:sc_select_file: called; type=2, path=3f0050154946
card-openpgp.c:1456:pgp_select_file: called
card-openpgp.c:1510:pgp_select_file: returning with: -1201 (File not found)
card.c:872:sc_select_file: 'SELECT' error: -1201 (File not found)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/pkcs15.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/pkcs15.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:337:sc_profile_load: called
profile.c:357:sc_profile_load: Using profile directory '/usr/local/share/opensc'.
profile.c:365:sc_profile_load: Trying profile file /usr/local/share/opensc/openpgp.profile
profile.c:370:sc_profile_load: profile /usr/local/share/opensc/openpgp.profile loaded ok
profile.c:384:sc_profile_load: returning with: 0 (Success)
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:428:sc_pkcs15init_bind: returning with: 0 (Success)
pkcs15-lib.c:761:sc_pkcs15init_finalize_profile: called
pkcs15-lib.c:776:sc_pkcs15init_finalize_profile: Finalize profile with application 'default'
profile.c:396:sc_profile_finish: called
profile.c:439:sc_profile_finish: returning with: 0 (Success)
pkcs15-lib.c:779:sc_pkcs15init_finalize_profile: sc_pkcs15init_finalize_profile() returns 0
pkcs15-lib.c:780:sc_pkcs15init_finalize_profile: returning with: 0 (Success)
pkcs15-lib.c:458:sc_pkcs15init_set_p15card: called
profile.c:633:sc_profile_get_file_by_path: called
profile.c:637:sc_profile_get_file_by_path: returning with: 0 (Success)
profile.c:633:sc_profile_get_file_by_path: called
profile.c:637:sc_profile_get_file_by_path: returning with: 0 (Success)
pkcs15-lib.c:491:sc_pkcs15init_set_p15card: sc_pkcs15init_set_p15card() returns
framework-pkcs15.c:3453:pkcs15_gen_keypair: Try on-card key pair generation
pkcs15-lib.c:1547:sc_pkcs15init_generate_key: called
pkcs15-lib.c:2538:check_keygen_params_consistency: returning with: 0 (Success)
pkcs15-lib.c:2561:check_key_compatibility: called
pkcs15-lib.c:2595:check_key_compatibility: returning with: 0 (Success)
pkcs15-lib.c:1244:sc_pkcs15init_init_prkdf: called
pkcs15-lib.c:2902:select_id: called
pkcs15-lib.c:2947:select_id: returning with: 0 (Success)
pkcs15-lib.c:3034:select_object_path: called
pkcs15-lib.c:3059:select_object_path: key-domain.private-key @3f005015 (auth_id.len=1)
profile.c:707:sc_profile_instantiate_template: Instantiating template key-domain at 3f005015
profile.c:790:sc_profile_instantiate_file: Instantiated private-key at 3f0050155f48
profile.c:791:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
pkcs15-lib.c:3081:select_object_path: instantiated template path 3f0050155f48
pkcs15-lib.c:3110:select_object_path: returns object path '3f0050155f48'
pkcs15-lib.c:3111:select_object_path: returning with: 0 (Success)
pkcs15-lib.c:1373:sc_pkcs15init_init_prkdf: returning with: 0 (Success)
pkcs15-lib.c:1484:_pkcd15init_set_aux_md_data: called
pkcs15-lib.c:1487:_pkcd15init_set_aux_md_data: returning with: 0 (Success)
pkcs15-openpgp.c:103:openpgp_create_key: called
pkcs15-openpgp.c:104:openpgp_create_key: returning with: 0 (Success)
pkcs15-openpgp.c:373:openpgp_generate_key: called
pkcs15-openpgp.c:209:openpgp_generate_key_rsa: called
pkcs15-openpgp.c:211:openpgp_generate_key_rsa: Key ID to be generated: 45
pkcs15-openpgp.c:217:openpgp_generate_key_rsa: Authentication key is to be generated.
card.c:1119:sc_card_ctl: called
card-openpgp.c:3584:pgp_card_ctl: called
card-openpgp.c:3020:pgp_gen_key: called
card-openpgp.c:2509:pgp_update_new_algo_attr: called
card-openpgp.c:1986:pgp_put_data: called
card-openpgp.c:1938:pgp_put_data_plain: called
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:DA, P1:0, P2:C3, data(6) 0x806009080
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
card-openpgp.c:1971:pgp_put_data_plain: returning with: 6
card-openpgp.c:2035:pgp_put_data: Updating the corresponding blob data
card-openpgp.c:2042:pgp_put_data: returning with: 6
card-openpgp.c:2572:pgp_update_new_algo_attr: returning with: 6
card-openpgp.c:3081:pgp_gen_key: Waiting for the card to generate key...
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:47, P1:80, P2:0, data(2) 0x7fffdf3f6026
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 

......i.L.
...$.JT.3.
......6i..
!....7..C.
@L...za...
..N.T9..a(
..b...1S.b
.S........
...M9....n
.]....F...
....B.....
.........2
;.....m..5
.Yt......U
....s....q
I.#.......
..........

apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
card-openpgp.c:3083:pgp_gen_key: Card has done key generation.
card-openpgp.c:2878:pgp_parse_and_set_pubkey_output: called
card-openpgp.c:2592:pgp_store_creationtime: called
card-openpgp.c:2612:pgp_store_creationtime: Creation time Tue Mar 12 12:16:58 2024 UTC.
card-openpgp.c:1986:pgp_put_data: called
card.c:893:sc_get_data: called, tag=007a
card-openpgp.c:1835:pgp_get_data: called
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:CA, P1:0, P2:7A, data(0) 0x0
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
card-openpgp.c:1862:pgp_get_data: returning with: 5
card.c:898:sc_get_data: returning with: 5
card-openpgp.c:1632:pgp_get_pubkey: called, tag=b600
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:47, P1:81, P2:0, data(2) 0x7fffdf3f38b6
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
iso7816.c:128:iso7816_check_sw: Referenced data not found
card-openpgp.c:1646:pgp_get_pubkey: Card returned error: -1216 (Data object not found)
card-openpgp.c:1632:pgp_get_pubkey: called, tag=b800
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:47, P1:81, P2:0, data(2) 0x7fffdf3f38b6
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
iso7816.c:128:iso7816_check_sw: Referenced data not found
card-openpgp.c:1646:pgp_get_pubkey: Card returned error: -1216 (Data object not found)
card-openpgp.c:1399:pgp_find_blob: Failed to seek the blob representing the tag 00D0. Error -1201.
card-openpgp.c:1938:pgp_put_data_plain: called
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:DA, P1:0, P2:D0, data(4) 0x7fffdf3f5d5c
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
card-openpgp.c:1971:pgp_put_data_plain: returning with: 4
card-openpgp.c:2042:pgp_put_data: returning with: 4
card-openpgp.c:2617:pgp_store_creationtime: returning with: 4
card-openpgp.c:2952:pgp_parse_and_set_pubkey_output: Calculate and store fingerprint
card-openpgp.c:2639:pgp_calculate_and_store_fingerprint: called
card-openpgp.c:2692:pgp_calculate_and_store_fingerprint: pk_packet_len is 269
card-openpgp.c:2774:pgp_calculate_and_store_fingerprint: Writing to DO 00C9.
card-openpgp.c:1986:pgp_put_data: called
card-openpgp.c:1632:pgp_get_pubkey: called, tag=b600
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:47, P1:81, P2:0, data(2) 0x7fffdf3f3896
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
iso7816.c:128:iso7816_check_sw: Referenced data not found
card-openpgp.c:1646:pgp_get_pubkey: Card returned error: -1216 (Data object not found)
card-openpgp.c:1632:pgp_get_pubkey: called, tag=b800
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:47, P1:81, P2:0, data(2) 0x7fffdf3f3896
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 



reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
iso7816.c:128:iso7816_check_sw: Referenced data not found
card-openpgp.c:1646:pgp_get_pubkey: Card returned error: -1216 (Data object not found)
card-openpgp.c:1399:pgp_find_blob: Failed to seek the blob representing the tag 00C9. Error -1201.
card-openpgp.c:1938:pgp_put_data_plain: called
apdu.c:550:sc_transmit_apdu: called
card.c:471:sc_lock: called
card.c:513:sc_lock: returning with: 0 (Success)
apdu.c:515:sc_transmit: called
apdu.c:363:sc_single_transmit: called
apdu.c:370:sc_single_transmit: CLA:0, INS:DA, P1:0, P2:C9, data(20) 0x7fffdf3f5d90
reader-pcsc.c:325:pcsc_transmit: reader 'Nitrokey Nitrokey 3 [CCID/ICCD Interface] 00 00'
reader-pcsc.c:326:pcsc_transmit: 

.^..M.oD._
X(.

reader-pcsc.c:244:pcsc_internal_transmit: called
reader-pcsc.c:335:pcsc_transmit: 



apdu.c:382:sc_single_transmit: returning with: 0 (Success)
apdu.c:539:sc_transmit: returning with: 0 (Success)
card.c:523:sc_unlock: called
card-openpgp.c:1971:pgp_put_data_plain: returning with: 20
card-openpgp.c:2042:pgp_put_data: returning with: 20
card-openpgp.c:2779:pgp_calculate_and_store_fingerprint: Updating fingerprint blob 00C5.
card-openpgp.c:2800:pgp_calculate_and_store_fingerprint: returning with: 20
card-openpgp.c:2956:pgp_parse_and_set_pubkey_output: Update blobs holding pubkey info.
card-openpgp.c:2819:pgp_update_pubkey_blob: called
card-openpgp.c:2832:pgp_update_pubkey_blob: Retrieving blob A401.
pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
card-openpgp.c:2860:pgp_update_pubkey_blob: Updating blob A401's content.
card-openpgp.c:2864:pgp_update_pubkey_blob: returning with: 0 (Success)
card-openpgp.c:2958:pgp_parse_and_set_pubkey_output: returning with: 0 (Success)
card-openpgp.c:2972:pgp_update_card_algorithms: called
card-openpgp.c:3001:pgp_update_card_algorithms: returning with: 0 (Success)
card-openpgp.c:3101:pgp_gen_key: returning with: 0 (Success)
card-openpgp.c:3598:pgp_card_ctl: returning with: 0 (Success)
card.c:1129:sc_card_ctl: returning with: 0 (Success)
pkcs15-openpgp.c:254:openpgp_generate_key_rsa: Set output modulus info
pkcs15-openpgp.c:261:openpgp_generate_key_rsa: Set output exponent info
pkcs15-openpgp.c:271:openpgp_generate_key_rsa: returning with: 0 (Success)
pkcs15-openpgp.c:399:openpgp_generate_key: returning with: 0 (Success)
pkcs15-lib.c:2795:sc_pkcs15init_select_intrinsic_id: called
pkcs15-lib.c:2888:sc_pkcs15init_select_intrinsic_id: returning with: 20
pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
pkcs15-lib.c:3328:sc_pkcs15init_add_object: called
pkcs15-lib.c:3329:sc_pkcs15init_add_object: add object 0x805c37000 to DF of type 0
pkcs15-lib.c:3353:sc_pkcs15init_add_object: Append object
pkcs15-openpgp.c:405:openpgp_emu_update_any_df: called
pkcs15-openpgp.c:408:openpgp_emu_update_any_df: returning with: 0 (Success)
pkcs15-lib.c:3372:sc_pkcs15init_add_object: returning with: 0 (Success)
pkcs15-openpgp.c:433:openpgp_store_data: called
pkcs15-openpgp.c:524:openpgp_store_data: returning with: 0 (Success)
pkcs15-lib.c:1865:sc_pkcs15init_store_public_key: called
pkcs15-lib.c:2795:sc_pkcs15init_select_intrinsic_id: called
pkcs15-lib.c:2804:sc_pkcs15init_select_intrinsic_id: returning with: 0 (Success)
pkcs15-lib.c:2902:select_id: called
pkcs15-lib.c:2912:select_id: returning with: 0 (Success)
pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
pkcs15-pubkey.c:776:sc_pkcs15_encode_pubkey_as_spki: called
pkcs15-pubkey.c:780:sc_pkcs15_encode_pubkey_as_spki: Encoding public key with algorithm 0
pkcs15-pubkey.c:583:sc_pkcs15_encode_pubkey_rsa: called
pkcs15-pubkey.c:594:sc_pkcs15_encode_pubkey_rsa: returning with: 0 (Success)
pkcs15-algo.c:535:sc_asn1_encode_algorithm_id: called
pkcs15-algo.c:536:sc_asn1_encode_algorithm_id: type of algorithm to encode: 0
pkcs15-algo.c:550:sc_asn1_encode_algorithm_id: encode algo 1.2.840.113549.1.1.1
pkcs15-algo.c:589:sc_asn1_encode_algorithm_id: return encoded algorithm ID: 06092A864886F70D0101010500
pkcs15-algo.c:590:sc_asn1_encode_algorithm_id: returning with: 0 (Success)
pkcs15-pubkey.c:856:sc_pkcs15_encode_pubkey_as_spki: returning with: 0 (Success)
pkcs15-lib.c:2406:sc_pkcs15init_store_data: called
pkcs15-openpgp.c:433:openpgp_store_data: called
pkcs15-openpgp.c:524:openpgp_store_data: returning with: 0 (Success)
pkcs15-lib.c:2411:sc_pkcs15init_store_data: returning with: 0 (Success)
pkcs15-lib.c:3328:sc_pkcs15init_add_object: called
pkcs15-lib.c:3329:sc_pkcs15init_add_object: add object 0x805c37c00 to DF of type 1
pkcs15-lib.c:3353:sc_pkcs15init_add_object: Append object
pkcs15-openpgp.c:405:openpgp_emu_update_any_df: called
pkcs15-openpgp.c:408:openpgp_emu_update_any_df: returning with: 0 (Success)
pkcs15-lib.c:3372:sc_pkcs15init_add_object: returning with: 0 (Success)
pkcs15-lib.c:2033:sc_pkcs15init_store_public_key: returning with: 0 (Success)
pkcs15-lib.c:1680:sc_pkcs15init_generate_key: returning with: 0 (Success)
framework-pkcs15.c:753:__pkcs15_create_pubkey_object: Get pubkey from PKCS#15 object
pkcs15-pubkey.c:900:sc_pkcs15_read_pubkey: called
pkcs15-pubkey.c:901:sc_pkcs15_read_pubkey: Public key type 0x201
pkcs15-pubkey.c:933:sc_pkcs15_read_pubkey: Using direct SPKI value,  tag 0x30
pkcs15-pubkey.c:1438:sc_pkcs15_pubkey_from_spki_sequence: called
pkcs15-pubkey.c:1328:sc_pkcs15_pubkey_from_spki_fields: sc_pkcs15_pubkey_from_spki_fields() called: 0x806045504:290
pkcs15-algo.c:494:sc_asn1_decode_algorithm_id: called
pkcs15-algo.c:502:sc_asn1_decode_algorithm_id: decoded OID '1.2.840.113549.1.1.1'
pkcs15-algo.c:519:sc_asn1_decode_algorithm_id: returning with: 0 (Success)
pkcs15-pubkey.c:1367:sc_pkcs15_pubkey_from_spki_fields: DEE pk_alg.algorithm=0
pkcs15-pubkey.c:560:sc_pkcs15_decode_pubkey_rsa: called
pkcs15-pubkey.c:571:sc_pkcs15_decode_pubkey_rsa: returning with: 0 (Success)
pkcs15-pubkey.c:1424:sc_pkcs15_pubkey_from_spki_fields: returning with: 0 (Success)
pkcs15-pubkey.c:1449:sc_pkcs15_pubkey_from_spki_sequence: returning with: 0 (Success)
pkcs15-pubkey.c:984:sc_pkcs15_read_pubkey: returning with: 0 (Success)
framework-pkcs15.c:1064:pkcs15_add_object: Slot:0 Setting object handle of 0x0 to 0x805c0b240
framework-pkcs15.c:1064:pkcs15_add_object: Slot:0 Setting object handle of 0x0 to 0x805c0b1e0
pkcs15-pubkey.c:1079:sc_pkcs15_dup_pubkey: called
pkcs15-algo.c:535:sc_asn1_encode_algorithm_id: called
pkcs15-algo.c:536:sc_asn1_encode_algorithm_id: type of algorithm to encode: 0
pkcs15-algo.c:550:sc_asn1_encode_algorithm_id: encode algo 1.2.840.113549.1.1.1
pkcs15-algo.c:589:sc_asn1_encode_algorithm_id: return encoded algorithm ID: 06092A864886F70D0101010500
pkcs15-algo.c:590:sc_asn1_encode_algorithm_id: returning with: 0 (Success)
pkcs15-algo.c:494:sc_asn1_decode_algorithm_id: called
pkcs15-algo.c:502:sc_asn1_decode_algorithm_id: decoded OID '1.2.840.113549.1.1.1'
pkcs15-algo.c:519:sc_asn1_decode_algorithm_id: returning with: 0 (Success)
pkcs15-pubkey.c:1163:sc_pkcs15_dup_pubkey: returning with: 0 (Success)
pkcs15-lib.c:438:sc_pkcs15init_unbind: called
pkcs15-lib.c:439:sc_pkcs15init_unbind: Pksc15init Unbind: 1:0x805c01280:1
pkcs15-lib.c:3200:sc_pkcs15init_update_lastupdate: called
pkcs15-lib.c:3166:sc_pkcs15init_update_tokeninfo: called
pkcs15-openpgp.c:414:openpgp_emu_update_tokeninfo: called
pkcs15-openpgp.c:417:openpgp_emu_update_tokeninfo: returning with: 0 (Success)
pkcs15-lib.c:3240:sc_pkcs15init_update_lastupdate: returning with: 0 (Success)
card.c:523:sc_unlock: called
card.c:523:sc_unlock: called
reader-pcsc.c:742:pcsc_unlock: called

IV. GetPublicKey

card.c:471:sc_lock: called
reader-pcsc.c:690:pcsc_lock: called
card-openpgp.c:3745:pgp_card_reader_lock_obtained: called
card-openpgp.c:3772:pgp_card_reader_lock_obtained: returning with: 0 (Success)
card.c:513:sc_lock: returning with: 0 (Success)
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_ENCRYPT = TRUE
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011150, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c23050
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456350800: Attribute 0x104 does NOT match.
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b240
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456252992: Attribute 0x104 does NOT match.
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b1e0
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34456252896: Attribute 0x104 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 0 matching objects
misc.c:289:session_get_operation: called
misc.c:289:session_get_operation: called
card.c:523:sc_unlock: called
reader-pcsc.c:742:pcsc_unlock: called

V. GetPublicKey (after reinserting the token)

card.c:471:sc_lock: called
reader-pcsc.c:690:pcsc_lock: called
card-openpgp.c:3745:pgp_card_reader_lock_obtained: called
card-openpgp.c:3772:pgp_card_reader_lock_obtained: returning with: 0 (Success)
card.c:513:sc_lock: returning with: 0 (Success)
pkcs11-object.c:377:C_FindObjectsInit: C_FindObjectsInit(slot = 0)
pkcs11-object.c:378:C_FindObjectsInit: C_FindObjectsInit(): CKA_ENCRYPT = TRUE
misc.c:267:session_start_operation: called
misc.c:268:session_start_operation: Session 0x806011310, type 0
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b180
framework-pkcs15.c:4000:pkcs15_prkey_get_attribute: pkcs15_prkey_get_attribute() called
pkcs11-object.c:409:C_FindObjectsInit: Object 0/34456252800: Private object and not logged in.
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x805c0b2a0
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:435:C_FindObjectsInit: Object 0/34456253088 matches
pkcs11-object.c:439:C_FindObjectsInit: realloc for 32 handles
pkcs11-object.c:400:C_FindObjectsInit: Object with handle 0x806019000
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
framework-pkcs15.c:5328:pkcs15_profile_get_attribute: pkcs15_profile_get_attribute() called
pkcs11-object.c:421:C_FindObjectsInit: Object 0/34460504064: Attribute 0x104 does NOT match.
pkcs11-object.c:452:C_FindObjectsInit: 1 matching objects
misc.c:289:session_get_operation: called
misc.c:289:session_get_operation: called
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456253088: CKA_MODULUS = <size inquiry>
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011310, hObject=0x805c0b2a0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456253088: CKA_MODULUS = D59AB869C84C1ED52734B957FAFDD4A324824A54B733A39E3403A87D6116FBB6
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011310, hObject=0x805c0b2a0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456253088: CKA_PUBLIC_EXPONENT = <size inquiry>
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011310, hObject=0x805c0b2a0) = CKR_OK
framework-pkcs15.c:4891:pkcs15_pubkey_get_attribute: pkcs15_pubkey_get_attribute() called
pkcs11-object.c:270:C_GetAttributeValue: Object 34456253088: CKA_PUBLIC_EXPONENT = 010001
pkcs11-object.c:295:C_GetAttributeValue: C_GetAttributeValue(hSession=0x806011310, hObject=0x805c0b2a0) = CKR_OK
card.c:523:sc_unlock: called
reader-pcsc.c:742:pcsc_unlock: called