Fedict / eid-mw

eID Middleware (main repository)
GNU Lesser General Public License v3.0
199 stars 79 forks source link

"CKR_TOKEN_NOT_PRESENT" error when signing and card is removed and inserted again. #103

Closed Jeroen-Van-Loocke closed 4 years ago

Jeroen-Van-Loocke commented 4 years ago

There is no problem signing as long as the card is in the reader and we use a cashed KeyStore of it. But when we remove the card and insert it back then we get the "CKR_TOKEN_NOT_PRESENT" error when we want to sign using the same KeyStore.

This has never been an issue until somewhere in the latest versions of the middleware. In Version 4.4.4 and previous this works but in version 4.4.24 this gives the above error. I think a change somewhere in version 4.4.16 or 4.4.18 caused this new behavior. Unfortunately I don't have the installers for the different versions of the middleware to test at what specific version this changed.

This can be reproduced by signing something and saving the KeyStore and then removing the card and put it back in and then again sign something using the same KeyStore.

Frederikus commented 4 years ago

Hello Jeroen,

I'm afraid I'm not quite following you. What KeyStore are you referring too?

Which applications are you using to sign?

Jeroen-Van-Loocke commented 4 years ago

Sorry if it isn't clear. Had to write it in a hurry. I mean the Java KeyStore. This is a class in Java. We use the sunpkcs11 library.

Frederikus commented 4 years ago

I think its clear now, thanks.

So you have a java application that uses the sunpkcs11 library, which loads our pkcs11 library?

And previously you could use a cached keystore object that kept on working when the card it was attached to got removed and re-inserted.

The issue might be that we went from pkcs#11 version 2.11 to version 2.20. Where in v2.11 the slot list is quite static, in v2.20 it changes far more often.

So after the slot list changed, the cached keystore object will be out of sync.

Jeroen-Van-Loocke commented 4 years ago

Thank you for the quick response. Do you know at what version of the middleware you changed to v2.20 for pkcs#11?

Have tried a few things but it seems it will be hard to determine when to reload the KeyStore. There is no easy way to check when the card has been removed and the keystore should be reloaded. Don't know if you have a suggestion?

Frederikus commented 4 years ago

Updating to pkcs#11 v2.20 was one of the first changes we did after the 4.4.4 release.

I'm not familiar with the Keystore API, but in C (pkcs#11 API) we have the C_waitforslotevent function that allows to wait for (or check for) slot changes. I presume they must have some wrapper above this in the sunpkcs11 lib?

Jeroen-Van-Loocke commented 4 years ago

I have made changes and now the keystore is reloaded correctly if the card is removed and inserted back. But I have still the same problem.

What we have noticed is that it works if we reinsert the PKCS provider for the slot and do a reload of the KeyStore when the card is not present.

Here are the steps where we get the CKR_TOKEN_NOT_PRESENT exception:

Here are the steps for when it does work:

I have made a small test program (in java) where this can be simulated. If you want I can send it to you.

If this is not an option can you try and simulate this?

I have also tried disabling the "Certificate propagation" service because maybe it interfered but this was not the case.

Is it possible that there is something that is cached in the middleware that causes the "wrong" KeyStore to be loaded?

Hope this gives more information and insight in the problem?

Frederikus commented 4 years ago

Hello Jeroen,

On the page " https://securehomes.esat.kuleuven.be/~decockd/wiki/bin/view.cgi/EidForums/ForumEidCardMiddleware0039" someone who had the same issue solved it by removing the provider. " I just had the same problem with pteid (Portugal) and solved by calling Security.removeProvider("SunPKCS11-SmartCard"); and then adding the provider each time I need to access the smart-card "

To have a better understanding of what is happening on pkcs#11 level, could you send me the pkcs#11 logs of the usecase where it goes wrong? https://eid.belgium.be/en/technical-documentation#7483

On Thu, Feb 27, 2020 at 10:56 AM Jeroen-Van-Loocke notifications@github.com wrote:

I have made changes and now the keystore is reloaded correctly if the card is removed and inserted back. But I have still the same problem.

What we have noticed is that it works if we reinsert the PKCS provider for the slot and do a reload of the KeyStore when the card is not present.

Here are the steps where we get the CKR_TOKEN_NOT_PRESENT exception:

  • Insert the card
  • set beid provider (beidpkcs11.dll)
  • load KeyStore
  • sign something
  • remove the card
  • remove the KeyStore
  • reinsert the card
  • set beid provider (beidpkcs11.dll)
  • load KeyStore (This goes a lot faster than the first time because it is probably constructed from something in a cache)
  • sign something --> CKR_TOKEN_NOT_PRESENT exception

