]> git.ipfire.org Git - thirdparty/knot-resolver.git/commitdiff
log: add level prefix to each message
authorLukáš Ježek <lukas.jezek@nic.cz>
Tue, 15 Jun 2021 10:35:53 +0000 (12:35 +0200)
committerTomas Krizek <tomas.krizek@nic.cz>
Thu, 29 Jul 2021 09:40:50 +0000 (11:40 +0200)
24 files changed:
daemon/lua/kres-gen-29.lua
daemon/lua/kres-gen.sh
daemon/worker.c
daemon/zimport.c
lib/cache/impl.h
lib/dnssec.c
lib/layer.h
lib/layer/iterate.c
lib/layer/validate.c
lib/log.c
lib/log.h
lib/resolve.c
lib/rplan.c
lib/selection.c
lib/selection_forward.c
lib/selection_iter.c
lib/utils.c
lib/utils.h
lib/zonecut.c
modules/cookies/cookiemonster.c
modules/hints/hints.c
modules/policy/policy.lua
modules/rebinding/rebinding.lua
modules/stats/stats.c

index e885c815d2fd0b2d581612829f3ebe7259d2dfa9..3ca1184b811964212759fa970f3a04516bba5ec9 100644 (file)
@@ -306,6 +306,7 @@ struct kr_server_selection {
        void (*error)(struct kr_query *, const struct kr_transport *, enum kr_selection_error);
        struct local_state *local_state;
 };
+typedef unsigned int log_groups_t;
 
 kr_layer_t kr_layer_t_static;
 _Bool kr_dbg_assertion_abort;
@@ -383,8 +384,8 @@ int kr_rplan_pop(struct kr_rplan *, struct kr_query *);
 struct kr_query *kr_rplan_resolved(struct kr_rplan *);
 struct kr_query *kr_rplan_last(struct kr_rplan *);
 int kr_forward_add_target(struct kr_request *, const struct sockaddr *);
-void kr_log_req(const struct kr_request * const, uint32_t, const unsigned int, const char *, const char *, ...);
-void kr_log_q(const struct kr_query * const, const char *, const char *, ...);
+void kr_log_req1(const struct kr_request * const, uint32_t, const unsigned int, log_groups_t, const char *, const char *, ...);
+void kr_log_q1(const struct kr_query * const, log_groups_t, const char *, const char *, ...);
 int kr_make_query(struct kr_query *, knot_pkt_t *);
 void kr_pkt_make_auth_header(knot_pkt_t *);
 int kr_pkt_put(knot_pkt_t *, const knot_dname_t *, uint32_t, uint16_t, uint16_t, const uint8_t *, uint16_t);
index 5018973a1457d6db55816d9a43643c2d7dff67fc..afaa19b9c9b8abf48035b2be4241d2357ca92610 100755 (executable)
@@ -138,6 +138,7 @@ ${CDEFS} ${LIBKRES} types <<-EOF
        struct kr_prop
        struct kr_module
        struct kr_server_selection
+       log_groups_t
 EOF
 
 # static variables; these lines might not be simple to generate
@@ -210,8 +211,8 @@ ${CDEFS} ${LIBKRES} functions <<-EOF
 # Forwarding
        kr_forward_add_target
 # Utils
-       kr_log_req
-       kr_log_q
+       kr_log_req1
+       kr_log_q1
        kr_make_query
        kr_pkt_make_auth_header
        kr_pkt_put
index b44663d8de139c1bf167de4bf58353e1fd404340..06b48452cfa3c54693f6e8467db428ac10944e31 100644 (file)
@@ -51,7 +51,7 @@
 #define MAX_PIPELINED 100
 #endif
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "wrkr", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_WORKER, __VA_ARGS__)
 
 /** Client request state. */
 struct request_ctx
