From 321d9aaa0eee4b4af4be52c228662c3d32c32ab6 Mon Sep 17 00:00:00 2001 From: nirenjan Date: Mon, 19 Jul 2021 09:35:20 -0700 Subject: [PATCH] Add benchmark program to tests --- Makefile.am | 52 ++++++++++++++++++++++++++++++- bench_pinelog.c | 82 +++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 133 insertions(+), 1 deletion(-) create mode 100644 bench_pinelog.c 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; +}