Merge pull request #6041 from janekmi/core_log_set_function-MT

common: add core_log_set_function() MT unit test

src/core/log.c

@@ -18,9 +18,6 @@
 #include <syslog.h>
 #include <time.h>
 #include <errno.h>
-#ifdef ATOMIC_OPERATIONS_SUPPORTED
-#include <stdatomic.h>
-#endif /* ATOMIC_OPERATIONS_SUPPORTED */
 #include <stdio.h>
 
 #include "log_internal.h"
@@ -40,15 +37,11 @@
 #endif
 
 /*
- * Core_log_function -- pointer to the logging function saved as uintptr_t to
- * make it _Atomic, because function pointers cannot be _Atomic. By default it
- * is core_log_default_function(), but could be a user-defined logging function
+ * Core_log_function -- pointer to the logging function. By default it is
+ * core_log_default_function(), but could be a user-defined logging function
  * provided via core_log_set_function().
  */
-#ifdef ATOMIC_OPERATIONS_SUPPORTED
-_Atomic
-#endif /* ATOMIC_OPERATIONS_SUPPORTED */
-uintptr_t Core_log_function = 0;
+static core_log_function *Core_log_function = NULL;
 
 /* threshold levels */
 static enum core_log_level Core_log_threshold[] = {
@@ -87,7 +80,7 @@ core_log_fini()
 	 * the previous value was the default logging function or a user
 	 * logging function.
 	 */
-	Core_log_function = 0;
+	Core_log_function = NULL;
 
 	/* cleanup the default logging function */
 	core_log_default_fini();
@@ -116,19 +109,13 @@ core_log_set_function(core_log_function *log_function)
 	if (log_function == CORE_LOG_USE_DEFAULT_FUNCTION)
 		log_function = core_log_default_function;
 
-#ifdef ATOMIC_OPERATIONS_SUPPORTED
-	atomic_store_explicit(&Core_log_function, (uintptr_t)log_function,
-		__ATOMIC_SEQ_CST);
-	return 0;
-#else
-	uintptr_t core_log_function_old = Core_log_function;
+	core_log_function *core_log_function_old = Core_log_function;
 	if (__sync_bool_compare_and_swap(&Core_log_function,
-			core_log_function_old, (uintptr_t)log_function)) {
+			core_log_function_old, log_function)) {
 		core_log_lib_info();
 		return 0;
 	}
 	return EAGAIN;
