diff --git a/include/blackmagic/log.h b/include/blackmagic/log.h index b37a211..2ebf57b 100644 --- a/include/blackmagic/log.h +++ b/include/blackmagic/log.h @@ -68,6 +68,8 @@ * So if you want to have a run-time threshold in your custom function, * be sure to set the compile-time threshold high enough, * possibly to @ref LOG_LEVEL_ALL + * + * @since 0.4 */ typedef void(*logging_callback)(unsigned level, const char* level_name, const char* file, const char* function, int line, const char* message, ...); diff --git a/include/blackmagic/log_structured.h b/include/blackmagic/log_structured.h new file mode 100644 index 0000000..84724cc --- /dev/null +++ b/include/blackmagic/log_structured.h @@ -0,0 +1,31 @@ +#include "blackmagic/for.h" +#include "blackmagic/log.h" +#include "blackmagic/pair.h" + + +/** + * To be used with @ref log_structured. + */ +#define eval(FLAG, EXPRESSION) (#EXPRESSION, FLAG, EXPRESSION) + +///@cond +#define _log_value(NAME, FLAG, VALUE) VALUE, + +#if LOG_FORMAT == LOG_FORMAT_JSON +#define _log_name(NAME, FLAG, VALUE) "\""NAME "\": %" FLAG ", " +#define log_structured(LEVEL, MESSAGE, ...) log_ ## LEVEL (MESSAGE "\", " FOR(EACH(__VA_ARGS__), PAIR_FLATTEN, _log_name) "\"\":\"%.0u", FOR(EACH(__VA_ARGS__), PAIR_FLATTEN, _log_value) 0) +#else +#define _log_name(NAME, FLAG, VALUE) NAME " = %" FLAG ", " +///@endcond + +/** + * Structured logging. + * + * Provide a list of fields of the form (name, flag, value), where flag is the printf format to be used. + * The @ref eval macro can be used to have the name be the expression itself + */ +#define log_structured(LEVEL, MESSAGE, ...) log_ ## LEVEL (MESSAGE "; " FOR(EACH(__VA_ARGS__), PAIR_FLATTEN, _log_name) "%.0u", FOR(EACH(__VA_ARGS__), PAIR_FLATTEN, _log_value) 0) + +///@cond +#endif +///@endcond diff --git a/include/blackmagic/trace.h b/include/blackmagic/trace.h new file mode 100644 index 0000000..c085c6e --- /dev/null +++ b/include/blackmagic/trace.h @@ -0,0 +1,72 @@ +#pragma once + +#include "blackmagic/log.h" +#include "blackmagic/log_structured.h" + +#include // strerror +#include + +#define BLACKMAGIC_ScopedTrace struct blackmagic_trace __attribute__((cleanup(blackmagic_trace_scopeend))) + +#define BLACKMAGIC_timespec_diff(A, B) ((B.tv_sec - A.tv_sec) * 1000000000UL + B.tv_nsec - A.tv_nsec) + +#define BLACKMAGIC_Scope(NAME) blackmagic_trace_scopestart(NAME, __FILE__, __func__, __LINE__) + +struct blackmagic_trace +{ + struct timespec start; + const char* scope_name; + const char* file_name; + const char* function_name; + unsigned line_number; +}; + +static inline struct blackmagic_trace +blackmagic_trace_scopestart(const char* scope_name, + const char* file_name, + const char* function_name, + unsigned line_number) +{ + struct timespec start = {0}; + int status = clock_gettime(CLOCK_MONOTONIC_RAW, &start); + +#ifndef NDEBUG + if (status != 0) + log_error("Unable to get time: %s", strerror(status)); +#endif + return (struct blackmagic_trace){ + start = start, + scope_name = scope_name, + file_name = file_name, + function_name = function_name, + line_number = line_number, + }; +} + +#ifndef LOG_LEVEL_SPAN +# define LOG_LEVEL_SPAN 5 +#endif + +#if LOG_LEVEL >= LOG_LEVEL_SPAN +#define log_span(MESSAGE, ...) \ + log__log(LOG_LEVEL_SPAN, "SPAN", COLOR(PURPLE), MESSAGE __VA_OPT__(, ) __VA_ARGS__) +#else +#define log_span(M, ...) +#endif + +static inline void blackmagic_trace_scopeend(struct blackmagic_trace* self) { + struct timespec end = {0}; + int status = clock_gettime(CLOCK_MONOTONIC_RAW, &end); + +#ifndef NDEBUG + if (status != 0) + log_error("Unable to get time: %s", strerror(status)); +#endif + log_structured(span, + "", + ("trace_scope", "s", self->scope_name), + ("trace_file", "s", self->file_name), + ("trace_function", "s", self->function_name), + ("trace_line", "u", self->line_number), + ("duration_ns", "lu", BLACKMAGIC_timespec_diff(self->start, end))); +}