Add structured logging and eval macros

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, ...);
 

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

include/blackmagic/trace.h

@@ -0,0 +1,72 @@
+#pragma once
+
+#include "blackmagic/log.h"
+#include "blackmagic/log_structured.h"
+
+#include <string.h> // strerror
+#include <time.h>
+
+#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)));
+}