Commit d0150ffa authored by Ondřej Surý's avatar Ondřej Surý

Split NDEBUG to NDEBUG (asserts) and NOVERBOSELOG (verbose logging); rename...

Split NDEBUG to NDEBUG (asserts) and NOVERBOSELOG (verbose logging); rename all related symbols to use VERBOSE instead of DEBUG
parent 074257f5
......@@ -73,7 +73,7 @@ The daemon features a CLI interface, type ``help()`` to see the list of availabl
Verbose output
--------------
If the debug logging is compiled in, i.e. not turned off by ``-DNLOGDEBUG``, you can turn on verbose tracing of server operation with the ``-v`` option.
If the verbose logging is compiled in, i.e. not turned off by ``-DNOVERBOSELOG``, you can turn on verbose tracing of server operation with the ``-v`` option.
You can also toggle it on runtime with ``verbose(true|false)`` command.
.. code-block:: bash
......
......@@ -141,9 +141,9 @@ static int l_quit(lua_State *L)
static int l_verbose(lua_State *L)
{
if (lua_isboolean(L, 1) || lua_isnumber(L, 1)) {
kr_debug_set(lua_toboolean(L, 1));
kr_verbose_set(lua_toboolean(L, 1));
}
lua_pushboolean(L, kr_debug_do_log);
lua_pushboolean(L, kr_verbose_do_log);
return 1;
}
......
......@@ -299,8 +299,8 @@ static void help(int argc, char *argv[])
" -f, --forks=N Start N forks sharing the configuration.\n"
" -q, --quiet Quiet output, no prompt in interactive mode.\n"
" -v, --verbose Run in verbose mode."
#ifdef NLOGDEBUG
" (Recompile without -DNLOGDEBUG to activate.)"
#ifdef NOVERBOSELOG
" (Recompile without -DNOVERBOSELOG to activate.)"
#endif
"\n"
" -V, --version Print version of the server.\n"
......@@ -347,7 +347,7 @@ static int run_worker(uv_loop_t *loop, struct engine *engine, fd_array_t *ipc_se
}
memcpy(&engine->ipc_set, ipc_set, sizeof(*ipc_set));
tls_setup_logging(kr_debug_do_log);
tls_setup_logging(kr_verbose_do_log);
/* Notify supervisor. */
#ifdef HAS_SYSTEMD
sd_notify(0, "READY=1");
......@@ -459,9 +459,9 @@ int main(int argc, char **argv)
}
break;
case 'v':
kr_debug_set(true);
#ifdef NLOGDEBUG
kr_log_info("--verbose flag has no effect due to compilation with -DNLOGDEBUG.\n");
kr_verbose_set(true);
#ifdef NOVERBOSELOG
kr_log_info("--verbose flag has no effect due to compilation with -DNOVERBOSELOG.\n");
#endif
break;
case 'q':
......
......@@ -35,6 +35,8 @@
#include "daemon/io.h"
#include "daemon/tls.h"
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE(qry, "wrkr", fmt)
/* @internal Union of various libuv objects for freelist. */
struct req
{
......@@ -51,13 +53,6 @@ struct req
} as;
};
/** @internal Debugging facility. */
#ifdef DEBUG
#define DEBUG_MSG(fmt...) printf("[daem] " fmt)
#else
#define DEBUG_MSG(fmt...)
#endif
/* Convenience macros */
#define qr_task_ref(task) \
do { ++(task)->refs; } while(0)
......@@ -560,10 +555,10 @@ 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_DEBUG {
WITH_VERBOSE {
char addr_str[INET6_ADDRSTRLEN];
inet_ntop(choice->sa_family, kr_inaddr(choice), addr_str, sizeof(addr_str));
QRDEBUG(qry, "wrkr", "=> server: '%s' flagged as 'bad'\n", addr_str);
VERBOSE_MSG(qry, "=> server: '%s' flagged as 'bad'\n", addr_str);
}
kr_nsrep_update_rtt(&qry->ns, choice, KR_NS_TIMEOUT,
worker->engine->resolver.cache_rtt, KR_NS_UPDATE);
......@@ -1103,4 +1098,4 @@ struct worker_ctx *worker_create(struct engine *engine, knot_mm_t *pool,
return worker;
}
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -102,7 +102,7 @@ When you have all the dependencies ready, you can build and install.
.. note:: Always build with ``PREFIX`` if you want to install, as it is hardcoded in the executable for module search path.
Production code should be compiled with ``-DNDEBUG``.
If you build the binary with ``-DNLOGDEBUG``, verbose logging will be disabled as well.
If you build the binary with ``-DNOVERBOSELOG``, verbose logging will be disabled as well.
Alternatively you can build only specific parts of the project, i.e. ``library``.
......
......@@ -35,8 +35,6 @@
#include "lib/dnssec/signature.h"
#include "lib/dnssec.h"
#define DEBUG_MSG(fmt...) fprintf(stderr, fmt)
void kr_crypto_init(void)
{
dnssec_crypto_init();
......@@ -378,6 +376,3 @@ void kr_dnssec_key_free(struct dseckey **key)
dnssec_key_free((dnssec_key_t *) *key);
*key = NULL;
}
#undef DEBUG_MSG
......@@ -19,15 +19,15 @@
#include "lib/defines.h"
#include "lib/utils.h"
#ifndef NLOGDEBUG
#ifndef NOVERBOSELOG
/** @internal Print a debug message related to resolution. */
#define QRDEBUG(query, cls, fmt, ...) WITH_DEBUG { \
#define QRVERBOSE(query, cls, fmt, ...) WITH_VERBOSE { \
unsigned _ind = 0; \
for (struct kr_query *q = (query); q; q = q->parent, _ind += 2); \
kr_log_debug("[%s] %*s" fmt, cls, _ind, "", ## __VA_ARGS__); \
kr_log_verbose("[%s] %*s" fmt, cls, _ind, "", ## __VA_ARGS__); \
}
#else
#define QRDEBUG(query, cls, fmt, ...)
#define QRVERBOSE(query, cls, fmt, ...)
#endif
/** Layer processing states. Only one value at a time (but see TODO).
......
......@@ -29,7 +29,7 @@
#include "lib/module.h"
#include "lib/dnssec/ta.h"
#define DEBUG_MSG(fmt...) QRDEBUG(req->current_query, "iter", fmt)
#define VERBOSE_MSG(fmt...) QRVERBOSE(req->current_query, "iter", fmt)
/* Iterator often walks through packet section, this is an abstraction. */
typedef int (*rr_callback_t)(const knot_rrset_t *, unsigned, struct kr_request *);
......@@ -186,11 +186,11 @@ static void fetch_glue(knot_pkt_t *pkt, const knot_dname_t *ns, struct kr_reques
}
}
}
WITH_DEBUG {
WITH_VERBOSE {
char name_str[KNOT_DNAME_MAXLEN];
knot_dname_to_str(name_str, ns, sizeof(name_str));
if (used_glue) {
DEBUG_MSG("<= using glue for '%s'\n", name_str);
VERBOSE_MSG("<= using glue for '%s'\n", name_str);
}
}
}
......@@ -220,7 +220,7 @@ static int update_cut(knot_pkt_t *pkt, const knot_rrset_t *rr, struct kr_request
/* Authority MUST be at/below the authority of the nameserver, otherwise
* possible cache injection attempt. */
if (!knot_dname_in(cut->name, rr->owner)) {
DEBUG_MSG("<= authority: ns outside bailiwick\n");
VERBOSE_MSG("<= authority: ns outside bailiwick\n");
#ifdef STRICT_MODE
return KR_STATE_FAIL;
#else
......@@ -257,7 +257,7 @@ static int update_cut(knot_pkt_t *pkt, const knot_rrset_t *rr, struct kr_request
int glue_records = has_glue(pkt, ns_name);
/* Glue is mandatory for NS below zone */
if (!glue_records && knot_dname_in(rr->owner, ns_name)) {
DEBUG_MSG("<= authority: missing mandatory glue, rejecting\n");
VERBOSE_MSG("<= authority: missing mandatory glue, rejecting\n");
continue;
}
kr_zonecut_add(cut, ns_name, NULL);
......@@ -377,7 +377,7 @@ static int process_answer(knot_pkt_t *pkt, struct kr_request *req)
int pkt_class = kr_response_classify(pkt);
if (!knot_dname_is_equal(knot_pkt_qname(pkt), query->sname) &&
(pkt_class & (PKT_NOERROR|PKT_NXDOMAIN|PKT_REFUSED|PKT_NODATA))) {
DEBUG_MSG("<= found cut, retrying with non-minimized name\n");
VERBOSE_MSG("<= found cut, retrying with non-minimized name\n");
query->flags |= QUERY_NO_MINIMIZE;
return KR_STATE_CONSUME;
}
......@@ -385,7 +385,7 @@ static int process_answer(knot_pkt_t *pkt, struct kr_request *req)
/* This answer didn't improve resolution chain, therefore must be authoritative (relaxed to negative). */
if (!(query->flags & QUERY_STUB) && !is_authoritative(pkt, query)) {
if (pkt_class & (PKT_NXDOMAIN|PKT_NODATA)) {
DEBUG_MSG("<= lame response: non-auth sent negative response\n");
VERBOSE_MSG("<= lame response: non-auth sent negative response\n");
return KR_STATE_FAIL;
}
}
......@@ -434,7 +434,7 @@ static int process_answer(knot_pkt_t *pkt, struct kr_request *req)
break;
}
if (cname_chain_len > an->count || cname_chain_len > KR_CNAME_CHAIN_LIMIT) {
DEBUG_MSG("<= too long cname chain\n");
VERBOSE_MSG("<= too long cname chain\n");
return KR_STATE_FAIL;
}
/* Don't use pending_cname immediately.
......@@ -470,14 +470,14 @@ static int process_answer(knot_pkt_t *pkt, struct kr_request *req)
return KR_STATE_DONE;
}
}
DEBUG_MSG("<= cname chain, following\n");
VERBOSE_MSG("<= cname chain, following\n");
/* Check if the same query was already resolved */
for (int i = 0; i < req->rplan.resolved.len; ++i) {
struct kr_query * q = req->rplan.resolved.at[i];
if (q->sclass == query->sclass &&
q->stype == query->stype &&
knot_dname_is_equal(q->sname, cname)) {
DEBUG_MSG("<= cname chain loop\n");
VERBOSE_MSG("<= cname chain loop\n");
return KR_STATE_FAIL;
}
}
......@@ -595,20 +595,20 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
* Note - we *MUST* check if it has at least a QUESTION,
* otherwise it would crash on accessing QNAME. */
if (pkt->parsed < pkt->size || pkt->parsed <= KNOT_WIRE_HEADER_SIZE) {
DEBUG_MSG("<= malformed response\n");
VERBOSE_MSG("<= malformed response\n");
return resolve_badmsg(pkt, req, query);
} else if (!is_paired_to_query(pkt, query)) {
DEBUG_MSG("<= ignoring mismatching response\n");
VERBOSE_MSG("<= ignoring mismatching response\n");
/* Force TCP, to work around authoritatives messing up question
* without yielding to spoofed responses. */
query->flags |= QUERY_TCP;
return resolve_badmsg(pkt, req, query);
} else if (knot_wire_get_tc(pkt->wire)) {
DEBUG_MSG("<= truncated response, failover to TCP\n");
VERBOSE_MSG("<= truncated response, failover to TCP\n");
if (query) {
/* Fail if already on TCP. */
if (query->flags & QUERY_TCP) {
DEBUG_MSG("<= TC=1 with TCP, bailing out\n");
VERBOSE_MSG("<= TC=1 with TCP, bailing out\n");
return resolve_error(pkt, req);
}
query->flags |= QUERY_TCP;
......@@ -616,7 +616,7 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
return KR_STATE_CONSUME;
}
#ifndef NLOGDEBUG
#ifndef NOVERBOSELOG
const knot_lookup_t *rcode = knot_lookup_by_id(knot_rcode_names, knot_wire_get_rcode(pkt->wire));
#endif
......@@ -628,7 +628,7 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
case KNOT_RCODE_REFUSED:
case KNOT_RCODE_SERVFAIL: {
if (query->flags & QUERY_STUB) { break; } /* Pass through in stub mode */
DEBUG_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
VERBOSE_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
query->fails += 1;
if (query->fails >= KR_QUERY_NSRETRY_LIMIT) {
query->fails = 0; /* Reset per-query counter. */
......@@ -640,10 +640,10 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
}
case KNOT_RCODE_FORMERR:
case KNOT_RCODE_NOTIMPL:
DEBUG_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
VERBOSE_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
return resolve_badmsg(pkt, req, query);
default:
DEBUG_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
VERBOSE_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
return resolve_error(pkt, req);
}
......@@ -651,11 +651,11 @@ static int resolve(kr_layer_t *ctx, knot_pkt_t *pkt)
int state = process_authority(pkt, req);
switch(state) {
case KR_STATE_CONSUME: /* Not referral, process answer. */
DEBUG_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
VERBOSE_MSG("<= rcode: %s\n", rcode ? rcode->name : "??");
state = process_answer(pkt, req);
break;
case KR_STATE_DONE: /* Referral */
DEBUG_MSG("<= referral response, follow\n");
VERBOSE_MSG("<= referral response, follow\n");
break;
default:
break;
......@@ -678,4 +678,4 @@ const kr_layer_api_t *iterate_layer(struct kr_module *module)
KR_MODULE_EXPORT(iterate)
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -24,7 +24,7 @@
#include "lib/module.h"
#include "lib/resolve.h"
#define DEBUG_MSG(qry, fmt...) QRDEBUG((qry), " pc ", fmt)
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE((qry), " pc ", fmt)
#define DEFAULT_MAXTTL (15 * 60)
#define DEFAULT_NOTTL (5) /* Short-time "no data" retention to avoid bursts */
......@@ -121,7 +121,7 @@ static int pktcache_peek(kr_layer_t *ctx, knot_pkt_t *pkt)
struct kr_cache *cache = &ctx->req->ctx->cache;
int ret = loot_pktcache(cache, pkt, qry, &flags);
if (ret == 0) {
DEBUG_MSG(qry, "=> satisfied from cache\n");
VERBOSE_MSG(qry, "=> satisfied from cache\n");
qry->flags |= QUERY_CACHED|QUERY_NO_MINIMIZE;
if (flags & KR_CACHE_FLAG_WCARD_PROOF) {
qry->flags |= QUERY_DNSSEC_WEXPAND;
......@@ -232,7 +232,7 @@ static int pktcache_stash(kr_layer_t *ctx, knot_pkt_t *pkt)
/* Stash answer in the cache */
int ret = kr_cache_insert(cache, KR_CACHE_PKT, qname, qtype, &header, data);
if (ret == 0) {
DEBUG_MSG(qry, "=> answer cached for TTL=%u\n", ttl);
VERBOSE_MSG(qry, "=> answer cached for TTL=%u\n", ttl);
}
kr_cache_sync(cache);
return ctx->state;
......@@ -251,4 +251,4 @@ const kr_layer_api_t *pktcache_layer(struct kr_module *module)
KR_MODULE_EXPORT(pktcache)
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -30,7 +30,7 @@
#include "lib/utils.h"
#include "lib/resolve.h"
#define DEBUG_MSG(qry, fmt...) QRDEBUG((qry), " rc ", fmt)
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE((qry), " rc ", fmt)
#define DEFAULT_MINTTL (5) /* Short-time "no data" retention to avoid bursts */
/** Record is expiring if it has less than 1% TTL (or less than 5s) */
......@@ -139,7 +139,7 @@ static int rrcache_peek(kr_layer_t *ctx, knot_pkt_t *pkt)
}
}
if (ret == 0) {
DEBUG_MSG(qry, "=> satisfied from cache\n");
VERBOSE_MSG(qry, "=> satisfied from cache\n");
qry->flags |= QUERY_CACHED|QUERY_NO_MINIMIZE;
pkt->parsed = pkt->size;
knot_wire_set_qr(pkt->wire);
......@@ -305,12 +305,12 @@ static int stash_answer(struct kr_query *qry, knot_pkt_t *pkt, map_t *stash, kno
char key[KR_RRKEY_LEN];
int ret = kr_rrkey(key, next_cname, rr->type, KR_RANK_AUTH);
if (ret != 0 || map_get(stash, key)) {
DEBUG_MSG(qry, "<= cname chain loop\n");
VERBOSE_MSG(qry, "<= cname chain loop\n");
next_cname = NULL;
}
}
if (cname_chain_len > answer->count || cname_chain_len > KR_CNAME_CHAIN_LIMIT) {
DEBUG_MSG(qry, "<= too long cname chain\n");
VERBOSE_MSG(qry, "<= too long cname chain\n");
next_cname = NULL;
}
}
......@@ -388,4 +388,4 @@ const kr_layer_api_t *rrcache_layer(struct kr_module *module)
KR_MODULE_EXPORT(rrcache)
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -35,7 +35,7 @@
#include "lib/defines.h"
#include "lib/module.h"
#define DEBUG_MSG(qry, fmt...) QRDEBUG(qry, "vldr", fmt)
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE(qry, "vldr", fmt)
/**
* Search in section for given type.
......@@ -141,7 +141,7 @@ static int validate_section(kr_rrset_validation_ctx_t *vctx, knot_mm_t *pool)
static int validate_records(struct kr_query *qry, knot_pkt_t *answer, knot_mm_t *pool, bool has_nsec3)
{
if (!qry->zone_cut.key) {
DEBUG_MSG(qry, "<= no DNSKEY, can't validate\n");
VERBOSE_MSG(qry, "<= no DNSKEY, can't validate\n");
return kr_error(EBADMSG);
}
......@@ -271,14 +271,14 @@ static int update_parent_keys(struct kr_query *qry, uint16_t answer_type)
assert(parent);
switch(answer_type) {
case KNOT_RRTYPE_DNSKEY:
DEBUG_MSG(qry, "<= parent: updating DNSKEY\n");
VERBOSE_MSG(qry, "<= parent: updating DNSKEY\n");
parent->zone_cut.key = knot_rrset_copy(qry->zone_cut.key, parent->zone_cut.pool);
if (!parent->zone_cut.key) {
return KR_STATE_FAIL;
}
break;
case KNOT_RRTYPE_DS:
DEBUG_MSG(qry, "<= parent: updating DS\n");
VERBOSE_MSG(qry, "<= parent: updating DS\n");
if (qry->flags & QUERY_DNSSEC_INSECURE) { /* DS non-existence proven. */
do {
parent->flags &= ~QUERY_DNSSEC_WANT;
......@@ -345,10 +345,10 @@ static int update_delegation(struct kr_request *req, struct kr_query *qry, knot_
}
}
if (ret != 0) {
DEBUG_MSG(qry, "<= bogus proof of DS non-existence\n");
VERBOSE_MSG(qry, "<= bogus proof of DS non-existence\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
} else {
DEBUG_MSG(qry, "<= DS doesn't exist, going insecure\n");
VERBOSE_MSG(qry, "<= DS doesn't exist, going insecure\n");
qry->flags &= ~QUERY_DNSSEC_WANT;
qry->flags |= QUERY_DNSSEC_INSECURE;
}
......@@ -356,7 +356,7 @@ static int update_delegation(struct kr_request *req, struct kr_query *qry, knot_
}
/* Extend trust anchor */
DEBUG_MSG(qry, "<= DS: OK\n");
VERBOSE_MSG(qry, "<= DS: OK\n");
cut->trust_anchor = new_ds;
return ret;
}
......@@ -393,7 +393,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
/* Answer for RRSIG may not set DO=1, but all records MUST still validate. */
bool use_signatures = (knot_pkt_qtype(pkt) != KNOT_RRTYPE_RRSIG);
if (!(qry->flags & QUERY_CACHED) && !knot_pkt_has_dnssec(pkt) && !use_signatures) {
DEBUG_MSG(qry, "<= got insecure response\n");
VERBOSE_MSG(qry, "<= got insecure response\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
return KR_STATE_FAIL;
}
......@@ -408,7 +408,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
if (ctx->state == KR_STATE_YIELD) { /* Already yielded for revalidation. */
return KR_STATE_FAIL;
}
DEBUG_MSG(qry, ">< cut changed, needs revalidation\n");
VERBOSE_MSG(qry, ">< cut changed, needs revalidation\n");
if (!signer) {
/* Not a DNSSEC-signed response, ask parent for DS to prove transition to INSECURE. */
} else if (knot_dname_is_sub(signer, qry->zone_cut.name)) {
......@@ -435,7 +435,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
if (knot_wire_get_aa(pkt->wire) && qtype == KNOT_RRTYPE_DNSKEY) {
ret = validate_keyset(qry, pkt, has_nsec3);
if (ret != 0) {
DEBUG_MSG(qry, "<= bad keys, broken trust chain\n");
VERBOSE_MSG(qry, "<= bad keys, broken trust chain\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
return KR_STATE_FAIL;
}
......@@ -450,7 +450,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
ret = kr_nsec3_name_error_response_check(pkt, KNOT_AUTHORITY, qry->sname);
}
if (ret != 0) {
DEBUG_MSG(qry, "<= bad NXDOMAIN proof\n");
VERBOSE_MSG(qry, "<= bad NXDOMAIN proof\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
return KR_STATE_FAIL;
}
......@@ -473,11 +473,11 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
}
if (ret != 0) {
if (has_nsec3 && (ret == kr_error(DNSSEC_NOT_FOUND))) {
DEBUG_MSG(qry, "<= can't prove NODATA due to optout, going insecure\n");
VERBOSE_MSG(qry, "<= can't prove NODATA due to optout, going insecure\n");
qry->flags &= ~QUERY_DNSSEC_WANT;
qry->flags |= QUERY_DNSSEC_INSECURE;
} else {
DEBUG_MSG(qry, "<= bad NODATA proof\n");
VERBOSE_MSG(qry, "<= bad NODATA proof\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
return KR_STATE_FAIL;
}
......@@ -490,7 +490,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
if (!(qry->flags & QUERY_CACHED)) {
ret = validate_records(qry, pkt, req->rplan.pool, has_nsec3);
if (ret != 0) {
DEBUG_MSG(qry, "<= couldn't validate RRSIGs\n");
VERBOSE_MSG(qry, "<= couldn't validate RRSIGs\n");
qry->flags |= QUERY_DNSSEC_BOGUS;
return KR_STATE_FAIL;
}
......@@ -517,7 +517,7 @@ static int validate(kr_layer_t *ctx, knot_pkt_t *pkt)
return KR_STATE_FAIL;
}
}
DEBUG_MSG(qry, "<= answer valid, OK\n");
VERBOSE_MSG(qry, "<= answer valid, OK\n");
return KR_STATE_DONE;
}
/** Module implementation. */
......@@ -537,4 +537,4 @@ int validate_init(struct kr_module *module)
KR_MODULE_EXPORT(validate)
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -35,7 +35,7 @@
#define KNOT_EDNS_OPTION_COOKIE 10
#endif /* defined(ENABLE_COOKIES) */
#define DEBUG_MSG(qry, fmt...) QRDEBUG((qry), "resl", fmt)
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE((qry), "resl", fmt)
/**
* @internal Defer execution of current query.
......@@ -186,7 +186,7 @@ static int ns_fetch_cut(struct kr_query *qry, struct kr_request *req, knot_pkt_t
check_empty_nonterms(qry, pkt, cache, qry->timestamp.tv_sec);
/* Go insecure if the zone cut is provably insecure */
if ((qry->flags & QUERY_DNSSEC_WANT) && !secured) {
DEBUG_MSG(qry, "=> NS is provably without DS, going insecure\n");
VERBOSE_MSG(qry, "=> NS is provably without DS, going insecure\n");
qry->flags &= ~QUERY_DNSSEC_WANT;
qry->flags |= QUERY_DNSSEC_INSECURE;
}
......@@ -223,13 +223,13 @@ static int ns_resolve_addr(struct kr_query *qry, struct kr_request *param)
if (!next_type || kr_rplan_satisfies(qry->parent, qry->ns.name, KNOT_CLASS_IN, next_type)) {
/* Fall back to SBELT if root server query fails. */
if (!next_type && qry->zone_cut.name[0] == '\0') {
DEBUG_MSG(qry, "=> fallback to root hints\n");
VERBOSE_MSG(qry, "=> fallback to root hints\n");
kr_zonecut_set_sbelt(ctx, &qry->zone_cut);
qry->flags |= QUERY_NO_THROTTLE; /* Pick even bad SBELT servers */
return kr_error(EAGAIN);
}
/* No IPv4 nor IPv6, flag server as unuseable. */
DEBUG_MSG(qry, "=> unresolvable NS address, bailing out\n");
VERBOSE_MSG(qry, "=> unresolvable NS address, bailing out\n");
qry->ns.reputation |= KR_NS_NOIP4 | KR_NS_NOIP6;
kr_nsrep_update_rep(&qry->ns, qry->ns.reputation, ctx->cache_rep);
invalidate_ns(rplan, qry);
......@@ -563,10 +563,10 @@ 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_DEBUG {
WITH_VERBOSE {
char addr_str[INET6_ADDRSTRLEN];
inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str));
DEBUG_MSG(qry, "<= server: '%s' rtt: %ld ms\n", addr_str, elapsed);
VERBOSE_MSG(qry, "<= server: '%s' rtt: %ld ms\n", addr_str, elapsed);
}
} else {
/* Response didn't come from this IP, but we know the RTT must be at least
......@@ -575,10 +575,10 @@ 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_DEBUG {
WITH_VERBOSE {
char addr_str[INET6_ADDRSTRLEN];
inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str));
DEBUG_MSG(qry, "<= server: '%s' rtt: >=%ld ms\n", addr_str, elapsed);
VERBOSE_MSG(qry, "<= server: '%s' rtt: >=%ld ms\n", addr_str, elapsed);
}
}
/* Subtract query start time from elapsed time */
......@@ -606,10 +606,10 @@ static void update_nslist_score(struct kr_request *request, struct kr_query *qry
/* Penalise resolution failures except validation failures. */
} else if (!(qry->flags & QUERY_DNSSEC_BOGUS)) {
kr_nsrep_update_rtt(&qry->ns, src, KR_NS_TIMEOUT, ctx->cache_rtt, KR_NS_RESET);
WITH_DEBUG {
WITH_VERBOSE {
char addr_str[INET6_ADDRSTRLEN];
inet_ntop(src->sa_family, kr_inaddr(src), addr_str, sizeof(addr_str));
DEBUG_MSG(qry, "=> server: '%s' flagged as 'bad'\n", addr_str);
VERBOSE_MSG(qry, "=> server: '%s' flagged as 'bad'\n", addr_str);
}
}
}
......@@ -717,7 +717,7 @@ static int trust_chain_check(struct kr_request *request, struct kr_query *qry)
/* Disable DNSSEC if it enters NTA. */
if (kr_ta_get(negative_anchors, qry->zone_cut.name)){
DEBUG_MSG(qry, ">< negative TA, going insecure\n");
VERBOSE_MSG(qry, ">< negative TA, going insecure\n");
qry->flags &= ~QUERY_DNSSEC_WANT;
}
/* Enable DNSSEC if enters a new island of trust. */
......@@ -725,10 +725,10 @@ static int trust_chain_check(struct kr_request *request, struct kr_query *qry)
if (!want_secured && kr_ta_get(trust_anchors, qry->zone_cut.name)) {
qry->flags |= QUERY_DNSSEC_WANT;
want_secured = true;
WITH_DEBUG {
WITH_VERBOSE {
char qname_str[KNOT_DNAME_MAXLEN];
knot_dname_to_str(qname_str, qry->zone_cut.name, sizeof(qname_str));
DEBUG_MSG(qry, ">< TA: '%s'\n", qname_str);
VERBOSE_MSG(qry, ">< TA: '%s'\n", qname_str);
}
}
if (want_secured && !qry->zone_cut.trust_anchor) {
......@@ -792,7 +792,7 @@ static int zone_cut_check(struct kr_request *request, struct kr_query *qry, knot
if (ret != 0) {
return KR_STATE_FAIL;
}
DEBUG_MSG(qry, "=> using root hints\n");
VERBOSE_MSG(qry, "=> using root hints\n");
qry->flags &= ~QUERY_AWAIT_CUT;
return KR_STATE_DONE;
} else {
......@@ -830,7 +830,7 @@ int kr_resolve_produce(struct kr_request *request, struct sockaddr **dst, int *t
case KR_STATE_DONE: return KR_STATE_PRODUCE;
default: break;
}
DEBUG_MSG(qry, "=> resuming yielded answer\n");
VERBOSE_MSG(qry, "=> resuming yielded answer\n");
struct kr_layer_pickle *pickle = qry->deferred;
request->state = KR_STATE_YIELD;
RESUME_LAYERS(layer_id(request, pickle->api), request, qry, consume, pickle->pkt);
......@@ -870,7 +870,7 @@ int kr_resolve_produce(struct kr_request *request, struct sockaddr **dst, int *t
/* This query has RD=0 or is ANY, stop here. */
if (qry->stype == KNOT_RRTYPE_ANY || !knot_wire_get_rd(request->answer->wire)) {
DEBUG_MSG(qry, "=> qtype is ANY or RD=0, bail out\n");
VERBOSE_MSG(qry, "=> qtype is ANY or RD=0, bail out\n");
return KR_STATE_FAIL;
}
......@@ -891,7 +891,7 @@ int kr_resolve_produce(struct kr_request *request, struct sockaddr **dst, int *t
* elect best address only, otherwise elect a completely new NS.
*/
if(++ns_election_iter >= KR_ITER_LIMIT) {
DEBUG_MSG(qry, "=> couldn't converge NS selection, bail out\n");
VERBOSE_MSG(qry, "=> couldn't converge NS selection, bail out\n");
return KR_STATE_FAIL;
}
......@@ -906,7 +906,7 @@ int kr_resolve_produce(struct kr_request *request, struct sockaddr **dst, int *t
}
kr_nsrep_elect(qry, request->ctx);
if (qry->ns.score > KR_NS_MAX_SCORE) {
DEBUG_MSG(qry, "=> no valid NS left\n");
VERBOSE_MSG(qry, "=> no valid NS left\n");
ITERATE_LAYERS(request, qry, reset);
kr_rplan_pop(rplan, qry);
return KR_STATE_PRODUCE;
......@@ -1008,7 +1008,7 @@ int kr_resolve_checkout(struct kr_request *request, struct sockaddr *src,
return kr_error(EINVAL);
}
WITH_DEBUG {
WITH_VERBOSE {
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));
......@@ -1022,7 +1022,7 @@ int kr_resolve_checkout(struct kr_request *request, struct sockaddr *src,
continue;
}
inet_ntop(addr->sa_family, kr_nsrep_inaddr(qry->ns.addr[i]), ns_str, sizeof(ns_str));
DEBUG_MSG(qry, "=> querying: '%s' score: %u zone cut: '%s' m12n: '%s' type: '%s' proto: '%s'\n",
VERBOSE_MSG(qry, "=> querying: '%s' score: %u zone cut: '%s' m12n: '%s' type: '%s' proto: '%s'\n",
ns_str, qry->ns.score, zonecut_str, qname_str, type_str, (qry->flags & QUERY_TCP) ? "tcp" : "udp");
break;
}}
......@@ -1032,7 +1032,7 @@ int kr_resolve_checkout(struct kr_request *request, struct sockaddr *src,
int kr_resolve_finish(struct kr_request *request, int state)
{
#ifndef NLOGDEBUG
#ifndef NOVERBOSELOG
struct kr_rplan *rplan = &request->rplan;
#endif
/* Finalize answer */
......@@ -1049,7 +1049,7 @@ int kr_resolve_finish(struct kr_request *request, int state)
request->state = state;
ITERATE_LAYERS(request, NULL, finish);
DEBUG_MSG(NULL, "finished: %d, queries: %zu, mempool: %zu B\n",
VERBOSE_MSG(NULL, "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;
}
......@@ -1070,5 +1070,4 @@ knot_mm_t *kr_resolve_pool(struct kr_request *request)
return NULL;
}
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -23,7 +23,7 @@
#include "lib/defines.h"
#include "lib/layer.h"
#define DEBUG_MSG(qry, fmt...) QRDEBUG(qry, "plan", fmt)
#define VERBOSE_MSG(qry, fmt...) QRVERBOSE(qry, "plan", fmt)
#define QUERY_PROVIDES(q, name, cls, type) \
((q)->sclass == (cls) && (q)->stype == type && knot_dname_is_equal((q)->sname, name))
......@@ -151,8 +151,8 @@ struct kr_query *kr_rplan_push_empty(struct kr_rplan *rplan, struct kr_query *pa
return NULL;
}
WITH_DEBUG {
DEBUG_MSG(parent, "plan '%s' type '%s'\n", "", "");
WITH_VERBOSE {
VERBOSE_MSG(parent, "plan '%s' type '%s'\n", "", "");
}
return qry;
}
......@@ -172,11 +172,11 @@ struct kr_query *kr_rplan_push(struct kr_rplan *rplan, struct kr_query *parent,
qry->sclass = cls;
qry->stype = type;
WITH_DEBUG {
WITH_VERBOSE {
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));
DEBUG_MSG(parent, "plan '%s' type '%s'\n", name_str, type_str);
VERBOSE_MSG(parent, "plan '%s' type '%s'\n", name_str, type_str);
}
return qry;
}
......@@ -223,4 +223,4 @@ struct kr_query *kr_rplan_resolved(struct kr_rplan *rplan)
return array_tail(rplan->resolved);
}
#undef DEBUG_MSG
#undef VERBOSE_MSG
......@@ -35,12 +35,12 @@
/* Always compile-in log symbols, even if disabled. */
#undef kr_debug_do_log
#undef kr_debug_set
#undef kr_log_debug
#undef kr_verbose_do_log
#undef kr_verbose_set
#undef kr_log_verbose
/* Logging & debugging */
bool kr_debug_do_log = false;
bool kr_verbose_do_log = false;
/** @internal CSPRNG context */
static isaac_ctx ISAAC;
......@@ -71,17 +71,17 @@ static inline int u16tostr(uint8_t *dst, uint16_t num)
* Cleanup callbacks.
*/
bool kr_debug_set(bool status)
bool kr_verbose_set(bool status)
{
#ifndef NLOGDEBUG
kr_debug_do_log = status;
#ifndef NOVERBOSELOG
kr_verbose_do_log = status;
#endif
return kr_debug_do_log;
return kr_verbose_do_log;
}
void kr_log_debug(const char *fmt, ...)
void kr_log_verbose(const char *fmt, ...)
{
if (kr_debug_do_log) {
if (kr_verbose_do_log) {
va_list args;
va_start(args, fmt);
vprintf(fmt, args);
......