diff --git a/SymCryptProvider/README.md b/SymCryptProvider/README.md index a374e26d..f7103e18 100644 --- a/SymCryptProvider/README.md +++ b/SymCryptProvider/README.md @@ -143,4 +143,5 @@ separate section. This section must be referenced in the symcrypt provider secti | - | - | - | | enabled | 0 or 1 to disable or enable keysinuse logging. | 0 | | max_file_size | Maximum size of the file events are written to. May be written as raw byte size or suffixed with KB/MB/GB | 5KB | -| logging_delay_seconds | Duration in seconds between events being written to the file. Any events that happen in between will be aggregate and logged as one event. | error | \ No newline at end of file +| logging_delay_seconds | Duration in seconds between events being written to the file. Any events that happen in between will be aggregate and logged as one event. | error | +| process_scope | Controls which processes run the KeysInUse logging thread when an application forks. Can be May be overridden at runtime by the `KEYSINUSE_PROCESS_SCOPE` environment variable. | both | \ No newline at end of file diff --git a/SymCryptProvider/src/p_scossl_base.c b/SymCryptProvider/src/p_scossl_base.c index 10a52482..0b67ec97 100644 --- a/SymCryptProvider/src/p_scossl_base.c +++ b/SymCryptProvider/src/p_scossl_base.c @@ -24,6 +24,7 @@ extern "C" { #define CONF_KEYSINUSE_ENABLED "keysinuse.enabled" #define CONF_KEYSINUSE_MAX_FILE_SIZE "keysinuse.max_file_size" #define CONF_KEYSINUSE_LOGGING_DELAY "keysinuse.logging_delay_seconds" +#define CONF_KEYSINUSE_PROCESS_SCOPE "keysinuse.process_scope" // Cap configured file size at 2GB #define SCOSSL_MAX_CONFIGURABLE_FILE_SIZE (2l << 30) @@ -413,12 +414,15 @@ static void p_scossl_start_keysinuse(_In_ const OSSL_CORE_HANDLE *handle) const char *confEnabled = NULL; const char *confMaxFileSize = NULL; const char *confLoggingDelay = NULL; + const char *confProcessScope = NULL; + const char *envProcessScope = NULL; const char *envEnabled = NULL; OSSL_PARAM keysinuseParams[] = { OSSL_PARAM_utf8_ptr(CONF_KEYSINUSE_ENABLED, &confEnabled, 0), OSSL_PARAM_utf8_ptr(CONF_KEYSINUSE_MAX_FILE_SIZE, &confMaxFileSize, 0), OSSL_PARAM_utf8_ptr(CONF_KEYSINUSE_LOGGING_DELAY, &confLoggingDelay, 0), + OSSL_PARAM_utf8_ptr(CONF_KEYSINUSE_PROCESS_SCOPE, &confProcessScope, 0), OSSL_PARAM_END}; // Config related errors shouldn't surface to caller @@ -501,6 +505,28 @@ static void p_scossl_start_keysinuse(_In_ const OSSL_CORE_HANDLE *handle) p_scossl_keysinuse_set_logging_delay(atol(confLoggingDelay)); } + // Environment overrides config. Config value is alreday fetched core_get_params above + if ((envProcessScope = NCONF_get_string(NULL, NULL, "KEYSINUSE_PROCESS_SCOPE")) != NULL) + { + confProcessScope = envProcessScope; + } + + if (confProcessScope != NULL) + { + if (OPENSSL_strcasecmp(confProcessScope, "main") == 0) + { + p_scossl_keysinuse_set_process_scope(KEYSINUSE_PROCESS_SCOPE_MAIN); + } + else if (OPENSSL_strcasecmp(confProcessScope, "child") == 0) + { + p_scossl_keysinuse_set_process_scope(KEYSINUSE_PROCESS_SCOPE_CHILD); + } + else + { + p_scossl_keysinuse_set_process_scope(KEYSINUSE_PROCESS_SCOPE_BOTH); + } + } + p_scossl_keysinuse_init(); } diff --git a/SymCryptProvider/src/p_scossl_keysinuse.c b/SymCryptProvider/src/p_scossl_keysinuse.c index 58945a7a..54f764b6 100644 --- a/SymCryptProvider/src/p_scossl_keysinuse.c +++ b/SymCryptProvider/src/p_scossl_keysinuse.c @@ -5,6 +5,7 @@ #include #include #include +#include #include #include #include @@ -25,6 +26,8 @@ static off_t max_file_size = 5 << 10; // Default to 5KB static long logging_delay = 60 * 60; // Default to 1 hour static BOOL keysinuse_enabled = FALSE; static BOOL p_scossl_keysinuse_child_enabled = FALSE; +static BOOL keysinuse_initialized = FALSE; +static UINT32 keysinuse_process_scope = KEYSINUSE_PROCESS_SCOPE_BOTH; static pid_t pid = 0; static pid_t logging_thread_tid = 0; @@ -107,6 +110,72 @@ static void p_scossl_keysinuse_logging_thread_cleanup() } } +// Starts the logging thread and marks keysinuse as enabled. Reainitializes +// lock thread globals and state. On failure caller is repsonsible for cleanup. +static SCOSSL_STATUS p_scossl_keysinuse_create_logging_thread() +{ + pthread_condattr_t attr; + int pthreadErr; + BOOL attr_initialized = FALSE; + sigset_t oldSigSet; + sigset_t blockSigSet; + SCOSSL_STATUS status = SCOSSL_FAILURE; + + // Monotonic clock needs to be set to prevent wall clock changes from + // affecting the logging delay sleep time. Allocate condition variable, + // releasing any instance inherited across a fork first. + OPENSSL_free(logging_thread_cond_wake_early); + logging_thread_cond_wake_early = NULL; + + if ((logging_thread_cond_wake_early = OPENSSL_malloc(sizeof(pthread_cond_t))) == NULL) + { + p_scossl_keysinuse_log_error("Failed to allocate condition variable"); + goto cleanup; + } + + if ((pthreadErr = pthread_condattr_init(&attr)) != 0) + { + p_scossl_keysinuse_log_error("Failed to init condition attributes,SYS_%d", pthreadErr); + goto cleanup; + } + + attr_initialized = TRUE; + is_logging = TRUE; + + if ((pthreadErr = pthread_condattr_setclock(&attr, CLOCK_MONOTONIC)) != 0 || + (pthreadErr = pthread_cond_init(logging_thread_cond_wake_early, &attr)) != 0) + { + p_scossl_keysinuse_log_error("Failed to initialize logging thread condition,SYS_%d", pthreadErr); + is_logging = FALSE; + goto cleanup; + } + + // Block all signals across creation of the logging thread so signal handlers + // never run in the logging thread. + sigfillset(&blockSigSet); + pthread_sigmask(SIG_SETMASK, &blockSigSet, &oldSigSet); + pthreadErr = pthread_create(&logging_thread, NULL, p_scossl_keysinuse_logging_thread_start, NULL); + pthread_sigmask(SIG_SETMASK, &oldSigSet, NULL); + + if (pthreadErr != 0) + { + p_scossl_keysinuse_log_error("Failed to start logging thread,SYS_%d", pthreadErr); + is_logging = FALSE; + goto cleanup; + } + + keysinuse_enabled = TRUE; + status = SCOSSL_SUCCESS; + +cleanup: + if (attr_initialized) + { + pthread_condattr_destroy(&attr); + } + + return status; +} + static void p_scossl_keysinuse_init_once() { int mkdirResult; @@ -117,10 +186,8 @@ static void p_scossl_keysinuse_init_once() char *procPath = NULL; int cbProcPath = PATH_MAX; int cbProcPathUsed = 0; - pthread_condattr_t attr; int pthreadErr; SCOSSL_STATUS status = SCOSSL_FAILURE; - BOOL attr_initialized = FALSE; // Store process PID for later use pid = getpid(); @@ -188,33 +255,6 @@ static void p_scossl_keysinuse_init_once() goto cleanup; } - // Start the logging thread. Monotonic clock needs to be set to - // prevent wall clock changes from affecting the logging delay sleep time - // Allocate condition variable - if ((logging_thread_cond_wake_early = OPENSSL_malloc(sizeof(pthread_cond_t))) == NULL) - { - p_scossl_keysinuse_log_error("Failed to allocate condition variable"); - goto cleanup; - } - - if ((pthreadErr = pthread_condattr_init(&attr)) != 0) - { - p_scossl_keysinuse_log_error("Failed to init condition attributes,SYS_%d", pthreadErr); - goto cleanup; - } - - attr_initialized = TRUE; - is_logging = TRUE; - - if ((pthreadErr = pthread_condattr_setclock(&attr, CLOCK_MONOTONIC)) != 0 || - (pthreadErr = pthread_cond_init(logging_thread_cond_wake_early, &attr)) != 0 || - (pthreadErr = pthread_create(&logging_thread, NULL, p_scossl_keysinuse_logging_thread_start, NULL)) != 0) - { - p_scossl_keysinuse_log_error("Failed to start logging thread,SYS_%d", pthreadErr); - is_logging = FALSE; - goto cleanup; - } - if ((pthreadErr = pthread_atfork(p_scossl_keysinuse_prepare, p_scossl_keysinuse_parent, p_scossl_keysinuse_child)) != 0) @@ -223,15 +263,18 @@ static void p_scossl_keysinuse_init_once() goto cleanup; } - keysinuse_enabled = TRUE; - status = SCOSSL_SUCCESS; + keysinuse_initialized = TRUE; -cleanup: - if (attr_initialized) + if ((keysinuse_process_scope & KEYSINUSE_PROCESS_SCOPE_MAIN) == 0) { - pthread_condattr_destroy(&attr); + status = SCOSSL_SUCCESS; + goto cleanup; } + // Start the logging thread. + status = p_scossl_keysinuse_create_logging_thread(); + +cleanup: if (status != SCOSSL_SUCCESS) { p_scossl_keysinuse_teardown(); @@ -249,7 +292,7 @@ void p_scossl_keysinuse_init() // Acquire all locks to freeze state before fork static void p_scossl_keysinuse_prepare() { - if (!keysinuse_enabled) + if (!keysinuse_initialized) { return; } @@ -286,7 +329,9 @@ static void p_scossl_keysinuse_prepare() closedir(task_dir); // Enable child logging only if no extra threads were found - if (!has_extra_threads && errno == 0) + if (!has_extra_threads && + errno == 0 && + (keysinuse_process_scope & KEYSINUSE_PROCESS_SCOPE_CHILD) != 0) { p_scossl_keysinuse_child_enabled = TRUE; } @@ -311,7 +356,7 @@ static void p_scossl_keysinuse_prepare() // Release all locks in reverse order after fork static void p_scossl_keysinuse_parent() { - if (!keysinuse_enabled) + if (!keysinuse_initialized) { return; } @@ -330,13 +375,10 @@ static void p_scossl_keysinuse_parent() static void p_scossl_keysinuse_child() { SCOSSL_PROV_KEYSINUSE_INFO *pKeysinuseInfo = NULL; - pthread_condattr_t attr; - int pthreadErr; SCOSSL_STATUS status = SCOSSL_FAILURE; int is_parent_logging = is_logging; - BOOL attr_initialized = FALSE; - if (!keysinuse_enabled) + if (!keysinuse_initialized) { return; } @@ -391,36 +433,13 @@ static void p_scossl_keysinuse_child() pthread_mutex_unlock(&logging_thread_mutex); - // Only recreate logging thread if it was running in the parent process - if (is_parent_logging && p_scossl_keysinuse_child_enabled) + // Only start the logging thread in the child process if child process + // logging is enabled and either the parent process was logging or + // parent process logging was disabled. + if (p_scossl_keysinuse_child_enabled && + (is_parent_logging || (keysinuse_process_scope & KEYSINUSE_PROCESS_SCOPE_MAIN) == 0)) { - OPENSSL_free(logging_thread_cond_wake_early); - if ((logging_thread_cond_wake_early = OPENSSL_malloc(sizeof(pthread_cond_t))) == NULL) - { - p_scossl_keysinuse_log_error("Failed to allocate condition variable"); - goto cleanup; - } - - if ((pthreadErr = pthread_condattr_init(&attr)) != 0) - { - p_scossl_keysinuse_log_error("Failed to init condition attributes,SYS_%d", pthreadErr); - goto cleanup; - } - - attr_initialized = TRUE; - is_logging = TRUE; - - if ((pthreadErr = pthread_condattr_setclock(&attr, CLOCK_MONOTONIC)) != 0 || - (pthreadErr = pthread_cond_init(logging_thread_cond_wake_early, &attr)) != 0 || - (pthreadErr = pthread_create(&logging_thread, NULL, p_scossl_keysinuse_logging_thread_start, NULL)) != 0) - { - p_scossl_keysinuse_log_error("Failed to start logging thread,SYS_%d", pthreadErr); - is_logging = FALSE; - goto cleanup; - } - - keysinuse_enabled = TRUE; - status = SCOSSL_SUCCESS; + status = p_scossl_keysinuse_create_logging_thread(); } cleanup: @@ -431,11 +450,6 @@ static void p_scossl_keysinuse_child() logging_thread_cond_wake_early = NULL; } - if (attr_initialized) - { - pthread_condattr_destroy(&attr); - } - if (status != SCOSSL_SUCCESS) { p_scossl_keysinuse_teardown(); @@ -452,6 +466,7 @@ void p_scossl_keysinuse_teardown() int pthreadErr; keysinuse_enabled = FALSE; + keysinuse_initialized = FALSE; // Finish logging thread if (is_logging) @@ -518,6 +533,15 @@ void p_scossl_keysinuse_set_logging_delay(INT64 delay) } } +void p_scossl_keysinuse_set_process_scope(UINT32 scope) +{ + if (scope != 0 && + (scope & ~(UINT32)KEYSINUSE_PROCESS_SCOPE_BOTH) == 0) + { + keysinuse_process_scope = scope; + } +} + // // KeysInUse info management // @@ -692,7 +716,7 @@ static void p_scossl_keysinuse_add_use(SCOSSL_PROV_KEYSINUSE_INFO *keysinuseInfo } else { - p_scossl_keysinuse_log_error("Add use failed to accquire mutex,SYS_%d", pthreadErr); + p_scossl_keysinuse_log_error("Add use failed to acquire mutex,SYS_%d", pthreadErr); } } } @@ -837,7 +861,7 @@ static void p_scossl_keysinuse_log_common(int level, const char *message, va_lis int fd; for (int i = 0; i < 3; i++) { - fd = open(log_path, O_WRONLY | O_APPEND | O_CREAT, 0200); + fd = open(log_path, O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC, 0200); if (fd >= 0 || errno != EACCES) { break; @@ -998,7 +1022,7 @@ static void *p_scossl_keysinuse_logging_thread_start(ossl_unused void *arg) if (pthreadErr != 0) { - p_scossl_keysinuse_log_error("Logging thread failed to accquire mutex,SYS_%d", pthreadErr); + p_scossl_keysinuse_log_error("Logging thread failed to acquire mutex,SYS_%d", pthreadErr); goto cleanup; } @@ -1025,48 +1049,54 @@ static void *p_scossl_keysinuse_logging_thread_start(ossl_unused void *arg) p_scossl_keysinuse_log_error("Failed to lock keysinuse info stack,OPENSSL_%d", ERR_get_error()); } - // Log all pending usage events under lock. We need to lock in this section - // in case fork is called - if ((pthreadErr = pthread_mutex_lock(&logging_thread_mutex)) == 0) + // Log all pending usage events. logging_thread_mutex is held only during + // the pKeysinuseInfo update and reference release to ensure the logging + // thread is not holding a lock during a fork. The slow log write is done + // outside the mutex. + while (sk_SCOSSL_PROV_KEYSINUSE_INFO_num(sk_keysinuse_info_pending) > 0) { - while (sk_SCOSSL_PROV_KEYSINUSE_INFO_num(sk_keysinuse_info_pending) > 0) + if ((pthreadErr = pthread_mutex_lock(&logging_thread_mutex)) != 0) { - pKeysinuseInfo = sk_SCOSSL_PROV_KEYSINUSE_INFO_pop(sk_keysinuse_info_pending); - if (CRYPTO_THREAD_write_lock(pKeysinuseInfo->lock)) - { - now = time(NULL); - - pKeysinuseInfo->firstLogTime = pKeysinuseInfo->lastLogTime == 0 ? now : pKeysinuseInfo->firstLogTime; - pKeysinuseInfo->lastLogTime = now; - pKeysinuseInfo->logPending = FALSE; + p_scossl_keysinuse_log_error("Logging thread failed to acquire mutex,SYS_%d", pthreadErr); + goto cleanup; + } - keysinuseInfoTmp = *pKeysinuseInfo; + pKeysinuseInfo = sk_SCOSSL_PROV_KEYSINUSE_INFO_pop(sk_keysinuse_info_pending); + if (pKeysinuseInfo != NULL && + CRYPTO_THREAD_write_lock(pKeysinuseInfo->lock)) + { + now = time(NULL); - pKeysinuseInfo->decryptCounter = 0; - pKeysinuseInfo->signCounter = 0; + pKeysinuseInfo->firstLogTime = pKeysinuseInfo->lastLogTime == 0 ? now : pKeysinuseInfo->firstLogTime; + pKeysinuseInfo->lastLogTime = now; + pKeysinuseInfo->logPending = FALSE; - CRYPTO_THREAD_unlock(pKeysinuseInfo->lock); - } - else - { - p_scossl_keysinuse_log_error("Failed to lock keysinuse info,OPENSSL_%d", ERR_get_error()); - keysinuseInfoTmp.refCount = -1; - } + keysinuseInfoTmp = *pKeysinuseInfo; - p_scossl_keysinuse_info_free(pKeysinuseInfo); + pKeysinuseInfo->decryptCounter = 0; + pKeysinuseInfo->signCounter = 0; - if (keysinuseInfoTmp.refCount > 0) - { - p_scossl_keysinuse_log_notice("%s,%d,%d,%ld,%ld", - keysinuseInfoTmp.keyIdentifier, - keysinuseInfoTmp.signCounter, - keysinuseInfoTmp.decryptCounter, - keysinuseInfoTmp.firstLogTime, - keysinuseInfoTmp.lastLogTime); - } + CRYPTO_THREAD_unlock(pKeysinuseInfo->lock); } + else + { + p_scossl_keysinuse_log_error("Failed to lock keysinuse info,OPENSSL_%d", ERR_get_error()); + keysinuseInfoTmp.refCount = -1; + } + + p_scossl_keysinuse_info_free(pKeysinuseInfo); pthread_mutex_unlock(&logging_thread_mutex); + + if (keysinuseInfoTmp.refCount > 0) + { + p_scossl_keysinuse_log_notice("%s,%d,%d,%ld,%ld", + keysinuseInfoTmp.keyIdentifier, + keysinuseInfoTmp.signCounter, + keysinuseInfoTmp.decryptCounter, + keysinuseInfoTmp.firstLogTime, + keysinuseInfoTmp.lastLogTime); + } } } while (isLoggingThreadRunning); diff --git a/SymCryptProvider/src/p_scossl_keysinuse.h b/SymCryptProvider/src/p_scossl_keysinuse.h index f0a29eee..526221a2 100644 --- a/SymCryptProvider/src/p_scossl_keysinuse.h +++ b/SymCryptProvider/src/p_scossl_keysinuse.h @@ -38,6 +38,12 @@ void p_scossl_keysinuse_set_logging_id(_In_ const char *id); void p_scossl_keysinuse_set_max_file_size(off_t size); void p_scossl_keysinuse_set_logging_delay(INT64 delay); +#define KEYSINUSE_PROCESS_SCOPE_MAIN 0x1 +#define KEYSINUSE_PROCESS_SCOPE_CHILD 0x2 +#define KEYSINUSE_PROCESS_SCOPE_BOTH (KEYSINUSE_PROCESS_SCOPE_MAIN | KEYSINUSE_PROCESS_SCOPE_CHILD) + +void p_scossl_keysinuse_set_process_scope(UINT32 scope); + // KeysInUse info management SCOSSL_PROV_KEYSINUSE_INFO *p_scossl_keysinuse_info_new(_In_reads_bytes_(cbPublicKey) PBYTE pbPublicKey, SIZE_T cbPublicKey); void p_scossl_keysinuse_info_free(_Inout_ SCOSSL_PROV_KEYSINUSE_INFO *keysinuseInfo);