-#endif /* ATOMIC_OPERATIONS_SUPPORTED */
 }
 
 /*
@@ -218,11 +205,10 @@ core_log_va(char *buf, size_t buf_len, enum core_log_level level,
 	if (level > _core_log_get_threshold_internal())
 		goto end;
 
-	if (0 == Core_log_function)
+	if (NULL == Core_log_function)
 		goto end;
 
-	((core_log_function *)Core_log_function)(level, file_name, line_no,
-		function_name, buf);
+	Core_log_function(level, file_name, line_no, function_name, buf);
 
 end:
 	if (errnum != NO_ERRNO)

src/test/Makefile

@@ -109,6 +109,7 @@ OTHER_TESTS = \
 	arch_flags\
 	core_log\
 	core_log_default_function\
+	core_log_function_mt\
 	core_log_internal\
 	core_log_max\
 	core_log_no_func\

src/test/core_log_function_mt/.gitignore

@@ -0,0 +1 @@
+core_log_function_mt

src/test/core_log_function_mt/Makefile

@@ -0,0 +1,12 @@
+# SPDX-License-Identifier: BSD-3-Clause
+# Copyright 2024, Intel Corporation
+
+TARGET = core_log_function_mt
+OBJS = core_log_function_mt.o
+
+BUILD_STATIC_DEBUG=n
+BUILD_STATIC_NONDEBUG=n
+
+LIBPMEMCORE=nondebug
+
+include ../Makefile.inc

src/test/core_log_function_mt/TESTS.py

@@ -0,0 +1,30 @@
+#!../env.py
+# SPDX-License-Identifier: BSD-3-Clause
+# Copyright 2024, Intel Corporation
+#
+
+
+import testframework as t
+from testframework import granularity as g
+
+
+@g.require_granularity(g.ANY)
+# The 'nondebug' build is chosen arbitrarily to ensure these tests are run only
+# once. No dynamic libraries are used nor .static_* builds are available.
+@t.require_build('nondebug')
+class TEST0(t.BaseTest):
+    test_type = t.Short
+    test_case = 'test_function_set_call'
+
+    def run(self, ctx):
+        ctx.exec('core_log_function_mt', self.test_case)
+
+
+@t.require_valgrind_enabled('helgrind')
+class TEST1(TEST0):
+    pass
+
+
+@t.require_valgrind_enabled('drd')
+class TEST2(TEST0):
+    pass

src/test/core_log_function_mt/core_log_function_mt.c

@@ -0,0 +1,155 @@
+// SPDX-License-Identifier: BSD-3-Clause
+/* Copyright 2024, Intel Corporation */
+
+/*
+ * core_log_function_mt.c -- unit test for core_log_set_function() and
+ * core_log() since both of them may write/read the log function pointer 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_CALL_MIN THREADS_SET_MAX
+#define THREADS_CALL_MAX (THREADS_CALL_MIN + THREADS_IN_GROUP)
+#define TOTAL_THREADS THREADS_CALL_MAX
+
+#define OP_REDO 4096
+
+#define LOG_FUNC(FUNC_NAME) \
+static void \
+FUNC_NAME(enum core_log_level level, const char *file_name, const int line_no, \
+	const char *function_name, const char *message) \
+{ \
+	SUPPRESS_UNUSED(level, file_name, line_no, function_name, message); \
+}
+
+LOG_FUNC(log_func0)
+LOG_FUNC(log_func1)
+LOG_FUNC(log_func2)
+LOG_FUNC(log_func3)
+LOG_FUNC(log_func4)
+LOG_FUNC(log_func5)
+LOG_FUNC(log_func6)
+LOG_FUNC(log_func7)
+LOG_FUNC(log_func8)
+LOG_FUNC(log_func9)
+
+core_log_function *log_funcs[] = {
+	log_func0,
+	log_func1,
+	log_func2,
+	log_func3,
+	log_func4,
+	log_func5,
+	log_func6,
+	log_func7,
+	log_func8,
+	log_func9,
+};
+
+#define N_LOG_FUNCS ARRAY_SIZE(log_funcs)
+
+os_mutex_t mutex;
+os_cond_t cond;
+unsigned threads_waiting;
+
+static void *
+helper_set(void *arg)
+{
+	uint64_t idx = (uint64_t)arg;
+	os_mutex_lock(&mutex);
+	++threads_waiting;
+	os_cond_wait(&cond, &mutex);
+	os_mutex_unlock(&mutex);
+	for (uint64_t i = 0; i < OP_REDO; ++i) {
+		core_log_function *log_func =
+			log_funcs[(i * (idx + 1)) % N_LOG_FUNCS];
+		int ret = core_log_set_function(log_func);
+		UT_ASSERT(ret == 0 || ret == EAGAIN);
+		if (ret == EAGAIN) {
+			UT_OUT("ret == EAGAIN"); /* just out of curiosity */
+		}
+	}
+	return NULL;
+}
+
+static void *
+helper_call(void *arg)
+{
+	SUPPRESS_UNUSED(arg);
+
+	os_mutex_lock(&mutex);
+	++threads_waiting;
+	os_cond_wait(&cond, &mutex);
+	os_mutex_unlock(&mutex);
+	for (uint64_t i = 0; i < OP_REDO; ++i) {
+		core_log(CORE_LOG_LEVEL_ERROR, NO_ERRNO, "", 0, "", "");
+	}
+	return NULL;
+}
+
+/* tests */
+
+/* Run core_log_set_function() and core_log() in parallel. */
+static int
+test_function_set_call(const struct test_case *tc, int argc, char *argv[])
+{
+	os_thread_t threads[TOTAL_THREADS];
+
+	os_mutex_init(&mutex);
+	os_cond_init(&cond);
+	threads_waiting = 0;
+
+	/* core_log_set_function() threads */
+	for (uint64_t idx = THREADS_SET_MIN; idx < THREADS_SET_MAX; idx++) {
+		THREAD_CREATE(&threads[idx], 0, helper_set, (void *)idx);
+	}
+
+	/* core_log() threads */
+	for (uint64_t idx = THREADS_CALL_MIN; idx < THREADS_CALL_MAX; idx++) {
+		THREAD_CREATE(&threads[idx], 0, helper_call, NULL);
+	}
+
+	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 (uint64_t idx = 0; idx < TOTAL_THREADS; idx++) {
+		void *retval;
+		THREAD_JOIN(&threads[idx], &retval);
+	}
+
+	os_cond_destroy(&cond);
+	os_mutex_destroy(&mutex);
+	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_function_set_call),
+};
+
+#define NTESTS ARRAY_SIZE(test_cases)
+
+int
+main(int argc, char *argv[])
+{
+	START(argc, argv, "core_log_function_mt");
+	TEST_CASE_PROCESS(argc, argv, test_cases, NTESTS);
+	DONE(NULL);
+}

src/test/core_log_threshold_mt/TESTS.py

@@ -17,29 +17,29 @@ def run(self, ctx):
         ctx.exec('core_log_threshold_mt', self.test_case)
 
 
-class THRESHOLD(CORE_LOG_MT):
+class TEST0(CORE_LOG_MT):
     test_case = 'test_threshold_set_get'
 
 
-class THRESHOLD_AUX(CORE_LOG_MT):
-    test_case = 'test_threshold_aux_set_get'
-
-
 @t.require_valgrind_enabled('helgrind')
-class TEST0(THRESHOLD):
+class TEST1(TEST0):
     pass
 
 
 @t.require_valgrind_enabled('drd')
-class TEST1(THRESHOLD):
+class TEST2(TEST0):
     pass
 
 
+class TEST3(CORE_LOG_MT):
+    test_case = 'test_threshold_aux_set_get'
+
+
 @t.require_valgrind_enabled('helgrind')
-class TEST2(THRESHOLD_AUX):
+class TEST4(TEST3):
     pass
 
 
 @t.require_valgrind_enabled('drd')
-class TEST3(THRESHOLD_AUX):
+class TEST5(TEST3):
     pass