236250 – AOL: certutil failed on virtual token

Bug 236250 - AOL: certutil failed on virtual token

Summary: AOL: certutil failed on virtual token

Keywords:
Status:	CLOSED WONTFIX
Alias:	None
Product:	Red Hat Certificate System
Classification:	Red Hat
Component:	Tools - Java
Sub Component:
Version:	7.2
Hardware:	All
OS:	Linux
Priority:	medium
Severity:	medium
Target Milestone:	rc
Target Release:	---
Assignee:	Christina Fu
QA Contact:	Chandrasekar Kannan
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	445047
TreeView+	depends on / blocked

Reported:	2007-04-12 17:48 UTC by Bob Lord
Modified:	2017-04-10 14:20 UTC (History)
CC List:	4 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2009-11-06 23:37:00 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
Luna Logs obtained from Red Hat's Lab environment (247.09 KB, text/plain) 2007-04-27 00:14 UTC, Thomas Kwan	no flags	Details
View All

Description Thomas Kwan 2007-04-12 17:48:08 UTC

When Fu runs certutil on the virtual token, certutil returns I/O error.

Enter Password or Pin for "epki-cs72-VT-cam":
certutil: problem printing certificate nicknames: An I/O error occurred during
security authorization.

Fu said that if he runs certutil on the hardware token directly, it will work.

Comment 1 Thomas Kwan 2007-04-12 17:49:13 UTC

I asked Marco to obtain the NSS's PKCS#11 debug log from Fu. 

