Can't import private key, sc_pkcs15init_authenticate fails

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Can't import private key, sc_pkcs15init_authenticate fails

Hubert Greiche
Hello,

I am trying to communicate with my Ikey 3000, under Debian. I have java
code that
talks to C code, which talks to opensc-pkcs11.so (v0.9.6)
I had been trying for a couple of days to import a certificate or a
public key using
C_CreateObject, but all I could get was an "Object not found error" as
well as a
CKR_GENERAL_ERROR. Later I understood I had to initialize the token,
using the
onepin option. When I did I could import public keys and certificates
without any
problems. But I still have the same error whenever I try to import a
private key.
Here is the error:

pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_CLASS =
CKO_PRIVATE_KEY
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_KEY_TYPE = CKK_RSA
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_MODULUS =
B961B32AE89269B7C15453D29E99BF2CBCC5B9DA30D0846C59C3D3E8F14CE8A2
pkcs11-object.c:43:C_CreateObject: C_CreateObject():
CKA_PRIVATE_EXPONENT =
0091F112663356209823414A04440BF1EF3C65C51CBAD54D8B2757FD9A236D52
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_PUBLIC_EXPONENT
= 010001
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): Attribute 0x124 =
00DB372654F00D034D378FBD97990EB3FF9DA5F5ACF9A62A7220119D9C8C0294
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): Attribute 0x125 =
00D87D266AAA88C562A0D63118B845AA3F6F792AE29972CC0077163B49AB2F2B
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_ID =
4643353139303134334139333531343446303737343543333132443742343041
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_TOKEN = TRUE
card.c:827:sc_card_ctl: called
card.c:833:sc_card_ctl: card_ctl(4) not supported
card.c:691:sc_select_file: called; type=2, path=3f0050154946
card-starcos.c:412:starcos_select_file: current path (path, valid):
3F005015 (len: 4)
card.c:229:sc_transmit_apdu: called
card.c:196:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 49 46 00 .....IF.
card.c:249:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 00 80 82 01 01 o........
card.c:229:sc_transmit_apdu: called
card.c:196:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:249:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
01 .
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 128
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:713:sc_select_file: returning with: 0
card.c:563:sc_read_binary: called; 128 bytes at index 0
card.c:229:sc_transmit_apdu: called
card.c:196:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:249:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
01 06 70 6B 63 73 31 35 02 06 6F 6E 65 70 69 6E ..pkcs15..onepin
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:594:sc_read_binary: returning with: 128
profile.c:308:sc_profile_load: Trying profile file
/usr/share/opensc//pkcs15.profile
profile.c:316:sc_profile_load: profile /usr/share/opensc//pkcs15.profile
loaded ok
profile.c:308:sc_profile_load: Trying profile file
/usr/share/opensc//starcos.profile
profile.c:316:sc_profile_load: profile
/usr/share/opensc//starcos.profile loaded ok
pkcs15-lib.c:1985:select_object_path: key-domain.private-key @3f005015
(auth_id.len=1)
profile.c:551:sc_profile_instantiate_template: Instantiating template
key-domain at 3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated private-key at
3f0050150037
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated public-key at
3f005015303b
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated certificate at
3f005015313c
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated extractable-key
at 3f0050153239
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated data at 3f0050153339
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
pkcs15-lib.c:2638:sc_pkcs15init_authenticate: path=3f005015, op=2
misc.c:79:sc_to_cryptoki_error: opensc error: Requested object not found
(-1407)

What am I doing wrong?

Thank you for your help,

Bob.
_______________________________________________
opensc-devel mailing list
[hidden email]
http://www.opensc.org/cgi-bin/mailman/listinfo/opensc-devel
Reply | Threaded
Open this post in threaded view
|

Re: Can't import private key, sc_pkcs15init_authenticate fails

Nils Larsch
Hubert Greiche wrote:

> Hello,
>
> I am trying to communicate with my Ikey 3000, under Debian. I have java
> code that
> talks to C code, which talks to opensc-pkcs11.so (v0.9.6)
> I had been trying for a couple of days to import a certificate or a
> public key using
> C_CreateObject, but all I could get was an "Object not found error" as
> well as a
> CKR_GENERAL_ERROR. Later I understood I had to initialize the token,
> using the
> onepin option. When I did I could import public keys and certificates
> without any
> problems. But I still have the same error whenever I try to import a
> private key.
> Here is the error:
....