index 51181c057f3bb6f9f4e34b7191b7ec0cd9f9d93b..de05e88d9daa734ac87db2332986f9c359cc8525 100644 (file)
@@ -47,7 +47,7 @@
 #include "lib/generic/map.h"
 #include "lib/generic/array.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "zimport", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_ZIMPORT, __VA_ARGS__)
 
 /* Pause between parse and import stages, milliseconds.
  * See comment in zi_zone_import() */
index cddd0b748980fa5266541af96294926c22a7fe46..54815fe2dcfcc4118aed49ebc827435ecb3207c1 100644 (file)
@@ -409,7 +409,7 @@ int nsec3_src_synth(struct key *k, struct answer *ans, const knot_dname_t *clenc
 
 
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), "cach",  ## __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), LOG_GRP_CACHE,  ## __VA_ARGS__)
 
 /** Shorthand for operations on cache backend */
 #define cache_op(cache, op, ...) (cache)->api->op((cache)->db, &(cache)->stats, ## __VA_ARGS__)
index 4acc9717ca0fd53f87568c9ea1bd1675318e3905..138e2f16c525ab48388d5a05cfd243d598688aea 100644 (file)
@@ -255,7 +255,7 @@ static int kr_rrset_validate_with_key(kr_rrset_validation_ctx_t *vctx,
                                        auto_free char
                                                *name_str = kr_dname_text(covered->owner),
                                                *type_str = kr_rrtype_text(covered->type);
-                                       QRVERBOSE(NULL, "vldr",
+                                       QRVERBOSE(NULL, LOG_GRP_VALIDATOR,
                                                "trimming TTL of %s %s: %d -> %d\n",
                                                name_str, type_str,
                                                (int)covered->ttl, (int)ttl_max);
index 40e62c7d4ebc4d56e4766694aa6dfff2c8ab7702..3ac844e0135ed93b22a5d72df34b838992d4cbf0 100644 (file)
  * \param _cls identifying string, typically of length exactly four (padded)
  * \param ...  printf-compatible list of parameters
  */
-#define QRVERBOSE(_query, _cls, ...) do { \
+#define QRVERBOSE(_query, grp, ...) do { \
        const struct kr_query *_qry = (_query); \
        if (VERBOSE_STATUS || kr_log_qtrace_enabled(_qry)) { \
-               kr_log_q(_qry, (_cls), __VA_ARGS__); \
+               kr_log_q1(_query, grp, grp ## _TAG, __VA_ARGS__); \
        }  \
 } while (false)
 
index 7be969b8f2452294cd40593e866a28667b608f63..91a4da445429d727e67774cb60ec9454eafb3c61 100644 (file)
@@ -32,8 +32,8 @@
 #include "lib/module.h"
 #include "lib/dnssec/ta.h"
 
-#define VERBOSE_MSG(...) QRVERBOSE(req->current_query, "iter", __VA_ARGS__)
-#define QVERBOSE_MSG(qry, ...) QRVERBOSE(qry, "iter", __VA_ARGS__)
+#define VERBOSE_MSG(...) QRVERBOSE(req->current_query, LOG_GRP_ITERATOR, __VA_ARGS__)
+#define QVERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_ITERATOR, __VA_ARGS__)
 
 /* Iterator often walks through packet section, this is an abstraction. */
 typedef int (*rr_callback_t)(const knot_rrset_t *, unsigned, struct kr_request *);
index 5f8a600852ed4a8640204523d6c777c2f04be4f8..08f96e8144755821942c1426a28ac37a54be5b91 100644 (file)
@@ -25,7 +25,7 @@
 #include "lib/module.h"
 #include "lib/selection.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "vldr", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_VALIDATOR, __VA_ARGS__)
 
 #define MAX_REVALIDATION_CNT 2
 
@@ -583,7 +583,7 @@ static const knot_dname_t *find_first_signer(ranked_rr_array_t *arr, struct kr_q
                        return signame;
                } else {
                        /* otherwise it's some nonsense, so we skip it */
-                       kr_log_q(qry, "vldr", "protocol violation: "
+                       kr_log_q(qry, LOG_GRP_VALIDATOR, "protocol violation: "
                                        "out-of-bailwick RRSIG signer, skipping\n");
                }
        }
index 4b335b3b48cbadc75f43858455d330b82454c399..5feb42b699881bb55712149a7ed4f118e6f65fd9 100644 (file)
--- a/lib/log.c
+++ b/lib/log.c
@@ -6,7 +6,9 @@
 
 #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>
@@ -20,21 +22,23 @@ log_level_t kr_log_level = LOG_CRIT;
 log_target_t kr_log_target = LOG_TARGET_STDOUT;
 log_groups_t kr_log_groups = 0;
 
+#define GRP_NAME_ITEM(grp) { grp ## _TAG, grp }
+
 log_group_names_t log_group_names[] = {
-       { "system",     LOG_GRP_SYSTEM },
-       { "cache",      LOG_GRP_CACHE },
-       { "io",         LOG_GRP_IO },
-       { "network",    LOG_GRP_NETWORK },
-       { "ta",         LOG_GRP_TA },
-       { "tls",        LOG_GRP_TLS },
-       { "gnutls",     LOG_GRP_GNUTLS },
-       { "tlsclient",  LOG_GRP_TLSCLIENT },
-       { "xdp",        LOG_GRP_XDP },
-       { "zimport",    LOG_GRP_ZIMPORT },
-       { "zscanner",   LOG_GRP_ZSCANNER },
-       { "doh",        LOG_GRP_DOH },
-       { "dnssec",     LOG_GRP_DNSSEC },
-       { "hint",       LOG_GRP_HINT },
+       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_ZIMPORT),
+       GRP_NAME_ITEM(LOG_GRP_ZSCANNER),
+       GRP_NAME_ITEM(LOG_GRP_DOH),
+       GRP_NAME_ITEM(LOG_GRP_DNSSEC),
+       GRP_NAME_ITEM(LOG_GRP_HINT),
        { NULL,         -1 },
 };
 
@@ -199,3 +203,55 @@ void kr_log_init(log_level_t level, log_target_t target)
        kr_log_level_set(level);
 }
 