>
>
>-1208191296[959b550]: Loaded library a.out (init)
>-1208191296[959b550]: Loaded library /usr/lib/dirsec/libfreebl3.so (load lib)
>-1208191296[959b550]: Loaded library /usr/lib/libCryptoki2.so (load lib)
>-1208191296[959b550]: C_Initialize
>-1208191296[959b550]:   pInitArgs = 0xf0d170
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetInfo
>-1208191296[959b550]:   pInfo = 0xbff5efa0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSlotList
>-1208191296[959b550]:   tokenPresent = 0x0
>-1208191296[959b550]:   pSlotList = 0x0
>-1208191296[959b550]:   pulCount = 0xbff5ef9c
>-1208191296[959b550]:   *pulCount = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSlotList
>-1208191296[959b550]:   tokenPresent = 0x0
>-1208191296[959b550]:   pSlotList = 0x9749f90
>-1208191296[959b550]:   pulCount = 0xbff5ef9c
>-1208191296[959b550]:   *pulCount = 0x2
>-1208191296[959b550]:   slotID[0] = 1
>-1208191296[959b550]:   slotID[1] = 2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSlotInfo
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   pInfo = 0xbff5eee0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetTokenInfo
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   pInfo = 0xbff5ee20
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   pMechanismList = 0x0
>-1208191296[959b550]:   pulCount = 0xbff5ed78
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   pMechanismList = 0x97481f8
>-1208191296[959b550]:   pulCount = 0xbff5ed78
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_OpenSession
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   flags = 0x4
>-1208191296[959b550]:   pApplication = 0x974a6d8
>-1208191296[959b550]:   Notify = 0xeb41da
>-1208191296[959b550]:   phSession = 0xbff5ee10
>-1208191296[959b550]:   *phSession = 0x1
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GenerateRandom
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   RandomData = 0xbff5edd0
>-1208191296[959b550]:   ulRandomLen = 32
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_SeedRandom
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   pSeed = 0xbff5edd0
>-1208191296[959b550]:   ulSeedLen = 32
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   pTemplate = 0xbff5eeb0
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_CLASS = CKO_NETSCAPE_BUILTIN_ROOT_LIST [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjects
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   phObject = 0xbff5ee70
>-1208191296[959b550]:   ulMaxObjectCount = 1
>-1208191296[959b550]:   pulObjectCount = 0xbff5ee68
>-1208191296[959b550]:   *pulObjectCount = 0x0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsFinal
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSlotInfo
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pInfo = 0xbff5eee0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetTokenInfo
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pInfo = 0xbff5ee20
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pMechanismList = 0x0
>-1208191296[959b550]:   pulCount = 0xbff5ed78
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pMechanismList = 0x97492e8
>-1208191296[959b550]:   pulCount = 0xbff5ed78
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_OpenSession
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   flags = 0x4
>-1208191296[959b550]:   pApplication = 0x97483d8
>-1208191296[959b550]:   Notify = 0xeb41da
>-1208191296[959b550]:   phSession = 0xbff5ee10
>-1208191296[959b550]:   *phSession = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GenerateRandom
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   RandomData = 0xbff5edd0
>-1208191296[959b550]:   ulRandomLen = 32
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_SeedRandom
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pSeed = 0xbff5edd0
>-1208191296[959b550]:   ulSeedLen = 32
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pTemplate = 0xbff5eeb0
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_CLASS = CKO_NETSCAPE_BUILTIN_ROOT_LIST [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjects
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   phObject = 0xbff5ee70
>-1208191296[959b550]:   ulMaxObjectCount = 1
>-1208191296[959b550]:   pulObjectCount = 0xbff5ee68
>-1208191296[959b550]:   *pulObjectCount = 0x0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsFinal
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSlotInfo
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   pInfo = 0xbff5ef00
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSessionInfo
>-1208191296[959b550]:   hSession = 0x1
>-1208191296[959b550]:   pInfo = 0xbff5eee0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSessionInfo
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pInfo = 0xbff5f100
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_Login
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   userType = 0x1
>-1208191296[959b550]:   pPin = 0x974b9e0
>-1208191296[959b550]:   ulPinLen = 8
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pMechanismList = 0x0
>-1208191296[959b550]:   pulCount = 0xbff5f058
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismList
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   pMechanismList = 0x9751460
>-1208191296[959b550]:   pulCount = 0xbff5f058
>-1208191296[959b550]:   *pulCount = 0x76
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_OpenSession
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   flags = 0x4
>-1208191296[959b550]:   pApplication = 0x97483d8
>-1208191296[959b550]:   Notify = 0xeb41da
>-1208191296[959b550]:   phSession = 0xbff5ed80
>-1208191296[959b550]:   *phSession = 0x3
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_CreateObject
>-1208191296[959b550]:   hSession = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5ee60
>-1208191296[959b550]:   ulCount = 4
>-1208191296[959b550]:   phObject = 0x9752a64
>-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ef30 [4]
>-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
>-1208191296[959b550]:     CKA_VALUE = 0x974b9e0 [8]
>-1208191296[959b550]:   *phObject = 0x0
>-1208191296[959b550]:   rv = 0xd1
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pTemplate = 0xbff5eea0
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_CLASS = CKO_PUBLIC_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5eecc [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjects
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   phObject = 0xbff5ee70
>-1208191296[959b550]:   ulMaxObjectCount = 1
>-1208191296[959b550]:   pulObjectCount = 0xbff5ee68
>-1208191296[959b550]:   *pulObjectCount = 0x1
>-1208191296[959b550]:   phObject[0] = 0x3
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsFinal
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5eea0
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_ID = 0x0 [20]
>-1208191296[959b550]:     CKA_CLASS = 0x0 [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5eea0
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_ID = 0x9752fb8 [20]
>-1208191296[959b550]:     CKA_CLASS = CKO_PUBLIC_KEY [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pTemplate = 0xbff5eea0
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_ID = 0x9752fb8 [20]
>-1208191296[959b550]:     CKA_CLASS = CKO_PRIVATE_KEY [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjects
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   phObject = 0xbff5ee60
>-1208191296[959b550]:   ulMaxObjectCount = 1
>-1208191296[959b550]:   pulObjectCount = 0xbff5ee58
>-1208191296[959b550]:   *pulObjectCount = 0x1
>-1208191296[959b550]:   phObject[0] = 0x4
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsFinal
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x4
>-1208191296[959b550]:   pTemplate = 0xbff5ee70
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ee6c [4]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x4
>-1208191296[959b550]:   pTemplate = 0xbff5ee60
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_TOKEN = CK_TRUE [1]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x4
>-1208191296[959b550]:   pTemplate = 0xbff5ee60
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_PRIVATE = CK_TRUE [1]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetSessionInfo
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pInfo = 0xbff5ee30
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5ee50
>-1208191296[959b550]:   ulCount = 4
>-1208191296[959b550]:     CKA_CLASS = CKO_PUBLIC_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5eeb8 [4]
>-1208191296[959b550]:     CKA_MODULUS = 0x0 [256]
>-1208191296[959b550]:     CKA_PUBLIC_EXPONENT = 0x0 [3]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5ee50
>-1208191296[959b550]:   ulCount = 4
>-1208191296[959b550]:     CKA_CLASS = CKO_PUBLIC_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0x9754120 [4]
>-1208191296[959b550]:     CKA_MODULUS = 0x9754128 [256]
>-1208191296[959b550]:     CKA_PUBLIC_EXPONENT = 0x9754228 [3]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetAttributeValue
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   hObject = 0x4
>-1208191296[959b550]:   pTemplate = 0xbff5eda0
>-1208191296[959b550]:   ulCount = 1
>-1208191296[959b550]:     CKA_PRIVATE = CK_TRUE [1]
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_GetMechanismInfo
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   type = 0x1
>-1208191296[959b550]:   pInfo = 0xbff5ed50
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_UnwrapKey
>-1208191296[959b550]:   hSession = 0x3
>-1208191296[959b550]:   pMechanism = 0xbff5ed70
>-1208191296[959b550]:   hUnwrappingKey = 0x4
>-1208191296[959b550]:   pWrappedKey = 0x9754920
>-1208191296[959b550]:   ulWrappedKeyLen = 256
>-1208191296[959b550]:   pTemplate = 0xbff5ec90
>-1208191296[959b550]:   ulAttributeCount = 4
>-1208191296[959b550]:   phKey = 0x9752a64
>-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ed8c [4]
>-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
>-1208191296[959b550]:     CKA_VALUE_LEN = 0xbff5ed88 [4]
>-1208191296[959b550]:       mechanism = 0x1
>-1208191296[959b550]:   *phKey = 0x0
>-1208191296[959b550]:   rv = 0x12
>-1208191296[959b550]: C_OpenSession
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   flags = 0x4
>-1208191296[959b550]:   pApplication = 0x97483d8
>-1208191296[959b550]:   Notify = 0xeb41da
>-1208191296[959b550]:   phSession = 0xbff5ebe0
>-1208191296[959b550]:   *phSession = 0x4
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_DecryptInit
>-1208191296[959b550]:   hSession = 0x4
>-1208191296[959b550]:   pMechanism = 0xbff5ed70
>-1208191296[959b550]:   hKey = 0x4
>-1208191296[959b550]:       mechanism = 0x1
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_Decrypt
>-1208191296[959b550]:   hSession = 0x4
>-1208191296[959b550]:   pEncryptedData = 0x9754920
>-1208191296[959b550]:   ulEncryptedDataLen = 256
>-1208191296[959b550]:   pData = 0x9755b88
>-1208191296[959b550]:   pulDataLen = 0xbff5ec3c
>-1208191296[959b550]:   *pulDataLen = 0x8
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_CloseSession
>-1208191296[959b550]:   hSession = 0x4
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_CreateObject
>-1208191296[959b550]:   hSession = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5ec90
>-1208191296[959b550]:   ulCount = 4
>-1208191296[959b550]:   phObject = 0x9752a64
>-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ed8c [4]
>-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
>-1208191296[959b550]:     CKA_VALUE = 0x9755b88 [8]
>-1208191296[959b550]:   *phObject = 0x0
>-1208191296[959b550]:   rv = 0xd1
>-1208191296[959b550]: C_CloseSession
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pTemplate = 0xbff5ef50
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_TOKEN = CK_TRUE [1]
>-1208191296[959b550]:     CKA_CLASS = CKO_CERTIFICATE [4]
>-1208191296[959b550]:   rv = 0xb3
>-1208191296[959b550]: C_FindObjectsInit
>-1208191296[959b550]:   hSession = 0x2
>-1208191296[959b550]:   pTemplate = 0xbff5f080
>-1208191296[959b550]:   ulCount = 2
>-1208191296[959b550]:     CKA_TOKEN = CK_TRUE [1]
>-1208191296[959b550]:     CKA_CLASS = CKO_CERTIFICATE [4]
>-1208191296[959b550]:   rv = 0xb3
>-1208191296[959b550]: C_CloseAllSessions
>-1208191296[959b550]:   slotID = 0x1
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_CloseSession
>-1208191296[959b550]:   hSession = 0x3
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_CloseAllSessions
>-1208191296[959b550]:   slotID = 0x2
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: C_Finalize
>-1208191296[959b550]:   pReserved = 0x0
>-1208191296[959b550]:   rv = 0x0
>-1208191296[959b550]: Unloaded library /usr/lib/libCryptoki2.so
>

Comment 2 Thomas Kwan 2007-04-12 17:50:00 UTC

Can you ask Fu to run certutil with debug on the hardware token directly?
NSS will perform some simple tests at startup. (certutil is an application
that uses NSS). Looks like it failed in the following places:

The unwrap operation failed:

-1208191296[959b550]: C_UnwrapKey
-1208191296[959b550]:   hSession = 0x3
-1208191296[959b550]:   pMechanism = 0xbff5ed70
-1208191296[959b550]:   hUnwrappingKey = 0x4
-1208191296[959b550]:   pWrappedKey = 0x9754920
-1208191296[959b550]:   ulWrappedKeyLen = 256
-1208191296[959b550]:   pTemplate = 0xbff5ec90
-1208191296[959b550]:   ulAttributeCount = 4
-1208191296[959b550]:   phKey = 0x9752a64
-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ed8c [4]
-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
-1208191296[959b550]:     CKA_VALUE_LEN = 0xbff5ed88 [4]
-1208191296[959b550]:       mechanism = 0x1
-1208191296[959b550]:   *phKey = 0x0
-1208191296[959b550]:   rv = 0x12

The creation of a symmetric key failed:

-1208191296[959b550]: C_CreateObject
-1208191296[959b550]:   hSession = 0x3
-1208191296[959b550]:   pTemplate = 0xbff5ec90
-1208191296[959b550]:   ulCount = 4
-1208191296[959b550]:   phObject = 0x9752a64
-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ed8c [4]
-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
-1208191296[959b550]:     CKA_VALUE = 0x9755b88 [8]
-1208191296[959b550]:   *phObject = 0x0
-1208191296[959b550]:   rv = 0xd1

It also failed to locate a certificate:

-1208191296[959b550]: C_FindObjectsInit
-1208191296[959b550]:   hSession = 0x2
-1208191296[959b550]:   pTemplate = 0xbff5ef50
-1208191296[959b550]:   ulCount = 2
-1208191296[959b550]:     CKA_TOKEN = CK_TRUE [1]
-1208191296[959b550]:     CKA_CLASS = CKO_CERTIFICATE [4]
-1208191296[959b550]:   rv = 0xb3

I want to see if running certutil on the hardware token directly
will have those errors.

Comment 3 Bob Relyea 2007-04-13 17:58:07 UTC

What is the actual certutil command. that is being run? (are we listing certs,
keys ?).

Some problems I see:

C_CreateObject
>-1208191296[959b550]:   hSession = 0x3
>-1208191296[959b550]:   pTemplate = 0xbff5ee60
>-1208191296[959b550]:   ulCount = 4
>-1208191296[959b550]:   phObject = 0x9752a64
>-1208191296[959b550]:     CKA_CLASS = CKO_SECRET_KEY [4]
>-1208191296[959b550]:     CKA_KEY_TYPE = 0xbff5ef30 [4]
>-1208191296[959b550]:     CKA_ENCRYPT = CK_TRUE [1]
>-1208191296[959b550]:     CKA_VALUE = 0x974b9e0 [8]
>-1208191296[959b550]:   *phObject = 0x0
>-1208191296[959b550]:   rv = 0xd1

Why are we getting CKR_TEMPLATE_INCONSISTANT here? does the value not match the
Keytype (hard to tell since we don't actually print out the key_type value here.

What looks like is happenning is the token claims to do some symetric algorithm
that NSS needs to verify, but the token seems to be broken (doesn't like our key
template). After a heroic effort to load the key in (using and RSA key
exchange), the unwrap fails with CKR_ATTRIBUTE_TYPE_INVALID. NSS again tries to
hand unwrap and insert the key which fails again.

Since the token claims to do an algorithm and it doesn't seem to support NSS
finally punts on the token. For some reason NSS does continue to try the find,
but at this point NSS as closed the session (See C_CloseSession just for for the
failed C_FindObjectsInit), so the 0xb3 (CKR_INVALID_SESSION) is correct behavior
on the PKCS #11 module.

You should be able to work around the issue by turning off the offending
symetric cipher in the virtual token. 

I would very much like to know why both the CreateObject and Unwrap are failing,
though, I doubt there's a bug in the NSS code (it's quite old), but I would like
to hear the justification for why these operations were rejected.

bob

Comment 4 Thomas Kwan 2007-04-26 23:56:03 UTC

I have enabled debug by using the following instructions:

Then, I ran certutil, it works in our environment, and here is the log that
shows the operations in question:

14:51:03 24969--1207974208:STRTUnwrapKey {Sesn=5 Mech=(CKM_RSA_PKCS,"")        
Obj=7 "01941ab8d265aea6e98ec9c4678b838f480b049c9f4d70a866eafbe3456fa5de3       
4baa464e96c7e83c6a6a6e26886c90b0175229a24c6890ac8c2cb1ee1ee6c0e03ec8c1d2       
df6422348d574a44153d0a42c6a0762d32ce182db67d1080e19f0d2b4dcb772a6fe5202e       
f2739602e9dfa56600a4abc9eb90e07f0a4c8076b88be69" AttrList={CKA_CLASS="04       
000000" CKA_KEY_TYPE="13000000" CKA_ENCRYPT="01" CKA_VALUE_LEN="08000000       
" } }

Note that CreateObject also failed in my certutil, but it did not affect the
certutil operation:

14:51:03 24969--1207974208:STRTCreateObject {Sesn=5 AttrList={CKA_CLASS=       
"04000000" CKA_KEY_TYPE="13000000" CKA_ENCRYPT="01" CKA_VALUE="ec5b25c2b       
53b4376" } }
14:51:03 24969--1207974208:FINICreateObject ***CKR_TEMPLATE_INCONSISTENT       
***(90ms) {Obj=0 }

14:51:03 24969--1207974208:FINIUnwrapKey CKR_OK(90ms) {Obj=46 }

Comment 5 Thomas Kwan 2007-04-26 23:57:21 UTC

Instructions are here:

How do you enable debug in Safenet's Lunasa?

You need to obtain the debug library cklog-3.2.0-0.i386.rpm from SafeNet. This
RPM should contain /usr/lunasa/lib/libcklog2.so. To enable debug, you must make
sure you have the following settings in your /etc/Chrystoki.conf:

 Chrystoki2 = {
    LibUNIX=/usr/lunasa/lib/libcklog2.so;
 }
 CkLog2 = {
    LibUNIX=/usr/lunasa/lib/libCryptoki2.so;
    Enabled=1;
    File=/tmp/luna.txt;
    Error=/tmp/err.txt;
    Format=0;
    NewFormat=1;
 }
 Luna = {
   DefaultTimeOut=500000;
   PEDTimeout1=100000;
   PEDTimeout2=100000;
 }
 CardReader = {
   RemoteCommand=1;
 }
 LunaSA Client = {
   ServerPort01 = 1792;
   ServerName01 = lunasa2;
   ClientPrivKeyFile = /usr/lunasa/cert/client/spoonboyKey.pem;
   ClientCertFile = /usr/lunasa/cert/client/spoonboy.pem;
   ServerPort00 = 1792;
   ServerName00 = lunasa1;
   NetClient=1;
   ServerCAFile=/usr/lunasa/cert/server/CAFile.pem;
   SSLConfigFile=/usr/lunasa/bin/openssl.cnf;
   ReceiveTimeout=20000;
 }
 Misc = {
       NetscapeCustomize=1023;
 }

After that, you also need to add libcklogs to your secmod.db by issuing

 modutil -dbdir . -nocertdb -add lunasa -libfile /usr/lunasa/lib/libcklog2.so

Note that if you are getting the following error, you must have something wrong
in your /etc/Chrystoki.conf

 /usr/bin/modutil: line 45: 24944 Segmentation fault      (core dumped)
${dir}/${COMMAND} "$@"


Run modutil list to confirm if you can still see the tokens:

 modutil -dbdir . -nocertdb -list

 Using database directory ....
 Listing of PKCS #11 Modules
 -----------------------------------------------------------
 1. NSS Internal PKCS #11 Module
        slots: 2 slots attached
       status: loaded
        slot: NSS Internal Cryptographic Services
       token: NSS Generic Crypto Services
        slot: NSS User Private Key and Certificate Services
       token: NSS Certificate DB
 2. lunasa
       library name: /usr/lunasa/lib/libcklog2.so
        slots: 3 slots attached
       status: loaded
        slot: LunaNet Slot
       token: lunasa1-ca
        slot: LunaNet Slot
       token: lunasa1-tks
        slot: LunaNet Slot
       token: lunasa2-ca
 -----------------------------------------------------------

To trigger some debug log, you can use certutil as follows:

 certutil -d . -L -h lunasa1-ca

The debug log should be in /tmp/luna.txt

Comment 6 Thomas Kwan 2007-04-27 00:02:43 UTC

I also tried creating a self-signed certificate in *our* virtual token
environment, it worked also.

[root@spoonboy alias]# certutil -d . -h virtual-lunasa -S -n testkey -s "CN=x"
-c "CN=x" -x -m 1 -t "CTu,CTu,CTu"
Enter Password or Pin for "virtual-lunasa":

A random seed must be generated that will be used in the
creation of your key.  One of the easiest ways to create a
random seed is to use the timing of keystrokes on a keyboard.

To begin, type keys on the keyboard until this progress meter
is full.  DO NOT USE THE AUTOREPEAT FUNCTION ON YOUR KEYBOARD!


Continue typing until the progress meter is full:

|************************************************************|

Finished.  Press enter to continue:


Generating key.  This may take a few moments...

[root@spoonboy alias]# certutil -d . -h virtual-lunasa -L Enter Password or Pin
for "virtual-lunasa":
...
virtual-lunasa:testkey                                       CTu,Cu,Cu

Comment 7 Thomas Kwan 2007-04-27 00:06:55 UTC

Here is the action item for AOL:

1) Install the debug library as in comment #5
2) Run certutil on the virtual token, and it should fail
3) Then, look in the /etc/luna.txt log to find the Unwrap operation
4) Send the STRTUnwrapKey request and response to AOL and Safenet so that we can
investigate why the PKCS#11 driver was returning 0x12 (CKR_ATTRIBUTE_TYPE_INVALID)

Comment 8 Thomas Kwan 2007-04-27 00:11:52 UTC

For COmment #7, Step 2) - Run certutil (list operation i.e. -L) ...

Comment 9 Thomas Kwan 2007-04-27 00:14:41 UTC

Created attachment 153563 [details]
Luna Logs obtained from Red Hat's Lab environment

Included this so that we can comparing ours to AOL's in future.

Comment 10 Thomas Kwan 2007-04-27 00:21:13 UTC

Ken, regarding to comment 7 again, 

Modification:

Step 2) Run certutil (list operation i.e. -L) on the virtual token
Step 3) The log file is in /tmp/luna.txt

Then, continue on comment 7, add the following steps:

5) clean up /tmp/luna.txt
6) run certutil (list operation) on the regular token (this should work)
7) Copy /tmp/luna.txt to /tmp/luna-good.txt
8) Send us /tmp/luna-good.txt as well

