Merge pull request #6033 from janekmi/core_log-ut

test: introduce core_log() unit tests

src/core/log_internal.h

@@ -83,20 +83,6 @@ typedef void core_log_function(
 
 int core_log_set_function(core_log_function *log_function, void *context);
 
-/* pointer to the logging function */
-extern
-#ifdef ATOMIC_OPERATIONS_SUPPORTED
-_Atomic
-#endif /* ATOMIC_OPERATIONS_SUPPORTED */
-uintptr_t Core_log_function;
-
-/* the logging function's context */
-extern
-#ifdef ATOMIC_OPERATIONS_SUPPORTED
-_Atomic
-#endif /* ATOMIC_OPERATIONS_SUPPORTED */
-void *Core_log_function_context;
-
 /* threshold levels */
 extern
 #ifdef ATOMIC_OPERATIONS_SUPPORTED

src/test/Makefile

@@ -107,10 +107,12 @@ OBJ_TESTS = \
 
 OTHER_TESTS = \
 	arch_flags\
-	core_log_internal\
+	core_log\
 	core_log_default_function\
+	core_log_internal\
 	core_log_max\
 	core_log_mt\
+	core_log_no_func\
 	checksum\
 	compat_incompat_features\
 	ctl_prefault\

src/test/core_log/.gitignore

@@ -0,0 +1 @@
+core_log

src/test/core_log/Makefile

@@ -0,0 +1,7 @@
+# SPDX-License-Identifier: BSD-3-Clause
+# Copyright 2024, Intel Corporation
+
+TARGET = core_log
+OBJS = core_log.o core_log_common.o
+
+include ./Makefile.inc

src/test/core_log/Makefile.inc

@@ -0,0 +1,12 @@
+# SPDX-License-Identifier: BSD-3-Clause
+# Copyright 2024, Intel Corporation
+
+BUILD_STATIC_DEBUG=n
+BUILD_STATIC_NONDEBUG=n
+
+# 'internal' is required for proper mock integration
+# 'debug' provides 'out_log()' required for 'ut_log_function()'
+LIBPMEMCORE=internal-debug
+
+include ../Makefile.inc
+LDFLAGS += $(call extract_funcs, ../core_log/core_log_common.c)

src/test/core_log/TESTS.py

@@ -0,0 +1,47 @@
+#!../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 CORE_LOG(t.BaseTest):
+    test_type = t.Short
+
+    def run(self, ctx):
+        ctx.exec('core_log', self.test_case)
+
+
+class TEST0(CORE_LOG):
+    test_case = 'test_CORE_LOG_LEVEL_ERROR_LAST'
+
+
+class TEST1(CORE_LOG):
+    test_case = 'test_vsnprintf_fail'
+
+
+class TEST2(CORE_LOG):
+    test_case = 'test_NO_ERRNO'
+
+
+class TEST3(CORE_LOG):
+    test_case = 'test_no_space_for_strerror_r'
+
+
+class TEST4(CORE_LOG):
+    test_case = 'test_strerror_r_fail'
+
+
+class TEST5(CORE_LOG):
+    test_case = 'test_level_gt_threshold'
+
+
+class TEST6(CORE_LOG):
+    test_case = 'test_happy_day'

src/test/core_log/core_log.c

@@ -0,0 +1,224 @@
+// SPDX-License-Identifier: BSD-3-Clause
+/* Copyright 2024, Intel Corporation */
+
+/*
+ * core_log.c -- unit test for core_log() and core_log_va()
+ */
+
+#include <syslog.h>
+
+#include "last_error_msg.h"
+#include "unittest.h"
+
+#include "core_log_common.h"
+
+/* tests */
+
+/*
+ * Check:
+ * - CORE_LOG_LEVEL_ERROR_LAST -> CORE_LOG_LEVEL_ERROR
+ * - buf == last_error_msg_get();
+ * - buf_len == CORE_LAST_ERROR_MSG_MAXPRINT
+ */
+static int
+test_CORE_LOG_LEVEL_ERROR_LAST(const struct test_case *tc, int argc,
+	char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	reset_mocks();
+
+	/* set the expectations */
+	Common.use_last_error_msg = true;
+	Vsnprintf_.ret = 0; /* empty but successful */
+	Log_function_.exp_level = CORE_LOG_LEVEL_ERROR;
+
+	core_log(CORE_LOG_LEVEL_ERROR_LAST, NO_ERRNO, FILE_NAME, LINE_NO,
+		FUNC_NAME, MSG_FORMAT);
+
+	/* check the call counters */
+	UT_ASSERTeq(RCOUNTER(last_error_msg_get), CALLED);
+	UT_ASSERTeq(RCOUNTER(vsnprintf), CALLED);
+	UT_ASSERTeq(RCOUNTER(__xpg_strerror_r), NOT_CALLED);
+	UT_ASSERTeq(RCOUNTER(core_log_default_function), CALLED);
+	return NO_ARGS_CONSUMED;
+}
+
+/*
+ * Check:
+ * - The log preparation stops after the failed vsnprintf() call.
+ * - The log function is not called.
+ */
+static int
+test_vsnprintf_fail(const struct test_case *tc, int argc, char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	reset_mocks();
+
+	/* set the expectations */
+	Vsnprintf_.ret = -1; /* negative value if an output error */
+	Log_function_.exp_level = CORE_LOG_LEVEL_ERROR;
+	Common.use_last_error_msg = false;
+
+	core_log(CORE_LOG_LEVEL_ERROR, NO_ERRNO, FILE_NAME, LINE_NO,
+		FUNC_NAME, MSG_FORMAT);
+
+	/* check the call counters */
+	UT_ASSERTeq(RCOUNTER(last_error_msg_get), NOT_CALLED);
+	UT_ASSERTeq(RCOUNTER(vsnprintf), CALLED);
+	UT_ASSERTeq(RCOUNTER(__xpg_strerror_r), NOT_CALLED);
+	UT_ASSERTeq(RCOUNTER(core_log_default_function), NOT_CALLED);
+	return NO_ARGS_CONSUMED;
+}
+
+/*
+ * Check:
+ * - NO_ERRNO means no strerror_r() call.
+ * - The produced log message is passed to the log function.
+ */
+static int
+test_NO_ERRNO(const struct test_case *tc, int argc, char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	reset_mocks();
+
+	/* set the expectations */
+	Vsnprintf_.ret = 0; /* leave a lot of space for the error string */
+	Log_function_.exp_level = CORE_LOG_LEVEL_ERROR;
+	Common.use_last_error_msg = false;
+
+	core_log(CORE_LOG_LEVEL_ERROR, NO_ERRNO, FILE_NAME, LINE_NO,
+		FUNC_NAME, MSG_FORMAT);
+
+	/* check the call counters */
+	UT_ASSERTeq(RCOUNTER(last_error_msg_get), NOT_CALLED);
+	UT_ASSERTeq(RCOUNTER(vsnprintf), CALLED);
+	UT_ASSERTeq(RCOUNTER(__xpg_strerror_r), NOT_CALLED);
+	UT_ASSERTeq(RCOUNTER(core_log_default_function), CALLED);
+	return NO_ARGS_CONSUMED;
+}
+
+/*
+ * Check:
+ * - fully fill the provided buffer in three ways:
+ *   (1) exactly (`- 1` for the terminating null-byte)
+ *   (2) one character too many (the null-byte would end up just after
+ *       the actual buffer space)
+ *   (3) two characters too many (no space for one character of the message and
+ *       for the null-byte)
+ * - the strerror_r() is not called despite an errno is provided.
+ */
+static int
+test_no_space_for_strerror_r(const struct test_case *tc, int argc, char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	for (int i = _CORE_LOG_MSG_MAXPRINT - 1;
+			i <= _CORE_LOG_MSG_MAXPRINT + 1; ++i) {
+		test_no_space_for_strerror_r_helper(i);
+	}
+
+	return NO_ARGS_CONSUMED;
+}
+
+/*
+ * Check:
+ * - strerror_r() fails in two ways:
+ *   (1) before glibc 2.13
+ *   (2) since glibc 2.13
+ * - The produced log message is passed to the log function.
+ */
+static int
+test_strerror_r_fail(const struct test_case *tc, int argc, char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	test_strerror_r_fail_helper(true);
+	test_strerror_r_fail_helper(false);
+
+	return NO_ARGS_CONSUMED;
+}
+
+/*
+ * Check:
+ * - if level <= threshold:
+ *   - the log function is called
+ * - else:
+ *   - the log function is not called
+ */
+static int
+test_level_gt_threshold(const struct test_case *tc, int argc, char *argv[])
+{
+	for (enum core_log_level threshold = CORE_LOG_LEVEL_HARK;
+			threshold < CORE_LOG_LEVEL_MAX; ++threshold) {
+		core_log_set_threshold(CORE_LOG_THRESHOLD, threshold);
+
+		for (enum core_log_level level = CORE_LOG_LEVEL_HARK;
+				level < CORE_LOG_LEVEL_MAX; ++level) {
+			bool log_function_called = (level <= threshold);
+			test_log_function_call_helper(level,
+				log_function_called);
+		}
+	}
+
+	return NO_ARGS_CONSUMED;
+}
+
+static int
+test_happy_day(const struct test_case *tc, int argc, char *argv[])
+{
+	/* Pass the message all the way to the logging function. */
+	core_log_set_threshold(CORE_LOG_THRESHOLD, CORE_LOG_LEVEL_ERROR);
+
+	reset_mocks();
+
+	/* set the expectations */
+	Vsnprintf_.ret = BASIC_MESSAGE_LEN;
+	Log_function_.exp_level = CORE_LOG_LEVEL_ERROR;
+	Common.use_last_error_msg = true;
+	Strerror_r.exp__buf = LAST_ERROR_MSG_MOCK + Vsnprintf_.ret;
+	Strerror_r.exp__buflen = CORE_LAST_ERROR_MSG_MAXPRINT -
+		(size_t)Vsnprintf_.ret;
+	Strerror_r.error = EXIT_SUCCESS;
+
+	core_log(CORE_LOG_LEVEL_ERROR_LAST, DUMMY_ERRNO1, FILE_NAME, LINE_NO,
+		FUNC_NAME, MSG_FORMAT);
+
+	/* check the call counters */
+	UT_ASSERTeq(RCOUNTER(last_error_msg_get), CALLED);
+	UT_ASSERTeq(RCOUNTER(vsnprintf), CALLED);
+	UT_ASSERTeq(RCOUNTER(__xpg_strerror_r), CALLED);
+	UT_ASSERTeq(RCOUNTER(core_log_default_function), CALLED);
+
+	return NO_ARGS_CONSUMED;
+}
+
+static struct test_case test_cases[] = {
+	TEST_CASE(test_CORE_LOG_LEVEL_ERROR_LAST),
+	TEST_CASE(test_vsnprintf_fail),
+	TEST_CASE(test_NO_ERRNO),
+	TEST_CASE(test_no_space_for_strerror_r),
+	TEST_CASE(test_strerror_r_fail),
+	TEST_CASE(test_level_gt_threshold),
+	TEST_CASE(test_happy_day),
+};
+
+#define NTESTS ARRAY_SIZE(test_cases)
+
+int
+main(int argc, char *argv[])
+{
+	START(argc, argv, "core_log");
+	core_log_set_function(CORE_LOG_USE_DEFAULT_FUNCTION, NULL);
+	openlog(NULL, LOG_NDELAY, LOG_USER);
+	TEST_CASE_PROCESS(argc, argv, test_cases, NTESTS);
+	closelog();
+	DONE(NULL);
+}