Re: Another problem with my PKCS#11 - my new log files(with process and thread identifer)
Hi bob: The list is my new log file content, OS is windows xp. My C statements which record logs just like this: LOG2(3, __FILE__, __LINE__, PID is %d, TID %d.PID = %d, TID = %d.\n, GetCurrentProcessId(), GetCurrentThreadId()); PID means current process id, TID is current thread id. View under logs, I just find ONLY ONE thread call my pkcs#11 library.There some problem: (1)When pkcs11 encrypt some data, we should call C_EncryptInit-C_EncryptUpdate-C_EncryptFinal, or C_EncryptInit-C_Encrypt; but mozilla call the C_EncryptInit-C_EncryptUpdate, lost C_EncryptFinal calling, it this right? (2)Mozilla call pkcs11 library close the session '1', which created by the main process of mozilla(I think), and then use this session to do communication with token(call C_FindObjectsInit), is this right? ... Thanks advanced. yours itspki C R Y P T O K IT E S T 2005/10/25 [17:58:47, pkcs11.cpp :2379] DLL_PROCESS_ATTACH. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :0331] C_GetFunctionList start... [17:58:47, pkcs11.cpp :0222] == [17:58:47, pkcs11.cpp :0223] C_Initialize start... [17:58:47, mdlcrptg.cpp:0091] ModuloCriptografico::C_Initialize, arg = 61f6ebf0 Flags 3 [17:58:47, mdlcrptg.cpp:0121] ModuloCriptografico::C_Initialize, Can't create OS threads This is OK [17:58:47, mdlcrptg.cpp:0192] ModuloCriptografico::C_Initialize, flag is set and function pointers are supplied. [17:58:47, pkcs11.cpp :0297] C_GetInfo start... [17:58:47, pkcs11.cpp :0426] C_GetSlotList start... [17:58:47, mdlcrptg.cpp:0284] ModuloCriptografico::C_GetSlotList, tokenPresent = 0, *pulCount = 0 [17:58:47, pkcs11.cpp :0426] C_GetSlotList start... [17:58:47, mdlcrptg.cpp:0284] ModuloCriptografico::C_GetSlotList, tokenPresent = 0, *pulCount = 1 [17:58:47, pkcs11.cpp :0448] C_GetSlotInfo start... [17:58:47, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [17:58:47, pkcs11.cpp :0477] C_GetTokenInfo start... [17:58:47, pkcs11.cpp :0530] C_GetMechanismList start... [17:58:47, pkcs11.cpp :0531] C_GetMechanismList, slotID = 1. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :0532] C_GetMechanismList, pulCount = 29981336. [17:58:47, pkcs11.cpp :0530] C_GetMechanismList start... [17:58:47, pkcs11.cpp :0531] C_GetMechanismList, slotID = 1. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :0532] C_GetMechanismList, pulCount = 15. [17:58:47, pkcs11.cpp :0680] C_OpenSession start... [17:58:47, pkcs11.cpp :0693] C_OpenSession, R/O session. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :0707] C_OpenSession, new session handle 1. [17:58:47, pkcs11.cpp :1170] C_FindObjectsInit start... [17:58:47, pkcs11.cpp :1171] C_FindObjectsInit, hSession = 1. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :1189] C_FindObjectsInit, 1/1, CKA_CLASS = 0xCE534354. [17:58:47, pkcs11.cpp :1232] C_FindObjects start... [17:58:47, pkcs11.cpp :1233] C_FindObjects, hSession = 1. [17:58:47, pkcs11.cpp :1251] C_FindObjects, 0 ojbects found. [17:58:47, pkcs11.cpp :1272] C_FindObjectsFinal start... [17:58:47, pkcs11.cpp :1273] C_FindObjectsFinal, hSession = 1. [17:58:47, pkcs11.cpp :0448] C_GetSlotInfo start... [17:58:47, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [17:58:47, pkcs11.cpp :0812] C_GetSessionInfo start... [17:58:47, pkcs11.cpp :0813] C_GetSessionInfo, hSession = 1. [17:58:47, pkcs11.cpp :1170] C_FindObjectsInit start... [17:58:47, pkcs11.cpp :1171] C_FindObjectsInit, hSession = 1. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :1189] C_FindObjectsInit, 2/4, CKA_CLASS = 0xCE534353. [17:58:47, pkcs11.cpp :1232] C_FindObjects start... [17:58:47, pkcs11.cpp :1233] C_FindObjects, hSession = 1. [17:58:47, pkcs11.cpp :1251] C_FindObjects, 0 ojbects found. [17:58:47, pkcs11.cpp :1272] C_FindObjectsFinal start... [17:58:47, pkcs11.cpp :1273] C_FindObjectsFinal, hSession = 1. [17:58:47, pkcs11.cpp :1170] C_FindObjectsInit start... [17:58:47, pkcs11.cpp :1171] C_FindObjectsInit, hSession = 1. PID = 1492, TID = 3460. [17:58:47, pkcs11.cpp :1189] C_FindObjectsInit, 2/4, CKA_CLASS = 0xCE534353. [17:58:47, pkcs11.cpp :1232] C_FindObjects start... [17:58:47, pkcs11.cpp :1233] C_FindObjects, hSession = 1. [17:58:47, pkcs11.cpp :1251] C_FindObjects, 0 ojbects found. [17:58:47, pkcs11.cpp :1272] C_FindObjectsFinal start... [17:58:47, pkcs11.cpp :1273] C_FindObjectsFinal, hSession = 1. [17:58:47, pkcs11.cpp :0448] C_GetSlotInfo start... [17:58:47, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [17:58:48, pkcs11.cpp :0448] C_GetSlotInfo start... [17:58:48, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [17:58:48, pkcs11.cpp :0477] C_GetTokenInfo start... [17:58:48, pkcs11.cpp :0812] C_GetSessionInfo start... [17:58:48, pkcs11.cpp :0813] C_GetSessionInfo, hSession = 1. [17:58:49,
Re: Another problem with my PKCS#11
itspki wrote: Hi bob: The list is new log file content, you can see NSS call C_Initialize on time, and load my pkcs#11 library twice(DLL_PROCESS_ATTACH and DLL_THREAD_ATTACH), and the problem still exist - login failed. That doesn't mean your PKCS #11 library is loaded twice. When a process loads your PKCS #11 library, you will get a DLL_PROCESS_ATTACH and at least one DLL_THREAD_ATTACH, because a process has at lease one thread. Wan-Teh ___ mozilla-crypto mailing list mozilla-crypto@mozilla.org http://mail.mozilla.org/listinfo/mozilla-crypto
Re: Another problem with my PKCS#11
Wan-Teh Chang wrote: itspki wrote: Hi bob: The list is new log file content, you can see NSS call C_Initialize on time, and load my pkcs#11 library twice(DLL_PROCESS_ATTACH and DLL_THREAD_ATTACH), and the problem still exist - login failed. That doesn't mean your PKCS #11 library is loaded twice. When a process loads your PKCS #11 library, you will get a DLL_PROCESS_ATTACH and at least one DLL_THREAD_ATTACH, because a process has at lease one thread. Wan-Teh Hi Wan-Teh: see:http://msdn.microsoft.com/library/default.asp?url=/library/en-us/dllproc/base/dllmain.asp A thread calling the DLL entry-point function with DLL_PROCESS_ATTACH does not call the DLL entry-point function with DLL_THREAD_ATTACH. Now, my problem is: (1)When pkcs11 encrypt some data, we should call C_EncryptInit-C_EncryptUpdate-C_EncryptFinal, or C_EncryptInit-C_Encrypt; but mozilla call the C_EncryptInit-C_EncryptUpdate, lost C_EncryptFinal calling, it this right? (2)Mozilla close the session '1', which created by the main process of mozilla(I think), and then use this session to do communication with token(call C_FindObjectsInit), is this right? thanks advanced, itspki ___ mozilla-crypto mailing list mozilla-crypto@mozilla.org http://mail.mozilla.org/listinfo/mozilla-crypto
Re: Another problem with my PKCS#11
itspki wrote: Wan-Teh Chang wrote: itspki wrote: Hi bob: The list is new log file content, you can see NSS call C_Initialize on time, and load my pkcs#11 library twice(DLL_PROCESS_ATTACH and DLL_THREAD_ATTACH), and the problem still exist - login failed. That doesn't mean your PKCS #11 library is loaded twice. When a process loads your PKCS #11 library, you will get a DLL_PROCESS_ATTACH and at least one DLL_THREAD_ATTACH, because a process has at lease one thread. Wan-Teh Hi Wan-Teh: see:http://msdn.microsoft.com/library/default.asp?url=/library/en-us/dllproc/base/dllmain.asp A thread calling the DLL entry-point function with DLL_PROCESS_ATTACH does not call the DLL entry-point function with DLL_THREAD_ATTACH. Now, my problem is: (1)When pkcs11 encrypt some data, we should call C_EncryptInit-C_EncryptUpdate-C_EncryptFinal, or C_EncryptInit-C_Encrypt; but mozilla call the C_EncryptInit-C_EncryptUpdate, lost C_EncryptFinal calling, it this right? When your session closes, you should finalize all your state. If NSS tries to call C_EncryptInit or C_DecryptInit on that same session, then there can be trouble. I'm not sure what is happening with the token that is causing NSS to behave this way. Is your token removable? (2)Mozilla close the session '1', which created by the main process of mozilla(I think), and then use this session to do communication with token(call C_FindObjectsInit), is this right? I'm not sure why you are seeing this. I know our tokens would break horribly if we had our primary session closed out from underneath us. My best guess is that for some reason NSS thinks your token has 'gone away'. It might be time to get a debugable version of mozilla... bob thanks advanced, itspki ___ mozilla-crypto mailing list mozilla-crypto@mozilla.org http://mail.mozilla.org/listinfo/mozilla-crypto smime.p7s Description: S/MIME Cryptographic Signature
Re: Another problem with my PKCS#11
Bob Relyea wrote: itspki wrote: Hi all: I load my pkcs#11 module to mozilla, it's worked. But when i log in to my token, some error occurred, mozilla give the dialog Log in Error. Look up the log file, i found the session, the first session create by mozilla, has been closed by mozilla. But mozilla try to call C_FindObjectsInit function with the session handle(but the handle has been closed by the mozilla), RV is CKR_SESSION_HANDLE_INVALID. the list is content of my log file- You apparently have your module loaded more than once (Note the 2 calls to C_Initialize). NSS thinks each module is a different instance, though your module does not. You need to go to the device manager and delete one of those instances. bob Hi bob: The list is new log file content, you can see NSS call C_Initialize on time, and load my pkcs#11 library twice(DLL_PROCESS_ATTACH and DLL_THREAD_ATTACH), and the problem still exist - login failed. thank you very much. itspki C R Y P T O K IT E S T 2005/10/25 [10:05:20, pkcs11.cpp :2348] DLL_PROCESS_ATTACH [10:05:20, pkcs11.cpp :0331] C_GetFunctionList [10:05:20, pkcs11.cpp :0222] == [10:05:20, pkcs11.cpp :0223] C_Initialize [10:05:20, mdlcrptg.cpp:0091] ModuloCriptografico::C_Initialize, arg = 61f6ebf0 Flags 3 [10:05:20, mdlcrptg.cpp:0121] ModuloCriptografico::C_Initialize, Can't create OS threads This is OK [10:05:20, mdlcrptg.cpp:0188] ModuloCriptografico::C_Initialize, flag is set and function pointers are supplied. [10:05:27, pkcs11.cpp :0297] C_GetInfo [10:05:27, pkcs11.cpp :0426] C_GetSlotList [10:05:27, mdlcrptg.cpp:0286] ModuloCriptografico::C_GetSlotList, tokenPresent = 0, *pulCount = 0 [10:05:27, pkcs11.cpp :0426] C_GetSlotList [10:05:27, mdlcrptg.cpp:0286] ModuloCriptografico::C_GetSlotList, tokenPresent = 0, *pulCount = 1 [10:05:27, pkcs11.cpp :0448] C_GetSlotInfo [10:05:27, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:27, pkcs11.cpp :0477] C_GetTokenInfo [10:05:27, pkcs11.cpp :0530] C_GetMechanismList [10:05:27, pkcs11.cpp :0531] C_GetMechanismList, slotID = 1. [10:05:27, pkcs11.cpp :0530] C_GetMechanismList [10:05:27, pkcs11.cpp :0531] C_GetMechanismList, slotID = 1. [10:05:27, pkcs11.cpp :0679] C_OpenSession [10:05:27, pkcs11.cpp :0692] C_OpenSession, R/O session. [10:05:27, pkcs11.cpp :0706] C_OpenSession, new session handle 1. [10:05:27, pkcs11.cpp :1172] C_FindObjectsInit [10:05:27, pkcs11.cpp :1173] C_FindObjectsInit, hSession = 1. [10:05:27, pkcs11.cpp :1191] C_FindObjectsInit, 1/1, CKA_CLASS = 0xCE534354. [10:05:27, pkcs11.cpp :1234] C_FindObjects [10:05:27, pkcs11.cpp :1235] C_FindObjects, hSession = 1. [10:05:27, pkcs11.cpp :1253] C_FindObjects, 0 ojbects found. [10:05:27, pkcs11.cpp :1274] C_FindObjectsFinal [10:05:27, pkcs11.cpp :1275] C_FindObjectsFinal, hSession = 1. [10:05:27, pkcs11.cpp :0448] C_GetSlotInfo [10:05:27, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:27, pkcs11.cpp :0815] C_GetSessionInfo [10:05:27, pkcs11.cpp :0816] C_GetSessionInfo, hSession = 1. [10:05:27, pkcs11.cpp :1172] C_FindObjectsInit [10:05:27, pkcs11.cpp :1173] C_FindObjectsInit, hSession = 1. [10:05:27, pkcs11.cpp :1191] C_FindObjectsInit, 2/4, CKA_CLASS = 0xCE534353. [10:05:27, pkcs11.cpp :1234] C_FindObjects [10:05:27, pkcs11.cpp :1235] C_FindObjects, hSession = 1. [10:05:27, pkcs11.cpp :1253] C_FindObjects, 0 ojbects found. [10:05:27, pkcs11.cpp :1274] C_FindObjectsFinal [10:05:27, pkcs11.cpp :1275] C_FindObjectsFinal, hSession = 1. [10:05:27, pkcs11.cpp :1172] C_FindObjectsInit [10:05:27, pkcs11.cpp :1173] C_FindObjectsInit, hSession = 1. [10:05:27, pkcs11.cpp :1191] C_FindObjectsInit, 2/4, CKA_CLASS = 0xCE534353. [10:05:27, pkcs11.cpp :1234] C_FindObjects [10:05:27, pkcs11.cpp :1235] C_FindObjects, hSession = 1. [10:05:27, pkcs11.cpp :1253] C_FindObjects, 0 ojbects found. [10:05:27, pkcs11.cpp :1274] C_FindObjectsFinal [10:05:27, pkcs11.cpp :1275] C_FindObjectsFinal, hSession = 1. [10:05:27, pkcs11.cpp :0448] C_GetSlotInfo [10:05:27, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:28, pkcs11.cpp :0448] C_GetSlotInfo [10:05:28, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:28, pkcs11.cpp :0815] C_GetSessionInfo [10:05:28, pkcs11.cpp :0816] C_GetSessionInfo, hSession = 1. [10:05:28, pkcs11.cpp :0448] C_GetSlotInfo [10:05:28, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:28, pkcs11.cpp :0477] C_GetTokenInfo [10:05:28, pkcs11.cpp :0815] C_GetSessionInfo [10:05:28, pkcs11.cpp :0816] C_GetSessionInfo, hSession = 1. [10:05:29, pkcs11.cpp :0448] C_GetSlotInfo [10:05:29, pkcs11.cpp :0449] C_GetSlotInfo, slotID = 1. [10:05:29, pkcs11.cpp :0815] C_GetSessionInfo [10:05:29, pkcs11.cpp :0816] C_GetSessionInfo, hSession = 1.
