{"action":"created","issue":{"url":"https://api.github.com/repos/OpenSC/OpenSC/issues/1377","repository_url":"https://api.github.com/repos/OpenSC/OpenSC","labels_url":"https://api.github.com/repos/OpenSC/OpenSC/issues/1377/labels{/name}","comments_url":"https://api.github.com/repos/OpenSC/OpenSC/issues/1377/comments","events_url":"https://api.github.com/repos/OpenSC/OpenSC/issues/1377/events","html_url":"https://github.com/OpenSC/OpenSC/issues/1377","id":329119508,"node_id":"MDU6SXNzdWUzMjkxMTk1MDg=","number":1377,"title":"Remove the CAC1 driver (another issues with card detection)","user":{"login":"Jakuje","id":2694489,"node_id":"MDQ6VXNlcjI2OTQ0ODk=","avatar_url":"https://avatars3.githubusercontent.com/u/2694489?v=4","gravatar_id":"","url":"https://api.github.com/users/Jakuje","html_url":"https://github.com/Jakuje","followers_url":"https://api.github.com/users/Jakuje/followers","following_url":"https://api.github.com/users/Jakuje/following{/other_user}","gists_url":"https://api.github.com/users/Jakuje/gists{/gist_id}","starred_url":"https://api.github.com/users/Jakuje/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Jakuje/subscriptions","organizations_url":"https://api.github.com/users/Jakuje/orgs","repos_url":"https://api.github.com/users/Jakuje/repos","events_url":"https://api.github.com/users/Jakuje/events{/privacy}","received_events_url":"https://api.github.com/users/Jakuje/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":3,"created_at":"2018-06-04T16:03:23Z","updated_at":"2018-06-05T09:33:11Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"### Problem Description\r\n\r\nTL;DR: Remove CAC1 driver. It breaks detection of misbehaving cards (soon after reset?).\r\n\r\nI run the [CI on master](https://gitlab.com/redhat-crypto/OpenSC/). We have a machine with two-slot reader with CAC and coolkey cards inserver. It worked fine until last week. The cards got swapped last week and now the coolkey card is no longer detected from my testsuite, while it works just fine if:\r\n\r\n * The `OPENSC_DRIVER` is set to `coolkey`\r\n * Configuration sets `card_drivers = coolkey, cac`\r\n * From `pkcs11-tool` (which is opening only one session, not more as a testsuite)\r\n\r\nThe `PKCS11SPY` trace looks like this (while before there was one more iteration of `C_Initialize()`, `C_Finalize()` before, whicih could have messed up something):\r\n```\r\n15: C_GetSlotInfo\r\n2018-06-04 05:58:05.473\r\n[in] slotID = 0x0\r\n[out] pInfo: \r\n      slotDescription:        'OMNIKEY CardMan (076B:3022) 3021'\r\n                              ' 00 00                          '\r\n      manufacturerID:         '                                '\r\n      hardwareVersion:         0.0\r\n      firmwareVersion:         0.0\r\n      flags:                   7\r\n        CKF_TOKEN_PRESENT                \r\n        CKF_REMOVABLE_DEVICE             \r\n        CKF_HW_SLOT                      \r\nReturned:  0 CKR_OK\r\n\r\n16: C_OpenSession\r\n2018-06-04 05:58:06.196\r\n[in] slotID = 0x0\r\n[in] flags = 0x6\r\npApplication=(nil)\r\nNotify=(nil)\r\n[out] *phSession = 0x16785f0\r\nReturned:  0 CKR_OK\r\n\r\n17: C_GetMechanismList\r\n2018-06-04 05:58:06.196\r\n[in] slotID = 0x0\r\nReturned:  224 CKR_TOKEN_NOT_PRESENT\r\n```\r\n\r\nFrom the logs, there are two separate issues:\r\n\r\n * Misdetection of coolkey cards as CAC (again)\r\n * Breaking some data structures while issuing several cycles of Initialize/Finalize (?)\r\n\r\nI can isolate the first issue to the configuration, where CAC driver is in front of coolkey driver, where I start seeing detection issues (the `pkcs11-tool` still detects the card, but in testsuite, it shows without any objects), but not yet this complete brokeness.\r\n\r\nThis is again issue of the coolkey cards responding to arbitrary APDUs with SW = `90 00`, which is not very well handled in the card drivers yet and now it bubbled down here to the CAC driver. Not even the #1367 is solving the issue since it is falling again to the legacy CAC1 driver.\r\n\r\n### Proposed Resolution\r\n\r\nThere are certainly issues in the CAC driver. Such as out of bounds reading. I was able to get the following logs from the master:\r\n```\r\n[...]\r\n0x7f6cb8f238c0 17:31:58.387 [opensc-pkcs11] pkcs15-cac.c:356:sc_pkcs15emu_cac_init: \r\ncert (99 bytes):\r\n63 3A 35 35 37 3A 73 63 5F 72 65 61 64 5F 62 69 c:557:sc_read_bi\r\n6E 61 72 79 3A 20 63 61 6C 6C 65 64 3B 20 32 35 nary: called; 25\r\n36 20 62 79 74 65 73 20 61 74 20 69 6E 64 65 78 6 bytes at index\r\n20 30 00 34 31 3A 73 63 5F 6C 6F 63 6B 3A 20 72  0.41:sc_lock: r\r\n65 74 75 72 6E 69 6E 67 20 77 69 74 68 3A 20 30 eturning with: 0\r\n20 28 53 75 63 63 65 73 73 29 0A 00 64 5F 62 69  (Success)..d_bi\r\n6E 61 72                                        nar\r\n0x7f6cb8f238c0 17:31:58.387 [opensc-pkcs11] pkcs15-cert.c:370:sc_pkcs15_read_certificate: called\r\n```\r\nI will fix these in the coming PR.\r\n\r\nI would also like to remove the CAC1 implementation, because it is getting problematic (it is just guesswork now, how it was supposed to work -- there is no documentation about its specification) and there is no good use for it anymore (no valid CAC cards are in use, `libcacard` is also moving away from this). Would you mind if I just remove that, or should I keep it available using either environment variable or some configuration?\r\n\r\nAnyway, dropping the CAC1 driver resolves both issues and I see the coolkey card working again.\r\n\r\nThe changes are building on top of #1367 so I am not yet sending a PR (it would be huge mess, but the changes look somehow like this, if I use ifdefs -- I don't oppose to removing the `#ifdefed` code completely:\r\n\r\nhttps://github.com/Jakuje/OpenSC/commits/drop-cac1\r\n\r\n### Steps to reproduce\r\n\r\n^^^ Two-slot reader, in first one coolkey card, in second CAC card. Build master (today) and run testsuite:\r\n```\r\ncd src/tests/p11test/ && ./p11test -s 0 -p 123456\r\n```\r\n### Logs\r\n\r\nSeveral runs reveal many logs of card detection. I can attach them if interested. "},"comment":{"url":"https://api.github.com/repos/OpenSC/OpenSC/issues/comments/394645426","html_url":"https://github.com/OpenSC/OpenSC/issues/1377#issuecomment-394645426","issue_url":"https://api.github.com/repos/OpenSC/OpenSC/issues/1377","id":394645426,"node_id":"MDEyOklzc3VlQ29tbWVudDM5NDY0NTQyNg==","user":{"login":"Jakuje","id":2694489,"node_id":"MDQ6VXNlcjI2OTQ0ODk=","avatar_url":"https://avatars3.githubusercontent.com/u/2694489?v=4","gravatar_id":"","url":"https://api.github.com/users/Jakuje","html_url":"https://github.com/Jakuje","followers_url":"https://api.github.com/users/Jakuje/followers","following_url":"https://api.github.com/users/Jakuje/following{/other_user}","gists_url":"https://api.github.com/users/Jakuje/gists{/gist_id}","starred_url":"https://api.github.com/users/Jakuje/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Jakuje/subscriptions","organizations_url":"https://api.github.com/users/Jakuje/orgs","repos_url":"https://api.github.com/users/Jakuje/repos","events_url":"https://api.github.com/users/Jakuje/events{/privacy}","received_events_url":"https://api.github.com/users/Jakuje/received_events","type":"User","site_admin":false},"created_at":"2018-06-05T09:33:11Z","updated_at":"2018-06-05T09:33:11Z","author_association":"CONTRIBUTOR","body":"From the second log, it indeed looks like the Muscle applet is matched (from a line 15294 and several other similar blocks can be seen there):\r\n```\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] card.c:269:sc_connect_card: trying driver 'muscle'\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] apdu.c:554:sc_transmit_apdu: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] card.c:401:sc_lock: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] reader-pcsc.c:613:pcsc_lock: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] card-muscle.c:818:muscle_card_reader_lock_obtained: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] card-muscle.c:826:muscle_card_reader_lock_obtained: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] card.c:441:sc_lock: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] apdu.c:521:sc_transmit: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] apdu.c:371:sc_single_transmit: called\r\n0x7f092b25e9c0 03:55:17.980 [opensc-pkcs11] apdu.c:378:sc_single_transmit: CLA:0, INS:A4, P1:4, P2:0, data(6) 0x7f092871ed10\r\n0x7f092b25e9c0 03:55:17.981 [opensc-pkcs11] reader-pcsc.c:284:pcsc_transmit: reader 'OMNIKEY CardMan (076B:3022) 3021 00 00'\r\n0x7f092b25e9c0 03:55:17.981 [opensc-pkcs11] reader-pcsc.c:285:pcsc_transmit: \r\nOutgoing APDU (11 bytes):\r\n00 A4 04 00 06 A0 00 00 00 01 01 ...........\r\n0x7f092b25e9c0 03:55:17.981 [opensc-pkcs11] reader-pcsc.c:213:pcsc_internal_transmit: called\r\n0x7f092b25e9c0 03:55:18.008 [opensc-pkcs11] reader-pcsc.c:294:pcsc_transmit: \r\nIncoming APDU (2 bytes):\r\n90 00 ..\r\n0x7f092b25e9c0 03:55:18.008 [opensc-pkcs11] apdu.c:390:sc_single_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.008 [opensc-pkcs11] apdu.c:543:sc_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.008 [opensc-pkcs11] card.c:451:sc_unlock: called\r\n0x7f092b25e9c0 03:55:18.008 [opensc-pkcs11] reader-pcsc.c:663:pcsc_unlock: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] apdu.c:554:sc_transmit_apdu: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] card.c:401:sc_lock: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] reader-pcsc.c:613:pcsc_lock: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] card-muscle.c:818:muscle_card_reader_lock_obtained: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] card-muscle.c:826:muscle_card_reader_lock_obtained: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] card.c:441:sc_lock: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] apdu.c:521:sc_transmit: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] apdu.c:371:sc_single_transmit: called\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] apdu.c:378:sc_single_transmit: CLA:B0, INS:3C, P1:0, P2:0, data(0) (nil)\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] reader-pcsc.c:284:pcsc_transmit: reader 'OMNIKEY CardMan (076B:3022) 3021 00 00'\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] reader-pcsc.c:285:pcsc_transmit: \r\nOutgoing APDU (5 bytes):\r\nB0 3C 00 00 40 .<..@\r\n0x7f092b25e9c0 03:55:18.017 [opensc-pkcs11] reader-pcsc.c:213:pcsc_internal_transmit: called\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] reader-pcsc.c:294:pcsc_transmit: \r\nIncoming APDU (2 bytes):\r\n6C 10 l.\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] apdu.c:390:sc_single_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] apdu.c:401:sc_set_le_and_transmit: called\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] apdu.c:371:sc_single_transmit: called\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] apdu.c:378:sc_single_transmit: CLA:B0, INS:3C, P1:0, P2:0, data(0) (nil)\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] reader-pcsc.c:284:pcsc_transmit: reader 'OMNIKEY CardMan (076B:3022) 3021 00 00'\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] reader-pcsc.c:285:pcsc_transmit: \r\nOutgoing APDU (5 bytes):\r\nB0 3C 00 00 10 .<...\r\n0x7f092b25e9c0 03:55:18.093 [opensc-pkcs11] reader-pcsc.c:213:pcsc_internal_transmit: called\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] reader-pcsc.c:294:pcsc_transmit: \r\nIncoming APDU (18 bytes):\r\n01 01 01 04 00 00 13 88 00 00 0B 03 01 04 00 00 ................\r\n90 00                                           ..\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] apdu.c:390:sc_single_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] apdu.c:422:sc_set_le_and_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] apdu.c:543:sc_transmit: returning with: 0 (Success)\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] card.c:451:sc_unlock: called\r\n0x7f092b25e9c0 03:55:18.159 [opensc-pkcs11] reader-pcsc.c:663:pcsc_unlock: called\r\n0x7f092b25e9c0 03:55:18.166 [opensc-pkcs11] card.c:283:sc_connect_card: matched: MuscleApplet\r\n```\r\nThe pkcs15 emulation fails to match after this, because it is based on the match above (line 20896):\r\n```\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] pkcs15-syn.c:156:sc_pkcs15_bind_synthetic: trying coolkey\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] pkcs15-coolkey.c:725:sc_pkcs15emu_coolkey_init_ex: called\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] pkcs15-coolkey.c:66:coolkey_detect_card: called\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] pkcs15-coolkey.c:732:sc_pkcs15emu_coolkey_init_ex: returning with: -1413 (Unsupported card)\r\n```\r\nas well as the muscle select file later on (line 20902):\r\n```\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] card.c:740:sc_select_file: called; type=1, path=e828bd080fa000000167455349474e::\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] card-muscle.c:377:select_item: returning with: -1201 (File not found)\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] card-muscle.c:446:muscle_select_file: returning with: -1201 (File not found)\r\n0x7f092b25e9c0 03:55:22.665 [opensc-pkcs11] card.c:762:sc_select_file: 'SELECT' error: -1201 (File not found)\r\n```\r\n\r\nSo it is looking like a misdetection by muscle driver (probably because the reason you mentioned above) and no other driver mangling the context (that is good)."}}
{"actor":{"display_login":"Jakuje"}}