From 9fa1a428a45eabff0122e199a687068f0e6280dd Mon Sep 17 00:00:00 2001 From: nirenjan Date: Mon, 19 Jul 2021 09:50:42 -0700 Subject: [PATCH] Squashed 'lib/pinelog/' changes from b5457f4..321d9aa 321d9aa Add benchmark program to tests a6e789e Remove config.h.in - this is autogenerated a3eb2c0 Add method to close output stream and reset to default fb9b51a Fix format-literal error in clang git-subtree-dir: lib/pinelog git-subtree-split: 321d9aaa0eee4b4af4be52c228662c3d32c32ab6 --- .gitignore | 1 - Makefile.am | 52 ++++++++++++++++++++++++++++++- bench_pinelog.c | 82 +++++++++++++++++++++++++++++++++++++++++++++++++ config.h.in | 67 ---------------------------------------- configure.ac | 1 + pinelog.c | 17 +++++++--- pinelog.h | 5 +++ test_pinelog.c | 23 ++++++-------- 8 files changed, 162 insertions(+), 86 deletions(-) create mode 100644 bench_pinelog.c delete mode 100644 config.h.in diff --git a/.gitignore b/.gitignore index 3cd4832..6166c2c 100644 --- a/.gitignore +++ b/.gitignore @@ -15,7 +15,6 @@ autom4te.cache m4 compile config.* -!config.h.in configure depcomp install-sh diff --git a/Makefile.am b/Makefile.am index ba23573..2eea553 100644 --- a/Makefile.am +++ b/Makefile.am @@ -20,6 +20,7 @@ libpinelog_la_CFLAGS = @PINELOG_CFLAGS@ $(WARN_CFLAGS) -I $(top_builddir) libpinelog_la_LDFLAGS = $(WARN_LDFLAGS) test_SRCFILES = test_pinelog.c $(libpinelog_la_SOURCES) +bench_SRCFILES = bench_pinelog.c $(libpinelog_la_SOURCES) test_CFLAGS = \ -DPINELOG_FATAL_STR='"F"' \ -DPINELOG_ERROR_STR='"E"' \ @@ -40,7 +41,15 @@ TESTS = \ test_nots_lvl_tr \ test_nots_lvl_notr \ test_nots_nolvl_tr \ - test_nots_nolvl_notr + test_nots_nolvl_notr \ + bench_ts_lvl_tr \ + bench_ts_lvl_notr \ + bench_ts_nolvl_tr \ + bench_ts_nolvl_notr \ + bench_nots_lvl_tr \ + bench_nots_lvl_notr \ + bench_nots_nolvl_tr \ + bench_nots_nolvl_notr check_PROGRAMS = $(TESTS) test_ts_lvl_tr_SOURCES = $(test_SRCFILES) @@ -82,3 +91,44 @@ test_nots_nolvl_notr_SOURCES = $(test_SRCFILES) test_nots_nolvl_notr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ -DPINELOG_SHOW_DATE=0 -DPINELOG_SHOW_LEVEL=0 -DPINELOG_SHOW_BACKTRACE=0 test_nots_nolvl_notr_LDFLAGS = $(WARN_LDFLAGS) + +bench_ts_lvl_tr_SOURCES = $(bench_SRCFILES) +bench_ts_lvl_tr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=1 -DPINELOG_SHOW_LEVEL=1 -DPINELOG_SHOW_BACKTRACE=1 +bench_ts_lvl_tr_LDFLAGS = $(WARN_LDFLAGS) + +bench_ts_lvl_notr_SOURCES = $(bench_SRCFILES) +bench_ts_lvl_notr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=1 -DPINELOG_SHOW_LEVEL=1 -DPINELOG_SHOW_BACKTRACE=0 +bench_ts_lvl_notr_LDFLAGS = $(WARN_LDFLAGS) + +bench_ts_nolvl_tr_SOURCES = $(bench_SRCFILES) +bench_ts_nolvl_tr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=1 -DPINELOG_SHOW_LEVEL=0 -DPINELOG_SHOW_BACKTRACE=1 +bench_ts_nolvl_tr_LDFLAGS = $(WARN_LDFLAGS) + +bench_ts_nolvl_notr_SOURCES = $(bench_SRCFILES) +bench_ts_nolvl_notr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=1 -DPINELOG_SHOW_LEVEL=0 -DPINELOG_SHOW_BACKTRACE=0 +bench_ts_nolvl_notr_LDFLAGS = $(WARN_LDFLAGS) + +bench_nots_lvl_tr_SOURCES = $(bench_SRCFILES) +bench_nots_lvl_tr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=0 -DPINELOG_SHOW_LEVEL=1 -DPINELOG_SHOW_BACKTRACE=1 +bench_nots_lvl_tr_LDFLAGS = $(WARN_LDFLAGS) + +bench_nots_lvl_notr_SOURCES = $(bench_SRCFILES) +bench_nots_lvl_notr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=0 -DPINELOG_SHOW_LEVEL=1 -DPINELOG_SHOW_BACKTRACE=0 +bench_nots_lvl_notr_LDFLAGS = $(WARN_LDFLAGS) + +bench_nots_nolvl_tr_SOURCES = $(bench_SRCFILES) +bench_nots_nolvl_tr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=0 -DPINELOG_SHOW_LEVEL=0 -DPINELOG_SHOW_BACKTRACE=1 +bench_nots_nolvl_tr_LDFLAGS = $(WARN_LDFLAGS) + +bench_nots_nolvl_notr_SOURCES = $(bench_SRCFILES) +bench_nots_nolvl_notr_CFLAGS = $(WARN_CFLAGS) $(test_CFLAGS) \ + -DPINELOG_SHOW_DATE=0 -DPINELOG_SHOW_LEVEL=0 -DPINELOG_SHOW_BACKTRACE=0 +bench_nots_nolvl_notr_LDFLAGS = $(WARN_LDFLAGS) + diff --git a/bench_pinelog.c b/bench_pinelog.c new file mode 100644 index 0000000..e9d6b8b --- /dev/null +++ b/bench_pinelog.c @@ -0,0 +1,82 @@ +/* + * Pinelog lightweight logging library - test harness + * + * Copyright (C) 2021 Nirenjan Krishnan (nirenjan@nirenjan.org) + * + * SPDX-License-Identifier: MIT + */ + + +#define pinelog_exit(_) +#include "pinelog.h" + +#include +#include +#include + +#define BENCH_COUNT 100000 + +static void print_time_difference(const char *type, struct timespec *ts) +{ + struct timespec ret; + uint64_t timeper; + uint64_t tp_usec; + uint64_t tp_nsec; + + // ts is a pointer to a 2 element array, second is always later + ret.tv_sec = ts[1].tv_sec - ts[0].tv_sec; + ret.tv_nsec = ts[1].tv_nsec - ts[0].tv_nsec; + + if (ts[0].tv_nsec > ts[1].tv_nsec) { + ret.tv_nsec += 1000000000; + ret.tv_sec--; + } + + timeper = (ret.tv_sec * 1000000000 + ret.tv_nsec) / BENCH_COUNT; + tp_usec = timeper / 1000; + tp_nsec = timeper % 1000; + + printf("# %s %lu.%03lu\u03BCs/log (Total %lu.%09lds)\n", + type, tp_usec, tp_nsec, ret.tv_sec, ret.tv_nsec); +} + +int main(int argc, char **argv) +{ + struct timespec ts_wall[2]; + struct timespec ts_cpu[2]; + int i; + + /* Set up defaults */ + pinelog_set_level(PINELOG_LVL_ERROR); + pinelog_set_output_file("/dev/null"); + + printf("# Timing logging for %u iterations\n", BENCH_COUNT); + + if (clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &ts_cpu[0]) < 0) { + perror("clock_gettime cputime 0"); + return 1; + } + if (clock_gettime(CLOCK_MONOTONIC, &ts_wall[0]) < 0) { + perror("clock_gettime monotonic 0"); + return 1; + } + + for (i = 0; i < BENCH_COUNT; i++) { + PINELOG_ERROR("Testing error log #%u of %u", i, BENCH_COUNT); + } + + clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &ts_cpu[1]); + clock_gettime(CLOCK_MONOTONIC, &ts_wall[1]); + + // Add a test plan and to avoid the TAP harness from flagging this as a + // failed test. + puts("1..1"); + printf("ok 1 Benchmark pinelog %stimestamp, %slevel, %sbacktrace\n", + PINELOG_SHOW_DATE ? "": "no ", + PINELOG_SHOW_LEVEL ? "": "no ", + PINELOG_SHOW_BACKTRACE ? "": "no "); + print_time_difference("cpu time", ts_cpu); + print_time_difference("wall time", ts_wall); + + return 0; +} diff --git a/config.h.in b/config.h.in deleted file mode 100644 index 392d9b0..0000000 --- a/config.h.in +++ /dev/null @@ -1,67 +0,0 @@ -/* config.h.in. Generated from configure.ac by autoheader. */ - -/* Define to 1 if you have the header file. */ -#undef HAVE_DLFCN_H - -/* Define to 1 if the system has the `constructor' function attribute */ -#undef HAVE_FUNC_ATTRIBUTE_CONSTRUCTOR - -/* Define to 1 if the system has the `format' function attribute */ -#undef HAVE_FUNC_ATTRIBUTE_FORMAT - -/* Define to 1 if you have the header file. */ -#undef HAVE_INTTYPES_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_MEMORY_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_STDINT_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_STDLIB_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_STRINGS_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_STRING_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_SYS_STAT_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_SYS_TYPES_H - -/* Define to 1 if you have the header file. */ -#undef HAVE_UNISTD_H - -/* Define to the sub-directory where libtool stores uninstalled libraries. */ -#undef LT_OBJDIR - -/* Name of package */ -#undef PACKAGE - -/* Define to the address where bug reports for this package should be sent. */ -#undef PACKAGE_BUGREPORT - -/* Define to the full name of this package. */ -#undef PACKAGE_NAME - -/* Define to the full name and version of this package. */ -#undef PACKAGE_STRING - -/* Define to the one symbol short name of this package. */ -#undef PACKAGE_TARNAME - -/* Define to the home page for this package. */ -#undef PACKAGE_URL - -/* Define to the version of this package. */ -#undef PACKAGE_VERSION - -/* Define to 1 if you have the ANSI C header files. */ -#undef STDC_HEADERS - -/* Version number of package */ -#undef VERSION diff --git a/configure.ac b/configure.ac index 133e102..b9d83a7 100644 --- a/configure.ac +++ b/configure.ac @@ -17,6 +17,7 @@ PKG_PROG_PKG_CONFIG PKG_INSTALLDIR AX_COMPILER_FLAGS AX_GCC_FUNC_ATTRIBUTE([constructor]) +AX_GCC_FUNC_ATTRIBUTE([destructor]) AX_GCC_FUNC_ATTRIBUTE([format]) AC_SUBST([PINELOG_CFLAGS]) diff --git a/pinelog.c b/pinelog.c index 1c793c5..e2e7c42 100644 --- a/pinelog.c +++ b/pinelog.c @@ -87,16 +87,25 @@ void pinelog_set_defaults(void) log_level = PINELOG_DEFAULT_LEVEL; } +#if HAVE_FUNC_ATTRIBUTE_DESTRUCTOR +__attribute__((destructor)) +#endif +void pinelog_close_output_stream(void) +{ + /* If current output stream is not stdout or stderr, then close it */ + if (output_stream != NULL && output_stream != stdout && output_stream != stderr) { + fclose(output_stream); + } + output_stream = PINELOG_DEFAULT_STREAM; +} + int pinelog_set_output_stream(FILE *stream) { if (stream == NULL) { return EINVAL; } - /* If current output stream is not stdout or stderr, then close it */ - if (output_stream != stdout && output_stream != stderr) { - fclose(output_stream); - } + pinelog_close_output_stream(); setlinebuf(stream); output_stream = stream; diff --git a/pinelog.h b/pinelog.h index 0020ad9..dfd2b0c 100644 --- a/pinelog.h +++ b/pinelog.h @@ -62,6 +62,11 @@ enum { */ void pinelog_set_defaults(void); +/** + * @brief Close the output stream and terminate the logs + */ +void pinelog_close_output_stream(void); + #ifdef PINELOG_TEST /** * @brief Get the pointer to the output stream. Only used in test harness. diff --git a/test_pinelog.c b/test_pinelog.c index dd568a8..0f59117 100644 --- a/test_pinelog.c +++ b/test_pinelog.c @@ -66,10 +66,8 @@ static void dump_data(const char *type, size_t len, char *data) printf("\n"); } -static void test_setup(int level, int filter, const char *file, int line, const char *fmt, ...) +static int test_setup(int level, int filter, const char *file, int line) { - va_list ap; - expected_len = 0; memset(expected_output, 0, sizeof(expected_output)); @@ -105,14 +103,10 @@ static void test_setup(int level, int filter, const char *file, int line, const "%s:%d ", file, line); } - va_start(ap, fmt); - expected_len += vsnprintf(&expected_output[expected_len], - sizeof(expected_output) - expected_len, - fmt, ap); - va_end(ap); - expected_output[expected_len] = '\n'; - expected_len++; + return 1; } + + return 0; } static void test_teardown(const char *desc) @@ -144,8 +138,11 @@ static void verify_defaults(void) #define PINELOG_WARNING PINELOG_WARN #define TEST_LOG(lvl, filter, fmt, ...) do { \ - test_setup(PINELOG_LVL_ ## lvl, PINELOG_LVL_ ## filter, \ - __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ + if (test_setup(PINELOG_LVL_ ## lvl, PINELOG_LVL_ ## filter, \ + __FILE__, __LINE__)) \ + expected_len += snprintf(&expected_output[expected_len], \ + sizeof(expected_output) - expected_len, \ + fmt "\n", ##__VA_ARGS__); \ PINELOG_ ## lvl (fmt, ##__VA_ARGS__); \ test_teardown("Log " #lvl " filter " #filter); \ } while(0) @@ -184,7 +181,7 @@ int main(int argc, char **argv) printf("1..%u\n", test_id); - fclose(observed_stream_w); + pinelog_close_output_stream(); fclose(observed_stream_r); close(fifo_fd_w); close(fifo_fd_r);