> profile.c:308:sc_profile_load: Trying profile file
> /usr/share/opensc//starcos.profile
> profile.c:316:sc_profile_load: profile
> /usr/share/opensc//starcos.profile loaded ok
> pkcs15-lib.c:1985:select_object_path: key-domain.private-key @3f005015
> (auth_id.len=1)
> profile.c:551:sc_profile_instantiate_template: Instantiating template
> key-domain at 3f005015
> profile.c:616:sc_profile_instantiate_file: Instantiated private-key at
> 3f0050150037
> profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
> profile.c:616:sc_profile_instantiate_file: Instantiated public-key at
> 3f005015303b
> profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
> profile.c:616:sc_profile_instantiate_file: Instantiated certificate at
> 3f005015313c
> profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
> profile.c:616:sc_profile_instantiate_file: Instantiated extractable-key
> at 3f0050153239
> profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
> profile.c:616:sc_profile_instantiate_file: Instantiated data at
> 3f0050153339
> profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
> pkcs15-lib.c:2638:sc_pkcs15init_authenticate: path=3f005015, op=2
> misc.c:79:sc_to_cryptoki_error: opensc error: Requested object not found
> (-1407)
>
> What am I doing wrong?

could you increase the debug level ? I would like see the last APDUs
send to the card.

Nils
_______________________________________________
opensc-devel mailing list
[hidden email]
http://www.opensc.org/cgi-bin/mailman/listinfo/opensc-devel
Reply | Threaded
Open this post in threaded view
|

Re: Can't import private key, sc_pkcs15init_authenticate fails

Hubert Greiche
In reply to this post by Hubert Greiche

> could you increase the debug level ? I would like see the last APDUs
> send to the card.
>
> Nils
>
Here is the increased debug level version:

