Boarman, Christopher L wrote:
> OK. It certainly is working now after I made the temporary change to the
> buffer size. However, the errors are not going to debug, they are going to
> stderr and show up in the runtime output of the apps that are using pkcs11
> module, which is why I was concerned that something was not right. The OpenSC
> pkcs11 module passed all the same authentication tests as the ActivIdentity
> pkcs11 module so from that perspective, we have essentially determined the
> source of the defect that I had identified in #189. I guess how you want to
> implement the solution for release is another activity.
>
I have expressed to NIST on a number of occasions that the lack of a directory
of
objects on the card have made it very difficult to avoid the "errors" showing up
when an attempt is made to read an object. I did not want to try and read all
objects on a card at startup for performance reasons and it is is not defined
how
a card will react to reading only a partial object, although it looks that might
be possible, to in effect create a directory.
In the cases were are interested in, i.e. pam_krb5 with PKINIT, Thunderbird and
Firefox
stderr is not normally printed.
You could also set the error_file in the opensc.conf to something other the
stderr.
#
# A special value of 'stderr' is recognized.
# Default: stderr
#
error_file = /dev/null;
> Perhaps when I get back from vacation, I could work with you more on this
> issue.
Sure.
>
> -----Original Message-----
> From: Douglas E. Engert [mailto:deeng...@anl.gov]
> Sent: Monday, July 06, 2009 9:42 AM
> To: Boarman, Christopher L
> Cc: Andreas Jellinghaus; opensc-devel@lists.opensc-project.org
> Subject: Re: [opensc-devel] Ticket #189 - Problems with opensc-pkcs11.so
>
>
>
> Boarman, Christopher L wrote:
>> Andreas,
>>
>> I added a 1000 byte buffer to the MAXLEN on the X.509 certs and that seemed
>> to temporarily resolve that issue but there were other errors that I am
>> seeing as well. There appear to be 2 categories of these errors:
>>
>> 1.) No cert found:
>
> The cal of PKCS#11 may ask for a list of all the certificates available.
> NIST 800-73 does not provide for a directory of what objects are present on a
> card
> and there is no standard as to what is returned if the object is not present.
>
> So the only what to see if there is an object it to try and read it.
>
>> [opensc-pkcs11] pkcs15.c:1672:sc_pkcs15_read_file: called, path=0102cece,
>> index=0, count=-1
>> [opensc-pkcs11] card.c:285:sc_lock: called
>> [opensc-pkcs11] card.c:532:sc_select_file: called; type=2, path=0102cece
>> [opensc-pkcs11] card-piv.c:1620:piv_select_file: called
>> [opensc-pkcs11] card-piv.c:1591:piv_find_obj_by_containerid: called
>> [opensc-pkcs11] card-piv.c:1592:piv_find_obj_by_containerid: str=0x0102
>> [opensc-pkcs11] card-piv.c:1597:piv_find_obj_by_containerid: returning with:
>> 8
>> [opensc-pkcs11] card-piv.c:1677:piv_select_file: returning with: 0
>> [opensc-pkcs11] card.c:554:sc_select_file: returning with: 0
>> [opensc-pkcs11] card.c:399:sc_read_binary: called; 3308 bytes at index 0
>> [opensc-pkcs11] card-piv.c:857:piv_read_binary: called
>> [opensc-pkcs11] card-piv.c:631:piv_get_data: called
>> [opensc-pkcs11] card-piv.c:632:piv_get_data: get_data: tag=8
>> [opensc-pkcs11] card-piv.c:299:piv_general_io: called
>> [opensc-pkcs11] card-piv.c:303:piv_general_io: piv_general_io cb 3f ff 5 :
>> 255 256
>> [opensc-pkcs11] card.c:285:sc_lock: called
>> [opensc-pkcs11] card-piv.c:334:piv_general_io: calling sc_transmit_apdu
>> flags=1 le=256, resplen=20000, resp=0xbfe30b8c
>> [opensc-pkcs11] apdu.c:516:sc_transmit_apdu: called
>> [opensc-pkcs11] card.c:285:sc_lock: called
>> [opensc-pkcs11] apdu.c:184:sc_apdu_log:
>> Outgoing APDU data [ 11 bytes] =====================================
>> 00 CB 3F FF 05 5C 03 5F C1 0B 00 ..?..\._...
>
> This above is trying to read "X.509 Certificate for Key Management" "5FC10B"
> (800-73-1 Table 6 lists the BER-TLV Tags)
>
>
>> ======================================================================
>> [opensc-pkcs11] reader-pcsc.c:161:pcsc_internal_transmit: called
>> [opensc-pkcs11] apdu.c:184:sc_apdu_log:
>> Incoming APDU data [ 10 bytes] =====================================
>> 53 06 70 00 71 00 FE 00 90 00 S.p.q.....
>
> What it read from the card is tag 53 indicating an object with length 6.
> The allowed tags for a cert object are listed in Appendix A, as
> certificate-70,
> certinfo-71, MSCUID-72 and Error detection code-FE.
> The 70 tag is followed by a length of 0, indicating a cert of length 0.
>
> So this is not an error, just no certificate on the card.
>
>> ======================================================================
>> [opensc-pkcs11] card.c:312:sc_unlock: called
>> [opensc-pkcs11] card-piv.c:341:piv_general_io: DEE r=0 apdu.resplen=8 sw1=90
>> sw2=00
>> [opensc-pkcs11] card-piv.c:378:piv_general_io: DEE got buffer 0x84cbab0 len 8
>> [opensc-pkcs11] card.c:312:sc_unlock: called
>> [opensc-pkcs11] card-piv.c:397:piv_general_io: returning with: 8
>> [opensc-pkcs11] card-piv.c:735:piv_get_data: returning with: 8
>> [opensc-pkcs11] card-piv.c:888:piv_read_binary: DEE rbuf=0x84cbab0,rbuflen=8,
>> [opensc-pkcs11] card-piv.c:764:piv_handle_certificate_data: returning with:
>> Object not found
>> [opensc-pkcs11] card-piv.c:936:piv_read_binary: returning with: Object not
>> found
>> [opensc-pkcs11] card.c:430:sc_read_binary: returning with: Object not found
>> [opensc-pkcs11] card.c:312:sc_unlock: called
>> [opensc-pkcs11] pkcs15-piv.c:323:sc_pkcs15emu_piv_init: No cert found,i=2
>>
>> 2.) Public key not found
>
> Since we are emulating a PKCS#15 file system for use by PKCS#11, the PKCS#11
> caller may ask for the public keys on the card. The PIV does not store public
> keys on the card, but the public key can be derived from the certificate.
>
> So this too is normal, in that the cert is not available to get the public
> key.
>
>> [opensc-pkcs11] pkcs15-piv.c:391:sc_pkcs15emu_piv_init: PIV-II adding pub
>> keys...
>> [opensc-pkcs11] pkcs15-piv.c:420:sc_pkcs15emu_piv_init: No cert for this pub
>> key i=2
>> [opensc-pkcs11] pkcs15-pubkey.c:387:sc_pkcs15_read_pubkey: called
>> [opensc-pkcs11] pkcs15.c:1672:sc_pkcs15_read_file: called, path=9d06,
>> index=0, count=-1
>> [opensc-pkcs11] card.c:285:sc_lock: called
>> [opensc-pkcs11] card.c:532:sc_select_file: called; type=2, path=9d06
>> [opensc-pkcs11] card-piv.c:1620:piv_select_file: called
>> [opensc-pkcs11] card-piv.c:1591:piv_find_obj_by_containerid: called
>> [opensc-pkcs11] card-piv.c:1592:piv_find_obj_by_containerid: str=0x9D06
>> [opensc-pkcs11] card-piv.c:1597:piv_find_obj_by_containerid: returning with:
>> 14
>> [opensc-pkcs11] card-piv.c:1677:piv_select_file: returning with: 0
>> [opensc-pkcs11] card.c:554:sc_select_file: returning with: 0
>> [opensc-pkcs11] card.c:399:sc_read_binary: called; 2048 bytes at index 0
>> [opensc-pkcs11] card-piv.c:857:piv_read_binary: called
>> [opensc-pkcs11] card-piv.c:631:piv_get_data: called
>> [opensc-pkcs11] card-piv.c:632:piv_get_data: get_data: tag=14
>> [opensc-pkcs11] card-piv.c:735:piv_get_data: returning with: File not found
>> [opensc-pkcs11] card-piv.c:936:piv_read_binary: returning with: File not
>> found
>> [opensc-pkcs11] card.c:430:sc_read_binary: returning with: File not found
>> [opensc-pkcs11] card.c:312:sc_unlock: called
>> [opensc-pkcs11] pkcs15-pubkey.c:404:sc_pkcs15_read_pubkey: Failed to read
>> public key file.
>>
>> What do you think is contributing to these errors? I have attached a new
>> debug file and I hope that you can take another look and let me know what
>> you think.
>>
>
> I made some trade offs between performance and error handling. In the traces
> these look like errors, because the fact that the cert is not present does not
> show up until one tries to reread it. These "errors" only show up in the
> debug logs. If NIST had placed a directory on the card, this would have made
> this much easier to handle earlier in the code.
>
>>
>> -----Original Message-----
>> From: Andreas Jellinghaus [mailto:a...@dungeon.inka.de]
>> Sent: Wednesday, June 24, 2009 6:33 AM
>> To: Boarman, Christopher L; Douglas E. Engert
>> Cc: opensc-devel@lists.opensc-project.org
>> Subject: Re: [opensc-devel] Ticket #189 - Problems with opensc-pkcs11.so
>>
>> Hi Christopher,
>>
>> your first email in this thread was:
>>> [opensc-pkcs11] card-piv.c:764:piv_handle_certificate_data: returning
>>> with: 2308
>>> [opensc-pkcs11] card-piv.c:924:piv_read_binary: returning with: 2308
>>> [opensc-pkcs11] pkcs15-cert.c:115:sc_pkcs15_read_certificate: called
>>>
>>> From there, I traced the call into asn1.c, in the function
>>> sc_asn1_read_tag, and the following is the code segment where the final
>>> point of failure occurs:
>> using the log file you provided, I check the data downloaded by the piv
>> code, and everything looks fine: 1509 bytes of data, containing a compound
>> tag with inside a 0x70 and 0x71 tag. 0x70 has the compressed certificate,
>> 0x71 has the single byte "01" as marker for "compressed" I guess,
>> and there is a final tag 0xfe with length 00 and no value - not evaluated
>> by the opensc code, I guess some end-of-content marker.
>>
>> the log file shows the code is properly decompressed to 2308 bytes.
>>
>> ok, I wrote a program to decode those bytes and have a look at the decoded
>> data...
>>
>> the data is a fine certificate in DER format. the size is 2658 bytes.
>> so the problem is opensc thinks the file should be only2308 bytes, requests
>> only 2308 bytes, and thus gets a broken cert that returns an error when
>> looking into it.
>>
>> The problem is here:
>> [opensc-pkcs11] pkcs15-piv.c:298:sc_pkcs15emu_piv_init: PIV-II adding
>> certs...
>> [opensc-pkcs11] pkcs15.c:1672:sc_pkcs15_read_file: called, path=0101cece,
>> index=
>> 0, count=-1
>> [opensc-pkcs11] card.c:285:sc_lock: called
>> [opensc-pkcs11] card.c:532:sc_select_file: called; type=2, path=0101cece
>> [opensc-pkcs11] card-piv.c:1608:piv_select_file: called
>> [opensc-pkcs11] card-piv.c:1579:piv_find_obj_by_containerid: called
>> [opensc-pkcs11] card-piv.c:1580:piv_find_obj_by_containerid: str=0x0101
>> [opensc-pkcs11] card-piv.c:1585:piv_find_obj_by_containerid: returning with:
>> 3
>> [opensc-pkcs11] card-piv.c:1665:piv_select_file: returning with: 0
>> [opensc-pkcs11] card.c:554:sc_select_file: returning with: 0
>> [opensc-pkcs11] card.c:399:sc_read_binary: called; 2308 bytes at index 0
>>
>> sc_pkcs15_read_file calls sc_read_binary with a buffer that is too small.
>> where did it get the size? frm sc_select_file. but we have no debug
>> information what that function did and how it got that value.
>>
>> ah, piv_find_obj_by_containerid seems to be the problem. it looks at the
>> static struct piv_object piv_objects[] = {
>> data in card-piv.c and that has a line:
>> { PIV_OBJ_X509_PIV_AUTH, "X.509 Certificate for PIV Authentication",
>> "2.16.840.1.101.3.7.2.1.1", 3, "\x5F\xC1\x05",
>> "\x01\x01", 1895+9+4+400} ,
>>
>> 1895+9+4+400 = 2308
>>
>> replace that with a higher value and you should be fine.
>>
>> I have no clue why we have that small value, and what the best way to fix
>> this problem is. lets wait till Douglas can have a look.
>>
>> but from my side, that "default size" ends up as the size of the buffer
>> sc_read_file allocates, and thus only that many bytes are passed back
>> from the lower level functions, and thus an incomplete certificate is
>> returned to the higher layer, which is refused as invalid, so that
>> is the reason the whole thing does not work.
>>
>> also the constants you mentioned comparing pkcs11-tool, they are all hard
>> coded in card-piv.c or pkcs15-piv.c. so it is normal, that different software
>> returns different names. If PIV standard dictates the names, we should
>> fix our software. if not, then it is a PIV problem. with PKCS#15 the
>> displayed string for a certificate is in the directory files, thus the
>> software doesn't need such hard coded values.
>>
>> if you want to experiment, you could add increase the hard coded sizes
>> and see if it helps.
>>
>> douglas, can you look at the decompression code and add some debugging,
>> so we see the size after decompression vs. the number of bytes returned?
>>
>> Regards, Andreas
>
--
Douglas E. Engert <deeng...@anl.gov>
Argonne National Laboratory
9700 South Cass Avenue
Argonne, Illinois 60439
(630) 252-5444
_______________________________________________
opensc-devel mailing list
opensc-devel@lists.opensc-project.org
http://www.opensc-project.org/mailman/listinfo/opensc-devel
