diff options
Diffstat (limited to '')
| -rw-r--r-- | lib/log.c | 328 |
1 files changed, 328 insertions, 0 deletions
diff --git a/lib/log.c b/lib/log.c new file mode 100644 index 0000000..9c8c7a6 --- /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(void) +{ + /* 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(void) +{ + 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); +} + |