ctx.c:598:sc_establish_context: ===================================
reader-openct.c:89:openct_reader_init: called
slot.c:83:card_detect: 0: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 1
slot.c:121:card_detect: 0: Connecting to SmartCard
card.c:345:sc_connect_card: called
reader-openct.c:217:openct_reader_connect: called
card.c:400:sc_connect_card: trying driver: Siemens CardOS
card.c:400:sc_connect_card: trying driver: Schlumberger
Multiflex/Cryptoflex
card.c:400:sc_connect_card: trying driver: Schlumberger Cyberflex
card.c:400:sc_connect_card: trying driver: Gemplus GPK driver
card.c:400:sc_connect_card: trying driver: MioCOS 1.1 cards
card.c:400:sc_connect_card: trying driver: MICARDO 2.1
card.c:400:sc_connect_card: trying driver: Setec smartcards
card.c:400:sc_connect_card: trying driver: driver for STARCOS SPK 2.3 cards
card.c:406:sc_connect_card: matched: driver for STARCOS SPK 2.3 cards
card.c:430:sc_connect_card: returning with: 0
slot.c:129:card_detect: 0: Detecting Framework
pkcs15.c:594:sc_pkcs15_bind: called
card.c:467:sc_lock: called
reader-openct.c:373:openct_reader_lock: called
pkcs15.c:474:sc_pkcs15_bind_internal: trying normal pkcs15 processing
card.c:690:sc_select_file: called; type=2, path=3f002f00
card-starcos.c:412:starcos_select_file: current path (path, valid):  
(len: 0)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 3F 00 00 .....?..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 2F 00 00 ...../..
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 00 80 82 01 01 o........
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
61 a
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 128
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 128 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
61 21 4F 0C A0 00 00 00 63 50 4B 43 53 2D 31 35 a!O.....cPKCS-15
50 0B 4F 70 65 6E 53 43 20 43 61 72 64 51 04 3F P.OpenSC CardQ.?
00 50 15 00 00 00 00 00 00 00 00 00 00 00 00 00 .P..............
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
asn1.c:1035:asn1_decode: called, left=128, depth 0
asn1.c:1060:asn1_decode: Looking for 'dirRecord', tag 0x11000001
asn1.c:859:asn1_decode_entry: decoding 'dirRecord'
asn1.c:1035:asn1_decode:  called, left=33, depth 1
asn1.c:1060:asn1_decode: Looking for 'aid', tag 0x1000000f
asn1.c:859:asn1_decode_entry:  decoding 'aid'
asn1.c:1060:asn1_decode: Looking for 'label', tag 0x10000010, OPTIONAL
asn1.c:859:asn1_decode_entry:  decoding 'label'
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x10000011, OPTIONAL
asn1.c:859:asn1_decode_entry:  decoding 'path'
asn1.c:1060:asn1_decode: Looking for 'ddo', tag 0x11000013, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1035:asn1_decode: called, left=93, depth 0
card.c:690:sc_select_file: called; type=2, path=3f005015
card-starcos.c:412:starcos_select_file: current path (path, valid): 3F00
(len: 2)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 15 00 .....P..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 50 15 .....P.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:690:sc_select_file: called; type=2, path=3f0050155031
card-starcos.c:412:starcos_select_file: current path (path, valid):
3F005015 (len: 4)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 31 00 .....P1.
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 01 00 82 01 01 o........
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
A8 .
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 256
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 256 bytes at index 0
card.c:562:sc_read_binary: called; 128 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
A8 0A 30 08 04 06 3F 00 50 15 44 01 A0 0A 30 08 ..0...?.P.D...0.
04 06 3F 00 50 15 44 02 00 00 00 00 00 00 00 00 ..?.P.D.........
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:562:sc_read_binary: called; 128 bytes at index 128
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 80 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:590:sc_read_binary: returning with: 256
asn1.c:1035:asn1_decode: called, left=256, depth 0, choice
asn1.c:1060:asn1_decode: Looking for 'privateKeys', tag 0x21000000, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'publicKeys', tag 0x21000001, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'trustedPublicKeys', tag
0x21000002, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'certificates', tag 0x21000004, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'trustedCertificates', tag
0x21000005, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'usefulCertificates', tag
0x21000006, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'dataObjects', tag 0x21000007, CHOICE
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'authObjects', tag 0x21000008, CHOICE
asn1.c:859:asn1_decode_entry: decoding 'authObjects'
asn1.c:1035:asn1_decode:  called, left=10, depth 1
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'path'
asn1.c:1035:asn1_decode:   called, left=8, depth 2
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x4
asn1.c:859:asn1_decode_entry:   decoding 'path'
asn1.c:1060:asn1_decode: Looking for 'index', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'length', tag 0x20000000, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1110:asn1_decode: returning with: 7
asn1.c:1035:asn1_decode: called, left=244, depth 0, choice
asn1.c:1060:asn1_decode: Looking for 'privateKeys', tag 0x21000000, CHOICE
asn1.c:859:asn1_decode_entry: decoding 'privateKeys'
asn1.c:1035:asn1_decode:  called, left=10, depth 1
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'path'
asn1.c:1035:asn1_decode:   called, left=8, depth 2
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x4
asn1.c:859:asn1_decode_entry:   decoding 'path'
asn1.c:1060:asn1_decode: Looking for 'index', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'length', tag 0x20000000, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1110:asn1_decode: returning with: 0
asn1.c:1035:asn1_decode: called, left=232, depth 0, choice
pkcs15.c:542:sc_pkcs15_bind_internal: The following DFs were found:
pkcs15.c:547:sc_pkcs15_bind_internal:   DF type 8, path 3f0050154401,
index 0, count -1
pkcs15.c:547:sc_pkcs15_bind_internal:   DF type 0, path 3f0050154402,
index 0, count -1
card.c:690:sc_select_file: called; type=2, path=3f0050155032
card-starcos.c:412:starcos_select_file: current path (path, valid):
3F005015 (len: 4)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 32 00 .....P2.
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 00 2A 82 01 01 o....*...
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
30 0
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 42
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 42 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 44 bytes):
00 B0 00 00 2A ....*
card.c:248:sc_transmit_apdu: Received 42 bytes (SW1=90 SW2=00)
30 28 02 01 00 04 02 00 00 0C 0E 4F 70 65 6E 53 0(.........OpenS
43 20 50 72 6F 6A 65 63 74 80 0B 4F 70 65 6E 53 C Project..OpenS
43 20 43 61 72 64 03 02 04 10                   C Card....
iso7816.c:126:iso7816_read_binary: returning with: 42
card.c:593:sc_read_binary: returning with: 42
asn1.c:1035:asn1_decode: called, left=42, depth 0
asn1.c:1060:asn1_decode: Looking for 'TokenInfo', tag 0x1000010
asn1.c:859:asn1_decode_entry: decoding 'TokenInfo'
asn1.c:1035:asn1_decode:  called, left=40, depth 1
asn1.c:1060:asn1_decode: Looking for 'version', tag 0x2
asn1.c:859:asn1_decode_entry:  decoding 'version'
asn1.c:1060:asn1_decode: Looking for 'serialNumber', tag 0x4
asn1.c:859:asn1_decode_entry:  decoding 'serialNumber'
asn1.c:1060:asn1_decode: Looking for 'manufacturerID', tag 0xc, OPTIONAL
asn1.c:859:asn1_decode_entry:  decoding 'manufacturerID'
asn1.c:1060:asn1_decode: Looking for 'label', tag 0x20000000, OPTIONAL
asn1.c:859:asn1_decode_entry:  decoding 'label'
asn1.c:1060:asn1_decode: Looking for 'tokenflags', tag 0x3
asn1.c:859:asn1_decode_entry:  decoding 'tokenflags'
asn1.c:1060:asn1_decode: Looking for 'seInfo', tag 0x1000010, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'recordInfo', tag 0x21000001, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'supportedAlgorithms', tag
0x21000002, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
card.c:487:sc_unlock: called
card.c:492:sc_unlock: Calling card logout function
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:1324:starcos_check_sw: sw1 = 0x90, sw2 = 0x00
reader-openct.c:400:openct_reader_unlock: called
framework-pkcs15.c:145:pkcs15_bind: Binding to PKCS#15, rc=0
slot.c:143:card_detect: 0: Detected framework 0. Creating tokens.
pkcs15.c:1255:sc_pkcs15_read_file: called, path=3f0050154401, index=0,
count=-1
card.c:467:sc_lock: called
reader-openct.c:373:openct_reader_lock: called
card.c:690:sc_select_file: called; type=2, path=3f0050154401
card-starcos.c:412:starcos_select_file: current path (path, valid):  
(len: 0)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 3F 00 00 .....?..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 15 00 .....P..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 50 15 .....P.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 44 01 00 .....D..
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 01 00 82 01 01 o........
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
30 0
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 256
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 256 bytes at index 0
card.c:562:sc_read_binary: called; 128 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
30 37 30 0E 0C 08 55 73 65 72 20 50 49 4E 03 02 070...User PIN..
06 C0 30 03 04 01 01 A1 20 30 1E 03 02 02 0C 0A ..0..... 0......
04 FF FF FF FF 02 01 04 02 01 08 80 01 01 04 01 ................
00 30 06 04 04 3F 00 50 15 FF FF FF FF FF FF FF .0...?.P........
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:562:sc_read_binary: called; 128 bytes at index 128
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 80 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:590:sc_read_binary: returning with: 256
card.c:487:sc_unlock: called
card.c:492:sc_unlock: Calling card logout function
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:1324:starcos_check_sw: sw1 = 0x90, sw2 = 0x00
reader-openct.c:400:openct_reader_unlock: called
asn1.c:1035:asn1_decode: called, left=256, depth 0
asn1.c:1060:asn1_decode: Looking for 'pin', tag 0x1000010
asn1.c:859:asn1_decode_entry: decoding 'pin'
asn1.c:1035:asn1_decode:  called, left=55, depth 1
asn1.c:1060:asn1_decode: Looking for 'commonObjectAttributes', tag
0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'commonObjectAttributes'
asn1.c:1035:asn1_decode:   called, left=14, depth 2
asn1.c:1060:asn1_decode: Looking for 'label', tag 0xc, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'label'
asn1.c:1060:asn1_decode: Looking for 'flags', tag 0x3, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'flags'
asn1.c:1060:asn1_decode: Looking for 'authId', tag 0x4, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'accessControlRules', tag
0x1000010, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1060:asn1_decode: Looking for 'classAttributes', tag 0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'classAttributes'
asn1.c:1035:asn1_decode:   called, left=3, depth 2
asn1.c:1060:asn1_decode: Looking for 'authId', tag 0x4
asn1.c:859:asn1_decode_entry:   decoding 'authId'
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1060:asn1_decode: Looking for 'subClassAttributes', tag
0x21000000, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'typeAttributes', tag 0x21000001
asn1.c:859:asn1_decode_entry:  decoding 'typeAttributes'
asn1.c:1035:asn1_decode:   called, left=32, depth 2
asn1.c:1060:asn1_decode: Looking for 'pinAttributes', tag 0x1000010
asn1.c:859:asn1_decode_entry:   decoding 'pinAttributes'
asn1.c:1035:asn1_decode:    called, left=30, depth 3
asn1.c:1060:asn1_decode: Looking for 'pinFlags', tag 0x3
asn1.c:859:asn1_decode_entry:    decoding 'pinFlags'
asn1.c:1060:asn1_decode: Looking for 'pinType', tag 0xa
asn1.c:859:asn1_decode_entry:    decoding 'pinType'
asn1.c:1060:asn1_decode: Looking for 'minLength', tag 0x2
asn1.c:859:asn1_decode_entry:    decoding 'minLength'
asn1.c:1060:asn1_decode: Looking for 'storedLength', tag 0x2
asn1.c:859:asn1_decode_entry:    decoding 'storedLength'
asn1.c:1060:asn1_decode: Looking for 'maxLength', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'pinReference', tag 0x20000000,
OPTIONAL
asn1.c:859:asn1_decode_entry:    decoding 'pinReference'
asn1.c:1060:asn1_decode: Looking for 'padChar', tag 0x4, OPTIONAL
asn1.c:859:asn1_decode_entry:    decoding 'padChar'
asn1.c:1060:asn1_decode: Looking for 'lastPinChange', tag 0x18, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x1000010, OPTIONAL
asn1.c:859:asn1_decode_entry:    decoding 'path'
asn1.c:1035:asn1_decode:     called, left=6, depth 4
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x4
asn1.c:859:asn1_decode_entry:     decoding 'path'
asn1.c:1060:asn1_decode: Looking for 'index', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'length', tag 0x20000000, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1035:asn1_decode: called, left=199, depth 0
framework-pkcs15.c:586:pkcs15_create_tokens: Found 1 authentication objects
pkcs15.c:1255:sc_pkcs15_read_file: called, path=3f0050154402, index=0,
count=-1
card.c:467:sc_lock: called
reader-openct.c:373:openct_reader_lock: called
card.c:690:sc_select_file: called; type=2, path=3f0050154402
card-starcos.c:412:starcos_select_file: current path (path, valid):  
(len: 0)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 3F 00 00 .....?..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 15 00 .....P..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 50 15 .....P.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 44 02 00 .....D..
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 01 00 82 01 01 o........
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
30 0
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 256
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 256 bytes at index 0
card.c:562:sc_read_binary: called; 128 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
30 5F 30 14 0C 0B 50 72 69 76 61 74 65 20 4B 65 0_0...Private Ke
79 03 02 06 C0 04 01 01 30 35 04 28 35 37 36 41 y.......05.(576A
35 30 41 31 44 34 39 38 30 43 46 37 36 45 41 34 50A1D4980CF76EA4
31 38 38 35 46 31 46 35 32 44 33 32 39 36 45 35 1885F1F52D3296E5
41 31 32 31 03 02 05 20 03 02 03 B8 02 01 91 A0 A121... ........
00 A1 0E 30 0C 30 06 04 04 3F 00 50 15 02 02 02 ...0.0...?.P....
00 FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:562:sc_read_binary: called; 128 bytes at index 128
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 80 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
card.c:590:sc_read_binary: returning with: 256
card.c:487:sc_unlock: called
card.c:492:sc_unlock: Calling card logout function
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:1324:starcos_check_sw: sw1 = 0x90, sw2 = 0x00
reader-openct.c:400:openct_reader_unlock: called
asn1.c:1035:asn1_decode: called, left=256, depth 0, choice
asn1.c:1060:asn1_decode: Looking for 'privateRSAKey', tag 0x1000010,
CHOICE, OPTIONAL
asn1.c:859:asn1_decode_entry: decoding 'privateRSAKey'
asn1.c:1035:asn1_decode:  called, left=95, depth 1
asn1.c:1060:asn1_decode: Looking for 'commonObjectAttributes', tag
0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'commonObjectAttributes'
asn1.c:1035:asn1_decode:   called, left=20, depth 2
asn1.c:1060:asn1_decode: Looking for 'label', tag 0xc, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'label'
asn1.c:1060:asn1_decode: Looking for 'flags', tag 0x3, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'flags'
asn1.c:1060:asn1_decode: Looking for 'authId', tag 0x4, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'authId'
asn1.c:1060:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'accessControlRules', tag
0x1000010, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1060:asn1_decode: Looking for 'classAttributes', tag 0x1000010
asn1.c:859:asn1_decode_entry:  decoding 'classAttributes'
asn1.c:1035:asn1_decode:   called, left=53, depth 2
asn1.c:1060:asn1_decode: Looking for 'iD', tag 0x4
asn1.c:859:asn1_decode_entry:   decoding 'iD'
asn1.c:1060:asn1_decode: Looking for 'usage', tag 0x3
asn1.c:859:asn1_decode_entry:   decoding 'usage'
asn1.c:1060:asn1_decode: Looking for 'native', tag 0x1, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'accessFlags', tag 0x3, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'accessFlags'
asn1.c:1060:asn1_decode: Looking for 'keyReference', tag 0x2, OPTIONAL
asn1.c:859:asn1_decode_entry:   decoding 'keyReference'
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1060:asn1_decode: Looking for 'subClassAttributes', tag
0x21000000, OPTIONAL
asn1.c:859:asn1_decode_entry:  decoding 'subClassAttributes'
asn1.c:1035:asn1_decode:   called, left=0, depth 2
asn1.c:1060:asn1_decode: Looking for 'typeAttributes', tag 0x21000001
asn1.c:859:asn1_decode_entry:  decoding 'typeAttributes'
asn1.c:1035:asn1_decode:   called, left=14, depth 2
asn1.c:1060:asn1_decode: Looking for 'privateRSAKeyAttributes', tag
0x1000010
asn1.c:859:asn1_decode_entry:   decoding 'privateRSAKeyAttributes'
asn1.c:1035:asn1_decode:    called, left=12, depth 3
asn1.c:1060:asn1_decode: Looking for 'value', tag 0x1000010
asn1.c:859:asn1_decode_entry:    decoding 'value'
asn1.c:1035:asn1_decode:     called, left=6, depth 4
asn1.c:1060:asn1_decode: Looking for 'path', tag 0x4
asn1.c:859:asn1_decode_entry:     decoding 'path'
asn1.c:1060:asn1_decode: Looking for 'index', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1060:asn1_decode: Looking for 'length', tag 0x20000000, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1060:asn1_decode: Looking for 'modulusLength', tag 0x2
asn1.c:859:asn1_decode_entry:    decoding 'modulusLength'
asn1.c:1060:asn1_decode: Looking for 'keyInfo', tag 0x2, OPTIONAL
asn1.c:1076:asn1_decode: not present
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1111:asn1_decode: returning with: 0
asn1.c:1110:asn1_decode: returning with: 0
asn1.c:1035:asn1_decode: called, left=159, depth 0, choice
framework-pkcs15.c:355:pkcs15_create_pkcs11_objects: Found 1 private key
framework-pkcs15.c:355:pkcs15_create_pkcs11_objects: Found 0 public keys
framework-pkcs15.c:355:pkcs15_create_pkcs11_objects: Found 0 certificates
slot.c:230:slot_allocate: Allocated slot 0
framework-pkcs15.c:546:pkcs15_init_slot: Initialized token 'OpenSC Card
(User PIN)'
framework-pkcs15.c:635:pkcs15_create_tokens: Adding private key 0 to PIN 0
slot.c:230:slot_allocate: Allocated slot 1
slot.c:230:slot_allocate: Allocated slot 2
slot.c:230:slot_allocate: Allocated slot 3
framework-pkcs15.c:668:pkcs15_create_tokens: All tokens created
slot.c:151:card_detect: 0: Detection ended
slot.c:83:card_detect: 1: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 1: Card absent
slot.c:183:card_removed: 1: SmartCard removed
slot.c:83:card_detect: 2: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 2: Card absent
slot.c:183:card_removed: 2: SmartCard removed
slot.c:83:card_detect: 3: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 3: Card absent
slot.c:183:card_removed: 3: SmartCard removed
slot.c:83:card_detect: 4: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 4: Card absent
slot.c:183:card_removed: 4: SmartCard removed
pkcs11-global.c:63:C_Initialize: C_Initialize: result = 0
pkcs11-global.c:152:C_GetSlotList: Getting slot listing
slot.c:83:card_detect: 0: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 1
slot.c:151:card_detect: 0: Detection ended
slot.c:83:card_detect: 1: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 1: Card absent
slot.c:183:card_removed: 1: SmartCard removed
slot.c:83:card_detect: 2: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 2: Card absent
slot.c:183:card_removed: 2: SmartCard removed
slot.c:83:card_detect: 3: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 3: Card absent
slot.c:183:card_removed: 3: SmartCard removed
slot.c:83:card_detect: 4: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 4: Card absent
slot.c:183:card_removed: 4: SmartCard removed
pkcs11-global.c:164:C_GetSlotList: was only a size inquiry (4)
pkcs11-global.c:152:C_GetSlotList: Getting slot listing
slot.c:83:card_detect: 0: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 1
slot.c:151:card_detect: 0: Detection ended
slot.c:83:card_detect: 1: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 1: Card absent
slot.c:183:card_removed: 1: SmartCard removed
slot.c:83:card_detect: 2: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 2: Card absent
slot.c:183:card_removed: 2: SmartCard removed
slot.c:83:card_detect: 3: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 3: Card absent
slot.c:183:card_removed: 3: SmartCard removed
slot.c:83:card_detect: 4: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 0
slot.c:102:card_detect: 4: Card absent
slot.c:183:card_removed: 4: SmartCard removed
pkcs11-global.c:181:C_GetSlotList: returned 4 slots
pkcs11-session.c:40:C_OpenSession: Opening new session for slot 0
pkcs11-global.c:202:C_GetSlotInfo: Getting info about slot 0
slot.c:83:card_detect: 0: Detecting SmartCard
sc.c:120:sc_detect_card_presence: called
reader-openct.c:193:openct_reader_detect_card_presence: called
sc.c:125:sc_detect_card_presence: returning with: 1
slot.c:151:card_detect: 0: Detection ended
pkcs11-global.c:238:C_GetTokenInfo: Getting info about token in slot 0
pkcs11-session.c:235:C_Login: Login for session 1
card.c:467:sc_lock: called
reader-openct.c:373:openct_reader_lock: called
card.c:690:sc_select_file: called; type=2, path=3f005015
card-starcos.c:412:starcos_select_file: current path (path, valid):  
(len: 0)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 3F 00 00 .....?..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 3F 00 .....?.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 50 15 00 .....P..
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=62 SW2=84)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 7 bytes (resp. 2 bytes):
00 A4 00 0C 02 50 15 .....P.
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
sec.c:157:sc_pin_cmd: called
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 13 bytes (resp. 2 bytes, sensitive):
00 20 00 01 08 31 32 33 34 00 00 00 00 . ...1234....
card.c:248:sc_transmit_apdu: Received 0 bytes (SW1=90 SW2=00)
card-starcos.c:1324:starcos_check_sw: sw1 = 0x90, sw2 = 0x00
sec.c:204:sc_pin_cmd: returning with: 0
framework-pkcs15.c:741:pkcs15_login: PIN verification returned 0
starting create object
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_CLASS =
CKO_PRIVATE_KEY
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_KEY_TYPE = CKK_RSA
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_MODULUS =
AD75CEE27106E4E388498DCC2D39918C848AA46684EA2578637694A03ED339CF
pkcs11-object.c:43:C_CreateObject: C_CreateObject():
CKA_PRIVATE_EXPONENT =
53252333DBA5C8556060917D8B380B1265FDE6EBD54E3F03C3F9752892B4C102
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_PUBLIC_EXPONENT
= 010001
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): Attribute 0x124 =
00D89EBCC60F6F75FBDF8554DDDCC44E3BEC77ADBC187935937852276737B2DA
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): Attribute 0x125 =
00CCFE74F2B91775717B13E0D97A5FC77E1FE5443AF57DC9A21822E492DE9801
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_ID =
3931443931354534464343464330464532313342383430384636373334413333
pkcs11-object.c:43:C_CreateObject: C_CreateObject(): CKA_TOKEN = TRUE
card.c:826:sc_card_ctl: called
card.c:832:sc_card_ctl: card_ctl(4) not supported
card.c:690:sc_select_file: called; type=2, path=3f0050154946
card-starcos.c:412:starcos_select_file: current path (path, valid):
3F005015 (len: 4)
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 8 bytes (resp. 260 bytes):
00 A4 00 00 02 49 46 00 .....IF.
card.c:248:sc_transmit_apdu: Received 9 bytes (SW1=90 SW2=00)
6F 07 80 02 00 80 82 01 01 o........
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 4 bytes):
00 B0 00 00 01 .....
card.c:248:sc_transmit_apdu: Received 1 bytes (SW1=90 SW2=00)
01 .
card-starcos.c:163:process_fci: processing FCI bytes
card-starcos.c:185:process_fci:   bytes in file: 128
card-starcos.c:234:process_fci:   type: working EF
card-starcos.c:235:process_fci:   EF structure: transparent
card-starcos.c:386:starcos_select_fid: returning with: 0
card.c:712:sc_select_file: returning with: 0
card.c:562:sc_read_binary: called; 128 bytes at index 0
card.c:228:sc_transmit_apdu: called
card.c:195:sc_transceive: Sending 5 bytes (resp. 130 bytes):
00 B0 00 00 80 .....
card.c:248:sc_transmit_apdu: Received 128 bytes (SW1=90 SW2=00)
01 06 70 6B 63 73 31 35 02 06 6F 6E 65 70 69 6E ..pkcs15..onepin
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF FF ................
iso7816.c:126:iso7816_read_binary: returning with: 128
card.c:593:sc_read_binary: returning with: 128
profile.c:308:sc_profile_load: Trying profile file
/usr/share/opensc//pkcs15.profile
profile.c:316:sc_profile_load: profile /usr/share/opensc//pkcs15.profile
loaded ok
profile.c:308:sc_profile_load: Trying profile file
/usr/share/opensc//starcos.profile
profile.c:316:sc_profile_load: profile
/usr/share/opensc//starcos.profile loaded ok
pkcs15-lib.c:1985:select_object_path: key-domain.private-key @3f005015
(auth_id.len=1)
profile.c:551:sc_profile_instantiate_template: Instantiating template
key-domain at 3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated private-key at
3f0050150040
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated public-key at
3f0050153044
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated certificate at
3f0050153145
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated extractable-key
at 3f0050153242
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
profile.c:616:sc_profile_instantiate_file: Instantiated data at
3f0050153342
profile.c:619:sc_profile_instantiate_file:   parent=PKCS15-AppDF@3f005015
pkcs15-lib.c:2638:sc_pkcs15init_authenticate: path=3f005015, op=2
misc.c:79:sc_to_cryptoki_error: opensc error: Requested object not found
(-1407)

