From 139d741bce768548baecdd744eb04e73776b92c3 Mon Sep 17 00:00:00 2001 From: Avril Date: Mon, 12 Jul 2021 17:50:30 +0100 Subject: [PATCH] Allow controling logging verbosity at runtime with `LOG_LEVEL=` env-var. Default is `DEBUG` (trace) on debug builds, and `WARN` on release builds. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit TRACE() is no longer a no-op in release builds. This may be expensive since each call to `_t_fprintf()` does an atomic read. TODO: Migrate true debug-only messages to `dprintf()` instead of `TRACE()`; maybe find a way to make `_t_fprintf()` more efficient. Fortune for naka's current commit: Future blessing − 末吉 --- include/macros.h | 19 ++++---- include/trace.h | 35 +++++++++++++++ src/main.c | 27 +++++++++++- src/trace.c | 112 +++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 181 insertions(+), 12 deletions(-) create mode 100644 include/trace.h create mode 100644 src/trace.c diff --git a/include/macros.h b/include/macros.h index 55223af..e4586c5 100644 --- a/include/macros.h +++ b/include/macros.h @@ -148,22 +148,21 @@ static_assert_eq(bswap(bswap(128lu)), 128, "bswap128 (lu) failed (3)"); // Trace message output -#define TRACEx(X, msg, ...) (fprintf(stderr, "[" X "] " __FILE__ ":%d->%s(): " msg "\n", __LINE__, __func__, ## __VA_ARGS__)) +#include "trace.h" + +#define TRACEx(L, X, msg, ...) (_t_fprintf(TRACE_LEVEL_ ## L, stderr, "[" X "] " __FILE__ ":%d->%s(): " msg "\n", __LINE__, __func__, ## __VA_ARGS__)) #ifdef DEBUG -#define TRACE(msg, ...) TRACEx("trace", msg, ## __VA_ARGS__) -#define dprintf(msg, ...) TRACEx("debug", msg, ## __VA_ARGS__) +#define dprintf(msg, ...) TRACEx(DEBUG, "debug", msg, ## __VA_ARGS__) #elif defined(_EVAL_DEBUG_ONLY_STMTS) -#define TRACE(msg, ...) _drain(msg, ## __VA_ARGS__) #define dprintf(msg, ...) _drain(msg, ## __VA_ARGS__) -#else -#define TRACE(msg, ...) _no_op #endif -#define INFO(msg, ...) TRACEx("info", msg, ## __VA_ARGS__) -#define WARN(msg, ...) TRACEx("warning", msg, ## __VA_ARGS__) -#define ERROR(msg, ...) TRACEx("error", msg, ## __VA_ARGS__) +#define TRACE(msg, ...) TRACEx(DEBUG, "trace", msg, ## __VA_ARGS__) +#define INFO(msg, ...) TRACEx(INFO, "info", msg, ## __VA_ARGS__) +#define WARN(msg, ...) TRACEx(WARN, "warning", msg, ## __VA_ARGS__) +#define ERROR(msg, ...) TRACEx(ERROR, "error", msg, ## __VA_ARGS__) -#define FATAL(msg, ...) (TRACEx("FATAL", msg, ## __VA_ARGS__), abort()) +#define FATAL(msg, ...) (TRACEx(FATAL, "FATAL", msg, ## __VA_ARGS__), abort()) #define TODO(x) FATAL("function %s() is unimplemented: " x, __func__) diff --git a/include/trace.h b/include/trace.h new file mode 100644 index 0000000..08c1eec --- /dev/null +++ b/include/trace.h @@ -0,0 +1,35 @@ +//! Trace messages +#ifndef _TRACE_H +#define _TRACE_H + +#include +#include + +enum trace_level { + TRACE_LEVEL_DEBUG = 0, + TRACE_LEVEL_INFO, + TRACE_LEVEL_WARN, + TRACE_LEVEL_ERROR, + TRACE_LEVEL_FATAL, + + _TRACE_LEVEL_NUM, +}; + +#ifdef DEBUG +#define _TRACE_LEVEL_DEFAULT TRACE_LEVEL_DEBUG +#else +#define _TRACE_LEVEL_DEFAULT TRACE_LEVEL_WARN +#endif + +int _t_fprintf(enum trace_level l, FILE* output, const char* msg, ...); + +enum trace_level trace_max_level(); +void trace_init_with(enum trace_level max_level); +// Initialise the tracer with env-var `_TRACE_CONTROL_ENV_NAME`. If the env-var is not found, the max trace level is not modified. If it is found but has an invalid value, this function returns 0. Otherwise it modifies the max trace level value and returns 1. +int trace_init(); + +const char* trace_name_of(enum trace_level lv); + +extern const char* const _TRACE_CONTROL_ENV_NAME; + +#endif /* _TRACE_H */ diff --git a/src/main.c b/src/main.c index 0882e94..151dee7 100644 --- a/src/main.c +++ b/src/main.c @@ -15,6 +15,24 @@ #include #include +static void pi_print_trace_infos(FILE* out) +{ + const char* name; + for(int i=0;i<(int)_TRACE_LEVEL_NUM;i++) + { + enum trace_level lv = (enum trace_level)i; + name = trace_name_of(lv); + if(name) { + fprintf(out, "-> level %d: \"%s\"\n", i, name); + } + } + enum trace_level def = _TRACE_LEVEL_DEFAULT; + name = trace_name_of(def); + debug_assert(name); + fprintf(out, "(default level: %d, \"%s\")\n", def, name); + fprintf(out, "Set `LOG_LEVEL=` to control logging verbosity level at runtime. The name string is case-sensitive.\n"); +} + void prog_info(FILE* out) { fprintf(out, PROG_NAME " v%s - " PROG_DESCRIPTION @@ -26,6 +44,8 @@ void prog_info(FILE* out) PROG_AUTHOUR, PROG_COMPILED_TIMESTAMP, PROG_LICENSE); + fprintf(out, "\nLogging levels: (set with env-var `%s')\n", _TRACE_CONTROL_ENV_NAME); + pi_print_trace_infos(out); } void usage(FILE* out, int argc, char** argv) @@ -34,7 +54,7 @@ void usage(FILE* out, int argc, char** argv) prog_info(out); fprintf(out, "\nUsage: %s \n", argv[0] ?: PROG_NAME); - fprintf(out, "\nUsage: %s --help\n", argv[0] ?: PROG_NAME); + fprintf(out, "Usage: %s --help\n", argv[0] ?: PROG_NAME); } // err: 0 for normal exit and print to stdout. @@ -70,7 +90,10 @@ static int map_haystacks(const char* const * h, map_t maps[pOUT]) int main(int argc, char** argv) { - TRACE("main start with %d (pn: %s, a1: %s)", argc, argv[0], argv[1] ?: ""); + if(!trace_init()) { + ERROR("Unknown trace value for %s: `%s'", _TRACE_CONTROL_ENV_NAME, getenv(_TRACE_CONTROL_ENV_NAME) ?: ""); + } + TRACE("main start with %d (pn: %s, a1: %s), log trace level (ctrl envar `%s'): %d", argc, argv[0], argv[1] ?: "", _TRACE_CONTROL_ENV_NAME, (int)trace_max_level()); if(!argv[1]) inv_args: diff --git a/src/trace.c b/src/trace.c new file mode 100644 index 0000000..1ccf60d --- /dev/null +++ b/src/trace.c @@ -0,0 +1,112 @@ +// Trace messages + +#include +#include +#include + +#include +#include + +#include +#include + +static _Atomic enum trace_level _t_level = _TRACE_LEVEL_DEFAULT; + +const char* const _TRACE_CONTROL_ENV_NAME = "LOG_LEVEL"; + +const struct {const char* const name; const enum trace_level level; } _trace_level_names[] = { +#define X(name) { #name, TRACE_LEVEL_ ## name } +#define Y(name, val) { #name, TRACE_LEVEL_ ## val } + X(DEBUG), Y(TRACE, DEBUG), + X(INFO), + X(WARN), + X(ERROR), + X(FATAL), +#undef Y +#undef X +}; +#define _trace_level_names_n (sizeof(_trace_level_names) / sizeof(_trace_level_names[0])) + + +static bool _trace_lookup(const char*pIN name, enum trace_level *pOUT olevel) +{ + debug_assert(name); + + for(usize i=0;i<_trace_level_names_n;i++) { + let level = &_trace_level_names[i]; + debug_assert(level && level->name); + if(strcmp(name, level->name) == 0) { + *olevel =level->level; + return true; + } + } + return false; +} + +static bool _trace_reverse_lookup(enum trace_level level, const char* *pOUT name) +{ + for(usize i=0;i<_trace_level_names_n;i++) { + let lv = &_trace_level_names[i]; + debug_assert(lv && lv->name); + if(lv->level == level) { + *name = lv->name; + return true; + } + } + return false; +} + +const char* trace_name_of(enum trace_level lv) +{ + const char* ret; + if(!_trace_reverse_lookup(lv, &ret)) return NULL; + else return ret; +} +inline enum trace_level trace_max_level() +{ + return _t_level; +} + +inline static bool _trace_hidden(enum trace_level l) +{ + return l < trace_max_level(); +} + +int _t_fprintf(enum trace_level l, FILE* output, const char* msg, ...) +{ + if(_trace_hidden(l)) return 0; + + va_list ap; + va_start(ap, msg); + register int r = vfprintf(output, msg, ap); + va_end(ap); + return r; +} + +void trace_init_with(enum trace_level max_level) +{ + _t_level = max_level; +} + +static inline bool _try_get_env(const char* name, const char* *pOUT value) +{ + return !!(*value = (const char*)getenv(name)); + +} + +int trace_init() +{ + const char* eval; + if(!_try_get_env(_TRACE_CONTROL_ENV_NAME, &eval)) return 1; + else { + assert(eval); + if(*eval == 0) return 1; // Count empty string as default. + + enum trace_level level; + if(!_trace_lookup(eval, &level)) return 0; + else { + trace_init_with(level); + } + } + return 1; +}