Comment 2 Henrik Andersson 2018-09-28 16:00:15 CEST

Here follows a log of running tlclient.bin driven by MainWindow::CheckCerts timer and
down the call chain PKCS11Module::HasChanged() is called which checks for events using 
C_WaitForSlotEvent:

  0x7f73a0f7e3c0 14:38:01.568 [opensc-pkcs11] pkcs11-global.c:608:C_WaitForSlotEvent: C_WaitForSlotEvent(block=0)
  0x7f73a0f7e3c0 14:38:01.568 [opensc-pkcs11] slot.c:414:slot_find_changed: called
  0x7f73a0f7e3c0 14:38:01.568 [opensc-pkcs11] slot.c:188:card_detect: Gemalto PC Twin Reader 00 00: Detecting smart card
  0x7f73a0f7e3c0 14:38:01.568 [opensc-pkcs11] sc.c:231:sc_detect_card_presence: called
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] reader-pcsc.c:370:pcsc_detect_card_presence: called
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] reader-pcsc.c:283:refresh_attributes: Gemalto PC Twin Reader 00 00 check

This is when when the reader is attached and fully working:

  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] reader-pcsc.c:299:refresh_attributes: returning with: 0 (Success)
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] reader-pcsc.c:375:pcsc_detect_card_presence: returning with: 1
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] sc.c:236:sc_detect_card_presence: returning with: 1
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:298:card_detect: Gemalto PC Twin Reader 00 00: Detection ended

And here is upon detaching of the reader:

  0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] reader-pcsc.c:301:refresh_attributes: Gemalto PC Twin Reader 00 
00:SCardGetStatusChange failed: 0x80100009
  0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] reader-pcsc.c:374:pcsc_detect_card_presence: returning with: -1900 (Unknown error)
  0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] sc.c:236:sc_detect_card_presence: returning with: -1900 (Unknown error)
  0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] slot.c:193:card_detect: Gemalto PC Twin Reader 00 00: failed, Unknown error
  0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] misc.c:61:sc_to_cryptoki_error_common: libopensc return value: -1900 (Unknown error)

Then following is the same for both of the cases:

  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:419:slot_find_changed: slot 0xffffffffffffffff token: 0 events: 0x00
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:425:slot_find_changed: mask: 0x0F events: 0x00 result: 0
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:419:slot_find_changed: slot 0x1 token: 1 events: 0x00
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:425:slot_find_changed: mask: 0x0F events: 0x00 result: 0
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:419:slot_find_changed: slot 0x2 token: 1 events: 0x00
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:425:slot_find_changed: mask: 0x0F events: 0x00 result: 0
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:419:slot_find_changed: slot 0x3 token: 1 events: 0x00
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:425:slot_find_changed: mask: 0x0F events: 0x00 result: 0
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:419:slot_find_changed: slot 0x4 token: 0 events: 0x00
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:425:slot_find_changed: mask: 0x0F events: 0x00 result: 0
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] slot.c:433:slot_find_changed: returning with: 8
  0x7f73a0f7e3c0 14:38:01.569 [opensc-pkcs11] pkcs11-global.c:673:C_WaitForSlotEvent: C_WaitForSlotEvent() = CKR_NO_EVENT, event in 0xf710524c0a620000

Comment 3 Henrik Andersson 2018-09-28 16:08:01 CEST

(In reply to comment #2)
> 
>   0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] reader-pcsc.c:301:refresh_attributes: Gemalto PC Twin Reader 00 00:SCardGetStatusChange failed: 0x80100009
>

Here is an important issue, SCardGetStatusChange is called on a reader that is removed and the error 0x80100009 is returned and which is defined as SCARD_E_UNKNOWN_READER. However, this error is not
handled uniqly here and is handled as any error in catch all manner.

Comment 4 Henrik Andersson 2018-10-02 09:36:47 CEST

