summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rw-r--r--daemon/bindings/net.c6
-rw-r--r--daemon/engine.c2
-rw-r--r--daemon/http.c30
-rw-r--r--daemon/io.c16
-rw-r--r--daemon/lua/kres-gen-29.lua2
-rw-r--r--daemon/lua/sandbox.lua.in4
-rw-r--r--daemon/main.c8
-rw-r--r--daemon/tls.c67
-rw-r--r--daemon/tls_session_ticket-srv.c2
-rw-r--r--daemon/worker.c20
-rw-r--r--lib/cache/api.c6
-rw-r--r--lib/cache/cdb_lmdb.c4
-rw-r--r--lib/cache/nsec1.c2
-rw-r--r--lib/log.c2
-rw-r--r--lib/log.h6
-rw-r--r--modules/dnstap/dnstap.c2
-rw-r--r--modules/nsid/nsid.c4
-rw-r--r--utils/cache_gc/db.c2
-rw-r--r--utils/cache_gc/kr_cache_gc.c2
19 files changed, 93 insertions, 94 deletions
diff --git a/daemon/bindings/net.c b/daemon/bindings/net.c
index 1c66358c..79993b01 100644
--- a/daemon/bindings/net.c
+++ b/daemon/bindings/net.c
@@ -653,8 +653,7 @@ static int net_tls_client(lua_State *L)
ca_file, gnutls_strerror_name(ret),
gnutls_strerror(ret));
} else {
- kr_log_verbose(
- "[tls_client] imported %d certs from file '%s'\n",
+ kr_log_debug(TLSCLIENT, "imported %d certs from file '%s'\n",
ret, ca_file);
}
@@ -731,8 +730,7 @@ static int net_tls_client(lua_State *L)
ERROR("failed to use system CA certificate store: %s",
ret ? gnutls_strerror(ret) : kr_strerror(ENOENT));
} else {
- kr_log_verbose(
- "[tls_client] imported %d certs from system store\n",
+ kr_log_debug(TLSCLIENT, "imported %d certs from system store\n",
ret);
}
}
diff --git a/daemon/engine.c b/daemon/engine.c
index 5119ed1c..cc684c66 100644
--- a/daemon/engine.c
+++ b/daemon/engine.c
@@ -724,7 +724,7 @@ int engine_loadconf(struct engine *engine, const char *config_path)
char cwd[PATH_MAX];
get_workdir(cwd, sizeof(cwd));
- kr_log_verbose("[system] loading config '%s' (workdir '%s')\n", config_path, cwd);
+ kr_log_debug(SYSTEM, "loading config '%s' (workdir '%s')\n", config_path, cwd);
int ret = luaL_dofile(engine->L, config_path);
if (ret != 0) {
diff --git a/daemon/http.c b/daemon/http.c
index b1563a9d..7472956f 100644
--- a/daemon/http.c
+++ b/daemon/http.c
@@ -230,8 +230,7 @@ static int process_uri_path(struct http_ctx *ctx, const char* path, int32_t stre
ret = kr_base64url_decode((uint8_t*)beg, end - beg, dest, remaining);
if (ret < 0) {
ctx->buf_pos = 0;
- kr_log_verbose("[http] base64url decode failed %s\n",
- strerror(ret));
+ kr_log_debug(DOH, "base64url decode failed %s\n", strerror(ret));
return ret;
}
@@ -288,8 +287,8 @@ static int begin_headers_callback(nghttp2_session *h2, const nghttp2_frame *fram
}
if (ctx->incomplete_stream != -1) {
- kr_log_verbose(
- "[http] stream %d incomplete, refusing\n", ctx->incomplete_stream);
+ kr_log_debug(DOH, "stream %d incomplete, refusing\n",
+ ctx->incomplete_stream);
refuse_stream(h2, stream_id);
} else {
http_cleanup_stream(ctx); // Free any leftover data and ensure pristine state
@@ -317,8 +316,8 @@ static int header_callback(nghttp2_session *h2, const nghttp2_frame *frame,
return 0;
if (ctx->incomplete_stream != stream_id) {
- kr_log_verbose(
- "[http] stream %d incomplete, refusing\n", ctx->incomplete_stream);
+ kr_log_debug(DOH, "stream %d incomplete, refusing\n",
+ ctx->incomplete_stream);
refuse_stream(h2, stream_id);
return 0;
}
@@ -330,8 +329,8 @@ static int header_callback(nghttp2_session *h2, const nghttp2_frame *frame,
/* Limit maximum value size to reduce attack surface. */
if (valuelen > HTTP_MAX_HEADER_IN_SIZE) {
- kr_log_verbose(
- "[http] stream %d: header too large (%zu B), refused\n",
+ kr_log_debug(DOH,
+ "stream %d: header too large (%zu B), refused\n",
stream_id, valuelen);
refuse_stream(h2, stream_id);
return 0;
@@ -394,8 +393,7 @@ static int data_chunk_recv_callback(nghttp2_session *h2, uint8_t flags, int32_t
bool is_first = queue_len(ctx->streams) == 0 || queue_tail(ctx->streams).id != ctx->incomplete_stream;
if (ctx->incomplete_stream != stream_id) {
- kr_log_verbose(
- "[http] stream %d incomplete, refusing\n",
+ kr_log_debug(DOH, "stream %d incomplete, refusing\n",
ctx->incomplete_stream);
refuse_stream(h2, stream_id);
ctx->incomplete_stream = -1;
@@ -455,7 +453,7 @@ static int on_frame_recv_callback(nghttp2_session *h2, const nghttp2_frame *fram
len = ctx->buf_pos - sizeof(uint16_t);
if (len <= 0 || len > KNOT_WIRE_MAX_PKTSIZE) {
- kr_log_verbose("[http] invalid dnsmsg size: %zd B\n", len);
+ kr_log_debug(DOH, "invalid dnsmsg size: %zd B\n", len);
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
@@ -573,14 +571,14 @@ ssize_t http_process_input_data(struct session *session, const uint8_t *buf,
ret = nghttp2_session_mem_recv(ctx->h2, buf, nread);
if (ret < 0) {
- kr_log_verbose("[http] nghttp2_session_mem_recv failed: %s (%zd)\n",
+ kr_log_debug(DOH, "nghttp2_session_mem_recv failed: %s (%zd)\n",
nghttp2_strerror(ret), ret);
return kr_error(EIO);
}
ret = nghttp2_session_send(ctx->h2);
if (ret < 0) {
- kr_log_verbose("[http] nghttp2_session_send failed: %s (%zd)\n",
+ kr_log_debug(DOH, "nghttp2_session_send failed: %s (%zd)\n",
nghttp2_strerror(ret), ret);
return kr_error(EIO);
}
@@ -644,14 +642,14 @@ static int http_send_response(nghttp2_session *h2, int32_t stream_id,
ret = nghttp2_session_set_stream_user_data(h2, stream_id, (void*)data);
if (ret != 0) {
- kr_log_verbose("[http] failed to set stream user data: %s\n", nghttp2_strerror(ret));
+ kr_log_debug(DOH, "failed to set stream user data: %s\n", nghttp2_strerror(ret));
free(data);
return kr_error(EIO);
}
ret = nghttp2_submit_response(h2, stream_id, hdrs, sizeof(hdrs)/sizeof(*hdrs), prov);
if (ret != 0) {
- kr_log_verbose("[http] nghttp2_submit_response failed: %s\n", nghttp2_strerror(ret));
+ kr_log_debug(DOH, "nghttp2_submit_response failed: %s\n", nghttp2_strerror(ret));
nghttp2_session_set_stream_user_data(h2, stream_id, NULL); // just in case
free(data);
return kr_error(EIO);
@@ -659,7 +657,7 @@ static int http_send_response(nghttp2_session *h2, int32_t stream_id,
ret = nghttp2_session_send(h2);
if(ret < 0) {
- kr_log_verbose("[http] nghttp2_session_send failed: %s\n", nghttp2_strerror(ret));
+ kr_log_debug(DOH, "nghttp2_session_send failed: %s\n", nghttp2_strerror(ret));
/* At this point, there was an error in some nghttp2 callback. The on_pkt_write()
* callback which also calls free(data) may or may not have been called. Therefore,
diff --git a/daemon/io.c b/daemon/io.c
index 39b6b4ec..84910a42 100644
--- a/daemon/io.c
+++ b/daemon/io.c
@@ -79,7 +79,7 @@ void udp_recv(uv_udp_t *handle, ssize_t nread, const uv_buf_t *buf,
if (kr_fails_assert(peer->sa_family != AF_UNSPEC))
return;
if (kr_sockaddr_cmp(peer, addr) != 0) {
- kr_log_verbose("[io] <= ignoring UDP from unexpected address '%s'\n",
+ kr_log_debug(IO, "<= ignoring UDP from unexpected address '%s'\n",
kr_straddr(addr));
return;
}
@@ -253,7 +253,7 @@ void tcp_timeout_trigger(uv_timer_t *timer)
} else {
struct sockaddr *peer = session_get_peer(s);
char *peer_str = kr_straddr(peer);
- kr_log_verbose("[io] => closing connection to '%s'\n",
+ kr_log_debug(IO, "=> closing connection to '%s'\n",
peer_str ? peer_str : "");
if (session_flags(s)->outgoing) {
worker_del_tcp_waiting(the_worker, peer);
@@ -284,7 +284,7 @@ static void tcp_recv(uv_stream_t *handle, ssize_t nread, const uv_buf_t *buf)
if (KR_LOG_LEVEL_IS(LOG_DEBUG)) {
struct sockaddr *peer = session_get_peer(s);
char *peer_str = kr_straddr(peer);
- kr_log_verbose("[io] => connection to '%s' closed by peer (%s)\n",
+ kr_log_debug(IO, "=> connection to '%s' closed by peer (%s)\n",
peer_str ? peer_str : "",
uv_strerror(nread));
}
@@ -303,7 +303,7 @@ static void tcp_recv(uv_stream_t *handle, ssize_t nread, const uv_buf_t *buf)
if (KR_LOG_LEVEL_IS(LOG_DEBUG)) {
struct sockaddr *peer = session_get_peer(s);
char *peer_str = kr_straddr(peer);
- kr_log_verbose("[io] => connection to '%s': "
+ kr_log_debug(IO, "=> connection to '%s': "
"error processing TLS data, close\n",
peer_str ? peer_str : "");
}
@@ -322,7 +322,7 @@ static void tcp_recv(uv_stream_t *handle, ssize_t nread, const uv_buf_t *buf)
if (KR_LOG_LEVEL_IS(LOG_DEBUG)) {
struct sockaddr *peer = session_get_peer(s);
char *peer_str = kr_straddr(peer);
- kr_log_verbose("[io] => connection to '%s': "
+ kr_log_debug(IO, "=> connection to '%s': "
"error processing HTTP data, close\n",
peer_str ? peer_str : "");
}
@@ -359,7 +359,7 @@ static ssize_t tls_send(const uint8_t *buf, const size_t len, struct session *se
sent = gnutls_record_send(ctx->c.tls_session, buf, len);
if (sent < 0) {
- kr_log_verbose("[http] gnutls_record_send failed: %s (%zd)\n",
+ kr_log_debug(DOH, "gnutls_record_send failed: %s (%zd)\n",
gnutls_strerror_name(sent), sent);
return kr_error(EIO);
}
@@ -821,7 +821,7 @@ static void xdp_rx(uv_poll_t* handle, int status, int events)
kr_log_error(XDP, "knot_xdp_recv(): %d, %s\n", ret, knot_strerror(ret));
return;
}
- kr_log_verbose("poll triggered, processing a batch of %d packets\n", (int)rcvd);
+ kr_log_debug(XDP, "poll triggered, processing a batch of %d packets\n", (int)rcvd);
kr_require(rcvd <= XDP_RX_BATCH_SIZE);
for (int i = 0; i < rcvd; ++i) {
const knot_xdp_msg_t *msg = &msgs[i];
@@ -837,7 +837,7 @@ static void xdp_rx(uv_poll_t* handle, int status, int events)
msg->eth_from, msg->eth_to, kpkt);
}
if (ret)
- kr_log_verbose("[xdp] worker_submit() == %d: %s\n", ret, kr_strerror(ret));
+ kr_log_debug(XDP, "worker_submit() == %d: %s\n", ret, kr_strerror(ret));
mp_flush(the_worker->pkt_pool.ctx);
}
knot_xdp_recv_finish(xhd->socket, msgs, rcvd);
diff --git a/daemon/lua/kres-gen-29.lua b/daemon/lua/kres-gen-29.lua
index 668c773c..bcc824f1 100644
--- a/daemon/lua/kres-gen-29.lua
+++ b/daemon/lua/kres-gen-29.lua
@@ -308,7 +308,7 @@ struct kr_server_selection {
};
typedef unsigned long log_groups_t;
typedef int log_level_t;
-enum kr_log_groups_type {LOG_GRP_SYSTEM = 1, LOG_GRP_CACHE, LOG_GRP_IO, LOG_GRP_NETWORK, LOG_GRP_TA, LOG_GRP_TLS, LOG_GRP_GNUTLS, LOG_GRP_TLSCLIENT, LOG_GRP_XDP, LOG_GRP_ZIMPORT, LOG_GRP_ZSCANNER, LOG_GRP_DOH, LOG_GRP_DNSSEC, LOG_GRP_HINT, LOG_GRP_PLAN, LOG_GRP_ITERATOR, LOG_GRP_VALIDATOR, LOG_GRP_RESOLVER, LOG_GRP_SELECTION, LOG_GRP_ZCUT, LOG_GRP_COOKIES, LOG_GRP_STATISTICS, LOG_GRP_REBIND, LOG_GRP_WORKER, LOG_GRP_POLICY, LOG_GRP_TASENTINEL, LOG_GRP_TASIGNALING, LOG_GRP_TAUPDATE, LOG_GRP_DAF, LOG_GRP_DETECTTIMEJUMP, LOG_GRP_DETECTTIMESKEW, LOG_GRP_GRAPHITE, LOG_GRP_PREFILL, LOG_GRP_PRIMING, LOG_GRP_SRVSTALE, LOG_GRP_WATCHDOG, LOG_GRP_TESTS};
+enum kr_log_groups_type {LOG_GRP_SYSTEM = 1, LOG_GRP_CACHE, LOG_GRP_IO, LOG_GRP_NETWORK, LOG_GRP_TA, LOG_GRP_TLS, LOG_GRP_GNUTLS, LOG_GRP_TLSCLIENT, LOG_GRP_XDP, LOG_GRP_ZIMPORT, LOG_GRP_ZSCANNER, LOG_GRP_DOH, LOG_GRP_DNSSEC, LOG_GRP_HINT, LOG_GRP_PLAN, LOG_GRP_ITERATOR, LOG_GRP_VALIDATOR, LOG_GRP_RESOLVER, LOG_GRP_SELECTION, LOG_GRP_ZCUT, LOG_GRP_COOKIES, LOG_GRP_STATISTICS, LOG_GRP_REBIND, LOG_GRP_WORKER, LOG_GRP_POLICY, LOG_GRP_TASENTINEL, LOG_GRP_TASIGNALING, LOG_GRP_TAUPDATE, LOG_GRP_DAF, LOG_GRP_DETECTTIMEJUMP, LOG_GRP_DETECTTIMESKEW, LOG_GRP_GRAPHITE, LOG_GRP_PREFILL, LOG_GRP_PRIMING, LOG_GRP_SRVSTALE, LOG_GRP_WATCHDOG, LOG_GRP_NSID, LOG_GRP_DNSTAP, LOG_GRP_TESTS};
kr_layer_t kr_layer_t_static;
_Bool kr_dbg_assertion_abort;
diff --git a/daemon/lua/sandbox.lua.in b/daemon/lua/sandbox.lua.in
index eff54eb8..5c4fcc51 100644
--- a/daemon/lua/sandbox.lua.in
+++ b/daemon/lua/sandbox.lua.in
@@ -31,8 +31,8 @@ local function curr_file() return debug.getinfo(4,'S').source end
local function curr_line() return debug.getinfo(4,'l').currentline end
local function log_fmt(grp, level, fmt, ...)
- ffi.C.kr_log_fmt(grp, level, "CODE_FILE="..curr_file(), "CODE_LINE="..curr_line(), "",
- "[%s]" .. fmt, ffi.C.kr_log_grp2name(grp), ...)
+ ffi.C.kr_log_fmt(grp, level, 'CODE_FILE='..curr_file(), 'CODE_LINE='..curr_line(), '',
+ '[%s] ' .. fmt .. '\n', ffi.C.kr_log_grp2name(grp), ...)
end
function log_req(req, qry_uid, indent, grp, fmt, ...)
diff --git a/daemon/main.c b/daemon/main.c
index 084cd102..08e662c3 100644
--- a/daemon/main.c
+++ b/daemon/main.c
@@ -384,7 +384,7 @@ static void drop_capabilities(void)
#if ENABLE_CAP_NG
/* Drop all capabilities when running under non-root user. */
if (geteuid() == 0) {
- kr_log_verbose("[system] running as root, no capabilities dropped\n");
+ kr_log_debug(SYSTEM, "running as root, no capabilities dropped\n");
return;
}
if (capng_have_capability(CAPNG_EFFECTIVE, CAP_SETPCAP)) {
@@ -395,11 +395,11 @@ static void drop_capabilities(void)
kr_log_error(SYSTEM, "failed to set process capabilities: %s\n",
strerror(errno));
} else {
- kr_log_verbose("[system] all capabilities dropped\n");
+ kr_log_debug(SYSTEM, "all capabilities dropped\n");
}
} else {
/* If user() was called, the capabilities were already dropped along with SETPCAP. */
- kr_log_verbose("[system] process not allowed to set capabilities, skipping\n");
+ kr_log_debug(SYSTEM, "process not allowed to set capabilities, skipping\n");
}
#endif /* ENABLE_CAP_NG */
}
@@ -465,7 +465,7 @@ int main(int argc, char **argv)
struct rlimit rlim;
ret = getrlimit(RLIMIT_NOFILE, &rlim);
if (ret == 0 && rlim.rlim_cur != rlim.rlim_max) {
- kr_log_verbose("[system] increasing file-descriptor limit: %ld -> %ld\n",
+ kr_log_debug(SYSTEM, "increasing file-descriptor limit: %ld -> %ld\n",
(long)rlim.rlim_cur, (long)rlim.rlim_max);
rlim.rlim_cur = rlim.rlim_max;
ret = setrlimit(RLIMIT_NOFILE, &rlim);
diff --git a/daemon/tls.c b/daemon/tls.c
index e402be7f..98168218 100644
--- a/daemon/tls.c
+++ b/daemon/tls.c
@@ -27,9 +27,15 @@
#define EPHEMERAL_CERT_EXPIRATION_SECONDS_RENEW_BEFORE (60*60*24*7)
#define GNUTLS_PIN_MIN_VERSION 0x030400
+#define VERBOSE_MSG(cl_side, ...)\
+ if (cl_side) \
+ kr_log_debug(TLSCLIENT, __VA_ARGS__); \
+ else \
+ kr_log_debug(TLS, __VA_ARGS__);
+
/** @internal Debugging facility. */
#ifdef DEBUG
-#define DEBUG_MSG(...) kr_log_verbose("[tls] " __VA_ARGS__)
+#define DEBUG_MSG(...) kr_log_debug(TLS, __VA_ARGS__)
#else
#define DEBUG_MSG(...)
#endif
@@ -40,9 +46,6 @@ struct async_write_ctx {
char buf[];
};
-static char const server_logstring[] = "tls";
-static char const client_logstring[] = "tls_client";
-
static int client_verify_certificate(gnutls_session_t tls_session);
/**
@@ -165,8 +168,8 @@ static ssize_t kres_gnutls_vec_push(gnutls_transport_ptr_t h, const giovec_t * i
if (ret < 0 && ret != UV_EAGAIN) {
/* uv_try_write() has returned error code other then UV_EAGAIN.
* Return. */
- kr_log_verbose("[%s] uv_try_write error: %s\n",
- t->client_side ? "tls_client" : "tls", uv_strerror(ret));
+ VERBOSE_MSG(t->client_side, "uv_try_write error: %s\n",
+ uv_strerror(ret));
ret = -1;
errno = EIO;
return ret;
@@ -224,8 +227,8 @@ static ssize_t kres_gnutls_vec_push(gnutls_transport_ptr_t h, const giovec_t * i
t->write_queue_size += 1;
} else {
free(p);
- kr_log_verbose("[%s] uv_write error: %s\n",
- t->client_side ? "tls_client" : "tls", uv_strerror(ret));
+ VERBOSE_MSG(t->client_side, "uv_write error: %s\n",
+ uv_strerror(ret));
errno = EIO;
ret = -1;
}
@@ -246,15 +249,14 @@ static ssize_t kres_gnutls_vec_push(gnutls_transport_ptr_t h, const giovec_t * i
*/
static int tls_handshake(struct tls_common_ctx *ctx, tls_handshake_cb handshake_cb) {
struct session *session = ctx->session;
- const char *logstring = ctx->client_side ? client_logstring : server_logstring;
int err = gnutls_handshake(ctx->tls_session);
if (err == GNUTLS_E_SUCCESS) {
/* Handshake finished, return success */
ctx->handshake_state = TLS_HS_DONE;
struct sockaddr *peer = session_get_peer(session);
- kr_log_verbose("[%s] TLS handshake with %s has completed\n",
- logstring, kr_straddr(peer));
+ VERBOSE_MSG(ctx->client_side, "TLS handshake with %s has completed\n",
+ kr_straddr(peer));
if (handshake_cb) {
if (handshake_cb(session, 0) != kr_ok()) {
return kr_error(EIO);
@@ -264,9 +266,8 @@ static int tls_handshake(struct tls_common_ctx *ctx, tls_handshake_cb handshake_
return kr_error(EAGAIN);
} else if (gnutls_error_is_fatal(err)) {
/* Fatal errors, return error as it's not recoverable */
- kr_log_verbose("[%s] gnutls_handshake failed: %s (%d)\n",
- logstring,
- gnutls_strerror_name(err), err);
+ VERBOSE_MSG(ctx->client_side, "gnutls_handshake failed: %s (%d)\n",
+ gnutls_strerror_name(err), err);
/* Notify the peer about handshake failure via an alert. */
gnutls_alert_send_appropriate(ctx->tls_session, err);
if (handshake_cb) {
@@ -278,8 +279,8 @@ static int tls_handshake(struct tls_common_ctx *ctx, tls_handshake_cb handshake_
const char *alert_name = gnutls_alert_get_name(gnutls_alert_get(ctx->tls_session));
if (alert_name != NULL) {
struct sockaddr *peer = session_get_peer(session);
- kr_log_verbose("[%s] TLS alert from %s received: %s\n",
- logstring, kr_straddr(peer), alert_name);
+ VERBOSE_MSG(ctx->client_side, "TLS alert from %s received: %s\n",
+ kr_straddr(peer), alert_name);
}
}
return kr_ok();
@@ -372,8 +373,7 @@ void tls_close(struct tls_common_ctx *ctx)
if (ctx->handshake_state == TLS_HS_DONE) {
const struct sockaddr *peer = session_get_peer(ctx->session);
- kr_log_verbose("[%s] closing tls connection to `%s`\n",
- ctx->client_side ? "tls_client" : "tls",
+ VERBOSE_MSG(ctx->client_side, "closing tls connection to `%s`\n",
kr_straddr(peer));
ctx->handshake_state = TLS_HS_CLOSING;
gnutls_bye(ctx->tls_session, GNUTLS_SHUT_RDWR);
@@ -409,15 +409,14 @@ int tls_write(uv_write_t *req, uv_handle_t *handle, knot_pkt_t *pkt, uv_write_cb
return kr_error(EINVAL);
const uint16_t pkt_size = htons(pkt->size);
- const char *logstring = tls_ctx->client_side ? client_logstring : server_logstring;
gnutls_session_t tls_session = tls_ctx->tls_session;
gnutls_record_cork(tls_session);
ssize_t count = 0;
if ((count = gnutls_record_send(tls_session, &pkt_size, sizeof(pkt_size)) < 0) ||
(count = gnutls_record_send(tls_session, pkt->wire, pkt->size) < 0)) {
- kr_log_verbose("[%s] gnutls_record_send failed: %s (%zd)\n",
- logstring, gnutls_strerror_name(count), count);
+ VERBOSE_MSG(tls_ctx->client_side, "gnutls_record_send failed: %s (%zd)\n",
+ gnutls_strerror_name(count), count);
return kr_error(EIO);
}
@@ -428,15 +427,14 @@ int tls_write(uv_write_t *req, uv_handle_t *handle, knot_pkt_t *pkt, uv_write_cb
if (!gnutls_error_is_fatal(ret)) {
return kr_error(EAGAIN);
} else {
- kr_log_verbose("[%s] gnutls_record_uncork failed: %s (%d)\n",
- logstring, gnutls_strerror_name(ret), ret);
+ VERBOSE_MSG(tls_ctx->client_side, "gnutls_record_uncork failed: %s (%d)\n",
+ gnutls_strerror_name(ret), ret);
return kr_error(EIO);
}
}
if (ret != submitted) {
- kr_log_error(TLS, "[%s] gnutls_record_uncork didn't send all data (%d of %zd)\n",
- logstring, ret, submitted);
+ kr_log_error(TLS, "gnutls_record_uncork didn't send all data (%d of %zd)\n", ret, submitted);
return kr_error(EIO);
}
@@ -460,8 +458,6 @@ ssize_t tls_process_input_data(struct session *s, const uint8_t *buf, ssize_t nr
if (kr_fails_assert(ok)) /* don't risk overflowing the buffer if we have a mistake somewhere */
return kr_error(EINVAL);
- const char *logstring = tls_p->client_side ? client_logstring : server_logstring;
-
tls_p->buf = buf;
tls_p->nread = nread >= 0 ? nread : 0;
tls_p->consumed = 0;
@@ -494,8 +490,8 @@ ssize_t tls_process_input_data(struct session *s, const uint8_t *buf, ssize_t nr
} else if (count == GNUTLS_E_REHANDSHAKE) {
/* See https://www.gnutls.org/manual/html_node/Re_002dauthentication.html */
struct sockaddr *peer = session_get_peer(s);
- kr_log_verbose("[%s] TLS rehandshake with %s has started\n",
- logstring, kr_straddr(peer));
+ VERBOSE_MSG(tls_p->client_side, "TLS rehandshake with %s has started\n",
+ kr_straddr(peer));
tls_set_hs_state(tls_p, TLS_HS_IN_PROGRESS);
int err = kr_ok();
while (tls_p->handshake_state <= TLS_HS_IN_PROGRESS) {
@@ -513,13 +509,13 @@ ssize_t tls_process_input_data(struct session *s, const uint8_t *buf, ssize_t nr
/* There are can be data available, check it. */
continue;
} else if (count < 0) {
- kr_log_verbose("[%s] gnutls_record_recv failed: %s (%zd)\n",
- logstring, gnutls_strerror_name(count), count);
+ VERBOSE_MSG(tls_p->client_side, "gnutls_record_recv failed: %s (%zd)\n",
+ gnutls_strerror_name(count), count);
return kr_error(EIO);
} else if (count == 0) {
break;
}
- DEBUG_MSG("[%s] received %zd data\n", logstring, count);
+ DEBUG_MSG("[%s] received %zd data\n", tls_p->client_side ? "tls_client" : "tls", count);
wire_buf += count;
wire_buf_size -= count;
submitted += count;
@@ -629,7 +625,7 @@ void tls_credentials_log_pins(struct tls_credentials *tls_credentials)
#else
void tls_credentials_log_pins(struct tls_credentials *tls_credentials)
{
- kr_log_verbose("[tls] could not calculate RFC 7858 OOB key-pin; GnuTLS 3.4.0+ required\n");
+ kr_log_debug(TLS, "could not calculate RFC 7858 OOB key-pin; GnuTLS 3.4.0+ required\n");
}
#endif
@@ -1082,9 +1078,9 @@ struct tls_client_ctx *tls_client_ctx_new(tls_client_param_t *entry,
if (ret == GNUTLS_E_SUCCESS && entry->hostname) {
ret = gnutls_server_name_set(ctx->c.tls_session, GNUTLS_NAME_DNS,
entry->hostname, strlen(entry->hostname));
- kr_log_verbose("[tls_client] set hostname, ret = %d\n", ret);
+ kr_log_debug(TLSCLIENT, "set hostname, ret = %d\n", ret);
} else if (!entry->hostname) {
- kr_log_verbose("[tls_client] no hostname\n");
+ kr_log_debug(TLSCLIENT, "no hostname\n");
}
if (ret != GNUTLS_E_SUCCESS) {
tls_client_ctx_free(ctx);
@@ -1194,3 +1190,4 @@ int tls_client_ctx_set_session(struct tls_client_ctx *ctx, struct session *sessi
}
#undef DEBUG_MSG
+#undef VERBOSE_MSG
diff --git a/daemon/tls_session_ticket-srv.c b/daemon/tls_session_ticket-srv.c
index 49b36f67..b5aee95d 100644
--- a/daemon/tls_session_ticket-srv.c
+++ b/daemon/tls_session_ticket-srv.c
@@ -190,7 +190,7 @@ static void tst_key_check(uv_timer_t *timer, bool force_update)
/* ^ +1 because we don't want to wake up half a millisecond before the epoch! */
if (kr_fails_assert(remain_ms < (TST_KEY_LIFETIME + 1 /*rounding tolerance*/) * 1000))
return;
- kr_log_verbose("[tls] session ticket: epoch %"PRIu64
+ kr_log_debug(TLS, "session ticket: epoch %"PRIu64
", scheduling rotation check in %"PRIu64" ms\n",
(uint64_t)epoch, remain_ms);
err = uv_timer_start(timer, &tst_timer_callback, remain_ms, 0);
diff --git a/daemon/worker.c b/daemon/worker.c
index 4647a8b7..a96e3a66 100644
--- a/daemon/worker.c
+++ b/daemon/worker.c
@@ -142,7 +142,7 @@ static uv_handle_t *ioreq_spawn(struct worker_ctx *worker,
bool precond = (socktype == SOCK_DGRAM || socktype == SOCK_STREAM)
&& (family == AF_INET || family == AF_INET6);
if (kr_fails_assert(precond)) {
- kr_log_verbose("[work] ioreq_spawn: pre-condition failed\n");
+ kr_log_debug(WORKER, "ioreq_spawn: pre-condition failed\n");
return NULL;
}
@@ -316,7 +316,7 @@ static void free_wire(const struct request_ctx *ctx)
uint32_t sent;
int ret = knot_xdp_send(xhd->socket, &out, 1, &sent);
kr_assert(ret == KNOT_EOK && sent == 0);
- kr_log_verbose("[xdp] freed unsent buffer, ret = %d\n", ret);
+ kr_log_debug(XDP, "freed unsent buffer, ret = %d\n", ret);
}
#endif
/* Helper functions for transport selection */
@@ -643,7 +643,7 @@ int qr_task_on_send(struct qr_task *task, const uv_handle_t *handle, int status)
}
if (!peer_str)
peer_str = "unknown"; // probably shouldn't happen
- kr_log_verbose( "[wrkr]=> disconnected from '%s': %s\n",
+ kr_log_debug(WORKER, "=> disconnected from '%s': %s\n",
peer_str, uv_strerror(status));
}
worker_end_tcp(s);
@@ -868,9 +868,9 @@ static int session_tls_hs_cb(struct session *session, int status)
tls_client_param_t *tls_params = tls_client_ctx->params;
gnutls_session_t tls_session = tls_client_ctx->c.tls_session;
if (gnutls_session_is_resumed(tls_session) != 0) {
- kr_log_verbose("[tls_client] TLS session has resumed\n");
+ kr_log_debug(TLSCLIENT, "TLS session has resumed\n");
} else {
- kr_log_verbose("[tls_client] TLS session has not resumed\n");
+ kr_log_debug(TLSCLIENT, "TLS session has not resumed\n");
/* session wasn't resumed, delete old session data ... */
if (tls_params->session_data.data != NULL) {
gnutls_free(tls_params->session_data.data);
@@ -986,7 +986,7 @@ static void on_connect(uv_connect_t *req, int status)
* it's timeouted session. */
if (VERBOSE_STATUS) {
const char *peer_str = kr_straddr(peer);
- kr_log_verbose( "[wrkr]=> connected to '%s', but session "
+ kr_log_debug(WORKER, "=> connected to '%s', but session "
"is already timeouted, close\n",
peer_str ? peer_str : "");
}
@@ -1003,7 +1003,7 @@ static void on_connect(uv_connect_t *req, int status)
* to reconnect to upstream after unsuccessful attempt. */
if (VERBOSE_STATUS) {
const char *peer_str = kr_straddr(peer);
- kr_log_verbose( "[wrkr]=> connected to '%s', but peer "
+ kr_log_debug(WORKER, "=> connected to '%s', but peer "
"is already connected, close\n",
peer_str ? peer_str : "");
}
@@ -1016,7 +1016,7 @@ static void on_connect(uv_connect_t *req, int status)
if (status != 0) {
if (VERBOSE_STATUS) {
const char *peer_str = kr_straddr(peer);
- kr_log_verbose( "[wrkr]=> connection to '%s' failed (%s), flagged as 'bad'\n",
+ kr_log_debug(WORKER, "=> connection to '%s' failed (%s), flagged as 'bad'\n",
peer_str ? peer_str : "", uv_strerror(status));
}
worker_del_tcp_waiting(worker, peer);
@@ -1049,7 +1049,7 @@ static void on_connect(uv_connect_t *req, int status)
if (VERBOSE_STATUS) {
const char *peer_str = kr_straddr(peer);
- kr_log_verbose( "[wrkr]=> connected to '%s'\n", peer_str ? peer_str : "");
+ kr_log_debug(WORKER, "=> connected to '%s'\n", peer_str ? peer_str : "");
}
session_flags(session)->connected = true;
@@ -1308,7 +1308,7 @@ static int xdp_push(struct qr_task *task, const uv_handle_t *src_handle)
ctx->req.answer->wire = NULL; /* it's been freed */
uv_idle_start(&xhd->tx_waker, xdp_tx_waker);
- kr_log_verbose("[xdp] pushed a packet, ret = %d\n", ret);
+ kr_log_debug(XDP, "pushed a packet, ret = %d\n", ret);
return qr_task_on_send(task, src_handle, ret);
#else
diff --git a/lib/cache/api.c b/lib/cache/api.c
index 34c99f57..1c64094e 100644
--- a/lib/cache/api.c
+++ b/lib/cache/api.c
@@ -83,13 +83,13 @@ static int assert_right_version(struct kr_cache *cache)
if (ret != 0) { /* Log for non-empty cache to limit noise on fresh start. */
kr_log_info(CACHE, "incompatible cache database detected, purging\n");
if (oldret) {
- kr_log_verbose("[cache] reading version returned: %d\n", oldret);
+ kr_log_debug(CACHE, "reading version returned: %d\n", oldret);
} else if (val.len != sizeof(CACHE_VERSION)) {
- kr_log_verbose("[cache] version has bad length: %d\n", (int)val.len);
+ kr_log_debug(CACHE, "version has bad length: %d\n", (int)val.len);
} else {
uint16_t ver;
memcpy(&ver, val.data, sizeof(ver));
- kr_log_verbose("[cache] version has bad value: %d instead of %d\n",
+ kr_log_debug(CACHE, "version has bad value: %d instead of %d\n",
(int)ver, (int)CACHE_VERSION);
}
}
diff --git a/lib/cache/cdb_lmdb.c b/lib/cache/cdb_lmdb.c
index ab36dbe6..5bf226a8 100644
--- a/lib/cache/cdb_lmdb.c
+++ b/lib/cache/cdb_lmdb.c
@@ -486,7 +486,7 @@ static int cdb_check_health(kr_cdb_pt db, struct kr_cdb_stats *stats)
}
if (st.st_dev != env->st_dev || st.st_ino != env->st_ino) {
- kr_log_verbose("[cache] cache file has been replaced, reopening\n");
+ kr_log_debug(CACHE, "cache file has been replaced, reopening\n");
int ret = reopen_env(env, stats, 0); // we accept mapsize from the new file
return ret == 0 ? 1 : ret;
}
@@ -598,7 +598,7 @@ static int cdb_clear(kr_cdb_pt db, struct kr_cdb_stats *stats)
ret = kr_ok();
// else pass some other error
} else {
- kr_log_verbose("[cache] clear: identical files, unlinking\n");
+ kr_log_debug(CACHE, "clear: identical files, unlinking\n");
// coverity[toctou]
unlink(env->mdb_data_path);
unlink(mdb_lockfile);
diff --git a/lib/cache/nsec1.c b/lib/cache/nsec1.c
index f6bf7275..ccf282c5 100644
--- a/lib/cache/nsec1.c
+++ b/lib/cache/nsec1.c
@@ -66,7 +66,7 @@ knot_db_val_t key_NSEC1(struct key *k, const knot_dname_t *name, bool add_wildca
/*
VERBOSE_MSG(NULL, "<> key_NSEC1; name: ");
kr_dname_print(name, add_wildcard ? "*." : "" , " ");
- kr_log_verbose("(zone name LF length: %d; total key length: %d)\n",
+ kr_log_debug(CACHE, "(zone name LF length: %d; total key length: %d)\n",
k->zlf_len, key_len);
*/
diff --git a/lib/log.c b/lib/log.c
index 702dfd34..3d8482d5 100644
--- a/lib/log.c
+++ b/lib/log.c
@@ -60,6 +60,8 @@ log_group_names_t log_group_names[] = {
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),
{ NULL, -1 },
};
diff --git a/lib/log.h b/lib/log.h
index c43f53f3..cbbd585a 100644
--- a/lib/log.h
+++ b/lib/log.h
@@ -66,6 +66,8 @@ enum kr_log_groups_type {
LOG_GRP_PRIMING,
LOG_GRP_SRVSTALE,
LOG_GRP_WATCHDOG,
+ LOG_GRP_NSID,
+ LOG_GRP_DNSTAP,
LOG_GRP_TESTS,
};
@@ -106,6 +108,8 @@ enum kr_log_groups_type {
#define LOG_GRP_PRIMING_TAG "primin"
#define LOG_GRP_SRVSTALE_TAG "srvstl"
#define LOG_GRP_WATCHDOG_TAG "wtchdg"
+#define LOG_GRP_NSID_TAG "nsid "
+#define LOG_GRP_DNSTAP_TAG "dnstap"
#define LOG_GRP_TESTS_TAG "tests "
KR_EXPORT
@@ -220,4 +224,4 @@ void kr_log_q1(const struct kr_query *qry, log_groups_t group, const char *tag,
/** 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
+
diff --git a/modules/dnstap/dnstap.c b/modules/dnstap/dnstap.c
index f813653b..1182a3ce 100644
--- a/modules/dnstap/dnstap.c
+++ b/modules/dnstap/dnstap.c
@@ -21,7 +21,7 @@
#include <sys/socket.h>
#include <uv.h>
-#define DEBUG_MSG(fmt, ...) kr_log_verbose("[dnstap] " fmt, ##__VA_ARGS__);
+#define DEBUG_MSG(fmt, ...) kr_log_debug(DNSTAP, fmt, ##__VA_ARGS__);
#define CFG_SOCK_PATH "socket_path"
#define CFG_IDENTITY_STRING "identity"
#define CFG_VERSION_STRING "version"
diff --git a/modules/nsid/nsid.c b/modules/nsid/nsid.c
index c0eabfdc..09f6d39e 100644
--- a/modules/nsid/nsid.c
+++ b/modules/nsid/nsid.c
@@ -38,7 +38,7 @@ static int nsid_finalize(kr_layer_t *ctx) {
/* Check violation of https://tools.ietf.org/html/rfc5001#section-2.1:
* The resolver MUST NOT include any NSID payload data in the query */
if (knot_edns_opt_get_length(req_nsid) != 0)
- kr_log_verbose("[%05u. ][nsid] FORMERR: NSID option in query "
+ kr_log_debug(NSID, "[%05u. ] FORMERR: NSID option in query "
"must not contain payload, continuing\n", req->uid);
/* FIXME: actually change RCODE in answer to FORMERR? */
@@ -50,7 +50,7 @@ static int nsid_finalize(kr_layer_t *ctx) {
config->local_nsid_len, config->local_nsid,
&req->pool) != KNOT_EOK) {
/* something went wrong and there is no way to salvage content of OPT RRset */
- kr_log_verbose("[%05u. ][nsid] unable to add NSID option\n", req->uid);
+ kr_log_debug(NSID, "[%05u. ] unable to add NSID option\n", req->uid);
knot_rrset_clear(req->answer->opt_rr, &req->pool);
}
diff --git a/utils/cache_gc/db.c b/utils/cache_gc/db.c
index 3b4a75be..923da87a 100644
--- a/utils/cache_gc/db.c
+++ b/utils/cache_gc/db.c
@@ -274,7 +274,7 @@ int kr_gc_cache_iter(knot_db_t * knot_db, const kr_cache_gc_cfg_t *cfg,
api->txn_abort(&txn);
- kr_log_verbose("DEBUG: iterated %u items, gc consistent %u, kr consistent %u\n",
+ kr_log_debug(CACHE, "iterated %u items, gc consistent %u, kr consistent %u\n",
counter_iter, counter_gc_consistent, counter_kr_consistent);
return KNOT_EOK;
}
diff --git a/utils/cache_gc/kr_cache_gc.c b/utils/cache_gc/kr_cache_gc.c
index 758a6e9a..d89352e8 100644
--- a/utils/cache_gc/kr_cache_gc.c
+++ b/utils/cache_gc/kr_cache_gc.c
@@ -229,7 +229,7 @@ int kr_cache_gc(kr_cache_gc_cfg_t *cfg, kr_cache_gc_state_t **state)
/* use less precise variant to avoid 32-bit overflow */
ssize_t amount_tofree = cats_sumsize / 100 * cfg->cache_to_be_freed;
- kr_log_verbose("tofree: %zd / %zd\n", amount_tofree, cats_sumsize);
+ kr_log_debug(CACHE, "tofree: %zd / %zd\n", amount_tofree, cats_sumsize);
if (VERBOSE_STATUS) {
for (int i = 0; i < CATEGORIES; i++) {
if (cats.categories_sizes[i] > 0) {
generated by cgit v1.2.3 (git 2.39.1) at 2025-01-29 23:45:35 +0100