pkcs11log.rst (4942B)
1 .. _mozilla_projects_nss_nss_tech_notes_nss_tech_note2: 2 3 Logging PKCS11 Calls 4 ==================== 5 6 .. container:: 7 8 The logger displays all activity between NSS and a specified PKCS #11 module. It works by 9 inserting a special set of entry points between NSS and the module. 10 11 To enable the module logger, you must set the environment variable NSS_DEBUG_PKCS11_MODULE to the 12 name of the target module. For example, to log the softoken, use: 13 14 .. code:: 15 16 NSS_DEBUG_PKCS11_MODULE="NSS Internal PKCS #11 Module" 17 18 Note: In the Command Prompt on Windows, do not quote the name of the target module, otherwise the 19 quotes are considered part of the name. For example, to log the softoken on Windows, use: 20 21 .. code:: 22 23 set NSS_DEBUG_PKCS11_MODULE=NSS Internal PKCS #11 Module 24 25 The logger is available by default in debug builds. For optimized builds, NSS must be built with 26 the variable DEBUG_PKCS11 set. 27 28 .. container:: 29 30 The logger has several modes of operation: 31 32 **1. Only display the sequence of PKCS #11 calls.** To enable this mode, set: 33 34 .. code:: 35 36 NSPR_LOG_MODULES=nss_mod_log:1 37 NSPR_LOG_FILE=<logfile> 38 39 The output format is: 40 41 .. code:: 42 43 OSThreadID[NSPRThreadID]: C_XXX 44 OSThreadID[NSPRThreadID]: rv = 0xYYYYYYYY 45 46 For example, 47 48 .. code:: 49 50 1024[805ef10]: C_Initialize 51 1024[805ef10]: rv = 0x0 52 1024[805ef10]: C_GetInfo 53 1024[805ef10]: rv = 0x0 54 1024[805ef10]: C_GetSlotList 55 1024[805ef10]: rv = 0x0 56 57 **2. Display the sequence of PKCS #11 calls, and the parameters given to them.** To enable this 58 mode, set: 59 60 .. code:: 61 62 NSPR_LOG_MODULES=nss_mod_log:3 63 NSPR_LOG_FILE=<logfile> 64 65 The output format is: 66 67 .. code:: 68 69 OSThreadID[NSPRThreadID]: C_XXX 70 OSThreadID[NSPRThreadID]: arg1 = 0xAAAAAAAA 71 ... 72 OSThreadID[NSPRThreadID]: argN = 0xAAAAAAAA 73 OSThreadID[NSPRThreadID]: rv = 0xYYYYYYYY 74 75 For example, 76 77 .. code:: 78 79 1024[805ef10]: C_Initialize 80 1024[805ef10]: pInitArgs = 0x4010c938 81 1024[805ef10]: rv = 0x0 82 1024[805ef10]: C_GetInfo 83 1024[805ef10]: pInfo = 0xbffff340 84 1024[805ef10]: rv = 0x0 85 1024[805ef10]: C_GetSlotList 86 1024[805ef10]: tokenPresent = 0x0 87 1024[805ef10]: pSlotList = 0x0 88 1024[805ef10]: pulCount = 0xbffff33c 89 1024[805ef10]: *pulCount = 0x2 90 1024[805ef10]: rv = 0x0 91 92 Note that when a PKCS #11 function takes a pointer argument for which it will set a value 93 (C_GetSlotList above), this mode will display the value upon return. 94 95 **3. Display verbose information, including template values, array values, etc.** To enable this 96 mode, set: 97 98 .. code:: 99 100 NSPR_LOG_MODULES=nss_mod_log:4 101 NSPR_LOG_FILE=<logfile> 102 103 The output format is the same as above, but with more information. For example, 104 105 .. code:: 106 107 1024[805ef10]: C_FindObjectsInit 108 1024[805ef10]: hSession = 0x1000001 109 1024[805ef10]: pTemplate = 0xbffff410 110 1024[805ef10]: ulCount = 3 111 1024[805ef10]: CKA_LABEL = localhost.nyc.rr.com [20] 112 1024[805ef10]: CKA_TOKEN = CK_TRUE [1] 113 1024[805ef10]: CKA_CLASS = CKO_CERTIFICATE [4] 114 1024[805ef10]: rv = 0x0 115 1024[805ef10]: C_FindObjects 116 1024[805ef10]: hSession = 0x1000001 117 1024[805ef10]: phObject = 0x806d810 118 1024[805ef10]: ulMaxObjectCount = 16 119 1024[805ef10]: pulObjectCount = 0xbffff38c 120 1024[805ef10]: *pulObjectCount = 0x1 121 1024[805ef10]: phObject[0] = 0xf6457d04 122 1024[805ef10]: rv = 0x0 123 1024[805ef10]: C_FindObjectsFinal 124 1024[805ef10]: hSession = 0x1000001 125 1024[805ef10]: rv = 0x0 126 1024[805ef10]: C_GetAttributeValue 127 1024[805ef10]: hSession = 0x1000001 128 1024[805ef10]: hObject = 0xf6457d04 129 1024[805ef10]: pTemplate = 0xbffff2d0 130 1024[805ef10]: ulCount = 2 131 1024[805ef10]: CKA_TOKEN = 0 [1] 132 1024[805ef10]: CKA_LABEL = 0 [20] 133 1024[805ef10]: rv = 0x0 134 1024[805ef10]: C_GetAttributeValue 135 1024[805ef10]: hSession = 0x1000001 136 1024[805ef10]: hObject = 0xf6457d04 137 1024[805ef10]: pTemplate = 0xbffff2d0 138 1024[805ef10]: ulCount = 2 139 1024[805ef10]: CKA_TOKEN = CK_TRUE [1] 140 1024[805ef10]: CKA_LABEL = localhost.nyc.rr.com [20] 141 1024[805ef10]: rv = 0x0 142 143 **4. Collect performance data.** This mode is most useful in optimized builds. The number of 144 calls to each PKCS #11 function will be counted, and the time spent in each function as well. A 145 summary of performance data is dumped during NSS shutdown. 146 147 No additional environment variables are required for this mode. If the environment variable 148 NSS_OUTPUT_FILE is set, its value will be used as the path name of the file to which the final 149 output will be written. Otherwise, the output will be written to stdout.