search

Pkcs11Interop / Pkcs11Interop.X509Store

Easy to use PKCS#11 based X.509 certificate store
Apache License 2.0
31 stars 18 forks source link

It takes too much time to load private Key #34

Closed tuandk1 closed 3 months ago

tuandk1 commented 11 months ago

I try pkcs11Interop.X509Store with the HSM Securosys. It can sign the XML file ok but It takes too much time to load the private key (over 20 seconds). pkcs11x509_time2 pkcs11x509_time1. It finds the certificate in 2 seconds and does GetRSAPrivateKey() in over 20 seconds. What is the problem?

jariq commented 11 months ago

Please collect logs with PKCS11-LOGGER and attach them to this issue.

tuandk1 commented 11 months ago

This is the log file of signing using pkcs11interop.x509 with PKCS11-LOGGER. pkcs11-logger-x64-x509.log

jariq commented 11 months ago

You can use grep command on the log file to extract times when individual PKCS#11 functions were executed:

grep -B1 "Calling C_" pkcs11-logger-x64-x509.log > times.txt

When you take a look at the output - times.txt - you'll find out that it was C_FindObjects function that took 5+ seconds to complete.

You need to ask your HSM vendor (producer of PKCS#11 library) why C_FindObjects function is so slow and what can be done to make it run faster.

tuandk1 commented 11 months ago

I will ask the HSM vendor. Thank you!

tuandk1 commented 11 months ago

I test pkcs11interop with PKCS11-LOGGER: find the privateKey by label key, then sign. I see it does Function C_FindObjects fast. Could pkcs11interop.x509 find the object has a problem? Here is the log file. pkcs11-logger-x64.log

jariq commented 3 months ago

There's no visible problem in attached log. Only the functions required to find private key and perform signing operation were called:

jariq@wsl:/mnt/c/temp$ grep -B1 C_ pkcs11-logger-x64.log
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:53 ***
0x00003080 : 0x00000f18 : Calling C_GetFunctionList
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:53 ***
0x00003080 : 0x00000f18 : Calling C_Initialize
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:53 ***
0x00003080 : 0x00000f18 : Calling C_GetSlotList
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:53 ***
0x00003080 : 0x00000f18 : Calling C_GetSlotList
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:53 ***
0x00003080 : 0x00000f18 : Calling C_OpenSession
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:54 ***
0x00003080 : 0x00000f18 : Calling C_Login
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:54 ***
0x00003080 : 0x00000f18 : Calling C_FindObjectsInit
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:54 ***
0x00003080 : 0x00000f18 : Calling C_FindObjects
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:54 ***
0x00003080 : 0x00000f18 : Calling C_FindObjectsFinal
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:55 ***
0x00003080 : 0x00000f18 : Calling C_SignInit
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:55 ***
0x00003080 : 0x00000f18 : Calling C_Sign
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:56 ***
0x00003080 : 0x00000f18 : Calling C_Sign
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:56 ***
0x00003080 : 0x00000f18 : Calling C_Logout
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:56 ***
0x00003080 : 0x00000f18 : Calling C_CloseSession
--
0x00003080 : 0x00000f18 : ****************************** 2023-08-18 18:36:56 ***
0x00003080 : 0x00000f18 : Calling C_Finalize