]> git.ipfire.org Git - thirdparty/knot-resolver.git/commitdiff
lib: added support for trace_log for verbose messages
authorMarek Vavruša <mvavrusa@cloudflare.com>
Mon, 27 Nov 2017 23:02:35 +0000 (15:02 -0800)
committerMarek Vavruša <mvavrusa@cloudflare.com>
Sat, 2 Dec 2017 02:50:20 +0000 (18:50 -0800)
The `QRVERBOSE` macro uses the `query` pointer to find out whether the
request has trace log enabled. If it does, it uses trace log to log verbose messages using that callback (regardless of whether verbose mode is set or not).

This required changing of structure printing functions to formatting functions returning textual representation of the objects (dname, rrset, pkt).
This is potentially slower as creates heap objects, but it doesn't happen
in the hotpath so it doesn't really matter for verbose logs.

14 files changed:
contrib/contrib.mk
contrib/ucw/lib.h
contrib/ucw/mempool-fmt.c [new file with mode: 0644]
daemon/worker.c
lib/dnssec/ta.c
lib/layer.h
lib/layer/iterate.c
lib/layer/rrcache.c
lib/layer/validate.c
lib/nsrep.c
lib/resolve.c
lib/rplan.c
lib/utils.c
lib/utils.h

index 1753b530fb1382739aa5c577f737886c71d0e3f8..b311c974d3fd1bc1ff674713204bc6add3ea5019 100644 (file)
@@ -4,6 +4,7 @@ contrib_SOURCES := \
        contrib/ccan/isaac/isaac.c \
        contrib/ccan/json/json.c \
        contrib/ucw/mempool.c \
+       contrib/ucw/mempool-fmt.c \
        contrib/murmurhash3/murmurhash3.c \
        contrib/base32hex.c \
        contrib/base64.c
index ad0f02d9a0ea12906bcfbd48b36815d588ffb38e..771879330c6c35b38310e0861136398017679f1a 100644 (file)
@@ -15,6 +15,7 @@
 
 #include <stdarg.h>
 #include <stdbool.h>
+#include <stdlib.h>
 
 #ifdef CONFIG_UCW_CLEAN_ABI
 #define assert_failed ucw_assert_failed
