/* Copyright (C) CZ.NIC, z.s.p.o. * SPDX-License-Identifier: GPL-3.0-or-later */ #include "kresconfig.h" #include #include #include #include "contrib/ucw/mempool.h" #include "lib/log.h" #include "lib/resolve.h" #if ENABLE_LIBSYSTEMD #include #include #include 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); }