PKCS#11 software HSM

11/14/2011 10:43:54 AM
Gravatar
Total Posts 300
Ugo Chirico http://www.ugochirico.com

Re: PKCS#11 software HSM

Hi Robert,

this is the piece of code that raises the exception:

 WriteMessage("Create new SessionData for slot %s", szReader);
pSessionData = new CSessionData(slotID, szReader);
WriteMessage("new CSessionData created for slot %s", szReader); 

it seems as the new operator raises an exception.

Now we added a catch to bad_alloc exception to see if actually is the new operator.

Try this version and let me know:

vcki4.zip

11/14/2011 10:47:34 AM
Gravatar
Total Posts 13

Re: PKCS#11 software HSM

[Mon Nov 14 10:46:11 2011],1,0, ************* START LIBRARY ****************,Message
[Mon Nov 14 10:46:11 2011],1,0,-> DLL_PROCESS_ATTACH,Message
[Mon Nov 14 10:46:11 2011],1,0,LX: virtuallx,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetFunctionList(000000001D33D658),Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetFunctionList(000000001D33D658),Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_Initialize(0000000000000000),Message
[Mon Nov 14 10:46:11 2011],1,0, * No init args ptr: no multithreading requested, but enabling anyway,Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_Initialize,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetInfo(000000001D33D760),Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetInfo(000000001D33D760),Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetSlotList(0,0000000000000000 000000001D33D628),Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetSlotList,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetSlotList(0,000000001D527C80 000000001D33D628),Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetSlotList,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetSlotInfo(3565006925,000000001D33D6C0),Message
[Mon Nov 14 10:46:11 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,inserted b ,Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetSlotInfo(3565006925,000000001D33D6B0),Message
[Mon Nov 14 10:46:11 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,inserted b ,Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetSlotInfo(3565006925,000000001D33D660),Message
[Mon Nov 14 10:46:11 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,inserted b ,Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_GetTokenInfo(3565006925,000000001D33D670),Message
[Mon Nov 14 10:46:11 2011],1,0,Call LX_isInserted 3565006925,Message
[Mon Nov 14 10:46:11 2011],1,0,LX_isInserted OK,Message
[Mon Nov 14 10:46:11 2011],1,0,Call LX_getTokenInfo,Message
[Mon Nov 14 10:46:11 2011],1,0,LX_getTokenInfo OK,Message
[Mon Nov 14 10:46:11 2011],1,0,<- C_GetTokenInfo,Message
[Mon Nov 14 10:46:11 2011],1,0,-> C_OpenSession(3565006925,6,0000000000000000,0000000000000000,000000001D33D6A8),Message
[Mon Nov 14 10:46:11 2011],1,0,Slot ID 3565006925,-729960371,d47db04d),Message
[Mon Nov 14 10:46:11 2011],1,0,CKF_RW_SESSION,Message
[Mon Nov 14 10:46:11 2011],1,0,g_slotTable.size() 1, -729960371,Message
[Mon Nov 14 10:46:11 2011],1,0,Create new Session with slot:-729960371-Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,CSession(), slotid: -729960371, slotname: Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,-> getSessionData, slotID: -729960371, Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],1,0,s_sessionDataTbl does not contains slot -729960371,Message
[Mon Nov 14 10:46:11 2011],1,0,Create new SessionData for slot Virtual Smart Card Reader,Message
[Mon Nov 14 10:46:11 2011],3,0,<- new SessionData raises an unexpected exception,Error
[Mon Nov 14 10:46:11 2011],1,0,->e<- Create Session error 5,Message
[Mon Nov 14 10:46:13 2011],1,0,-> C_Finalize(0000000000000000),Message
[Mon Nov 14 10:46:13 2011],1,0,Finalize OK,Message
[Mon Nov 14 10:46:13 2011],1,0,DeleteCriticalSection OK,Message
[Mon Nov 14 10:46:13 2011],1,0,LX_close OK,Message
[Mon Nov 14 10:46:13 2011],1,0,<- C_Finalize,Message
[Mon Nov 14 10:46:13 2011],1,0, ************* STOP LIBRARY ****************,Message

 

11/14/2011 12:17:49 PM
Gravatar
Total Posts 300
Ugo Chirico http://www.ugochirico.com

Re: PKCS#11 software HSM

The exception seems still raised in the "new" operator.

We tried on several of our PCs, with Win7 sp1 64bit, XP 64 bit, and so on and we are not able to reproduce that bug. On our PCs and also on several other customers' PC it always works without any proble.

Try again with this vcki5.zip and send us also the piece of code that you are using to test it.

11/14/2011 12:22:54 PM
Gravatar
Total Posts 13

Re: PKCS#11 software HSM

It works now.

 

[Mon Nov 14 12:21:37 2011],1,0, ************* START LIBRARY ****************,Message
[Mon Nov 14 12:21:37 2011],1,0,-> DLL_PROCESS_ATTACH,Message
[Mon Nov 14 12:21:37 2011],1,0,LX: virtuallx,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetFunctionList(000000001C92DBF8),Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetFunctionList(000000001C92DBF8),Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_Initialize(0000000000000000),Message
[Mon Nov 14 12:21:37 2011],1,0, * No init args ptr: no multithreading requested, but enabling anyway,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_Initialize,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetInfo(000000001C92DD00),Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetInfo(000000001C92DD00),Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSlotList(0,0000000000000000 000000001C92DBC8),Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSlotList,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSlotList(0,000000001C697C80 000000001C92DBC8),Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSlotList,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSlotInfo(3565006925,000000001C92DC60),Message
[Mon Nov 14 12:21:37 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,inserted b ,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSlotInfo(3565006925,000000001C92DC50),Message
[Mon Nov 14 12:21:37 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,inserted b ,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSlotInfo(3565006925,000000001C92DC00),Message
[Mon Nov 14 12:21:37 2011],1,0,Slot Name is: -729960371 - Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,inserted b ,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSlotInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetTokenInfo(3565006925,000000001C92DC10),Message
[Mon Nov 14 12:21:37 2011],1,0,Call LX_isInserted 3565006925,Message
[Mon Nov 14 12:21:37 2011],1,0,LX_isInserted OK,Message
[Mon Nov 14 12:21:37 2011],1,0,Call LX_getTokenInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,LX_getTokenInfo OK,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetTokenInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_OpenSession(3565006925,6,0000000000000000,0000000000000000,000000001C92DC48),Message
[Mon Nov 14 12:21:37 2011],1,0,Slot ID 3565006925,-729960371,d47db04d),Message
[Mon Nov 14 12:21:37 2011],1,0,CKF_RW_SESSION,Message
[Mon Nov 14 12:21:37 2011],1,0,g_slotTable.size() 1, -729960371,Message
[Mon Nov 14 12:21:37 2011],1,0,Create new Session with slot:-729960371-Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,CSession(), slotid: -729960371, slotname: Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,-> getSessionData, slotID: -729960371, Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,s_sessionDataTbl does not contains slot -729960371,Message
[Mon Nov 14 12:21:37 2011],1,0,Create new SessionData for slot Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,-> CSessionData(),Message
[Mon Nov 14 12:21:37 2011],1,0,<-- CSessionData(),Message
[Mon Nov 14 12:21:37 2011],1,0,new CSessionData created for slot Virtual Smart Card Reader,Message
[Mon Nov 14 12:21:37 2011],1,0,LX_connect OK,Message
[Mon Nov 14 12:21:37 2011],1,0,<- getSessionData,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_OpenSession 1EBA7DB0 ,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_Login(1eba7db0,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> Login: getUserType() ffffffff - given usertype 1,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_Login,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetSessionInfo(1eba7db0,000000001C92DB78),Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetSessionInfo,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_FindObjectsInit (1eba7db0 , 000000001C5C6B30, 3),Message
[Mon Nov 14 12:21:37 2011],1,0,-> findInit,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 3,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: 3,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: 0,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Keydll,Message
[Mon Nov 14 12:21:37 2011],1,0,-> loadObjects,Message
[Mon Nov 14 12:21:37 2011],1,0,-> reload,Message
[Mon Nov 14 12:21:37 2011],1,0,CLASS 2,Message
[Mon Nov 14 12:21:37 2011],1,0,nObjIdLen: 0,Message
[Mon Nov 14 12:21:37 2011],1,0,m_pObjID = NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,CKA_ID len: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,CKA_ID = 1W5, 1,Message
[Mon Nov 14 12:21:37 2011],1,0,C11PublicKey: ID: 1321269632-487357768,Message
[Mon Nov 14 12:21:37 2011],1,0,CLASS 3,Message
[Mon Nov 14 12:21:37 2011],1,0,nObjIdLen: 0,Message
[Mon Nov 14 12:21:37 2011],1,0,m_pObjID = NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,CKA_ID len: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,CKA_ID = 1â, 1,Message
[Mon Nov 14 12:21:37 2011],1,0,C11PrivateKey flags: E3, 0, 0, 0, 1, 1,Message
[Mon Nov 14 12:21:37 2011],1,0,C11RSAPrivateKey: ID: 1321269632-487357768,Message
[Mon Nov 14 12:21:37 2011],1,0,--> C11RSAPrivateKey: ID (ctor): 1321269632-487357768,Message
[Mon Nov 14 12:21:37 2011],1,0,-> reload,Message
[Mon Nov 14 12:21:37 2011],1,0,<- loadObjects,Message
[Mon Nov 14 12:21:37 2011],1,0,<- findInit,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_FindObjectsInit,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_FindObjects(515538352,000000001C697130,10,000000001C92DA78),Message
[Mon Nov 14 12:21:37 2011],1,0,-> find,Message
[Mon Nov 14 12:21:37 2011],1,0,Objects found: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,<- find,Message
[Mon Nov 14 12:21:37 2011],1,0,Object found: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_FindObjects,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 0, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 0, valuelen: (4), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: 9,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: 3,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 100, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 100, valuelen: (4), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: 9,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: 0,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_FindObjectsFinal(515538352),Message
[Mon Nov 14 12:21:37 2011],1,0,-> findFinal,Message
[Mon Nov 14 12:21:37 2011],1,0,<- findFinal,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_FindObjectsFinal,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (13), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: ,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Key,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (13), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: ,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Key,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 3, valuelen: (13), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,1,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: ,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Key,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_FindObjectsInit (1eba7db0 , 000000001C5C6B30, 3),Message
[Mon Nov 14 12:21:37 2011],1,0,-> findInit,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 3,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: 2,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: 0,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Key,Message
[Mon Nov 14 12:21:37 2011],1,0,-> loadObjects,Message
[Mon Nov 14 12:21:37 2011],1,0,reload not needed,Message
[Mon Nov 14 12:21:37 2011],1,0,<- findInit,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_FindObjectsInit,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_FindObjects(515538352,000000001C697C80,1,000000001C92DA78),Message
[Mon Nov 14 12:21:37 2011],1,0,-> find,Message
[Mon Nov 14 12:21:37 2011],1,0,Objects found: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,<- find,Message
[Mon Nov 14 12:21:37 2011],1,0,Object found: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_FindObjects,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 0, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 0, valuelen: (4), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: A,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: CKA_CLASS valuelen: (4), value: 2,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:37 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 100, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:37 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:37 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:37 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:37 2011],1,0,type: 100, valuelen: (4), value: NULL,Message
[Mon Nov 14 12:21:37 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:37 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:38 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:38 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: A,Message
[Mon Nov 14 12:21:38 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:38 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen 4 4,Message
[Mon Nov 14 12:21:38 2011],1,0,type: CKA_KEY_TYPE valuelen: (4), value: 0,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_FindObjectsFinal(515538352),Message
[Mon Nov 14 12:21:38 2011],1,0,-> findFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,<- findFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_FindObjectsFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:38 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen 0 0,Message
[Mon Nov 14 12:21:38 2011],1,0,type: 3, valuelen: (0), value: NULL,Message
[Mon Nov 14 12:21:38 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:38 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:38 2011],1,0,type: 3, valuelen: (13), value: NULL,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_GetAttributeValue(515538352,2,1),Message
[Mon Nov 14 12:21:38 2011],1,0,-> getObjectAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:38 2011],1,0,type: CKA_LABEL valuelen: (13), value: ,Message
[Mon Nov 14 12:21:38 2011],1,0,doing printTemplate,Message
[Mon Nov 14 12:21:38 2011],1,0,doing getAttributes,Message
[Mon Nov 14 12:21:38 2011],1,0,Template count: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pTemplate[i].ulValueLen d 13,Message
[Mon Nov 14 12:21:38 2011],1,0,type: CKA_LABEL valuelen: (13), value: Ugo's new Key,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_GetAttributeValue,Message
[Mon Nov 14 12:21:38 2011],1,0,C_SignInit(515538352,000000001C92DBE8,1),Message
[Mon Nov 14 12:21:38 2011],1,0,-> signInit,Message
[Mon Nov 14 12:21:38 2011],1,0,CKM_SHA1_RSA_PKCS,Message
[Mon Nov 14 12:21:38 2011],1,0,<- signInit,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_SignInit,Message
[Mon Nov 14 12:21:38 2011],1,0,C_Sign(515538352,000000001C698010,11,0000000000000000,000000001C92DA28),Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_Sign OK,Message
[Mon Nov 14 12:21:38 2011],1,0,C_Sign(515538352,000000001C698010,11,000000001C6987E0,000000001C92DA28),Message
[Mon Nov 14 12:21:38 2011],1,0,-> signUpdate,Message
[Mon Nov 14 12:21:38 2011],1,0,<- signUpdate,Message
[Mon Nov 14 12:21:38 2011],1,0,-> signFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,padding,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C11RSAPrivateKey::loadPublicKey,Message
[Mon Nov 14 12:21:38 2011],1,0,ID PATH: 1321269632-487357768,Message
[Mon Nov 14 12:21:38 2011],1,0,BER decode pubkey ok,Message
[Mon Nov 14 12:21:38 2011],1,0,pubKey.getModulus() OK,Message
[Mon Nov 14 12:21:38 2011],1,0,pubKey.getExponent() OK,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C11RSAPrivateKey::loadPublicKey,Message
[Mon Nov 14 12:21:38 2011],1,0,Modulus len: 80,Message
[Mon Nov 14 12:21:38 2011],1,0,Modulus: CAEE7FDEE4EE769054D37D774FF5E301252AE1B4943E69EF2FFCD584AA183DEEDFEE07D7F3952522DAADAA0A3967E6AAEB16CD350676C8812092F0D0096EA666277D37309AEC33787528F368E1C9AE39D82C807D4DDBEFF41AB3410D27E623437C2ACB2D98963A660AC6CA0510304794C3AB51D4DB6C2C8A79712EB9A358A66D,Message
[Mon Nov 14 12:21:38 2011],1,0,toSign: 0001FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF003021300906052B0E03021A050004140A4D55A8D778E5022FAB701977C5D840BBC486D0,Message
[Mon Nov 14 12:21:38 2011],1,0,<- signFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_VerifyInit(515538352,000000001C92DBE8,2),Message
[Mon Nov 14 12:21:38 2011],1,0,-> verifyInit,Message
[Mon Nov 14 12:21:38 2011],1,0,<- verifyInit,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_VerifyInit,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_Verify,Message
[Mon Nov 14 12:21:38 2011],1,0,ClearText - Len B, Content:48656C6C6F20576F726C,Message
[Mon Nov 14 12:21:38 2011],1,0,SignedText - Len 80, Content:3E8EF289102F6B7DCE5C,Message
[Mon Nov 14 12:21:38 2011],1,0,-> verifyUpdate,Message
[Mon Nov 14 12:21:38 2011],1,0,-> verifyUpdate,Message
[Mon Nov 14 12:21:38 2011],1,0,-> verifyFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,-> loadPublicKey,Message
[Mon Nov 14 12:21:38 2011],1,0,BER decode pubkey ok,Message
[Mon Nov 14 12:21:38 2011],1,0,modulus.MinEncodedSize() 128,Message
[Mon Nov 14 12:21:38 2011],1,0,pubKey.getModulus() OK,Message
[Mon Nov 14 12:21:38 2011],1,0,exponent.MinEncodedSize() 1,Message
[Mon Nov 14 12:21:38 2011],1,0,pubKey.getExponent() OK,Message
[Mon Nov 14 12:21:38 2011],1,0,Modulus len: 80,Message
[Mon Nov 14 12:21:38 2011],1,0,Modulus: CAEE7FDEE4EE769054D37D774FF5E301252AE1B4943E69EF2FFCD584AA183DEEDFEE07D7F3952522DAADAA0A3967E6AAEB16CD350676C8812092F0D0096EA666277D37309AEC33787528F368E1C9AE39D82C807D4DDBEFF41AB3410D27E623437C2ACB2D98963A660AC6CA0510304794C3AB51D4DB6C2C8A79712EB9A358A66D,Message
[Mon Nov 14 12:21:38 2011],1,0,Exponent len: 1,Message
[Mon Nov 14 12:21:38 2011],1,0,Exponent: 11,Message
[Mon Nov 14 12:21:38 2011],1,0,nAlgo: 3,Message
[Mon Nov 14 12:21:38 2011],1,0,signed_text: 3E8EF289102F6B7DCE5C58217E5B58B286C99B85358B4BA55773A2370C6B307C17DB65BB35C89034CB1F4D3E76B7E5A88CC05DC1E7E3E1E3F5F934EDB2BB79019DBD7FD582DB3C9E6831A52F75A8A62DB27901B07FF296652A5838B990FEE115B744DAD36C9E8ABC1AF6A8357C1929F15AA28157D8EAAC31ACF3118710A3C5CA,Message
[Mon Nov 14 12:21:38 2011],1,0,<- verifyFinal,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_Verify,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_Logout(515538352),Message
[Mon Nov 14 12:21:38 2011],1,0,-> logout; 000000001EBA7DB0,Message
[Mon Nov 14 12:21:38 2011],1,0,<- logout,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_Logout,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_CloseSession (1eba7db0),Message
[Mon Nov 14 12:21:38 2011],1,0,-> close: 000000001EBA7DB0,Message
[Mon Nov 14 12:21:38 2011],1,0,<- close,Message
[Mon Nov 14 12:21:38 2011],1,0,~CSession,Message
[Mon Nov 14 12:21:38 2011],1,0,Release session data: -729960371,Message
[Mon Nov 14 12:21:38 2011],1,0,-> release, slotID: -729960371,Message
[Mon Nov 14 12:21:38 2011],1,0,s_sessionDataTbl contains slot -729960371,Message
[Mon Nov 14 12:21:38 2011],1,0,m_ulRefCount == 0,Message
[Mon Nov 14 12:21:38 2011],1,0,-> ~CSessionData,Message
[Mon Nov 14 12:21:38 2011],1,0,<- ~CSessionData,Message
[Mon Nov 14 12:21:38 2011],1,0,<- release,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_CloseSession,Message
[Mon Nov 14 12:21:38 2011],1,0,-> C_Finalize(0000000000000000),Message
[Mon Nov 14 12:21:38 2011],1,0,Finalize OK,Message
[Mon Nov 14 12:21:38 2011],1,0,DeleteCriticalSection OK,Message
[Mon Nov 14 12:21:38 2011],1,0,LX_close OK,Message
[Mon Nov 14 12:21:38 2011],1,0,<- C_Finalize,Message
[Mon Nov 14 12:21:42 2011],1,0,-> C_Finalize(0000000000000000),Message
[Mon Nov 14 12:21:42 2011],3,0, ->e<- CKR_CRYPTOKI_NOT_INITIALIZED,Error
[Mon Nov 14 12:21:42 2011],1,0, ************* STOP LIBRARY ****************,Message
 

Best Regards,

Robert

11/14/2011 12:40:58 PM
Gravatar
Total Posts 300
Ugo Chirico http://www.ugochirico.com

Re: PKCS#11 software HSM

Very good!!!

Finally we have found the bug!

During the creation of a CSession object, we call winscard.dll (Smart Card API) to see if the smart card service is up. If not an exception is raised. In the latest version I sent you (that works) we removed such a call (actually this call is non needed so we remove it definitely)

I guess you don't have the smart card service up this is why the exception was thrown in the old versions.