From e06c1625ca189ba3fed02f62e3a8c1f63e2e9186 Mon Sep 17 00:00:00 2001 From: Jan Michalski Date: Wed, 6 Mar 2024 14:12:33 -0500 Subject: [PATCH] common: core_log_set/get_threshold MT unit tests (part 2) - make core_log_threshold_mt a dedicated test - keep Core_log_threshold available only via API - add _core_log_get_threshold_internal() calls Ref: #6035 Signed-off-by: Jan Michalski --- src/core/log.c | 16 +- src/core/log_default.c | 4 +- src/core/log_internal.h | 12 +- src/test/Makefile | 2 +- src/test/core_log_mt/.gitignore | 1 - src/test/core_log_mt/core_log_mt.c | 105 ------------ src/test/core_log_threshold_mt/.gitignore | 1 + .../Makefile | 4 +- .../TESTS.py | 6 +- .../core_log_threshold_mt.c | 158 ++++++++++++++++++ 10 files changed, 186 insertions(+), 123 deletions(-) delete mode 100644 src/test/core_log_mt/.gitignore delete mode 100644 src/test/core_log_mt/core_log_mt.c create mode 100644 src/test/core_log_threshold_mt/.gitignore rename src/test/{core_log_mt => core_log_threshold_mt}/Makefile (73%) rename src/test/{core_log_mt => core_log_threshold_mt}/TESTS.py (82%) create mode 100644 src/test/core_log_threshold_mt/core_log_threshold_mt.c diff --git a/src/core/log.c b/src/core/log.c index de18b7c04b4..9151cb8e3bb 100644 --- a/src/core/log.c +++ b/src/core/log.c @@ -51,7 +51,7 @@ _Atomic uintptr_t Core_log_function = 0; /* threshold levels */ -enum core_log_level Core_log_threshold[] = { +static enum core_log_level Core_log_threshold[] = { CORE_LOG_THRESHOLD_DEFAULT, CORE_LOG_THRESHOLD_AUX_DEFAULT }; @@ -146,6 +146,7 @@ core_log_set_threshold(enum core_log_threshold threshold, return EINVAL; enum core_log_level level_old; + /* fed with already validated arguments it can't fail */ (void) core_log_get_threshold(threshold, &level_old); if (!__sync_bool_compare_and_swap(&Core_log_threshold[threshold], @@ -175,6 +176,17 @@ core_log_get_threshold(enum core_log_threshold threshold, return 0; } +/* + * _core_log_get_threshold_internal -- a core_log_get_threshold variant + * optimized for performance and not affecting the stack size of all + * the functions using the CORE_LOG_* macros. + */ +volatile enum core_log_level +_core_log_get_threshold_internal() +{ + return Core_log_threshold[CORE_LOG_THRESHOLD]; +} + static void inline core_log_va(char *buf, size_t buf_len, enum core_log_level level, int errnum, const char *file_name, int line_no, @@ -203,7 +215,7 @@ core_log_va(char *buf, size_t buf_len, enum core_log_level level, * the CORE_LOG() macro it has to be done here again since it is not * performed in the case of the CORE_LOG_TO_LAST macro. Sorry. */ - if (level > Core_log_threshold[CORE_LOG_THRESHOLD]) + if (level > _core_log_get_threshold_internal()) goto end; if (0 == Core_log_function) diff --git a/src/core/log_default.c b/src/core/log_default.c index 563844af97d..7f1549efce5 100644 --- a/src/core/log_default.c +++ b/src/core/log_default.c @@ -104,6 +104,7 @@ core_log_default_function(enum core_log_level level, const char *file_name, char file_info_buffer[256] = ""; const char *file_info = file_info_buffer; const char file_info_error[] = "[file info error]: "; + enum core_log_level threshold_aux; if (file_name) { /* extract base_file_name */ @@ -136,7 +137,8 @@ core_log_default_function(enum core_log_level level, const char *file_name, } /* secondary logging destination (CORE_LOG_THRESHOLD_AUX) */ - if (level <= Core_log_threshold[CORE_LOG_THRESHOLD_AUX]) { + (void) core_log_get_threshold(CORE_LOG_THRESHOLD_AUX, &threshold_aux); + if (level <= threshold_aux) { char times_tamp[45] = ""; get_timestamp_prefix(times_tamp, sizeof(times_tamp)); (void) fprintf(stderr, "%s[%ld] %s%s%s\n", times_tamp, diff --git a/src/core/log_internal.h b/src/core/log_internal.h index fb1a8bcf452..f058d871a0e 100644 --- a/src/core/log_internal.h +++ b/src/core/log_internal.h @@ -62,6 +62,8 @@ int core_log_set_threshold(enum core_log_threshold threshold, int core_log_get_threshold(enum core_log_threshold threshold, enum core_log_level *level); +volatile enum core_log_level _core_log_get_threshold_internal(void); + /* * the type used for defining logging functions */ @@ -81,13 +83,6 @@ typedef void core_log_function( int core_log_set_function(core_log_function *log_function); -/* threshold levels */ -extern -#ifdef ATOMIC_OPERATIONS_SUPPORTED -_Atomic -#endif /* ATOMIC_OPERATIONS_SUPPORTED */ -enum core_log_level Core_log_threshold[CORE_LOG_THRESHOLD_MAX]; - void core_log_init(void); void core_log_fini(void); @@ -119,7 +114,8 @@ void core_log(enum core_log_level level, int errnum, const char *file_name, #define _CORE_LOG(level, errnum, format, ...) \ do { \ - if (level <= Core_log_threshold[CORE_LOG_THRESHOLD]) { \ + if (level <= \ + _core_log_get_threshold_internal()) { \ core_log(level, errnum, __FILE__, __LINE__, \ __func__, format, ##__VA_ARGS__); \ } \ diff --git a/src/test/Makefile b/src/test/Makefile index 0f96dc0167f..1bf789e4fac 100644 --- a/src/test/Makefile +++ b/src/test/Makefile @@ -111,8 +111,8 @@ OTHER_TESTS = \ core_log_default_function\ core_log_internal\ core_log_max\ - core_log_mt\ core_log_no_func\ + core_log_threshold_mt\ checksum\ compat_incompat_features\ ctl_prefault\ diff --git a/src/test/core_log_mt/.gitignore b/src/test/core_log_mt/.gitignore deleted file mode 100644 index 806ac7ab750..00000000000 --- a/src/test/core_log_mt/.gitignore +++ /dev/null @@ -1 +0,0 @@ -core_log_mt diff --git a/src/test/core_log_mt/core_log_mt.c b/src/test/core_log_mt/core_log_mt.c deleted file mode 100644 index c69e7b714fd..00000000000 --- a/src/test/core_log_mt/core_log_mt.c +++ /dev/null @@ -1,105 +0,0 @@ -// SPDX-License-Identifier: BSD-3-Clause -/* Copyright 2024, Intel Corporation */ - -/* - * core_log_internal.c -- unit test to CORE_LOG_... - */ - -#include "unittest.h" -#include "log_internal.h" - -#define NO_ARGS_CONSUMED 0 - -#define THREADS_IN_GROUP 10 -#define TOTAL_THREADS (THREADS_IN_GROUP * 2) -#define OP_REDO 4096 - -struct test_threshold_helper_ctx { - enum core_log_threshold threshold; - enum core_log_level level; -} threshold_helper_ [TOTAL_THREADS]; - -static void * -test_threshold_helper_set(void *arg) -{ - struct test_threshold_helper_ctx *ctx = - (struct test_threshold_helper_ctx *)arg; - for (int i = 0; i < OP_REDO; ++i) { - core_log_set_threshold(ctx->threshold, ctx->level); - } - return NULL; -} - -static void * -test_threshold_helper_get(void *arg) -{ - struct test_threshold_helper_ctx *ctx = - (struct test_threshold_helper_ctx *)arg; - for (int i = 0; i < OP_REDO; ++i) { - core_log_get_threshold(ctx->threshold, &ctx->level); - } - (void) ctx->level; - return NULL; -} - -static void -test_threshold_helper(enum core_log_threshold threshold) -{ - os_thread_t threads[TOTAL_THREADS]; - - /* core_log_set_threshold() threads */ - for (int idx = 0; idx < THREADS_IN_GROUP; idx++) { - threshold_helper_[idx].threshold = threshold; - threshold_helper_[idx].level = - (enum core_log_level)(idx % CORE_LOG_LEVEL_MAX); - THREAD_CREATE(&threads[idx], 0, test_threshold_helper_set, - (void *)&threshold_helper_[idx]); - } - - /* core_log_get_threshold() threads */ - for (int idx = THREADS_IN_GROUP; idx < TOTAL_THREADS; idx++) { - threshold_helper_[idx].threshold = threshold; - THREAD_CREATE(&threads[idx], 0, test_threshold_helper_get, - (void *)&threshold_helper_[idx]); - } - - for (int idx = 0; idx < TOTAL_THREADS; idx++) { - void *retval; - THREAD_JOIN(&threads[idx], &retval); - } -} - -/* Run core_log_set/get_threshold(CORE_LOG_THRESHOLD, ...) in parallel. */ -static int -test_threshold(const struct test_case *tc, int argc, char *argv[]) -{ - test_threshold_helper(CORE_LOG_THRESHOLD); - return NO_ARGS_CONSUMED; -} - -/* Run core_log_set/get_threshold(CORE_LOG_THRESHOLD_AUX, ...) in parallel. */ -static int -test_threshold_aux(const struct test_case *tc, int argc, char *argv[]) -{ - test_threshold_helper(CORE_LOG_THRESHOLD_AUX); - return NO_ARGS_CONSUMED; -} - -/* - * A Valgrind tool external to the test binary is assumed to monitor - * the execution and assess synchronisation correctness. - */ -static struct test_case test_cases[] = { - TEST_CASE(test_threshold), - TEST_CASE(test_threshold_aux), -}; - -#define NTESTS ARRAY_SIZE(test_cases) - -int -main(int argc, char *argv[]) -{ - START(argc, argv, "core_log_mt"); - TEST_CASE_PROCESS(argc, argv, test_cases, NTESTS); - DONE(NULL); -} diff --git a/src/test/core_log_threshold_mt/.gitignore b/src/test/core_log_threshold_mt/.gitignore new file mode 100644 index 00000000000..c949af1fe1d --- /dev/null +++ b/src/test/core_log_threshold_mt/.gitignore @@ -0,0 +1 @@ +core_log_threshold_mt diff --git a/src/test/core_log_mt/Makefile b/src/test/core_log_threshold_mt/Makefile similarity index 73% rename from src/test/core_log_mt/Makefile rename to src/test/core_log_threshold_mt/Makefile index 8df2f390710..2c7ad36734d 100644 --- a/src/test/core_log_mt/Makefile +++ b/src/test/core_log_threshold_mt/Makefile @@ -1,8 +1,8 @@ # SPDX-License-Identifier: BSD-3-Clause # Copyright 2024, Intel Corporation -TARGET = core_log_mt -OBJS = core_log_mt.o +TARGET = core_log_threshold_mt +OBJS = core_log_threshold_mt.o BUILD_STATIC_DEBUG=n BUILD_STATIC_NONDEBUG=n diff --git a/src/test/core_log_mt/TESTS.py b/src/test/core_log_threshold_mt/TESTS.py similarity index 82% rename from src/test/core_log_mt/TESTS.py rename to src/test/core_log_threshold_mt/TESTS.py index 13a2377e89f..2b94d1a250c 100755 --- a/src/test/core_log_mt/TESTS.py +++ b/src/test/core_log_threshold_mt/TESTS.py @@ -14,15 +14,15 @@ class CORE_LOG_MT(t.BaseTest): test_type = t.Short def run(self, ctx): - ctx.exec('core_log_mt', self.test_case) + ctx.exec('core_log_threshold_mt', self.test_case) class THRESHOLD(CORE_LOG_MT): - test_case = 'test_threshold' + test_case = 'test_threshold_set_get' class THRESHOLD_AUX(CORE_LOG_MT): - test_case = 'test_threshold_aux' + test_case = 'test_threshold_aux_set_get' @t.require_valgrind_enabled('helgrind') diff --git a/src/test/core_log_threshold_mt/core_log_threshold_mt.c b/src/test/core_log_threshold_mt/core_log_threshold_mt.c new file mode 100644 index 00000000000..39abf21c66e --- /dev/null +++ b/src/test/core_log_threshold_mt/core_log_threshold_mt.c @@ -0,0 +1,158 @@ +// SPDX-License-Identifier: BSD-3-Clause +/* Copyright 2024, Intel Corporation */ + +/* + * core_log_threshold_mt.c -- unit test for core_log_set/get_threshold() and + * CORE_LOG_X() since all of them may write/read thresholds in parallel. + */ + +#include "unittest.h" +#include "log_internal.h" + +#define NO_ARGS_CONSUMED 0 + +#define THREADS_IN_GROUP 10 +#define THREADS_SET_MIN 0 +#define THREADS_SET_MAX (THREADS_SET_MIN + THREADS_IN_GROUP) +#define THREADS_GET_MIN THREADS_SET_MAX +#define THREADS_GET_MAX (THREADS_GET_MIN + THREADS_IN_GROUP) +#define TOTAL_THREADS THREADS_GET_MAX + +#define OP_REDO 4096 + +struct helper_ctx { + enum core_log_threshold threshold; + int idx; +} helper_ctx_ [TOTAL_THREADS]; + +os_mutex_t mutex; +os_cond_t cond; +unsigned threads_waiting; + +static void * +helper_set(void *arg) +{ + struct helper_ctx *ctx = (struct helper_ctx *)arg; + os_mutex_lock(&mutex); + ++threads_waiting; + os_cond_wait(&cond, &mutex); + os_mutex_unlock(&mutex); + for (int i = 0; i < OP_REDO; ++i) { + /* + * a simple attempt to generate a different sequence of values + * for each of the threads + */ + enum core_log_level level = + (enum core_log_level)((i * (ctx->idx + 1)) % + CORE_LOG_LEVEL_MAX); + int ret = core_log_set_threshold(ctx->threshold, level); + UT_ASSERT(ret == 0 || ret == EAGAIN); + if (ret == EAGAIN) { + UT_OUT("ret == EAGAIN"); /* just out of curiosity */ + } + } + return NULL; +} + +static void * +helper_get(void *arg) +{ + struct helper_ctx *ctx = (struct helper_ctx *)arg; + os_mutex_lock(&mutex); + ++threads_waiting; + os_cond_wait(&cond, &mutex); + os_mutex_unlock(&mutex); + for (int i = 0; i < OP_REDO; ++i) { + enum core_log_level level; + int ret = core_log_get_threshold(ctx->threshold, &level); + UT_ASSERTeq(ret, 0); + level = _core_log_get_threshold_internal(); + } + return NULL; +} + +static void +helper(enum core_log_threshold threshold) +{ + os_thread_t threads[TOTAL_THREADS]; + + os_mutex_init(&mutex); + os_cond_init(&cond); + threads_waiting = 0; + + /* core_log_set_threshold() threads */ + for (int idx = THREADS_SET_MIN; idx < THREADS_SET_MAX; idx++) { + helper_ctx_[idx].threshold = threshold; + helper_ctx_[idx].idx = idx; + THREAD_CREATE(&threads[idx], 0, helper_set, + (void *)&helper_ctx_[idx]); + } + + /* core_log_get_threshold/_core_log_get_threshold_internal() threads */ + for (int idx = THREADS_GET_MIN; idx < THREADS_GET_MAX; idx++) { + helper_ctx_[idx].threshold = threshold; + THREAD_CREATE(&threads[idx], 0, helper_get, + (void *)&helper_ctx_[idx]); + } + + do { + os_mutex_lock(&mutex); + if (threads_waiting == TOTAL_THREADS) { + os_cond_broadcast(&cond); + os_mutex_unlock(&mutex); + break; + } + os_mutex_unlock(&mutex); + } while (1); + + for (int idx = 0; idx < TOTAL_THREADS; idx++) { + void *retval; + THREAD_JOIN(&threads[idx], &retval); + } + + os_cond_destroy(&cond); + os_mutex_destroy(&mutex); +} + +/* tests */ + +/* + * Run core_log_set/get_threshold(CORE_LOG_THRESHOLD, ...) and CORE_LOG_X() + * in parallel. + */ +static int +test_threshold_set_get(const struct test_case *tc, int argc, char *argv[]) +{ + helper(CORE_LOG_THRESHOLD); + return NO_ARGS_CONSUMED; +} + +/* + * Run core_log_set/get_threshold(CORE_LOG_THRESHOLD_AUX, ...) and CORE_LOG_X() + * in parallel. + */ +static int +test_threshold_aux_set_get(const struct test_case *tc, int argc, char *argv[]) +{ + helper(CORE_LOG_THRESHOLD_AUX); + return NO_ARGS_CONSUMED; +} + +/* + * A Valgrind tool external to the test binary is assumed to monitor + * the execution and assess synchronisation correctness. + */ +static struct test_case test_cases[] = { + TEST_CASE(test_threshold_set_get), + TEST_CASE(test_threshold_aux_set_get), +}; + +#define NTESTS ARRAY_SIZE(test_cases) + +int +main(int argc, char *argv[]) +{ + START(argc, argv, "core_log_threshold_mt"); + TEST_CASE_PROCESS(argc, argv, test_cases, NTESTS); + DONE(NULL); +}