diff --git a/contrib/ucw/mempool-fmt.c b/contrib/ucw/mempool-fmt.c
new file mode 100644 (file)
index 0000000..e9db0ab
--- /dev/null
@@ -0,0 +1,98 @@
+/*
+ *  UCW Library -- Memory Pools (Formatting)
+ *
+ *  (c) 2005 Martin Mares <mj@ucw.cz>
+ *  (c) 2007 Pavel Charvat <pchar@ucw.cz>
+ *
+ *  This software may be freely distributed and used according to the terms
+ *  of the GNU Lesser General Public License.
+ */
+
+#include <ucw/lib.h>
+#include <ucw/mempool.h>
+
+#include <alloca.h>
+#include <stdio.h>
+#include <string.h>
+
+static char *
+mp_vprintf_at(struct mempool *mp, size_t ofs, const char *fmt, va_list args)
+{
+  char *ret = mp_grow(mp, ofs + 1) + ofs;
+  va_list args2;
+  va_copy(args2, args);
+  int cnt = vsnprintf(ret, mp_avail(mp) - ofs, fmt, args2);
+  va_end(args2);
+  if (cnt < 0)
+    {
+      /* Our C library doesn't support C99 return value of vsnprintf, so we need to iterate */
+      do
+  {
+    ret = mp_expand(mp) + ofs;
+    va_copy(args2, args);
+    cnt = vsnprintf(ret, mp_avail(mp) - ofs, fmt, args2);
+    va_end(args2);
+  }
+      while (cnt < 0);
+    }
+  else if ((uint)cnt >= mp_avail(mp) - ofs)
+    {
+      ret = mp_grow(mp, ofs + cnt + 1) + ofs;
+      va_copy(args2, args);
+      vsnprintf(ret, cnt + 1, fmt, args2);
+      va_end(args2);
+    }
+  mp_end(mp, ret + cnt + 1);
+  return ret - ofs;
+}
+
+char *
+mp_vprintf(struct mempool *mp, const char *fmt, va_list args)
+{
+  mp_start(mp, 1);
+  return mp_vprintf_at(mp, 0, fmt, args);
+}
+
+char *
+mp_printf(struct mempool *p, const char *fmt, ...)
+{
+  va_list args;
+  va_start(args, fmt);
+  char *res = mp_vprintf(p, fmt, args);
+  va_end(args);
+  return res;
+}
+
+char *
+mp_vprintf_append(struct mempool *mp, char *ptr, const char *fmt, va_list args)
+{
+  size_t ofs = mp_open(mp, ptr);
+  ASSERT(ofs && !ptr[ofs - 1]);
+  return mp_vprintf_at(mp, ofs - 1, fmt, args);
+}
+
+char *
+mp_printf_append(struct mempool *mp, char *ptr, const char *fmt, ...)
+{
+  va_list args;
+  va_start(args, fmt);
+  char *res = mp_vprintf_append(mp, ptr, fmt, args);
+  va_end(args);
+  return res;
+}
+
+#ifdef TEST
+
+int main(void)
+{
+  struct mempool *mp = mp_new(64);
+  char *x = mp_printf(mp, "<Hello, %s!>", "World");
+  fputs(x, stdout);
+  x = mp_printf_append(mp, x, "<Appended>");
+  fputs(x, stdout);
+  x = mp_printf(mp, "<Hello, %50s!>\n", "World");
+  fputs(x, stdout);
+  return 0;
+}
+
+#endif
\ No newline at end of file
index 5168608c56dbe9f47b39b551a7eb1a6d29c7c03a..1c46052b28761a58ed98f78442011f57101ee3ec 100644 (file)
@@ -587,7 +587,7 @@ static void on_timeout(uv_timer_t *req)
                struct sockaddr_in6 *addrlist = (struct sockaddr_in6 *)task->addrlist;
                for (uint16_t i = 0; i < MIN(task->pending_count, task->addrlist_count); ++i) {
                        struct sockaddr *choice = (struct sockaddr *)(&addrlist[i]);
-                       WITH_VERBOSE {
+                       WITH_VERBOSE(qry) {
                                char addr_str[INET6_ADDRSTRLEN];
                                inet_ntop(choice->sa_family, kr_inaddr(choice), addr_str, sizeof(addr_str));
                                VERBOSE_MSG(qry, "=> server: '%s' flagged as 'bad'\n", addr_str);
index 740444eeb22d5f195301bc5baeb0eb12889b020c..28d26724f9aec33c2eacbf7d12e333a06787ce95 100644 (file)
@@ -14,6 +14,7 @@
     along with this program.  If not, see <https://www.gnu.org/licenses/>.
  */
 
+#include <contrib/cleanup.h>
 #include <libknot/descriptor.h>
 #include <libknot/rdataset.h>
 #include <libknot/rrset.h>
@@ -90,8 +91,9 @@ static int insert_ta(map_t *trust_anchors, const knot_dname_t *name,
                knot_rrset_free(&ta_rr, NULL);
                return kr_error(ENOMEM);
        }
-       WITH_VERBOSE {
-               kr_rrset_print(ta_rr, "[ ta ] new state of trust anchors for a domain:\n");
+       if(VERBOSE_STATUS) {
+               auto_free char *rr_text = kr_rrset_text(ta_rr);
+               kr_log_verbose("[ ta ] new state of trust anchors for a domain: %s\n", rr_text);
        }
        if (is_new_key) {
                return map_set(trust_anchors, (const char *)name, ta_rr);
index c3c28accea515507384edfb51babfd49bdbf2583..2d2e86cda7d7c6fc8f9bc25c809ff8e0f76b0f0d 100644 (file)
 
 #ifndef NOVERBOSELOG
  /** @internal Print a debug message related to resolution. */
- #define QRVERBOSE(query, cls, fmt, ...) WITH_VERBOSE { \
-    unsigned _ind = 0; \
+ #define QRVERBOSE(query, cls, fmt, ...) { \
     const struct kr_query *q = (query); \
-    uint16_t _id = q ? q->id : 0; \
-    for (; q; q = q->parent, _ind += 2); \
-    kr_log_verbose("[%5hu][%s] %*s" fmt, _id, cls, _ind, "", ##  __VA_ARGS__); \
-    }
+    if (kr_log_trace_enabled(q)) { \
+        kr_log_trace(q, cls, fmt, ##  __VA_ARGS__); \
+    } else WITH_VERBOSE(q) { \
+        unsigned _ind = 0; \
+        uint16_t _id = q ? q->id : 0; \
+        for (; q; q = q->parent, _ind += 2); \
+        kr_log_verbose("[%5hu][%s] %*s" fmt, _id, cls, _ind, "", ##  __VA_ARGS__); \
+    } \
+}
 #else
  #define QRVERBOSE(query, cls, fmt, ...)
 #endif
index 9d5ded5ceb8d8ae3dc8bd9c38dc4173e4328a204..e1c0cf10632d376a7d6c2bf1ee4ff06714b4bf49 100644 (file)
@@ -31,6 +31,7 @@
 #include <assert.h>
 #include <arpa/inet.h>
 
+#include <contrib/cleanup.h>
 #include <libknot/descriptor.h>
 #include <libknot/rrtype/rdname.h>
 #include <libknot/rrtype/rrsig.h>
@@ -155,7 +156,7 @@ static int update_nsaddr(const knot_rrset_t *rr, struct kr_query *query)
                const int addr_len = knot_rdata_rdlen(rdata);
                char name_str[KNOT_DNAME_MAXLEN];
                char addr_str[INET6_ADDRSTRLEN];
-               WITH_VERBOSE {
+               WITH_VERBOSE(query) {
                        const int af = (addr_len == sizeof(struct in_addr)) ?
                                       AF_INET : AF_INET6;
                        knot_dname_to_str(name_str, rr->owner, sizeof(name_str));
@@ -819,11 +820,11 @@ int kr_make_query(struct kr_query *query, knot_pkt_t *pkt)
        query->id = rnd ^ (rnd >> 16); /* cheap way to strengthen unpredictability */
        knot_wire_set_id(pkt->wire, query->id);
        pkt->parsed = pkt->size;
-       WITH_VERBOSE {
+       WITH_VERBOSE(query) {
                char name_str[KNOT_DNAME_MAXLEN], type_str[16];
                knot_dname_to_str(name_str, query->sname, sizeof(name_str));
                knot_rrtype_to_string(query->stype, type_str, sizeof(type_str));
-               QVERBOSE_MSG(query, "'%s' type '%s' id was assigned, parent id %hu\n",
+               QVERBOSE_MSG(query, "'%s' type '%s' created outbound query, parent id %hu\n",
                            name_str, type_str, query->parent ? query->parent->id : 0);
        }
        return kr_ok();
@@ -882,11 +883,11 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
                return ctx->state;
        }
 
-       WITH_VERBOSE {
-       if (query->flags.TRACE) {
-               VERBOSE_MSG("<= answer received:\n");
-               kr_pkt_print(pkt);
-       }
+       WITH_VERBOSE(query) {
+               if (query->flags.TRACE) {
+                       auto_free char *pkt_text = kr_pkt_text(pkt);
+                       VERBOSE_MSG("<= answer received: \n%s\n", pkt_text);
+               }
        }
 
        if (query->flags.RESOLVED || query->flags.BADCOOKIE_AGAIN) {
index fc7adc4815c72520c3a48a759c893aaf1c17a093..474103f138f8333d6a395873e023b741ad772846 100644 (file)
@@ -28,6 +28,7 @@
 
 #include <assert.h>
 
+#include <contrib/cleanup.h>
 #include <libknot/descriptor.h>
 #include <libknot/errcode.h>
 #include <libknot/rrset.h>
@@ -75,13 +76,11 @@ static int loot_rr(struct kr_cache *cache, knot_pkt_t *pkt, const knot_dname_t *
                return ret;
        }
 
-       WITH_VERBOSE {
-               VERBOSE_MSG(qry, "=> rank: 0%0.2o, lowest 0%0.2o, ", *rank, lowest_rank);
-               if (fetch_rrsig) {
-                       kr_log_verbose("RRSIG for ");
-               }
-               kr_rrtype_print(rrtype, "", " ");
-               kr_dname_print(name, "", "\n");
+       WITH_VERBOSE(qry) {
+               auto_free char *name_text = kr_dname_text(name);
+               auto_free char *type_text = kr_rrtype_text(rrtype);
+               VERBOSE_MSG(qry, "=> rank: 0%0.2o, lowest 0%0.2o, %s%s %s\n",
+                       *rank, lowest_rank, fetch_rrsig ? "RRSIG for " : "", name_text, type_text);
        }
 
        if (*rank < lowest_rank) {
@@ -320,10 +319,10 @@ static int commit_rr(const char *key, void *val, void *data)
                }
        }
 
-       WITH_VERBOSE {
-               VERBOSE_MSG(baton->qry, "=> stashing rank: 0%0.2o, ", rank);
-               kr_rrtype_print(rr->type, "", " ");
-               kr_dname_print(rr->owner, "", "\n");
+       WITH_VERBOSE(baton->qry) {
+               auto_free char *name_text = kr_dname_text(rr->owner);
+               auto_free char *type_text = kr_rrtype_text(rr->type);
+               VERBOSE_MSG(baton->qry, "=> stashing rank: 0%0.2o, %s %s\n", rank, name_text, type_text);
        }
 
        uint8_t flags = KR_CACHE_FLAG_NONE;
index 1b6e9f37bbdbd728ee51b4d9ceacaae4bef22cbd..f58ded96d0824839bcedd0fe8e535bde2d2880b6 100644 (file)
@@ -20,6 +20,7 @@
 #include <stdio.h>
 #include <string.h>
 
+#include <contrib/cleanup.h>
 #include <libknot/packet/wire.h>
 #include <libknot/rrtype/rdname.h>
 #include <libknot/rrtype/rrsig.h>
@@ -119,10 +120,10 @@ static int validate_section(kr_rrset_validation_ctx_t *vctx, const struct kr_que
                        kr_rank_set(&entry->rank, KR_RANK_SECURE);
 
                } else if (kr_rank_test(rank_orig, KR_RANK_TRY)) {
-                       WITH_VERBOSE {
-                               VERBOSE_MSG(qry, ">< failed to validate but skipping: ");
-                               kr_rrtype_print(rr->type, "", " ");
-                               kr_dname_print(rr->owner, "", "\n");
+                       WITH_VERBOSE(qry) {
+                               auto_free char *name_text = kr_dname_text(rr->owner);
+                               auto_free char *type_text = kr_rrtype_text(rr->type);
+                               VERBOSE_MSG(qry, ">< failed to validate but skipping: %s %s\n", name_text, type_text);
                        }
                        vctx->result = kr_ok();
                        kr_rank_set(&entry->rank, KR_RANK_TRY);
@@ -553,10 +554,10 @@ static int check_validation_result(kr_layer_t *ctx, ranked_rr_array_t *arr)
                VERBOSE_MSG(qry, ">< cut changed (new signer), needs revalidation\n");
                ret = KR_STATE_YIELD;
        } else if (kr_rank_test(invalid_entry->rank, KR_RANK_MISSING)) {
-               WITH_VERBOSE {
-                       VERBOSE_MSG(qry, ">< no valid RRSIGs found for ");
-                       kr_rrtype_print(invalid_entry->rr->type, "", " ");
-                       kr_dname_print(invalid_entry->rr->owner, "", "\n");
+               WITH_VERBOSE(qry) {
+                       auto_free char *name_text = kr_dname_text(invalid_entry->rr->owner);
+                       auto_free char *type_text = kr_rrtype_text(invalid_entry->rr->type);
+                       VERBOSE_MSG(qry, ">< no valid RRSIGs found for %s %s\n", name_text, type_text);
                }
                ret = rrsig_not_found(ctx, rr);
        } else if (!kr_rank_test(invalid_entry->rank, KR_RANK_SECURE)) {
index e4452b57d8b2e4ca4167bd3482f541fed708978b..aafa717ebfdd77983becbcd26d895db69fb619c5 100644 (file)
@@ -375,7 +375,7 @@ int kr_nsrep_sort(struct kr_nsrep *ns, kr_nsrep_lru_t *cache)
                } else {
                        scores[i] = *score;
                }
-               WITH_VERBOSE {
+               if (VERBOSE_STATUS) {
                        char sa_str[INET6_ADDRSTRLEN];
                        inet_ntop(sa->sa_family, kr_inaddr(sa), sa_str, sizeof(sa_str));
                        kr_log_verbose("[     ][nsre] score %d for %s;\t cached RTT: %d\n",
index 2e91000d86e589e477c3b7c921e851cf16c9192e..20b773ba65a3cd7beed1dc25bcbca735515393e3 100644 (file)
@@ -810,7 +810,7 @@ static void update_nslist_rtt(struct kr_context *ctx, struct kr_query *qry, cons
                /* If this address is the source of the answer, update its RTT */
                if (kr_inaddr_equal(src, addr)) {
                        kr_nsrep_update_rtt(&qry->ns, addr, elapsed, ctx->cache_rtt, KR_NS_UPDATE);
-                       WITH_VERBOSE {
+                       WITH_VERBOSE(qry) {
                                char addr_str[INET6_ADDRSTRLEN];
                                inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str));
                                VERBOSE_MSG(qry, "<= server: '%s' rtt: %ld ms\n", addr_str, elapsed);
@@ -822,7 +822,7 @@ static void update_nslist_rtt(struct kr_context *ctx, struct kr_query *qry, cons
                         * that 'b' didn't respond for at least 350 - (1 * 300) ms. We can't say that
                         * its RTT is 50ms, but we can say that its score shouldn't be less than 50. */
                         kr_nsrep_update_rtt(&qry->ns, addr, elapsed, ctx->cache_rtt, KR_NS_MAX);
-                        WITH_VERBOSE {
+                        WITH_VERBOSE(qry) {
                                char addr_str[INET6_ADDRSTRLEN];
                                inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str));
                                VERBOSE_MSG(qry, "<= server: '%s' rtt: >=%ld ms\n", addr_str, elapsed);
@@ -854,7 +854,7 @@ static void update_nslist_score(struct kr_request *request, struct kr_query *qry
        /* Penalise resolution failures except validation failures. */
        } else if (!(qry->flags.DNSSEC_BOGUS)) {
                kr_nsrep_update_rtt(&qry->ns, src, KR_NS_TIMEOUT, ctx->cache_rtt, KR_NS_RESET);
-               WITH_VERBOSE {
+               WITH_VERBOSE(qry) {
                        char addr_str[INET6_ADDRSTRLEN];
                        inet_ntop(src->sa_family, kr_inaddr(src), addr_str, sizeof(addr_str));
                        VERBOSE_MSG(qry, "=> server: '%s' flagged as 'bad'\n", addr_str);
@@ -866,7 +866,7 @@ bool check_resolution_time(struct kr_query *qry, struct timeval *now)
 {
        long resolving_time = time_diff(&qry->creation_time, now);
        if (resolving_time > KR_RESOLVE_TIME_LIMIT) {
-               WITH_VERBOSE {
+               WITH_VERBOSE(qry) {
                        VERBOSE_MSG(qry, "query resolution time limit exceeded\n");
                }
                return false;
@@ -1123,7 +1123,7 @@ static int forward_trust_chain_check(struct kr_request *request, struct kr_query
            kr_ta_get(trust_anchors, wanted_name)) {
                qry->flags.DNSSEC_WANT = true;
                want_secured = true;
-               WITH_VERBOSE {
+               WITH_VERBOSE(qry) {
                char qname_str[KNOT_DNAME_MAXLEN];
                knot_dname_to_str(qname_str, wanted_name, sizeof(qname_str));
                VERBOSE_MSG(qry, ">< TA: '%s'\n", qname_str);
@@ -1202,7 +1202,7 @@ static int trust_chain_check(struct kr_request *request, struct kr_query *qry)
                        mm_free(qry->zone_cut.pool, qry->zone_cut.trust_anchor);
                        qry->zone_cut.trust_anchor = knot_rrset_copy(ta_rr, qry->zone_cut.pool);
 
-                       WITH_VERBOSE {
+                       WITH_VERBOSE(qry) {
                        char qname_str[KNOT_DNAME_MAXLEN];
                        knot_dname_to_str(qname_str, ta_rr->owner, sizeof(qname_str));
                        VERBOSE_MSG(qry, ">< TA: '%s'\n", qname_str);
@@ -1523,7 +1523,7 @@ int kr_resolve_checkout(struct kr_request *request, struct sockaddr *src,
                return kr_error(EINVAL);
        }
 
-       WITH_VERBOSE {
+       WITH_VERBOSE(qry) {
        char qname_str[KNOT_DNAME_MAXLEN], zonecut_str[KNOT_DNAME_MAXLEN], ns_str[INET6_ADDRSTRLEN], type_str[16];
        knot_dname_to_str(qname_str, knot_pkt_qname(packet), sizeof(qname_str));
        knot_dname_to_str(zonecut_str, qry->zone_cut.name, sizeof(zonecut_str));
@@ -1564,7 +1564,9 @@ int kr_resolve_finish(struct kr_request *request, int state)
 
        request->state = state;
        ITERATE_LAYERS(request, NULL, finish);
-       VERBOSE_MSG(NULL, "finished: %d, queries: %zu, mempool: %zu B\n",
+
+       struct kr_query *last = rplan->resolved.len > 0 ? array_tail(rplan->resolved) : NULL;
+       VERBOSE_MSG(last, "finished: %d, queries: %zu, mempool: %zu B\n",
                  request->state, rplan->resolved.len, (size_t) mp_total_size(request->pool.ctx));
        return KR_STATE_DONE;
 }
index 4069a8cc598399a693531606d2ed1a6c677bb7bb..26ba106c50ad5740c0890f1046850241023060d8 100644 (file)
@@ -186,8 +186,8 @@ struct kr_query *kr_rplan_push_empty(struct kr_rplan *rplan, struct kr_query *pa
                return NULL;
        }
 
-       WITH_VERBOSE {
-       VERBOSE_MSG(parent, "plan '%s' type '%s'\n", "", "");
+       WITH_VERBOSE(qry) {
+       VERBOSE_MSG(qry, "plan '%s' type '%s'\n", "", "");
        }
        return qry;
 }
@@ -207,7 +207,7 @@ struct kr_query *kr_rplan_push(struct kr_rplan *rplan, struct kr_query *parent,
        qry->sclass = cls;
        qry->stype = type;
 
-       WITH_VERBOSE {
+       WITH_VERBOSE(qry) {
        char name_str[KNOT_DNAME_MAXLEN], type_str[16];
        knot_dname_to_str(name_str, name, sizeof(name_str));
        knot_rrtype_to_string(type, type_str, sizeof(type_str));
index eb1cad05947a2908fa8ccec8865626693815e9d6..3dae6331ad7370208b2f23dea3c2ccac55f7cad1 100644 (file)
@@ -23,6 +23,7 @@
 #include <contrib/cleanup.h>
 #include <contrib/ccan/asprintf/asprintf.h>
 #include <ccan/isaac/isaac.h>
+#include <ucw/mempool.h>
 #include <gnutls/gnutls.h>
 #include <libknot/descriptor.h>
 #include <libknot/dname.h>
@@ -661,21 +662,6 @@ char *kr_module_call(struct kr_context *ctx, const char *module, const char *pro
        return NULL;
 }
 
-void kr_rrset_print(const knot_rrset_t *rr, const char *prefix)
-{
-#if KNOT_VERSION_HEX < ((2 << 16) | (4 << 8))
-       char rrtext[KNOT_DNAME_MAXLEN * 2] = {0};
-       knot_rrset_txt_dump(rr, rrtext, sizeof(rrtext), &KNOT_DUMP_STYLE_DEFAULT);
-       kr_log_verbose("%s%s", prefix, rrtext);
-#else
-       size_t size = 4000;
-       char *rrtext = malloc(size);
-       knot_rrset_txt_dump(rr, &rrtext, &size, &KNOT_DUMP_STYLE_DEFAULT);
-       kr_log_verbose("%s%s", prefix, rrtext);
-       free(rrtext);
-#endif
-}
-
 static void flags_to_str(char *dst, const knot_pkt_t *pkt, size_t maxlen)
 {
        int offset = 0;
@@ -707,7 +693,7 @@ static void flags_to_str(char *dst, const knot_pkt_t *pkt, size_t maxlen)
        dst[offset] = 0;
 }
 
-static void print_section_opt(const knot_rrset_t *rr, const uint8_t rcode)
+static char *print_section_opt(struct mempool *mp, char *endp, const knot_rrset_t *rr, const uint8_t rcode)
 {
        uint8_t ercode = knot_edns_get_ext_rcode(rr);
        uint16_t ext_rcode_id = knot_edns_whole_rcode(ercode, rcode);
@@ -723,18 +709,25 @@ static void print_section_opt(const knot_rrset_t *rr, const uint8_t rcode)
                }
        }
 
-       kr_log_verbose(";; EDNS PSEUDOSECTION:\n;; "
-                      "Version: %u; flags: %s; UDP size: %u B; ext-rcode: %s\n\n",
-                      knot_edns_get_version(rr),
-                      (knot_edns_do(rr) != 0) ? "do" : "",
-                      knot_edns_get_payload(rr),
-                      ext_rcode_str);
+       return mp_printf_append(mp, endp,
+               ";; EDNS PSEUDOSECTION:\n;; "
+               "Version: %u; flags: %s; UDP size: %u B; ext-rcode: %s\n\n",
+               knot_edns_get_version(rr),
+               (knot_edns_do(rr) != 0) ? "do" : "",
+               knot_edns_get_payload(rr),
+               ext_rcode_str);
 
 }
 
-void kr_pkt_print(knot_pkt_t *pkt)
+char *kr_pkt_text(const knot_pkt_t *pkt)
 {
-       char *snames[] = {";; ANSWER SECTION",";; AUTHORITY SECTION",";; ADDITIONAL SECTION"};
+       if (!pkt) {
+               return NULL;
+       }
+
+       struct mempool *mp = mp_new(512);
+
+       static char *snames[] = {";; ANSWER SECTION",";; AUTHORITY SECTION",";; ADDITIONAL SECTION"};
        char rrtype[32];
        char flags[32];
        char qname[KNOT_DNAME_MAXLEN];
@@ -754,77 +747,67 @@ void kr_pkt_print(knot_pkt_t *pkt)
                opcode_str = opcode->name;
        }
        flags_to_str(flags, pkt, sizeof(flags));
-       kr_log_verbose(";; ->>HEADER<<- opcode: %s; status: %s; id: %hu\n",
-                      opcode_str, rcode_str, qry_id);
 
-       kr_log_verbose(";; Flags: %s QUERY: %hu; ANSWER: %hu; "
-                      "AUTHORITY: %hu; ADDITIONAL: %hu\n\n",
-                      flags,
-                      qdcount,
-                      knot_wire_get_ancount(pkt->wire),
-                      knot_wire_get_nscount(pkt->wire),
-                      knot_wire_get_arcount(pkt->wire));
+       char *ptr = mp_printf(mp,
+               ";; ->>HEADER<<- opcode: %s; status: %s; id: %hu\n"
+               ";; Flags: %s QUERY: %hu; ANSWER: %hu; "
+               "AUTHORITY: %hu; ADDITIONAL: %hu\n\n",
+               opcode_str, rcode_str, qry_id,
+               flags,
+               qdcount,
+               knot_wire_get_ancount(pkt->wire),
+               knot_wire_get_nscount(pkt->wire),
+               knot_wire_get_arcount(pkt->wire));
 
        if (knot_pkt_has_edns(pkt)) {
-               print_section_opt(pkt->opt_rr,
-                                 knot_wire_get_rcode(pkt->wire));
+               ptr = print_section_opt(mp, ptr, pkt->opt_rr, knot_wire_get_rcode(pkt->wire));
        }
 
        if (qdcount == 1) {
                knot_dname_to_str(qname, knot_pkt_qname(pkt), KNOT_DNAME_MAXLEN);
                knot_rrtype_to_string(knot_pkt_qtype(pkt), rrtype, sizeof(rrtype));
-               kr_log_verbose(";; QUESTION SECTION\n%s\t\t%s\n\n", qname, rrtype);
+               ptr = mp_printf_append(mp, ptr, ";; QUESTION SECTION\n%s\t\t%s\n", qname, rrtype);
        } else if (qdcount > 1) {
-               kr_log_verbose(";; Warning: unsupported QDCOUNT %hu\n", qdcount);
+               ptr = mp_printf_append(mp, ptr, ";; Warning: unsupported QDCOUNT %hu\n", qdcount);
        }
-       for (knot_section_t i = KNOT_ANSWER; i <= KNOT_AUTHORITY; ++i) {
+
+       for (knot_section_t i = KNOT_ANSWER; i <= KNOT_ADDITIONAL; ++i) {
                const knot_pktsection_t *sec = knot_pkt_section(pkt, i);
-               if (sec->count == 0) {
+               if (sec->count == 0 || knot_pkt_rr(sec, 0)->type == KNOT_RRTYPE_OPT) {
                        continue;
                }
-               kr_log_verbose("%s\n", snames[i - KNOT_ANSWER]);
+
+               ptr = mp_printf_append(mp, ptr, "\n%s\n", snames[i - KNOT_ANSWER]);
                for (unsigned k = 0; k < sec->count; ++k) {
                        const knot_rrset_t *rr = knot_pkt_rr(sec, k);
-                       kr_rrset_print(rr, "");
-               }
-               kr_log_verbose("\n");
-       }
-       const knot_pktsection_t *sec = knot_pkt_section(pkt, KNOT_ADDITIONAL);
-       bool header_was_printed = false;
-       for (unsigned k = 0; k < sec->count; ++k) {
-               const knot_rrset_t *rr = knot_pkt_rr(sec, k);
-               if (rr->type == KNOT_RRTYPE_OPT) {
-                       continue;
-               }
-               if (!header_was_printed) {
-                       header_was_printed = true;
-                       kr_log_verbose("%s\n", snames[KNOT_ADDITIONAL - KNOT_ANSWER]);
+                       if (rr->type == KNOT_RRTYPE_OPT) {
+                               continue;
+                       }
+                       auto_free char *rr_text = kr_rrset_text(rr);
+                       ptr = mp_printf_append(mp, ptr, "%s", rr_text);
                }
-               kr_rrset_print(rr, "");
        }
-       kr_log_verbose("\n");
-}
 
-void kr_dname_print(const knot_dname_t *name, const char *prefix, const char *postfix)
-{
-       char str[KNOT_DNAME_MAXLEN] = {0};
-       knot_dname_to_str(str, name, KNOT_DNAME_MAXLEN);
-       kr_log_verbose("%s%s%s", prefix, str, postfix);
+       /* Close growing buffer and duplicate result before deleting */
+       char *result = strdup(ptr);
+       mp_delete(mp);
+       return result;
 }
 
-void kr_rrtype_print(const uint16_t rrtype, const char *prefix, const char *postfix)
+char *kr_rrset_text(const knot_rrset_t *rr)
 {
-       char str[32] = {0};
-       knot_rrtype_to_string(rrtype, str, 32);
-       kr_log_verbose("%s%s%s", prefix, str, postfix);
-}
+       if (!rr) {
+               return NULL;
+       }
 
-void kr_qry_print(const struct kr_query *qry, const char *prefix, const char *postfix)
-{
-       char str[6] = {0};
-       knot_rrclass_to_string(qry->sclass, str, sizeof(str));
-       kr_dname_print(qry->sname, prefix, " ");
-       kr_log_verbose("%s",str);
-       kr_rrtype_print(qry->stype, " ", postfix);
-}
+       /* Note: knot_rrset_txt_dump will double the size until the rrset fits */
+       char *buf = malloc(128);
+       size_t bufsize = sizeof(128);
+       int ret = knot_rrset_txt_dump(rr, &buf, &bufsize, &KNOT_DUMP_STYLE_DEFAULT);
+       if (ret < 0) {
+               free(buf);
+               return NULL;
+       }
 
+       return buf;
+}
\ No newline at end of file
index 639ad9a7f1c1c2040fbcd25ea441acfb3b7ef4af..0b9528c52eea488f11fe9023e6c8945ad1cdbc02 100644 (file)
@@ -74,8 +74,9 @@ KR_EXPORT bool kr_log_trace(const struct kr_query *query, const char *source, co
 #endif
 
 /** Block run in --verbose mode; optimized when not run. */
-#define WITH_VERBOSE if(__builtin_expect(kr_verbose_status, false))
-#define kr_log_verbose WITH_VERBOSE kr_log_verbose
+#define VERBOSE_STATUS __builtin_expect(kr_verbose_status, false)
+#define WITH_VERBOSE(query) if(__builtin_expect(kr_verbose_status || kr_log_trace_enabled(query), false))
+#define kr_log_verbose if(VERBOSE_STATUS) kr_log_verbose
 
 
 /* C11 compatibility, but without any implementation so far. */
@@ -278,11 +279,23 @@ int kr_ranked_rrarray_set_wire(ranked_rr_array_t *array, bool to_wire,
                               uint32_t qry_uid, bool check_dups,
                               bool (*extraCheck)(const ranked_rr_array_entry_t *));
 
-void kr_rrset_print(const knot_rrset_t *rr, const char *prefix);
-void kr_qry_print(const struct kr_query *qry, const char *prefix, const char *postfix);
-void kr_pkt_print(knot_pkt_t *pkt);
-void kr_dname_print(const knot_dname_t *name, const char *prefix, const char *postfix);
-void kr_rrtype_print(const uint16_t rrtype, const char *prefix, const char *postfix);
+KR_PURE
+char *kr_pkt_text(const knot_pkt_t *pkt);
+
+KR_PURE
+char *kr_rrset_text(const knot_rrset_t *rr);
+
+KR_PURE
+static inline char *kr_dname_text(const knot_dname_t *name) {
+       return knot_dname_to_str_alloc(name);
+}
+
+KR_CONST
+static inline char *kr_rrtype_text(const uint16_t rrtype) {
+       char type_str[32] = {0};
+       knot_rrtype_to_string(rrtype, type_str, sizeof(type_str));
+       return strdup(type_str);
+}
 
 /**
  * Call module property.