From 38400ae7327c41b4f9f2997f585ea26ba3cab79d Mon Sep 17 00:00:00 2001 From: artikell <739609084@qq.com> Date: Sat, 15 Jun 2024 15:28:45 +0800 Subject: [PATCH] Enhance the test framework, add --only, --loglevel, --count option Signed-off-by: artikell <739609084@qq.com> --- src/unit/test_crc64combine.c | 25 ++++++------ src/unit/test_help.h | 40 ++++++++++++++++++- src/unit/test_intset.c | 2 +- src/unit/test_main.c | 75 ++++++++++++++++++++++++++++++------ src/unit/test_zmalloc.c | 10 ++--- 5 files changed, 120 insertions(+), 32 deletions(-) diff --git a/src/unit/test_crc64combine.c b/src/unit/test_crc64combine.c index ba5c29a42d..83d216bc19 100644 --- a/src/unit/test_crc64combine.c +++ b/src/unit/test_crc64combine.c @@ -35,7 +35,7 @@ static int bench_crc64(unsigned char *data, uint64_t size, long long passes, uin min = (original_end - original_start) * 1000 / passes; /* approximate nanoseconds without nstime */ if (csv) { - printf("%s,%" PRIu64 ",%" PRIu64 ",%d\n", name, size, (1000 * size) / min, hash == check); + TEST_PRINT_INFO("%s,%" PRIu64 ",%" PRIu64 ",%d", name, size, (1000 * size) / min, hash == check); } else { TEST_PRINT_INFO("test size=%" PRIu64 " algorithm=%s %" PRIu64 " M/sec matches=%d", size, name, (1000 * size) / min, hash == check); @@ -55,9 +55,9 @@ static void bench_combine(char *label, uint64_t size, uint64_t expect, int csv) /* ran 1000 times, want ns per, counted us per 1000 ... */ min = original_end - original_start; if (csv) { - printf("%s,%" PRIu64 ",%" PRIu64 "\n", label, size, min); + TEST_PRINT_INFO("%s,%" PRIu64 ",%" PRIu64, label, size, min); } else { - printf("%s size=%" PRIu64 " in %" PRIu64 " nsec\n", label, size, min); + TEST_PRINT_INFO("%s size=%" PRIu64 " in %" PRIu64 " nsec", label, size, min); } } @@ -97,13 +97,14 @@ int test_crc64combine(int argc, char **argv, int flags) { combine = 1; } else { invalid: - printf("Invalid option \"%s\" or option argument missing\n\n", argv[i]); + TEST_PRINT_INFO("Invalid option \"%s\" or option argument missing\n", argv[i]); usage: - printf("Usage: --single test_crc64combine.c [OPTIONS]\n\n" - " --csv Output in CSV format\n" - " -l Loop. Run the tests forever\n" - " --crc Benchmark crc64 faster options, using a buffer this big, and quit when done.\n" - " --combine Benchmark crc64 combine value ranges and timings.\n"); + TEST_PRINT_LINE( + "Usage: --single test_crc64combine.c [OPTIONS]\n\n" + " --csv Output in CSV format\n" + " -l Loop. Run the tests forever\n" + " --crc Benchmark crc64 faster options, using a buffer this big, and quit when done.\n" + " --combine Benchmark crc64 combine value ranges and timings."); return 1; } } @@ -131,7 +132,7 @@ int test_crc64combine(int argc, char **argv, int flags) { uint64_t expect = crc64(0, data, crc64_test_size); if (!combine && crc64_test_size) { - if (csv && init_this_loop) printf("algorithm,buffer,performance,crc64_matches\n"); + if (csv && init_this_loop) TEST_PRINT_LINE("algorithm,buffer,performance,crc64_matches"); /* get the single-character version for single-byte Redis behavior */ set_crc64_cutoffs(0, crc64_test_size + 1); @@ -180,8 +181,8 @@ int test_crc64combine(int argc, char **argv, int flags) { init_end -= init_start; init_end *= 1000; if (csv) { - printf("operation,size,nanoseconds\n"); - printf("init_64,%" PRIu64 ",%" PRIu64 "\n", INIT_SIZE, (uint64_t)init_end); + TEST_PRINT_LINE("operation,size,nanoseconds"); + TEST_PRINT_INFO("init_64,%" PRIu64 ",%" PRIu64, INIT_SIZE, (uint64_t)init_end); } else { TEST_PRINT_INFO("init_64 size=%" PRIu64 " in %" PRIu64 " nsec", INIT_SIZE, (uint64_t)init_end); } diff --git a/src/unit/test_help.h b/src/unit/test_help.h index 9be2f2b40e..5602cd3799 100644 --- a/src/unit/test_help.h +++ b/src/unit/test_help.h @@ -14,6 +14,7 @@ #include #include +#include /* The flags are the following: * --accurate: Runs tests with more iterations. @@ -23,15 +24,36 @@ #define UNIT_TEST_LARGE_MEMORY (1 << 1) #define UNIT_TEST_SINGLE (1 << 2) +#define LL_DEBUG 0 +#define LL_VERBOSE 1 +#define LL_NOTICE 2 +#define LL_WARNING 3 +#define LL_NOTHING 4 +#define LL_RAW (1 << 10) /* Modifier to log without timestamp */ + #define KRED "\33[31m" #define KGRN "\33[32m" #define KBLUE "\33[34m" #define KRESET "\33[0m" -#define TEST_PRINT_ERROR(descr) printf("[" KRED "%s - %s:%d" KRESET "] %s\n", __func__, __FILE__, __LINE__, descr) +int verbosity; + +#define serverLog(level, ...) \ + do { \ + if (((level) & 0xff) < verbosity) break; \ + printf(__VA_ARGS__); \ + } while (0) + +#define TEST_PRINT_ERROR(descr) \ + serverLog(LL_WARNING, "[" KRED "%s - %s:%d" KRESET "] %s\n", __func__, __FILE__, __LINE__, descr) + +#define TEST_PRINT_LINE(descr) \ + serverLog(LL_VERBOSE, "[" KBLUE "%s - %s:%d" KRESET "] " descr "\n", __func__, __FILE__, __LINE__); #define TEST_PRINT_INFO(descr, ...) \ - printf("[" KBLUE "%s - %s:%d" KRESET "] " descr "\n", __func__, __FILE__, __LINE__, __VA_ARGS__) + serverLog(LL_VERBOSE, "[" KBLUE "%s -88 %s:%d" KRESET "] " descr "\n", __func__, __FILE__, __LINE__, __VA_ARGS__); + +#define TEST_PRINT_REPORT(descr, ...) serverLog(LL_NOTICE, descr "\n", __VA_ARGS__) #define TEST_ASSERT_MESSAGE(descr, _c) \ do { \ @@ -47,4 +69,18 @@ #define UNUSED(x) (void)(x) #endif +static inline unsigned long long getMonotonicNs(void) { + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + return ((unsigned long long)ts.tv_sec) * 1000000000 + ts.tv_nsec; +} + +static inline void elapsedMonoStart(unsigned long long *start_time) { + *start_time = getMonotonicNs(); +} + +static inline unsigned long long elapsedMonoNs(unsigned long long start_time) { + return getMonotonicNs() - start_time; +} + #endif diff --git a/src/unit/test_intset.c b/src/unit/test_intset.c index f47b162184..ef1701b02a 100644 --- a/src/unit/test_intset.c +++ b/src/unit/test_intset.c @@ -208,7 +208,7 @@ int test_intsetStressLookups(int argc, char **argv, int flags) { start = usec(); for (i = 0; i < num; i++) intsetSearch(is, rand() % ((1 << bits) - 1), NULL); - TEST_PRINT_INFO("%ld lookups, %ld element set, %lldusec\n", num, size, usec() - start); + TEST_PRINT_INFO("%ld lookups, %ld element set, %lldusec", num, size, usec() - start); zfree(is); return 0; diff --git a/src/unit/test_main.c b/src/unit/test_main.c index 277d1b42c1..5e724c560f 100644 --- a/src/unit/test_main.c +++ b/src/unit/test_main.c @@ -6,49 +6,100 @@ #include #include +#include #include "test_files.h" #include "test_help.h" /* We override the default assertion mechanism, so that it prints out info and then dies. */ void _serverAssert(const char *estr, const char *file, int line) { - printf("[" KRED "serverAssert - %s:%d" KRESET "] - %s\n", file, line, estr); + TEST_PRINT_REPORT("[" KRED "serverAssert - %s:%d" KRESET "] - %s", file, line, estr); exit(1); } /* Run the tests defined by the test suite. */ -int runTestSuite(struct unitTestSuite *test, int argc, char **argv, int flags) { +int runTestSuite(struct unitTestSuite *test, int argc, char **argv, int count, char *pattern, int flags) { int test_num = 0; int failed_tests = 0; - printf("[" KBLUE "START" KRESET "] - %s\n", test->filename); + int test_result = 0; + int run_num = 0; + unsigned long long duration; + unsigned long long start_time; + + regex_t regex; + if (pattern != NULL) regcomp(®ex, pattern, 0); + TEST_PRINT_REPORT("[" KBLUE "START" KRESET "] - %s", test->filename); for (int id = 0; test->tests[id].proc != NULL; id++) { + if (pattern != NULL && regexec(®ex, test->tests[id].name, 0, NULL, 0)) { + TEST_PRINT_REPORT("[" KBLUE "skip" KRESET "] - %s:%s", test->filename, test->tests[id].name); + continue; + } + test_num++; - int test_result = (test->tests[id].proc(argc, argv, flags) != 0); + elapsedMonoStart(&start_time); + for (run_num = 0; run_num < count; run_num++) { + test_result = (test->tests[id].proc(argc, argv, flags) != 0); + if (test_result) break; + } + duration = elapsedMonoNs(start_time); if (!test_result) { - printf("[" KGRN "ok" KRESET "] - %s:%s\n", test->filename, test->tests[id].name); + TEST_PRINT_REPORT("[" KGRN "ok" KRESET "] - %s:%s\t%d\t%.4lf ns/op", test->filename, test->tests[id].name, + count, ((double)duration / count)); } else { - printf("[" KRED "fail" KRESET "] - %s:%s\n", test->filename, test->tests[id].name); + TEST_PRINT_REPORT("[" KRED "fail" KRESET "] - %s:%s", test->filename, test->tests[id].name); failed_tests++; } } - printf("[" KBLUE "END" KRESET "] - %s: ", test->filename); - printf("%d tests, %d passed, %d failed\n", test_num, test_num - failed_tests, failed_tests); + TEST_PRINT_REPORT("[" KBLUE "END" KRESET "] - %s: ", test->filename); + TEST_PRINT_REPORT("%d tests, %d passed, %d failed", test_num, test_num - failed_tests, failed_tests); return !failed_tests; } int main(int argc, char **argv) { int flags = 0; + char *pattern = NULL; char *file = NULL; + int count = 1; + regex_t regex; + + verbosity = LL_NOTICE; for (int j = 1; j < argc; j++) { char *arg = argv[j]; if (!strcasecmp(arg, "--accurate")) flags |= UNIT_TEST_ACCURATE; else if (!strcasecmp(arg, "--large-memory")) flags |= UNIT_TEST_LARGE_MEMORY; - else if (!strcasecmp(arg, "--single") && (j + 1 < argc)) { + else if (!strcasecmp(arg, "--count") && (j + 1 < argc)) { + count = atoi(argv[j + 1]); + j++; + } else if (!strcasecmp(arg, "--single") && (j + 1 < argc)) { flags |= UNIT_TEST_SINGLE; file = argv[j + 1]; + j++; + } else if (!strcasecmp(arg, "--only") && (j + 1 < argc)) { + pattern = argv[j + 1]; + if (regcomp(®ex, pattern, 0)) { + TEST_PRINT_REPORT("pattern compile error %s", pattern); + return 1; + } + j++; + } else if (!strcasecmp(arg, "--loglevel") && (j + 1 < argc)) { + if (!strcasecmp(argv[j + 1], "debug")) + verbosity = LL_DEBUG; + else if (!strcasecmp(argv[j + 1], "verbose")) + verbosity = LL_VERBOSE; + else if (!strcasecmp(argv[j + 1], "notice")) + verbosity = LL_NOTICE; + else if (!strcasecmp(argv[j + 1], "warning")) + verbosity = LL_WARNING; + else if (!strcasecmp(argv[j + 1], "nothing")) + verbosity = LL_NOTHING; + else { + TEST_PRINT_REPORT("loglevel error %s, help: debug, verbose, notice, warning, nothing", argv[j + 1]); + return 1; + } + j++; } } @@ -56,13 +107,13 @@ int main(int argc, char **argv) { int failed_num = 0, suites_executed = 0; for (int j = 0; j < numtests; j++) { if (file && strcasecmp(file, unitTestSuite[j].filename)) continue; - if (!runTestSuite(&unitTestSuite[j], argc, argv, flags)) { + if (!runTestSuite(&unitTestSuite[j], argc, argv, count, pattern, flags)) { failed_num++; } suites_executed++; } - printf("%d test suites executed, %d passed, %d failed\n", suites_executed, suites_executed - failed_num, - failed_num); + TEST_PRINT_REPORT("%d test suites executed, %d passed, %d failed", suites_executed, suites_executed - failed_num, + failed_num); return failed_num == 0 ? 0 : 1; } diff --git a/src/unit/test_zmalloc.c b/src/unit/test_zmalloc.c index 6c1d03e8e1..077bbe9b10 100644 --- a/src/unit/test_zmalloc.c +++ b/src/unit/test_zmalloc.c @@ -19,17 +19,17 @@ int test_zmallocAllocReallocCallocAndFree(int argc, char **argv, int flags) { void *ptr, *ptr2; ptr = zmalloc(123); - TEST_PRINT_INFO("Allocated 123 bytes; used: %zu\n", zmalloc_used_memory()); + TEST_PRINT_INFO("Allocated 123 bytes; used: %zu", zmalloc_used_memory()); ptr = zrealloc(ptr, 456); - TEST_PRINT_INFO("Reallocated to 456 bytes; used: %zu\n", zmalloc_used_memory()); + TEST_PRINT_INFO("Reallocated to 456 bytes; used: %zu", zmalloc_used_memory()); ptr2 = zcalloc(123); - TEST_PRINT_INFO("Callocated 123 bytes; used: %zu\n", zmalloc_used_memory()); + TEST_PRINT_INFO("Callocated 123 bytes; used: %zu", zmalloc_used_memory()); zfree(ptr); zfree(ptr2); - TEST_PRINT_INFO("Freed pointers; used: %zu\n", zmalloc_used_memory()); + TEST_PRINT_INFO("Freed pointers; used: %zu", zmalloc_used_memory()); TEST_ASSERT(zmalloc_used_memory() == 0); @@ -44,7 +44,7 @@ int test_zmallocAllocZeroByteAndFree(int argc, char **argv, int flags) { void *ptr; ptr = zmalloc(0); - TEST_PRINT_INFO("Allocated 0 bytes; used: %zu\n", zmalloc_used_memory()); + TEST_PRINT_INFO("Allocated 0 bytes; used: %zu", zmalloc_used_memory()); zfree(ptr); TEST_ASSERT(zmalloc_used_memory() == 0);