+
+/*
+ * Cleanup callbacks.
+ */
+static void kr_vlog_req(
+       const struct kr_request * const req, uint32_t qry_uid,
+       const unsigned int indent, log_groups_t group, const char *tag, const char *fmt,
+       va_list args)
+{
+       if (!(KR_LOG_LEVEL_IS(LOG_DEBUG) || group_is_set(group)))
+               return; // skip alloc and string copy
+
+       struct mempool *mp = mp_new(512);
+
+       const uint32_t req_uid = req ? req->uid : 0;
+       char *msg = mp_printf(mp, "[%05u.%02u] %*s",
+                               req_uid, qry_uid, indent, "");
+
+       msg = mp_vprintf_append(mp, msg, fmt, args);
+
+       if (kr_log_rtrace_enabled(req))
+               req->trace_log(req, msg);
+       else
+               kr_log_fmt(group, LOG_DEBUG, SD_JOURNAL_METADATA, "[%s]%s", tag, msg);
+
+       mp_delete(mp);
+}
+
+void kr_log_req1(const struct kr_request * const req, uint32_t qry_uid,
+               const unsigned int indent, log_groups_t 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);
+}
+
+void kr_log_q1(const struct kr_query * const qry,
+               log_groups_t group, const char *tag, const char *fmt, ...)
+{
+       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;
+       const struct kr_request *req = qry ? qry->request : NULL;
+
+       va_list args;
+       va_start(args, fmt);
+       kr_vlog_req(req, qry_uid, ind, group, tag, fmt, args);
+       va_end(args);
+}
+
index 18481272b3954f2e45c1d6e376af5f2f25ffb221..eaa88ffff011d8e9a63ab9e825d56720d85384e0 100644 (file)
--- a/lib/log.h
+++ b/lib/log.h
@@ -27,7 +27,7 @@ typedef struct {
        log_groups_t    g_val;
 } log_group_names_t;
 