(In reply to comment #3)
> (In reply to comment #2)
> > 
> >   0x7f73a0f7e3c0 14:38:04.569 [opensc-pkcs11] reader-pcsc.c:301:refresh_attributes: Gemalto PC Twin Reader 00 00:SCardGetStatusChange failed: 0x80100009
> >
> 
> Here is an important issue, SCardGetStatusChange is called on a reader that is
> removed and the error 0x80100009 is returned and which is defined as
> SCARD_E_UNKNOWN_READER. However, this error is not
> handled uniqly here and is handled as any error in catch all manner.
>

The function pcsc_detect_card_presence() is used to check for card presence, the current implementation does not handle reader precense and raises an error
instead of card precence state change. This is also true for master upstream so
an upgrade wont fix this problem.

Comment 5 Henrik Andersson 2018-10-02 09:41:21 CEST

Created attachment 890 [details]
patch to signal reader detach event

This patch fixes the issue by handling SCARD_E_UNKNOWN_READER error in refresh_attributes() and by that change the SC_READER_CARD_PRESENT flag
to trigger the chain that card is remove with the reader itself.

Comment 6 Henrik Andersson 2018-10-02 09:43:44 CEST

Created attachment 891 [details]
pkcs11 test program

Minimal test program for pkcs11 module and event loop. Make sure pkcs11.h is in path when building like:

  gcc -o pkcs11_test test.c -ldl

Comment 7 Henrik Andersson 2018-10-02 10:25:00 CEST

Another issues found when investigating this issue is that C_GetSlotList() gives you a list of slots where a slot might be invalid.

One MUST call C_GetSlotInfo() before using the slot for validating [1].

For example we break this rule in PKCS11Module::FindCertitificate() in tlclient file tlclient_pkcs11.cc.


[1] http://docs.oasis-open.org/pkcs11/pkcs11-base/v2.40/os/pkcs11-base-v2.40-os.html#_Toc416959741

Comment 8 Pierre Ossman 2018-10-03 16:08:06 CEST

Also note this from the latest PKCS#11 standard:

All slots which C_GetSlotList reports MUST be able to be queried as valid slots by C_GetSlotInfo.  Furthermore, the set of slots accessible through a Cryptoki library is checked at the time that C_GetSlotList, for list length prediction (NULL pSlotList argument) is called. If an application calls C_GetSlotList with a non-NULL pSlotList, and then the user adds or removes a hardware device, the changed slot list will only be visible and effective if C_GetSlotList is called again with NULL. Even if C_ GetSlotList is successfully called this way, it may or may not be the case that the changed slot list will be successfully recognized depending on the library implementation.  On some platforms, or earlier PKCS11 compliant libraries, it may be necessary to successfully call C_Initialize or to restart the entire system.

Basically a driver is only allowed to update the number of slots when C_GetSlotList() is called with NULL. So perhaps we should make sure we do that on changes (or event poll?) to allow the driver to update the slots?

Comment 9 Pierre Ossman 2018-10-03 16:10:25 CEST

(In reply to comment #5)
> Created an attachment (id=890) [details]
> patch to signal reader detach event
> 
> This patch fixes the issue by handling SCARD_E_UNKNOWN_READER error in
> refresh_attributes() and by that change the SC_READER_CARD_PRESENT flag
> to trigger the chain that card is remove with the reader itself.

I think this looks promising. Perhaps we should also return SC_ERROR_READER_DETACHED? There is some code further down in that same function that does that for when the reader is unresponsive. Need to check how this error propagates upwards.

Comment 12 Pierre Ossman 2019-02-28 13:22:25 CET

Seems to work fine now. Only tested on Linux so far though.

Comment 13 Pierre Ossman 2019-02-28 15:58:02 CET

Also reported upstream:

https://github.com/OpenSC/OpenSC/pull/1615

Comment 14 Pierre Ossman 2019-03-01 12:30:20 CET

Does not work on Windows unfortunately. Need to check what differs.

Comment 15 Pierre Ossman 2019-03-01 14:03:37 CET

It wasn't terribly Windows specific. We just needed to handle more error codes. There are two more scenarios:

 * This was the last reader, so we can get SCARD_E_NO_READERS_AVAILABLE

 * The smart card daemon has shut down, then we get SCARD_E_SERVICE_STOPPED

Upstream has already identified these scenarios, so let's merge our variant and theirs.

Comment 20 Pierre Ossman 2019-03-01 15:43:29 CET

Fixed.

Tester should make sure to test both with multiple readers and just one.

Comment 21 Samuel Mannehed 2019-03-04 10:44:59 CET

Works well now, tested build 6057 on both Windows 10 and macOS 10.14.

Verified both removing the readers and the cards, both with the client gui and with a running session. Tested with both a single reader and two readers.