Here are the steps for when it does work:

  • Insert the card
  • set beid provider (beidpkcs11.dll)
  • load KeyStore
  • sign something
  • remove the card
  • remove the KeyStore
  • set beid provider (beidpkcs11.dll)
  • load KeyStore --> Fails because no card is present but this is expected behavior
  • reinsert the card
  • set beid provider (beidpkcs11.dll)
  • load KeyStore (This takes as long as the first time, probably constructed completely new like it should)
  • sign something

I have made a small test program (in java) where this can be simulated. If you want I can send it to you.

If this is not an option can you try and simulate this?

I have also tried disabling the "Certificate propagation" service because maybe it interfered but this was not the case.

Is it possible that there is something that is cached in the middleware that causes the "wrong" KeyStore to be loaded?

Hope this gives more information and insight in the problem?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/Fedict/eid-mw/issues/103?email_source=notifications&email_token=AA4FYJDEYQQYFUKLFD7HIUDRE6E5JA5CNFSM4K3L27C2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOENDWWMA#issuecomment-591883056, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4FYJFXWBKUMDOP5CH4KNLRE6E5JANCNFSM4K3L27CQ .

Jeroen-Van-Loocke commented 4 years ago

That is exactly what we are doing. We are resetting the provider every time. The big change now in the latest version of the middleware is that we do not only have to reset the provider when the card is reinserted but also when the card is removed. If this is not done then we get an "old"/"Out of sync" keystore back that causes the "CKR_TOKEN_NOT_PRESENT" error.

I have added 2 logs ".BEID_Fail.log" and ".BEID_Success.log". These log files are created with the steps I described in my previous comment. You can clearly see in these logs that the middleware does not notice that the card has been reinserted and just tries to sign again using the previous context/session but fails. In the success log you can see that the full context of the card is recreated and the pin code is asked again. .BEID_Fail.log .BEID_Success.log

The big question of course is if this is something that the middleware should be handling or not? I think it is possible to write a workaround for this on my side but that means that when we detect that the card has been removed we also reset the provider and try to create a KeyStore. This will fail but that is what we want to reset the context/session of the middleware. Then it will work.

Naturally we would like to avoid such code if possible..

Have you been able to reproduce this kind of behavior? (in Java or .Net)

Frederikus commented 4 years ago

The main reader/card state handling is expected to be done by the layers/application above. Our pkcs#11 library has no thread running on its own, so it cannot detect reader/card state changes when they happen, but it does checks the card state in relevant functions.

And it tries to respond to card changes (removed / re-inserted cards) in those functions. One of these functions is the C_signinit function.

Between version 4.4.4 and version 4.4.24 we switched to a different pcsc function to check for these card changes, but also the logic around it has changed a little. The issue you experience seems to be caused by throwing an error from the card state check upwards, rather then trying to disconnect and reconnect to the new card.

(I did not write a test yet (to check if the pcsc function throws an error indeed), but this seems to be the most lickely cause) We'll try to fix this and let you know when we have a build ready for testing (in case you want to test the fix)

Jeroen-Van-Loocke commented 4 years ago

Thank you for looking into this. A fix would be helpful. Currently I wrote a workaround where we reset the provider when a card is removed. This seems to solve the problem for now. But we still need to test this in scenarios where we do rekeying and/or activate a new card. Hopefully this workaround does not introduce other problems.

If it helps then surely I would test a new build.

Frederikus commented 4 years ago

Hello Jeroen,

We have a pkcs#11 build that should fix this issue. Are you still available for testing?

Do you have an account on the mailing list, so we can mail you directly? https://groups.google.com/forum/#!forum/eid-middleware-dev

Jeroen-Van-Loocke commented 4 years ago

I'm sorry for the late reply. Yes I would like to test this.

I'm not sure what you mean with an account on the mailing list?

Frederikus commented 4 years ago

Excellent, thanks

Actually I just meant if I could get your email, then I'll provide you with a test build.

On Wed, May 13, 2020 at 10:13 AM Jeroen-Van-Loocke notifications@github.com wrote:

I'm sorry for the late reply. Yes I would like to test this.

I'm not sure what you mean with an account on the mailing list?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/Fedict/eid-mw/issues/103#issuecomment-627825380, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA4FYJBZ7TEJWO5WF3RFPUTRRJJDHANCNFSM4K3L27CQ .

Frederikus commented 4 years ago

Hello Jeroen,

This issue has been tested against eidmw version 4.4.27, and was reported fixed. You can find this eidmw version at https://eid.belgium.be/en/future-versions-eid-software-and-eid-viewer

So I'm closing this issue now. Should you have different results, please feel free to open it again.

Wkr, Frederik