-/* Don't forget add name to log_group_names[] (log.c) */
+/* Don't forget add *_TAG below and log_group_names[] item (log.c) */
 #define LOG_GRP_SYSTEM         (1 << 1)
 #define LOG_GRP_CACHE          (1 << 2)
 #define LOG_GRP_IO             (1 << 3)
@@ -42,6 +42,44 @@ typedef struct {
 #define LOG_GRP_DOH            (1 << 12)
 #define LOG_GRP_DNSSEC         (1 << 13)
 #define LOG_GRP_HINT           (1 << 14)
+#define LOG_GRP_PLAN           (1 << 15)
+#define LOG_GRP_ITERATOR       (1 << 16)
+#define LOG_GRP_VALIDATOR      (1 << 17)
+#define LOG_GRP_RESOLVER       (1 << 18)
+#define LOG_GRP_SELECTION      (1 << 19)
+#define LOG_GRP_ZCUT           (1 << 20)
+#define LOG_GRP_COOKIES                (1 << 21)
+#define LOG_GRP_STATISTICS     (1 << 22)
+#define LOG_GRP_REBIND         (1 << 23)
+#define LOG_GRP_WORKER         (1 << 24)
+#define LOG_GRP_POLICY         (1 << 25)
+
+#define LOG_GRP_SYSTEM_TAG     "system"
+#define LOG_GRP_CACHE_TAG      "cache "
+#define LOG_GRP_IO_TAG         "io    "
+#define LOG_GRP_NETWORK_TAG    "net   "
+#define LOG_GRP_TA_TAG         "ta    "
+#define LOG_GRP_TLS_TAG                "tls   "
+#define LOG_GRP_GNUTLS_TAG     "gnutls"
+#define LOG_GRP_TLSCLIENT_TAG  "tls_cl"
+#define LOG_GRP_XDP_TAG                "xdp   "
+#define LOG_GRP_ZIMPORT_TAG    "zimprt"
+#define LOG_GRP_ZSCANNER_TAG   "zscann"
+#define LOG_GRP_DOH_TAG                "doh   "
+#define LOG_GRP_DNSSEC_TAG     "dnssec"
+#define LOG_GRP_HINT_TAG       "hint  "
+#define LOG_GRP_PLAN_TAG       "plan  "
+#define LOG_GRP_ITERATOR_TAG   "iterat"
+#define LOG_GRP_VALIDATOR_TAG  "valdtr"
+#define LOG_GRP_RESOLVER_TAG   "resolv"
+#define LOG_GRP_SELECTION_TAG  "select"
+#define LOG_GRP_ZCUT_TAG       "zoncut"
+#define LOG_GRP_COOKIES_TAG    "cookie"
+#define LOG_GRP_STATISTICS_TAG "statis"
+#define LOG_GRP_REBIND_TAG     "rebind"
+#define LOG_GRP_WORKER_TAG     "worker"
+#define LOG_GRP_POLICY_TAG     "policy"
+
 
 KR_EXPORT
 extern log_groups_t kr_log_groups;
@@ -79,20 +117,20 @@ void kr_log_init(log_level_t level, log_target_t target);
 #define SD_JOURNAL_METADATA "CODE_FILE=" __FILE__, "CODE_LINE=" TO_STR(__LINE__), ""
 
 #define kr_log_debug(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_DEBUG, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_DEBUG, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 #define kr_log_info(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_INFO, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_INFO, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 #define kr_log_notice(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_NOTICE, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_NOTICE, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 #define kr_log_warning(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_WARNING, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_WARNING, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 #define kr_log_error(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_ERR, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_ERR, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 #define kr_log_fatal(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_CRIT, SD_JOURNAL_METADATA, fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_CRIT, SD_JOURNAL_METADATA, "[" grp ## _TAG "] " fmt, ## __VA_ARGS__)
 
 #define kr_log_deprecate(grp, fmt, ...) \
-       kr_log_fmt(grp, LOG_WARNING,SD_JOURNAL_METADATA, "deprecation WARNING: " fmt, ## __VA_ARGS__)
+       kr_log_fmt(grp, LOG_WARNING,SD_JOURNAL_METADATA, "[" grp ## _TAG "] deprecation WARNING: " fmt, ## __VA_ARGS__)
 
 #define KR_LOG_LEVEL_IS(exp) ((kr_log_level >= (exp)) ? true : false)
 
@@ -113,3 +151,39 @@ typedef struct _code {
 KR_EXPORT
 extern syslog_code_t prioritynames[];
 #endif
+
+
+/* Misc. */
+
+struct kr_request;
+struct kr_query;
+
+/**
+ * Log a message through the request log handler or stdout.
+ * Caller is responsible for detecting verbose mode, use QRVERBOSE() macro.
+ * @param  qry_uid query ID to append to request ID, 0 means "no query"
+ * @param  indent level of indentation between [req.qry][source] and message
+ * @param  source message source
+ * @param  fmt message format
+ */
+#define kr_log_req(req, qry_id, indent, grp, fmt, ...) \
+       kr_log_req1(req, qry_id, indent, grp, grp ## _TAG, fmt, ## __VA_ARGS__)
+KR_EXPORT KR_PRINTF(6)
+void kr_log_req1(const struct kr_request * const req, uint32_t qry_uid,
+               const unsigned int indent, log_groups_t group, const char *tag, const char *fmt, ...);
+
+/**
+ * Log a message through the request log handler or stdout.
+ * Caller is responsible for detecting verbose mode, use QRVERBOSE() macro.
+ * @param  qry current query
+ * @param  source message source
+ * @param  fmt message format
+ */
+#define kr_log_q(qry, grp, fmt, ...) kr_log_q1(qry, grp, grp ## _TAG, fmt, ## __VA_ARGS__)
+KR_EXPORT KR_PRINTF(4)
+void kr_log_q1(const struct kr_query *qry, log_groups_t group, const char *tag, const char *fmt, ...);
+
+/** Block run in --verbose mode; optimized when not run. */
+#define VERBOSE_STATUS __builtin_expect(KR_LOG_LEVEL_IS(LOG_DEBUG), false) // TODO vyhodit
+#define WITH_VERBOSE(query) if(__builtin_expect(KR_LOG_LEVEL_IS(LOG_DEBUG) || kr_log_qtrace_enabled(query), false))
+#define kr_log_verbose if(VERBOSE_STATUS) printf
index dfb6d6b6f60263485c787caa8b9fd54a67c5f417..3c3b61542f786a7496295d29749217c5e57d7584 100644 (file)
@@ -26,7 +26,7 @@
 #define KNOT_EDNS_OPTION_COOKIE 10
 #endif /* ENABLE_COOKIES */
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), "resl",  __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), LOG_GRP_RESOLVER,  __VA_ARGS__)
 
 bool kr_rank_check(uint8_t rank)
 {
@@ -458,7 +458,7 @@ static void answer_fail(struct kr_request *request)
 {
        /* Note: OPT in SERVFAIL response is still useful for cookies/additional info. */
        if (VERBOSE_STATUS || kr_log_rtrace_enabled(request))
-               kr_log_req(request, 0, 0, "resl",
+               kr_log_req(request, 0, 0, LOG_GRP_RESOLVER,
                        "request failed, answering with empty SERVFAIL\n");
        knot_pkt_t *answer = request->answer;
        knot_rrset_t *opt_rr = answer->opt_rr; /* it gets NULLed below */
@@ -834,7 +834,7 @@ int kr_resolve_consume(struct kr_request *request, struct kr_transport **transpo
                if (request->state & KR_STATE_FAIL) {
                        if (++request->count_fail_row > KR_CONSUME_FAIL_ROW_LIMIT) {
                                if (VERBOSE_STATUS || kr_log_rtrace_enabled(request)) {
-                                       kr_log_req(request, 0, 2, "resl",
+                                       kr_log_req(request, 0, 2, LOG_GRP_RESOLVER,
                                                "=> too many failures in a row, "
                                                "bail out (mitigation for NXNSAttack "
                                                "CVE-2020-12667)\n");
index e88b982b6d7c2aaf930a0c27f58b8125f4386c8c..7eac9fa0b2ea109c0ddadfa508b66d6637f8311d 100644 (file)
@@ -11,7 +11,7 @@
 #include "lib/defines.h"
 #include "lib/layer.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "plan",  __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_PLAN,  __VA_ARGS__)
 
 inline static unsigned char chars_or(const unsigned char a, const unsigned char b)
 {
index 535af1691ae17b4c065c9fde9f4e173e96e4f093..dc2382d1a358c44c89bc96d8f2b8c1356c7688cb 100644 (file)
@@ -14,7 +14,7 @@
 
 #include "lib/utils.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), "slct", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), LOG_GRP_SELECTION, __VA_ARGS__)
 
 #define DEFAULT_TIMEOUT 400
 #define MAX_TIMEOUT 10000
index cde634d569754f836867a92a5d9b378ebc63cf94..f2f233d1a560228fff18ea72bb78f60ce19d13bb 100644 (file)
@@ -5,7 +5,7 @@
 #include "lib/selection_forward.h"
 #include "lib/resolve.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), "slct", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), LOG_GRP_SELECTION, __VA_ARGS__)
 
 #define FORWARDING_TIMEOUT 2000
 
index 87206cc014f5a7424f4cf2c02d88e01ba20d59d7..0a5bbda17adda1826c3e808bf6aafbd6ae3971d2 100644 (file)
@@ -10,7 +10,7 @@
 #include "lib/zonecut.h"
 #include "lib/resolve.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), "slct", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE((qry), LOG_GRP_SELECTION, __VA_ARGS__)
 
 /// To be held per query and locally.  Allocations are in the kr_request's mempool.
 struct iter_local_state {
index db5988bdb3c6230edfb1077b0f38e64c25649d85..016247c56a5bec8c81fcac94643c5a04aaf555df 100644 (file)
@@ -85,55 +85,6 @@ static inline int u16tostr(uint8_t *dst, uint16_t num)
        return 5;
 }
 
-/*
- * Cleanup callbacks.
- */
-static void kr_vlog_req(
-       const struct kr_request * const req, uint32_t qry_uid,
-       const unsigned int indent, const char *source, 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, "[%05u.%02u][%-4s] %*s",
-                               req_uid, qry_uid, source, indent, "");
-
-       msg = mp_vprintf_append(mp, msg, fmt, args);
-
-       if (kr_log_rtrace_enabled(req))
-               req->trace_log(req, msg);
-       else
-               /* caller is responsible for detecting verbose mode, use QRVERBOSE() macro */
-               printf("%s", msg);
-
-       mp_delete(mp);
-}
-
-void kr_log_req(const struct kr_request * const req, uint32_t qry_uid,
-               const unsigned int indent, const char *source, const char *fmt, ...)
-{
-       va_list args;
-       va_start(args, fmt);
-       kr_vlog_req(req, qry_uid, indent, source, fmt, args);
-       va_end(args);
-}
-
-void kr_log_q(const struct kr_query * const qry,
-               const char *source, const char *fmt, ...)
-{
-       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;
-       const struct kr_request *req = qry ? qry->request : NULL;
-
-       va_list args;
-       va_start(args, fmt);
-       kr_vlog_req(req, qry_uid, ind, source, fmt, args);
-       va_end(args);
-}
-
 char* kr_strcatdup(unsigned n, ...)
 {
        if (n < 1) {
@@ -817,7 +768,7 @@ int kr_ranked_rrarray_finalize(ranked_rr_array_t *array, uint32_t qry_uid, knot_
                                if (knot_rdata_cmp(ra->at[i], ra->at[i + 1]) == 0) {
                                        ra->at[i] = NULL;
                                        ++dup_count;
-                                       QRVERBOSE(NULL, "iter", "deleted duplicate RR\n");
+                                       QRVERBOSE(NULL, LOG_GRP_ITERATOR, "deleted duplicate RR\n");
                                }
                        }
                        /* Prepare rdataset, except rdata contents. */
index 4e9c7699d17516276ab4b36f031cc1abdd592200..ba628b417c08def3a0847c173135e59cb5d4bba5 100644 (file)
@@ -28,8 +28,6 @@
 #include "lib/generic/array.h"
 #include "lib/log.h"
 
-struct kr_query;
-struct kr_request;
 
 /*
  * Logging and debugging.
@@ -107,33 +105,6 @@ static inline bool kr_assert_func(bool result, const char *expr, const char *fun
        (qry) && kr_log_rtrace_enabled(qry->request), \
        false))
 
-/**
- * Log a message through the request log handler or stdout.
- * Caller is responsible for detecting verbose mode, use QRVERBOSE() macro.
- * @param  qry_uid query ID to append to request ID, 0 means "no query"
- * @param  indent level of indentation between [req.qry][source] and message
- * @param  source message source
- * @param  fmt message format
- */
-KR_EXPORT KR_PRINTF(5)
-void kr_log_req(const struct kr_request * const req, uint32_t qry_uid,
-               const unsigned int indent, const char *source, const char *fmt, ...);
-
-/**
- * Log a message through the request log handler or stdout.
- * Caller is responsible for detecting verbose mode, use QRVERBOSE() macro.
- * @param  qry current query
- * @param  source message source
- * @param  fmt message format
- */
-KR_EXPORT KR_PRINTF(3)
-void kr_log_q(const struct kr_query *qry, const char *source, const char *fmt, ...);
-
-/** Block run in --verbose mode; optimized when not run. */
-#define VERBOSE_STATUS __builtin_expect(KR_LOG_LEVEL_IS(LOG_DEBUG), false)
-#define WITH_VERBOSE(query) if(__builtin_expect(KR_LOG_LEVEL_IS(LOG_DEBUG) || kr_log_qtrace_enabled(query), false))
-#define kr_log_verbose if(VERBOSE_STATUS) printf
-
 #define KR_DNAME_GET_STR(dname_str, dname) \
        char dname_str[KR_DNAME_STR_MAXLEN]; \
        knot_dname_to_str(dname_str, (dname), sizeof(dname_str)); \
index 4577c634b5b89fc82479b045199e690376b52066..b0d5aeb5b029fbb6343cc93dac51bf1de69aeb26 100644 (file)
@@ -15,7 +15,7 @@
 #include <libknot/packet/wire.h>
 #include <libknot/rrtype/rdname.h>
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "zcut", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_ZCUT, __VA_ARGS__)
 
 /** Information for one NS name + address type. */
 typedef enum {
index 3cb06cb5bec5c4784cf72ecb057e21e5b7ba0b5b..eca6df8fbc2e13961b241be32350a64f0262b7ce 100644 (file)
@@ -20,7 +20,7 @@
 #include "lib/rplan.h"
 #include "modules/cookies/cookiemonster.h"
 
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "cookies", __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_COOKIES, __VA_ARGS__)
 
 /**
  * Obtain address from query/response context if if can be obtained.
index 740999000dd8a07175b3737b1b22aae4c4d7d0e3..35cdaf44f6f26b6a2eeab9cd2acf18425ec3a123 100644 (file)
@@ -25,8 +25,8 @@
 #include <math.h>
 
 /* Defaults */
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "hint",  __VA_ARGS__)
-#define ERR_MSG(...) kr_log_error(LOG_GRP_HINT, "[     ][hint]" __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_HINT,  __VA_ARGS__)
+#define ERR_MSG(...) kr_log_error(LOG_GRP_HINT, "[     ]" __VA_ARGS__)
 
 struct hints_data {
        struct kr_zonecut hints;
index 1b450d84f269d7bff32ea86594e57eade86c227a..a3cd304175a49ccd8df4f087c81530641474f796 100644 (file)
@@ -652,15 +652,17 @@ ffi.gc(debug_logline_cb, free_cb)
 
 local debug_logfinish_cb = ffi.cast('trace_callback_f', function (req)
        jit.off(true, true) -- JIT for (C -> lua)^2 nesting isn't allowed
-       ffi.C.kr_log_req(req, 0, 0, 'dbg',
+       local LOG_GRP_POLICY= bit.lshift(1, 25)
+       local LOG_GRP_POLICY_TAG="policy"
+       ffi.C.kr_log_req1(req, 0, 0, LOG_GRP_POLICY, LOG_GRP_POLICY_TAG,
                'following rrsets were marked as interesting:\n' ..
                req:selected_tostring())
        if req.answer ~= nil then
-               ffi.C.kr_log_req(req, 0, 0, 'dbg',
+               ffi.C.kr_log_req1(req, 0, 0, LOG_GRP_POLICY, LOG_GRP_POLICY_TAG,
                        'answer packet:\n' ..
                        tostring(req.answer))
        else
-               ffi.C.kr_log_req(req, 0, 0, 'dbg',
+               ffi.C.kr_log_req1(req, 0, 0, LOG_GRP_POLICY, LOG_GRP_POLICY_TAG,
                        'answer packet DROPPED\n')
        end
 end)
@@ -668,7 +670,10 @@ ffi.gc(debug_logfinish_cb, free_cb)
 
 -- log request packet
 function policy.REQTRACE(_, req)
-       ffi.C.kr_log_req(req, 0, 0, 'dbg', 'request packet:\n%s',
+       local LOG_GRP_POLICY= bit.lshift(1, 25)
+       local LOG_GRP_POLICY_TAG="policy"
+       ffi.C.kr_log_req1(req, 0, 0, LOG_GRP_POLICY, LOG_GRP_POLICY_TAG,
+               'request packet:\n%s',
                tostring(req.qsource.packet))
 end
 
index f75656ca88900b176a1553622f4007a979bbd4d8..68c6fd89ee7f08f110503a2c1312d4cd82830250 100644 (file)
@@ -108,7 +108,9 @@ function M.layer.consume(state, req, pkt)
                state = refuse(req)
        end
        if verbose() then
-               ffi.C.kr_log_q(qry, 'rebinding',
+               local LOG_GRP_REBIND= bit.lshift(1, 23)
+               local LOG_GRP_REBIND_TAG="rebind"
+               ffi.C.kr_log_q1(qry, LOG_GRP_REBIND, LOG_GRP_REBIND_TAG,
                    'blocking blacklisted IP in RR \'%s\'\n', kres.rr2str(bad_rr))
        end
        return state
index 5deb09323ae93b1bfb4ce554ee0055733fe26131..75b6a91272f41cffbf2b758f1e71803bf44194b7 100644 (file)
@@ -25,7 +25,7 @@
 #include "lib/resolve.h"
 
 /* Defaults */
-#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "stat",  __VA_ARGS__)
+#define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, LOG_GRP_STATISTICS,  __VA_ARGS__)
 #define FREQUENT_PSAMPLE  10 /* Sampling rate, 1 in N */
 #ifdef LRU_REP_SIZE
  #define FREQUENT_COUNT LRU_REP_SIZE /* Size of frequent tables */