Description of problem: SSH Agent admitted failure to sign using the key Version-Release number of selected component (if applicable): Version opensc-0.12.0-4.fc16.x86_64.rpm works for me. This was true for F15, F16 and now for F17. Installing any newer version produces an error. I tried every new version that came out. How reproducible: Install opensc version newer than opensc-0.12.0-4.fc16.x86_64.rpm (this is the last version that works for me). Steps to Reproduce: 1. [user@workstation ~]$ exec /usr/bin/ssh-agent $SHELL 2. [user@workstation ~]$ ssh-add -s /usr/lib64/opensc-pkcs11.so Card added: /usr/lib64/opensc-pkcs11.so 3. Try to connect to server using SecureCard Actual results: Connect fails. ---------- ssh root@server Agent admitted failure to sign using the key. root@server's password: ---------- Expected results: Connection success. ---------- ssh root@server [root@server]# ---------- Additional info: Installed Packages ---------- opensc.x86_64 0.12.2-4.fc17 @fedora pcsc-lite.x86_64 1.8.3-1.fc17 @anaconda-0 pcsc-lite-ccid.x86_64 1.4.6-1.fc17 @anaconda-0 pcsc-lite-libs.x86_64 1.8.3-1.fc17 @anaconda-0 pcsc-perl.x86_64 1.4.12-3.fc17 @fedora pcsc-tools.x86_64 1.4.17-3.fc17 @fedora Reader info ---------- [user@workstation ~]$ opensc-tool --list-readers # Detected readers (pcsc) Nr. Card Features Name 0 Yes Gemalto USB Shell Token V2 00 00 ---------- Keys found by ssh: ---------- [user@workstation ~]$ ssh-add -l 1024 xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx /usr/lib64/opensc-pkcs11.so (RSA) 2048 xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx /usr/lib64/opensc-pkcs11.so (RSA) 1024 xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx /usr/lib64/opensc-pkcs11.so (RSA) ---------- Keys info: ---------- [user@workstation ~]$ pkcs15-tool --list-keys Using reader with a card: Gemalto USB Shell Token V2 00 00 Private RSA Key [Digital Signature] Object Flags : [0x3], private, modifiable Usage : [0x2C], sign, signRecover, unwrap Access Flags : [0x0] ModLength : 1024 Key ref : -1 (0xFFFFFFFF) Native : yes Path : xxxxxxxxxx01 Auth ID : 01 ID : 11 Private RSA Key [Non Repudiation] Object Flags : [0x3], private, modifiable Usage : [0x200], nonRepudiation Access Flags : [0x0] ModLength : 1024 Key ref : -1 (0xFFFFFFFF) Native : yes Path : xxxxxxxxxx02 Auth ID : 01 ID : 33 ---------- Debug output ---------- [peter@workstation ~]$ ssh -v root@server OpenSSH_5.9p1, OpenSSL 1.0.0j-fips 10 May 2012 debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 50: Applying options for * debug1: Connecting to server [192.168.1.100] port 22. debug1: Connection established. debug1: identity file /home/user/.ssh/id_rsa type -1 debug1: identity file /home/user/.ssh/id_rsa-cert type -1 debug1: identity file /home/user/.ssh/id_dsa type -1 debug1: identity file /home/user/.ssh/id_dsa-cert type -1 debug1: Remote protocol version 2.0, remote software version OpenSSH_5.1p1 Debian-5 debug1: match: OpenSSH_5.1p1 Debian-5 pat OpenSSH* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_5.9 debug1: SSH2_MSG_KEXINIT sent debug1: SSH2_MSG_KEXINIT received debug1: kex: server->client aes128-ctr hmac-md5 none debug1: kex: client->server aes128-ctr hmac-md5 none debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP debug1: SSH2_MSG_KEX_DH_GEX_INIT sent debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY debug1: Server host key: RSA xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx:xx debug1: Host 'server' is known and matches the RSA host key. debug1: Found key in /home/user/.ssh/known_hosts:35 debug1: ssh_rsa_verify: signature correct debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug1: SSH2_MSG_NEWKEYS received debug1: Roaming not allowed by server debug1: SSH2_MSG_SERVICE_REQUEST sent debug1: SSH2_MSG_SERVICE_ACCEPT received debug1: Authentications that can continue: publickey,password debug1: Next authentication method: publickey debug1: Offering RSA public key: /usr/lib64/opensc-pkcs11.so debug1: Server accepts key: pkalg ssh-rsa blen 151 Agent admitted failure to sign using the key. debug1: Offering RSA public key: /usr/lib64/opensc-pkcs11.so debug1: Authentications that can continue: publickey,password debug1: Offering RSA public key: /usr/lib64/opensc-pkcs11.so debug1: Authentications that can continue: publickey,password debug1: Trying private key: /home/user/.ssh/id_rsa debug1: Trying private key: /home/user/.ssh/id_dsa debug1: Next authentication method: password ----------
Sorry, don't know if this really qualifies for a Security Sensitive Bug. Please edit if necessary.
Can you post any details on how the card is setup? What commands did you use to create the SSH key(s) on it? I'm just wondering because, your card shows: Key ref : -1 (0xFFFFFFFF) which seems odd, my card shows entries like: Key ref : 2 (0x2)
This is a standard card setup released by our company's CA. If you need any specific detail let me know exactly what would you need and i will try to get the information. I don't know what this "Key ref" parameter actually describes?
I do not think this is a security sensitive bug.
Ticking the "Security Sensitive Bug" makes the ticket unavailable for public view. I just pointed upstream to this ticket and they are unable to read it. Can you uncheck this, please?
Can you enable opensc debugging, and generate a log? The debug logging can be enabled by editing /etc/opensc.conf and setting "debug = 9" and uncommenting "debug_file = ". Also, just a wild stab in the dark -- can you try the opensc build at http://koji.fedoraproject.org/koji/taskinfo?taskID=4362793 ? I can see that 0.12.2-4 was built against openssl 1.0.1, which later got downgraded back to 1.0 in F17. The scratch build above is now properly rebuilt against openssl 1.0, without any opensc code changes. ABI changes between openssl versions can possibly lead to hard-to-diagnose bugs like this, for example when struct sizes change.
Ok, last sections of debug log: 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] card.c:330:sc_unlock: called 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] iso7816.c:150:iso7816_read_binary: returning with: 30 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] card.c:455:sc_read_binary: returning with: 30 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] card.c:330:sc_unlock: called 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] card.c:452:sc_read_binary: returning with: 798 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] card.c:330:sc_unlock: called 0x7fcb808d0800 07:47:23.617 [opensc-pkcs11] reader-pcsc.c:548:pcsc_unlock: called 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] pkcs15.c:1944:sc_pkcs15_read_file: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=794, depth 0 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'tbsCertificate', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'tbsCertificate' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=514, depth 1 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'version', tag 0x21000000, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'version' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=3, depth 2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'version', tag 0x2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'version' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1162:asn1_decode_entry: decoding 'version' returned 2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'serialNumber', tag 0x2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'serialNumber' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'signature', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'signature' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'issuer', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'issuer' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'validity', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'validity' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'subject', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'subject' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'subjectPublicKeyInfo', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'subjectPublicKeyInfo' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] pkcs15-pubkey.c:869:sc_pkcs15_pubkey_from_spki: sc_pkcs15_pubkey_from_spki 0x7fcb81fd1553:290 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=290, depth 0 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'algorithm', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'algorithm' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=13, depth 1 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'algorithm', tag 0x6 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'algorithm' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'nullParam', tag 0x5, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'nullParam' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'subjectPublicKey', tag 0x3 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'subjectPublicKey' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] pkcs15-pubkey.c:894:sc_pkcs15_pubkey_from_spki: DEE pk_alg.algorithm=0 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=270, depth 0 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'publicKeyCoefficients', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'publicKeyCoefficients' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=266, depth 1 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'modulus', tag 0x2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'modulus' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'exponent', tag 0x2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'exponent' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'extensions', tag 0x21000003, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'extensions' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=51, depth 2 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'x509v3', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'x509v3' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=49, depth 3 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'certificatePolicies', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'certificatePolicies' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'subjectKeyIdentifier', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'subjectKeyIdentifier' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'crlDistributionPoints', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'crlDistributionPoints' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'authorityKeyIdentifier', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1359:asn1_decode: not present 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'keyUsage', tag 0x1000010, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1359:asn1_decode: not present 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'signatureAlgorithm', tag 0x1000010 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'signatureAlgorithm' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1322:asn1_decode: called, left=13, depth 1 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'algorithm', tag 0x6 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'algorithm' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'nullParam', tag 0x5, OPTIONAL 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'nullParam' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1345:asn1_decode: Looking for 'signatureValue', tag 0x3 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1138:asn1_decode_entry: decoding 'signatureValue' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1394:asn1_decode: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1424:asn1_encode_entry: encoding 'serialNumber' 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1429:asn1_encode_entry: type=4, tag=0x02, parm=0x7fcb81fca8f0, len=3 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] asn1.c:1605:asn1_encode_entry: length of encoded item=5 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] framework-pkcs15.c:576:pkcs15_create_pkcs11_objects: Found 0 data objects 0x7fcb808d0800 07:47:23.620 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:593:__pkcs15_prkey_bind_related: Object is a private key and has id 11 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:593:__pkcs15_prkey_bind_related: Object is a private key and has id 33 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 2 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:635:__pkcs15_cert_bind_related: Object is a certificate and has id 11 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:664:__pkcs15_cert_bind_related: Associating object 0 as private key 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:654:__pkcs15_cert_bind_related: Associating object 6 (id 38383935353137393834353238363130353131) as issuer 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 3 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 4 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:635:__pkcs15_cert_bind_related: Object is a certificate and has id 33 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:664:__pkcs15_cert_bind_related: Associating object 1 as private key 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:654:__pkcs15_cert_bind_related: Associating object 6 (id 38383935353137393834353238363130353131) as issuer 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 5 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 6 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:635:__pkcs15_cert_bind_related: Object is a certificate and has id 38383935353137393834353238363130353131 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:685:pkcs15_bind_related_objects: Looking for objects related to object 7 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:293:slot_allocate: Allocated slot 0x1 for card in reader Gemalto USB Shell Token V2 00 00 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:844:pkcs15_init_slot: Initialized token 'Electronic ID (PIN1)' in slot 0x1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:994:pkcs15_create_tokens: Adding private key 0 to PIN 0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fc80f0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fcfb00 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fcfb60 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fd18e0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fd1940 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:994:pkcs15_create_tokens: Adding private key 1 to PIN 0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fcaa70 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fd07f0 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:753:pkcs15_add_object: Setting object handle of 0x0 to 0x7fcb81fd1070 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:1046:pkcs15_create_tokens: All tokens created 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:261:card_detect: Gemalto USB Shell Token V2 00 00: Detection ended 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:259:C_Initialize: C_Initialize() = CKR_OK 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:329:C_GetInfo: C_GetInfo() 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:375:C_GetSlotList: C_GetSlotList(token=1, plug-n-play) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:870:pcsc_detect_readers: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:878:pcsc_detect_readers: Probing pcsc readers 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:1023:pcsc_detect_readers: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:188:card_detect: Gemalto USB Shell Token V2 00 00: Detecting smart card 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sc.c:195:sc_detect_card_presence: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:364:pcsc_detect_card_presence: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:277:refresh_attributes: Gemalto USB Shell Token V2 00 00 check 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:293:refresh_attributes: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:369:pcsc_detect_card_presence: returning with: 1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sc.c:200:sc_detect_card_presence: returning with: 1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:261:card_detect: Gemalto USB Shell Token V2 00 00: Detection ended 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:411:C_GetSlotList: was only a size inquiry (1) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:375:C_GetSlotList: C_GetSlotList(token=1, refresh) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:188:card_detect: Gemalto USB Shell Token V2 00 00: Detecting smart card 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sc.c:195:sc_detect_card_presence: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:364:pcsc_detect_card_presence: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:277:refresh_attributes: Gemalto USB Shell Token V2 00 00 check 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:293:refresh_attributes: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] reader-pcsc.c:369:pcsc_detect_card_presence: returning with: 1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sc.c:200:sc_detect_card_presence: returning with: 1 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] slot.c:261:card_detect: Gemalto USB Shell Token V2 00 00: Detection ended 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-global.c:428:C_GetSlotList: returned 1 slots 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] framework-pkcs15.c:332:C_GetTokenInfo: C_GetTokenInfo(1) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sec.c:157:sc_pin_cmd: called 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] sec.c:204:sc_pin_cmd: returning with: -1408 (Not supported) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-session.c:57:C_OpenSession: C_OpenSession(0x1) 0x7fcb808d0800 07:47:23.621 [opensc-pkcs11] pkcs11-session.c:83:C_OpenSession: C_OpenSession handle: 0x7fcb81fd1b70 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] pkcs11-session.c:86:C_OpenSession: C_OpenSession() = CKR_OK 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] pkcs11-session.c:259:C_Login: C_Login(0x7fcb81fd1b70, 1) 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] pkcs15-pin.c:234:sc_pkcs15_verify_pin: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] pkcs15-pin.c:235:sc_pkcs15_verify_pin: PIN(0x7fcb81fba0d0;len:8) 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] card.c:292:sc_lock: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] reader-pcsc.c:511:pcsc_lock: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] sec.c:157:sc_pin_cmd: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] apdu.c:525:sc_transmit_apdu: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] card.c:292:sc_lock: called 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] reader-pcsc.c:243:pcsc_transmit: reader 'Gemalto USB Shell Token V2 00 00' 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] apdu.c:184:sc_apdu_log: Outgoing APDU data [ 13 bytes] ===================================== [edited] ====================================================================== 0x7fcb808d0800 07:47:23.622 [opensc-pkcs11] reader-pcsc.c:176:pcsc_internal_transmit: called 0x7fcb808d0800 07:47:23.688 [opensc-pkcs11] apdu.c:184:sc_apdu_log: Incoming APDU data [ 2 bytes] ===================================== [edited] ====================================================================== 0x7fcb808d0800 07:47:23.688 [opensc-pkcs11] card.c:330:sc_unlock: called 0x7fcb808d0800 07:47:23.688 [opensc-pkcs11] sec.c:204:sc_pin_cmd: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.688 [opensc-pkcs11] pkcs15-pin.c:509:sc_pkcs15_pincache_add: called 0x7fcb808d0800 07:47:23.688 [opensc-pkcs11] pkcs15-pin.c:543:sc_pkcs15_pincache_add: PIN(PIN1) cached 0x7fcb808d0800 07:47:23.689 [opensc-pkcs11] card.c:330:sc_unlock: called 0x7fcb808d0800 07:47:23.689 [opensc-pkcs11] reader-pcsc.c:548:pcsc_unlock: called 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs15-pin.c:296:sc_pkcs15_verify_pin: returning with: 0 (Success) 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] framework-pkcs15.c:1186:pkcs15_login: PKCS15 verify PIN returned 0 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] framework-pkcs15.c:1195:pkcs15_login: Check if pkcs15 object list can be completed. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:307:C_FindObjectsInit: C_FindObjectsInit(slot = 1) 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:308:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = CKO_PUBLIC_KEY 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] misc.c:136:session_start_operation: called 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] misc.c:137:session_start_operation: Session 0x7fcb81fd1b70, type 0 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fc80f0 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114158352: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcfb00 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114127104: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcfb60 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114127008: Attribute 0x0 matches. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:362:C_FindObjectsInit: Object 1/-2114127008 matches 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:367:C_FindObjectsInit: realloc for 32 handles 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd18e0 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114119456: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd1940 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114119360: Attribute 0x0 matches. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:362:C_FindObjectsInit: Object 1/-2114119360 matches 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcaa70 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114147728: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd07f0 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114123792: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd1070 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114121616: Attribute 0x0 matches. 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:362:C_FindObjectsInit: Object 1/-2114121616 matches 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:380:C_FindObjectsInit: 3 matching objects 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_ID = <size inquiry> 0x7fcb808d0800 07:47:23.691 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_MODULUS = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_PUBLIC_EXPONENT = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fcfb60) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_ID = 11 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_MODULUS = 977B15370F4E8371D3546891BD3ACFDEE1F92051BABD4985DA15B4F9531A534E 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035928928: CKA_PUBLIC_EXPONENT = 010001 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fcfb60) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_ID = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_MODULUS = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_PUBLIC_EXPONENT = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fd1940) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_ID = 38383935353137393834353238363130353131 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_MODULUS = BCA3260196E59DAC1A0202397CACDC064C374AAE074875E8271CA431FD0AA723 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035936576: CKA_PUBLIC_EXPONENT = 010001 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fd1940) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_ID = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_MODULUS = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_PUBLIC_EXPONENT = <size inquiry> 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fd1070) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_ID = 33 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_MODULUS = 93F5F0505CD942207C4942AA4A9CB591CBF66A371C9F81C2A8E39A99E381D7FB 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:213:C_GetAttributeValue: Object 140512035934320: CKA_PUBLIC_EXPONENT = 03 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:235:C_GetAttributeValue: C_GetAttributeValue(hSession=0x7fcb81fd1b70, hObject=0x7fcb81fd1070) = CKR_OK 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:23.692 [opensc-pkcs11] pkcs11-object.c:60:sc_find_release: freeing 32 handles used 3 at 0x7fcb81fd1d20 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:307:C_FindObjectsInit: C_FindObjectsInit(slot = 1) 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:308:C_FindObjectsInit: C_FindObjectsInit(): CKA_CLASS = CKO_PRIVATE_KEY 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:308:C_FindObjectsInit: C_FindObjectsInit(): CKA_ID = 11 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:308:C_FindObjectsInit: C_FindObjectsInit(): CKA_SIGN = TRUE 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] misc.c:136:session_start_operation: called 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] misc.c:137:session_start_operation: Session 0x7fcb81fd1b70, type 0 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fc80f0 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114158352: Attribute 0x0 matches. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114158352: Attribute 0x102 matches. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114158352: Attribute 0x108 matches. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:362:C_FindObjectsInit: Object 1/-2114158352 matches 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:367:C_FindObjectsInit: realloc for 32 handles 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcfb00 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114127104: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcfb60 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114127008: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd18e0 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114119456: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd1940 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114119360: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fcaa70 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:357:C_FindObjectsInit: Object 1/-2114147728: Attribute 0x0 matches. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114147728: Attribute 0x102 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd07f0 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114123792: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:329:C_FindObjectsInit: Object with handle 0x7fcb81fd1070 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:350:C_FindObjectsInit: Object 1/-2114121616: Attribute 0x0 does NOT match. 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:380:C_FindObjectsInit: 1 matching objects 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] misc.c:158:session_get_operation: called 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:60:sc_find_release: freeing 32 handles used 1 at 0x7fcb81fb9110 0x7fcb808d0800 07:47:41.968 [opensc-pkcs11] pkcs11-object.c:594:C_SignInit: C_SignInit() = CKR_MECHANISM_INVALID
(In reply to comment #6) > Also, just a wild stab in the dark -- can you try the opensc build at > http://koji.fedoraproject.org/koji/taskinfo?taskID=4362793 ? > I can see that 0.12.2-4 was built against openssl 1.0.1, which later got > downgraded back to 1.0 in F17. The scratch build above is now properly > rebuilt against openssl 1.0, without any opensc code changes. ABI changes > between openssl versions can possibly lead to hard-to-diagnose bugs like > this, for example when struct sizes change. How do i download this build? I cannot seem to find the actual package to download it.
(In reply to comment #8) > (In reply to comment #6) > > > Also, just a wild stab in the dark -- can you try the opensc build at > > http://koji.fedoraproject.org/koji/taskinfo?taskID=4362793 ? > > I can see that 0.12.2-4 was built against openssl 1.0.1, which later got > > downgraded back to 1.0 in F17. The scratch build above is now properly > > rebuilt against openssl 1.0, without any opensc code changes. ABI changes > > between openssl versions can possibly lead to hard-to-diagnose bugs like > > this, for example when struct sizes change. > > How do i download this build? I cannot seem to find the actual package to > download it. The build was already deleted. I don't believe it will help but I did another scratch build for you: http://koji.fedoraproject.org/koji/taskinfo?taskID=4398121
Indeed, it seems there is no difference, debug log ends with the same lines: 0x7f7e34bcb800 17:56:46.546 [opensc-pkcs11] pkcs11-object.c:594:C_SignInit: C_SignInit() = CKR_MECHANISM_INVALID
Hi all, here's an update on this matter. I tried it with another reader. No success. I tried a card with different version of the chip. SUCCESS. Description of problem: SSH Agent admitted failure to sign using the key Version-Release number of selected component (if applicable): Version opensc-0.12.0-4.fc16.x86_64.rpm works for me. This was true for F15, F16, F17 and now for F18. Installing any newer version produces an error. I tried every new version that came out. How reproducible: Install opensc version newer than opensc-0.12.0-4.fc16.x86_64.rpm (this is the last version that works for me). Steps to Reproduce: 1. [user@workstation ~]$ exec /usr/bin/ssh-agent $SHELL 2. [user@workstation ~]$ ssh-add -s /usr/lib64/opensc-pkcs11.so Card added: /usr/lib64/opensc-pkcs11.so 3. Try to connect to server using SecureCard Actual results: Connect fails. ---------- ssh root@server Agent admitted failure to sign using the key. root@server's password: ---------- OR: ---------- ssh -I /usr/lib/opensc-pkcs11.so root@server Enter PIN for 'Electronic ID (PIN1)': C_SignInit failed: 112 ssh_rsa_sign: RSA_sign failed: error:25066067:DSO support routines:DLFCN_LOAD:could not load the shared library Received disconnect from 192.168.2.22: 2: Too many authentication failures for root ---------- Expected results: Connection success. ---------- ssh root@server [root@server]# ---------- Additional info: Installed Packages ---------- opensc.x86_64 0.12.2-6.fc18 @fedora pcsc-lite.x86_64 1.8.7-1.fc18 installed pcsc-lite-ccid.x86_64 1.4.8-1.fc18 installed pcsc-lite-libs.x86_64 1.8.7-1.fc18 installed pcsc-perl.x86_64 1.4.12-5.fc18 installed pcsc-tools.x86_64 1.4.17-4.fc18 installed Reader info ---------- [user@workstation ~]$ opensc-tool --list-readers # Detected readers (pcsc) Nr. Card Features Name 0 No OMNIKEY AG CardMan 3021 00 00 1 Yes Gemalto USB Shell Token V2 01 00 ---------- So apparently, it goes like this (the card names are from Nexus Personal): - opensc-0.12.0-4.fc16.x86_64.rpm works only with card "SetCOS 4.3" - opensc-0.12.2-6.fc18.x86_64.rpm works only with card "SetCOS 4.4.1" - neither of them works with card "Gemalto Classic Applet V3" I think this problem is connected somehow with the drivers. opensc-tool --info opensc 0.12.2 [gcc 4.7.1 20120720 (Red Hat 4.7.1-5)] Enabled features: zlib readline openssl pcsc(libpcsclite.so.1) opensc-tool --list-drivers Configured card drivers: cardos Siemens CardOS flex Schlumberger Multiflex/Cryptoflex cyberflex Schlumberger Cyberflex gpk Gemplus GPK gemsafeV1 driver for the Gemplus GemSAFE V1 applet miocos MioCOS 1.1 mcrd MICARDO 2.1 / EstEID 1.0 - 3.0 asepcos Athena ASEPCOS starcos STARCOS SPK 2.3/2.4 tcos TCOS 3.0 openpgp OpenPGP card jcop JCOP cards with BlueZ PKCS#15 applet oberthur Oberthur AuthentIC.v2/CosmopolIC.v4 authentic Oberthur AuthentIC v3.1 iasecc IAS-ECC belpic Belpic cards ias IAS incrypto34 Incard Incripto34 acos5 ACS ACOS5 card akis TUBITAK UEKAE AKIS entersafe entersafe rutoken Rutoken driver rutoken_ecp Rutoken ECP driver westcos WESTCOS compatible cards myeid MyEID cards with PKCS#15 applet setcos Setec cards muscle MuscleApplet atrust-acos A-Trust ACOS cards piv PIV-II for multiple cards itacns Italian CNS javacard JavaCard (without supported applet) default Default driver for unknown cards My question to all is, has setcos driver changed from opensc 0.12.0 to opensc 0.12.2?
I also got this same problem. The interesting thing is that ALL was working fine up till I installed the most recent updates for fedora 18 using "yum update". This problem started then. I am not sure if it helps to add my 2 cents, but here is a slightly edited version of the ssh -v log (removed my RSH key and server name and IP). In addition I tacked on the results of a couple "ls -l" commands as I wanted to see what ssh was complaining about. --- output of ssh -v OpenSSH_6.1p1, OpenSSL 1.0.1e-fips 11 Feb 2013 debug1: Reading configuration data /home/ray/.ssh/config debug1: /home/ray/.ssh/config line 16: Applying options for lnwprod debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 50: Applying options for * debug1: Connecting to SOME_MACHINE.com [SOME_IP_ADDR] port 22. debug1: Connection established. debug1: identity file /home/ray/.ssh/id_rsa type 1 debug1: identity file /home/ray/.ssh/id_rsa-cert type -1 debug1: identity file /home/ray/.ssh/id_dsa type -1 debug1: identity file /home/ray/.ssh/id_dsa-cert type -1 debug1: Remote protocol version 2.0, remote software version OpenSSH_4.3 debug1: match: OpenSSH_4.3 pat OpenSSH_4* debug1: Enabling compatibility mode for protocol 2.0 debug1: Local version string SSH-2.0-OpenSSH_6.1 debug1: SSH2_MSG_KEXINIT sent debug1: SSH2_MSG_KEXINIT received debug1: kex: server->client aes128-ctr hmac-md5 none debug1: kex: client->server aes128-ctr hmac-md5 none debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP debug1: SSH2_MSG_KEX_DH_GEX_INIT sent debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY debug1: Server host key: RSA MY_SECRET_KEY_REMOVED debug1: Host 'SOME_MACHINE.com' is known and matches the RSA host key. debug1: Found key in /home/ray/.ssh/known_hosts:12 debug1: ssh_rsa_verify: signature correct debug1: SSH2_MSG_NEWKEYS sent debug1: expecting SSH2_MSG_NEWKEYS debug1: SSH2_MSG_NEWKEYS received debug1: Roaming not allowed by server debug1: SSH2_MSG_SERVICE_REQUEST sent debug1: SSH2_MSG_SERVICE_ACCEPT received debug1: Authentications that can continue: publickey,gssapi-with-mic,password debug1: Next authentication method: gssapi-with-mic debug1: Unspecified GSS failure. Minor code may provide more information Credentials cache file '/run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/tkt' not found debug1: Unspecified GSS failure. Minor code may provide more information Credentials cache file '/run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/tkt' not found debug1: Unspecified GSS failure. Minor code may provide more information debug1: Unspecified GSS failure. Minor code may provide more information Credentials cache file '/run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/tkt' not found debug1: Next authentication method: publickey debug1: Offering RSA public key: /home/ray/.ssh/id_rsa debug1: Server accepts key: pkalg ssh-rsa blen 279 Agent admitted failure to sign using the key. debug1: Trying private key: /home/ray/.ssh/id_dsa debug1: Next authentication method: password ray's password: debug1: Authentication succeeded (password). Authenticated to SOME_MACHINE.com ([SOME_IP_ADDR]:22). debug1: channel 0: new [client-session] debug1: Entering interactive session. debug1: Sending environment. debug1: Sending env XMODIFIERS = @im=none debug1: Sending env LANG = en_US.UTF-8 Last login: Thu Mar 7 08:18:41 2013 from cpe-74-78-75-119.maine.res.rr.com [ray@SOME_MACHINE ~]$ debug1: client_input_channel_req: channel 0 rtype exit-status reply 0 debug1: channel 0: forcing write logout debug1: channel 0: free: client-session, nchannels 1 debug1: fd 1 clearing O_NONBLOCK Connection to SOME_MACHINE.com closed. Transferred: sent 2296, received 2344 bytes, in 3.4 seconds Bytes per second: sent 684.4, received 698.7 debug1: Exit status 0 ------information AFTER the ssh is done about file not found ls -ld /run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/ drwx------. 2 ray staff 60 Mar 6 15:41 /run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/ ls -l /run/user/1000/krb5cc_6ccfcd85452fac11a7aff9665137a9fc/ total 4 -rw-------. 1 ray staff 4 Mar 6 15:41 primary
OOPS - I should say that my machine is fedora 18, but the target machine(s) are fedora 12 (yea, I know - we are working on that). BUT AGAIN, this was working fine last week before I "yum update"d my box.
*** Bug 922038 has been marked as a duplicate of this bug. ***
This message is a reminder that Fedora 18 is nearing its end of life. Approximately 4 (four) weeks from now Fedora will stop maintaining and issuing updates for Fedora 18. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as WONTFIX if it remains open with a Fedora 'version' of '18'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version prior to Fedora 18's end of life. Thank you for reporting this issue and we are sorry that we may not be able to fix it before Fedora 18 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior to Fedora 18's end of life. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 18 changed to end-of-life (EOL) status on 2014-01-14. Fedora 18 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.