1 files changed, 328 insertions, 0 deletions
diff --git a/lib/log.c b/lib/log.c
new file mode 100644
index 0000000..1a3d715
--- /dev/null
+++ b/lib/log.c
@@ -0,0 +1,328 @@
+/*  Copyright (C) CZ.NIC, z.s.p.o. <knot-resolver@labs.nic.cz>
+ *  SPDX-License-Identifier: GPL-3.0-or-later
+ */
+
+#include "kresconfig.h"
+
+#include <stdarg.h>
+#include <stdio.h>
+#include <gnutls/gnutls.h>
+#include "contrib/ucw/mempool.h"
+#include "lib/log.h"
+#include "lib/resolve.h"
+
+#if ENABLE_LIBSYSTEMD
+#include <stdlib.h>
+#include <systemd/sd-daemon.h>
+#include <systemd/sd-journal.h>
+bool use_journal = false;
+#else
+#define use_journal false
+#endif
+
+kr_log_level_t kr_log_level = LOG_DEFAULT_LEVEL;
+kr_log_target_t kr_log_target = LOG_TARGET_DEFAULT;
+
+/** Set of log-groups that are on debug level.  It's a bitmap over 1 << enum kr_log_group. */
+static uint64_t kr_log_groups = 0;
+
+typedef struct {
+	const char		*g_name;
+	enum kr_log_group	g_val;
+} log_group_names_t;
+
+#define GRP_NAME_ITEM(grp) { grp ## _TAG, grp }
+
+const log_group_names_t log_group_names[] = {
+	GRP_NAME_ITEM(LOG_GRP_SYSTEM),
+	GRP_NAME_ITEM(LOG_GRP_CACHE),
+	GRP_NAME_ITEM(LOG_GRP_IO),
+	GRP_NAME_ITEM(LOG_GRP_NETWORK),
+	GRP_NAME_ITEM(LOG_GRP_TA),
+	GRP_NAME_ITEM(LOG_GRP_TLS),
+	GRP_NAME_ITEM(LOG_GRP_GNUTLS),
+	GRP_NAME_ITEM(LOG_GRP_TLSCLIENT),
+	GRP_NAME_ITEM(LOG_GRP_XDP),
+	GRP_NAME_ITEM(LOG_GRP_DOH),
+	GRP_NAME_ITEM(LOG_GRP_DNSSEC),
+	GRP_NAME_ITEM(LOG_GRP_HINT),
+	GRP_NAME_ITEM(LOG_GRP_PLAN),
+	GRP_NAME_ITEM(LOG_GRP_ITERATOR),
+	GRP_NAME_ITEM(LOG_GRP_VALIDATOR),
+	GRP_NAME_ITEM(LOG_GRP_RESOLVER),
+	GRP_NAME_ITEM(LOG_GRP_SELECTION),
+	GRP_NAME_ITEM(LOG_GRP_ZCUT),
+	GRP_NAME_ITEM(LOG_GRP_COOKIES),
+	GRP_NAME_ITEM(LOG_GRP_STATISTICS),
+	GRP_NAME_ITEM(LOG_GRP_REBIND),
+	GRP_NAME_ITEM(LOG_GRP_WORKER),
+	GRP_NAME_ITEM(LOG_GRP_POLICY),
+	GRP_NAME_ITEM(LOG_GRP_TASENTINEL),
+	GRP_NAME_ITEM(LOG_GRP_TASIGNALING),
+	GRP_NAME_ITEM(LOG_GRP_TAUPDATE),
+	GRP_NAME_ITEM(LOG_GRP_DAF),
+	GRP_NAME_ITEM(LOG_GRP_DETECTTIMEJUMP),
+	GRP_NAME_ITEM(LOG_GRP_DETECTTIMESKEW),
+	GRP_NAME_ITEM(LOG_GRP_GRAPHITE),
+	GRP_NAME_ITEM(LOG_GRP_PREFILL),
+	GRP_NAME_ITEM(LOG_GRP_PRIMING),
+	GRP_NAME_ITEM(LOG_GRP_SRVSTALE),
+	GRP_NAME_ITEM(LOG_GRP_WATCHDOG),
+	GRP_NAME_ITEM(LOG_GRP_NSID),
+	GRP_NAME_ITEM(LOG_GRP_DNSTAP),
+	GRP_NAME_ITEM(LOG_GRP_TESTS),
+	GRP_NAME_ITEM(LOG_GRP_DOTAUTH),
+	GRP_NAME_ITEM(LOG_GRP_HTTP),
+	GRP_NAME_ITEM(LOG_GRP_CONTROL),
+	GRP_NAME_ITEM(LOG_GRP_MODULE),
+	GRP_NAME_ITEM(LOG_GRP_DEVEL),
+	GRP_NAME_ITEM(LOG_GRP_RENUMBER),
+	GRP_NAME_ITEM(LOG_GRP_EDE),
+	GRP_NAME_ITEM(LOG_GRP_REQDBG),
+	{ NULL, LOG_GRP_UNKNOWN },
+};
+static_assert(LOG_GRP_REQDBG <= 8 * sizeof(kr_log_groups), "Too many log groups.");
+
+bool kr_log_group_is_set(enum kr_log_group group)
+{
+	if (kr_fails_assert(group >= 0))
+		return false;
+
+	return kr_log_groups & (1ULL << group);
+}
+
+void kr_log_fmt(enum kr_log_group group, kr_log_level_t level, const char *file,
+		const char *line, const char *func, const char *fmt, ...)
+{
+	va_list args;
+
+	if (!(KR_LOG_LEVEL_IS(level) || kr_log_group_is_set(group)))
+		return;
+
+	if (kr_log_target == LOG_TARGET_SYSLOG) {
+		if (kr_log_group_is_set(group))
+			setlogmask(LOG_UPTO(LOG_DEBUG));
+
+		va_start(args, fmt);
+		if (use_journal) {
+		#if ENABLE_LIBSYSTEMD
+			sd_journal_printv_with_location(level, file, line, func, fmt, args);
+		#endif
+		} else {
+			vsyslog(level, fmt, args);
+		}
+		va_end(args);
+
+		if (kr_log_group_is_set(group))
+			setlogmask(LOG_UPTO(kr_log_level));
+	} else {
+		FILE *stream;
+		switch(kr_log_target) {
+		case LOG_TARGET_STDOUT: stream = stdout; break;
+		default: kr_assert(false); // fall through
+		case LOG_TARGET_STDERR: stream = stderr; break;
+		}
+
+		va_start(args, fmt);
+		vfprintf(stream, fmt, args);
+		va_end(args);
+	}
+}
+
+static void kres_gnutls_log(int level, const char *message)
+{
+	kr_log_debug(GNUTLS, "(%d) %s", level, message);
+}
+
+
+struct log_level_name {
+	const char *name;
+	kr_log_level_t level;
+};
+const struct log_level_name level_names[] = {
+	{ "alert",	LOG_ALERT },
+	{ "crit",	LOG_CRIT },
+	{ "debug",	LOG_DEBUG },
+	{ "emerg",	LOG_EMERG },
+	{ "err",	LOG_ERR },
+	{ "info",	LOG_INFO },
+	{ "notice",	LOG_NOTICE },
+	{ "warning",	LOG_WARNING },
+	{ NULL,		-1 },
+};
+
+const char *kr_log_level2name(kr_log_level_t level)
+{
+	for (int i = 0; level_names[i].name; ++i)
+	{
+		if (level_names[i].level == level)
+			return level_names[i].name;
+	}
+
+	return NULL;
+}
+
+kr_log_level_t kr_log_name2level(const char *name)
+{
+	if (kr_fails_assert(name))
+		return LOG_UNKNOWN_LEVEL;
+
+	for (int i = 0; level_names[i].name; ++i)
+	{
+		if (strcmp(level_names[i].name, name) == 0)
+			return level_names[i].level;
+	}
+
+	return LOG_UNKNOWN_LEVEL;
+}
+
+const char *kr_log_grp2name(enum kr_log_group group)
+{
+	for (int i = 0; log_group_names[i].g_name; ++i)
+	{
+		if (log_group_names[i].g_val == group)
+			return log_group_names[i].g_name;
+	}
+
+	return NULL;
+}
+
+enum kr_log_group kr_log_name2grp(const char *name)
+{
+	if (kr_fails_assert(name))
+		return LOG_GRP_UNKNOWN;
+
+	for (int i = 0; log_group_names[i].g_name; ++i)
+	{
+		if (strcmp(log_group_names[i].g_name, name) == 0)
+			return log_group_names[i].g_val;
+	}
+
+	return LOG_GRP_UNKNOWN;
+}
+
+
+
+static void kr_gnutls_log_level_set()
+{
+	/* gnutls logs messages related to our TLS and also libdnssec,
+	 * and the logging is set up in a global way only */
+	if (KR_LOG_LEVEL_IS(LOG_DEBUG) || kr_log_group_is_set(LOG_GRP_GNUTLS)) {
+		gnutls_global_set_log_function(kres_gnutls_log);
+		gnutls_global_set_log_level(LOG_GNUTLS_LEVEL);
+	} else {
+		gnutls_global_set_log_level(0);
+	}
+}
+
+void kr_log_level_set(kr_log_level_t level)
+{
+	if (level < LOG_CRIT || level > LOG_DEBUG) {
+		kr_log_warning(SYSTEM, "invalid log level\n");
+		return;
+	}
+
+	kr_log_level = level;
+	setlogmask(LOG_UPTO(kr_log_level));
+
+	kr_gnutls_log_level_set();
+}
+
+void kr_log_group_add(enum kr_log_group group)
+{
+	if (kr_fails_assert(group >= 0))
+		return;
+
+	kr_log_groups |= (1ULL << group);
+	if (group == LOG_GRP_GNUTLS)
+		kr_gnutls_log_level_set();
+}
+
+void kr_log_group_reset()
+{
+	bool had_gnutls = kr_log_group_is_set(LOG_GRP_GNUTLS);
+	kr_log_groups = 0;
+	kr_log_group_add(LOG_GRP_REQDBG);
+	if (had_gnutls)
+		kr_gnutls_log_level_set();
+}
+
+void kr_log_target_set(kr_log_target_t target)
+{
+	kr_log_target = target;
+	if (target != LOG_TARGET_SYSLOG)
+		return;
+
+	int ret = 0;
+#if ENABLE_LIBSYSTEMD
+	ret = sd_booted();
+	use_journal = ret > 0;
+#endif
+	if (!use_journal)
+		openlog(NULL, LOG_PID, LOG_DAEMON);
+	if (ret < 0)
+		kr_log_error(SYSTEM, "failed test for systemd presence: %s\n",
+				strerror(abs(ret)));
+}
+
+static inline bool req_has_trace_log(const struct kr_request *req)
+{
+	return unlikely(req && req->trace_log);
+}
+
+static void kr_vlog_req(
+	const struct kr_request * const req, uint32_t qry_uid,
+	const unsigned int indent, enum kr_log_group group, const char *tag, const char *fmt,
+	va_list args)
+{
+	struct mempool *mp = mp_new(512);
+
+	const uint32_t req_uid = req ? req->uid : 0;
+	char *msg = mp_printf(mp, "[%-6s][%05u.%02u] %*s",
+				tag, req_uid, qry_uid, indent, "");
+
+	msg = mp_vprintf_append(mp, msg, fmt, args);
+
+	if (req_has_trace_log(req))
+		req->trace_log(req, msg);
+
+	kr_log_fmt(group, LOG_DEBUG, SD_JOURNAL_METADATA, "%s", msg);
+
+	mp_delete(mp);
+}
+
+void kr_log_req1(const struct kr_request * const req, uint32_t qry_uid,
+		const unsigned int indent, enum kr_log_group group, const char *tag, const char *fmt, ...)
+{
+	va_list args;
+	va_start(args, fmt);
+	kr_vlog_req(req, qry_uid, indent, group, tag, fmt, args);
+	va_end(args);
+}
+
+bool kr_log_is_debug_fun(enum kr_log_group group, const struct kr_request *req)
+{
+	return req_has_trace_log(req)
+		|| kr_log_group_is_set(group)
+		|| KR_LOG_LEVEL_IS(LOG_DEBUG);
+}
+
+void kr_log_q1(const struct kr_query * const qry,
+		enum kr_log_group group, const char *tag, const char *fmt, ...)
+{
+	// Optimize: this is probably quite a hot path.
+	const struct kr_request *req = likely(qry != NULL) ? qry->request : NULL;
+	if (likely(!kr_log_is_debug_fun(group, req)))
+		return;
+
+	unsigned ind = 0;
+	for (const struct kr_query *q = qry; q; q = q->parent)
+		ind += 2;
+	const uint32_t qry_uid = qry ? qry->uid : 0;
+
+	va_list args;
+	va_start(args, fmt);
+	kr_vlog_req(req, qry_uid, ind, group, tag, fmt, args);
+	va_end(args);
+}
+