Thank you for your help

Bob
_______________________________________________
opensc-devel mailing list
[hidden email]
http://www.opensc.org/cgi-bin/mailman/listinfo/opensc-devel
Reply | Threaded
Open this post in threaded view
|

Re: Can't import private key, sc_pkcs15init_authenticate fails

Stef Hoeben
Hi,

could you try to set
    cache_pins = true;
in opensc.conf?

Cheers,
Stef

Hubert Greiche wrote:

>
>> could you increase the debug level ? I would like see the last APDUs
>> send to the card.
>>
>> Nils
>>
> Here is the increased debug level version:

 > []

>
> misc.c:79:sc_to_cryptoki_error: opensc error: Requested object not
> found (-1407)
>
> Thank you for your help
>
> Bob


_______________________________________________
opensc-devel mailing list
[hidden email]
http://www.opensc.org/cgi-bin/mailman/listinfo/opensc-devel
Reply | Threaded
Open this post in threaded view
|

Re: Can't import private key, sc_pkcs15init_authenticate fails

Hubert Greiche
In reply to this post by Hubert Greiche
Stef Hoeben wrote:

> Hi,
>
> could you try setting
>    cache_pins = true;
> int opensc.conf (and let us know if that helps)?
>
> Cheers,
> Stef
>

Yes, it works. Thank you!

Cheers,

Bob.
_______________________________________________
opensc-devel mailing list
[hidden email]
http://www.opensc.org/cgi-bin/mailman/listinfo/opensc-devel