void pkcs11_logger_log(const char* message, ...) { FILE *fw = NULL; FILE *output = stdout; va_list ap; // Acquire exclusive access to the file pkcs11_logger_lock_acquire(); va_start(ap, message); // Determine log filename char *log_file_name = getenv("PKCS11_LOGGER_LOG_FILE"); if (NULL == log_file_name) log_file_name = DEFAULT_PKCS11_LOGGER_LOG_FILE; // Open log file fw = fopen(log_file_name, "a"); if (NULL != fw) output = fw; // Output message to log file or stdout fprintf(output, "%0#10x : ", get_process_id()); fprintf(output, "%0#10x : ", get_thread_id()); vfprintf(output, message, ap); fprintf(output, "\n"); // Cleanup va_end(ap); CALL_N_CLEAR(fclose, fw); // Release exclusive access to the file pkcs11_logger_lock_release(); }
void pkcs11_logger_log_attribute_template_with_indent(CK_ATTRIBUTE_PTR pTemplate, CK_ULONG ulCount, int level) { int i = 0; char indent[level*3+1]; char horizontal_line[] = "--------------------------------------"; if ((NULL == pTemplate) || (ulCount < 1)) return; for(i = 0; i < level*3+1; i++) { indent[i] = ' '; } if(i > 1) { indent[i++] = '|'; } indent[i] = '\0'; for (i = 0; i < ulCount; i++) { pkcs11_logger_log("%s Attribute %d", indent, i); pkcs11_logger_log("%s Attribute: %lu (%s)", indent, pTemplate[i].type, pkcs11_logger_translate_ck_attribute(pTemplate[i].type)); pkcs11_logger_log("%s pValue: %p", indent, pTemplate[i].pValue); pkcs11_logger_log("%s ulValueLen: %lu", indent, pTemplate[i].ulValueLen); if (NULL != pTemplate[i].pValue) { char *value = NULL; if(0x40000000 & pTemplate[i].type) { pkcs11_logger_log("%s *pValue: is nested attribute array", indent); pkcs11_logger_log("%s %s", indent, horizontal_line); pkcs11_logger_log_attribute_template_with_indent(pTemplate[i].pValue, pTemplate[i].ulValueLen / sizeof(CK_ATTRIBUTE), level + 1); pkcs11_logger_log("%s %s", indent, horizontal_line); } else { value = pkcs11_logger_translate_ck_byte_ptr(pTemplate[i].pValue, pTemplate[i].ulValueLen); if (NULL != value) { pkcs11_logger_log("%s *pValue: HEX(%s)", indent, value); CALL_N_CLEAR(free, value); } else { pkcs11_logger_log("%s *pValue: *** cannot be displayed ***", indent); } } } } }
void pkcs11_logger_log_byte_array(const char *name, CK_BYTE_PTR byte_array, CK_ULONG byte_array_len) { if (NULL != byte_array) { char *array = NULL; array = pkcs11_logger_translate_ck_byte_ptr(byte_array, byte_array_len); if (NULL != array) { pkcs11_logger_log("%s: HEX(%s)", name, array); CALL_N_CLEAR(free, array); } else { pkcs11_logger_log("%s: *** cannot be displayed ***", name); } } }
// Logs array of cryptoki attributes void pkcs11_logger_log_attribute_template(CK_ATTRIBUTE_PTR pTemplate, CK_ULONG ulCount) { CK_ULONG i = 0; if ((NULL == pTemplate) || (ulCount < 1)) return; pkcs11_logger_log(" *** Begin attribute template ***"); for (i = 0; i < ulCount; i++) { pkcs11_logger_log(" Attribute %d", i); pkcs11_logger_log(" Attribute: %lu (%s)", pTemplate[i].type, pkcs11_logger_translate_ck_attribute(pTemplate[i].type)); pkcs11_logger_log(" pValue: %p", pTemplate[i].pValue); pkcs11_logger_log(" ulValueLen: %lu", pTemplate[i].ulValueLen); if (NULL != pTemplate[i].pValue) { char *value = NULL; if ((pTemplate[i].type & CKF_ARRAY_ATTRIBUTE) == CKF_ARRAY_ATTRIBUTE) { if (0 == (pTemplate[i].ulValueLen % sizeof(CK_ATTRIBUTE))) { pkcs11_logger_log_attribute_template(pTemplate[i].pValue, pTemplate[i].ulValueLen / sizeof(CK_ATTRIBUTE)); continue; } } value = pkcs11_logger_translate_ck_byte_ptr(pTemplate[i].pValue, pTemplate[i].ulValueLen); if (NULL != value) { pkcs11_logger_log(" *pValue: HEX(%s)", value); CALL_N_CLEAR(free, value); } else { pkcs11_logger_log(" *pValue: *** cannot be displayed ***"); } } } pkcs11_logger_log(" *** End attribute template ***"); }
void pkcs11_logger_log_nonzero_string(const char *name, const unsigned char *nonzero_string, CK_ULONG nonzero_string_len) { if (NULL != nonzero_string) { unsigned char *zero_string = NULL; zero_string = (unsigned char*) malloc(nonzero_string_len + 1); if (NULL != zero_string) { memset(zero_string, 0, nonzero_string_len + 1); memcpy(zero_string, nonzero_string, nonzero_string_len); pkcs11_logger_log("%s: %s", name, zero_string); CALL_N_CLEAR(free, zero_string); } else { pkcs11_logger_log("%s: *** cannot be displayed ***", name); } } }
// Logs message void pkcs11_logger_log(const char* message, ...) { va_list ap; unsigned long disable_log_file = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_DISABLE_LOG_FILE) == PKCS11_LOGGER_FLAG_DISABLE_LOG_FILE); unsigned long disable_process_id = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_DISABLE_PROCESS_ID) == PKCS11_LOGGER_FLAG_DISABLE_PROCESS_ID); unsigned long disable_thread_id = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_DISABLE_THREAD_ID) == PKCS11_LOGGER_FLAG_DISABLE_THREAD_ID); unsigned long enable_stdout = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_ENABLE_STDOUT) == PKCS11_LOGGER_FLAG_ENABLE_STDOUT); unsigned long enable_stderr = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_ENABLE_STDERR) == PKCS11_LOGGER_FLAG_ENABLE_STDERR); unsigned long enable_fclose = ((pkcs11_logger_globals.flags & PKCS11_LOGGER_FLAG_ENABLE_FCLOSE) == PKCS11_LOGGER_FLAG_ENABLE_FCLOSE); // Acquire exclusive access to the file pkcs11_logger_lock_acquire(); #ifdef _WIN32 #pragma warning(push) #pragma warning(disable: 4996) #endif // Open log file if ((!disable_log_file) && (NULL != pkcs11_logger_globals.env_var_log_file_path) && (NULL == pkcs11_logger_globals.log_file_handle)) { pkcs11_logger_globals.log_file_handle = fopen((const char *)pkcs11_logger_globals.env_var_log_file_path, "a"); } #ifdef _WIN32 #pragma warning(pop) #endif // Log to file if ((!disable_log_file) && (NULL != pkcs11_logger_globals.log_file_handle)) { va_start(ap, message); if (!disable_process_id) fprintf(pkcs11_logger_globals.log_file_handle, "%0#10x : ", pkcs11_logger_utils_get_process_id()); if (!disable_thread_id) fprintf(pkcs11_logger_globals.log_file_handle, "%0#10x : ", pkcs11_logger_utils_get_thread_id()); vfprintf(pkcs11_logger_globals.log_file_handle, message, ap); fprintf(pkcs11_logger_globals.log_file_handle, "\n"); va_end(ap); } // Log to stdout if (enable_stdout) { va_start(ap, message); if (!disable_process_id) fprintf(stdout, "%0#10x : ", pkcs11_logger_utils_get_process_id()); if (!disable_thread_id) fprintf(stdout, "%0#10x : ", pkcs11_logger_utils_get_thread_id()); vfprintf(stdout, message, ap); fprintf(stdout, "\n"); va_end(ap); } // Log to stderr if (enable_stderr || CK_FALSE == pkcs11_logger_globals.env_vars_read) { va_start(ap, message); if (!disable_process_id) fprintf(stderr, "%0#10x : ", pkcs11_logger_utils_get_process_id()); if (!disable_thread_id) fprintf(stderr, "%0#10x : ", pkcs11_logger_utils_get_thread_id()); vfprintf(stderr, message, ap); fprintf(stderr, "\n"); va_end(ap); } // Cleanup if (enable_fclose) { CALL_N_CLEAR(fclose, pkcs11_logger_globals.log_file_handle); } else { if (NULL != pkcs11_logger_globals.log_file_handle) fflush(pkcs11_logger_globals.log_file_handle); } // Release exclusive access to the file pkcs11_logger_lock_release(); }