Andreas, I'll understand if you don't have time to help me look at this problem. You mentioned that you wrote a program to decode the bytes that are downloaded by the piv code and I was wondering maybe you could send me your decoder code so I can try to further investigate the issues I am seeing.
-----Original Message----- From: Boarman, Christopher L Sent: Wednesday, June 24, 2009 8:20 PM To: Andreas Jellinghaus; Douglas E. Engert Cc: opensc-devel@lists.opensc-project.org Subject: RE: [opensc-devel] Ticket #189 - Problems with opensc-pkcs11.so 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: [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 ..?..\._... ====================================================================== [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..... ====================================================================== [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 [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. -----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 _______________________________________________ opensc-devel mailing list opensc-devel@lists.opensc-project.org http://www.opensc-project.org/mailman/listinfo/opensc-devel