Comment 11 Thomas Kwan 2007-04-27 01:56:36 UTC

Message from Safenet

Anup Marwaha wrote:

> Thanks for this... I assume that with this CKA_KEY_TYPE value the
> C_UnwrapKey call succeeds?

Yes

> However, CKA_KEY_TYPE="13000000" still does not
> map to anything for me... is there anyway to know what exactly are you
> passing?
>  
>
In the log, I see CKA_CLASS="04000000" CKA_KEY_TYPE="13000000" CKA_ENCRYPT="01"
CKA_VALUE_LEN="08000000"

I think we are passing in CKO_SECRET_KEY (0x00000004), and luna log shows
"04000000".
So it is possible that CKA_KEY_TYPE="13000000" means "00000013" (CKK_DES)??

thomas

Comment 12 Thomas Kwan 2007-04-27 02:35:08 UTC

Anup,

The NSS (our security library) code that does the verification is here.

http://ftp.mozilla.org/pub/mozilla.org/security/nss/releases/NSS_3_2_1_RTM/src/nss-3.2.1/mozilla/security/nss/lib/pk11wrap/pk11slot.c

The test starts in the function pk11_CheckVerifyTest. If the test failed, NSS
returns I/O error.

In the function PK11_VerifySlotMechanisms, NSS verifies
a set of mechanisms that the hardware token claims to support. The verification
is done by generating a key in the token (you can see that in PK11_VerifyMechanism).
It tries to generate a DES key which failed in both in our lab and in AOL's
environment, then the code tries to find a RSA public key, and then find the
corresponding
private key on the hardware token, and then it tries to unwrap a test key on the
token.
The unwrapping of the test key failed in AOL's environment, but it works in ours.

thomas

Comment 13 Bob Relyea 2007-04-27 23:02:10 UTC

re comment 13.

there appears to be endian issues with the output. It's probably outputing the
raw bytes, not the integer value. That would make CLASS=4 KEY_TYPE=13 and
VALUE_LEN=8.

These all appear to be correct (SECRET_KEY, CKK_DES and 8 bytes).

Comment 14 Red Hat Bugzilla 2007-10-27 15:29:19 UTC

User nkwan's account has been closed

Comment 15 Red Hat Bugzilla 2007-10-27 15:41:36 UTC

User nkwan's account has been closed

Note You need to log in before you can comment on or make changes to this bug.