diff --git a/daemon/bindings/cache.c b/daemon/bindings/cache.c index 3ab1e53219168b09c816f0cabefee8bf1110159b..4f7d2f7da742a5380c65fa9b44495d6b11c3e0e7 100644 --- a/daemon/bindings/cache.c +++ b/daemon/bindings/cache.c @@ -206,7 +206,7 @@ static int cache_open(lua_State *L) * even in case of not having any work to do. */ ret = kr_cache_check_health(&engine->resolver.cache, 5000); if (ret != 0) { - kr_log_error("[cache] periodic health check failed (ignored): %s\n", + kr_log_error(LOG_GRP_CACHE, "[cache] periodic health check failed (ignored): %s\n", kr_strerror(ret)); } diff --git a/daemon/bindings/impl.h b/daemon/bindings/impl.h index 7003d2e24c95bd7e4d75af2143f35a701683439d..92e82a460aa9f62846feb3d550166e1b8ca81d05 100644 --- a/daemon/bindings/impl.h +++ b/daemon/bindings/impl.h @@ -69,7 +69,7 @@ static inline int execute_callback(lua_State *L, int argc) { int ret = engine_pcall(L, argc); if (ret != 0) { - kr_log_error("error: %s\n", lua_tostring(L, -1)); + kr_log_error(LOG_GRP_SYSTEM, "[system] error: %s\n", lua_tostring(L, -1)); } /* Clear the stack, there may be event a/o enything returned */ lua_settop(L, 0); diff --git a/daemon/bindings/net.c b/daemon/bindings/net.c index b5c9312f4ea98274a60b61a7c60be5d3a53ed363..b0d3d549291a6deb031eab20e4ccdd9b81b98bd9 100644 --- a/daemon/bindings/net.c +++ b/daemon/bindings/net.c @@ -141,7 +141,7 @@ static bool net_listen_addrs(lua_State *L, int port, endpoint_flags_t flags, int if (ret == 0) return true; /* success */ if (is_unix) { - kr_log_error("[system] bind to '%s' (UNIX): %s\n", + kr_log_error(LOG_GRP_NETWORK, "[network] bind to '%s' (UNIX): %s\n", str, kr_strerror(ret)); } else if (flags.xdp) { const char *err_str = knot_strerror(ret); @@ -157,18 +157,18 @@ static bool net_listen_addrs(lua_State *L, int port, endpoint_flags_t flags, int /* Notable OK strerror: KNOT_EPERM Operation not permitted */ if (nic_queue == -1) { - kr_log_error("[system] failed to initialize XDP for '%s@%d'" + kr_log_error(LOG_GRP_NETWORK, "[network] failed to initialize XDP for '%s@%d'" " (nic_queue = <auto>): %s\n", str, port, err_str); } else { - kr_log_error("[system] failed to initialize XDP for '%s@%d'" + kr_log_error(LOG_GRP_NETWORK, "[network] failed to initialize XDP for '%s@%d'" " (nic_queue = %d): %s\n", str, port, nic_queue, err_str); } } else { const char *stype = flags.sock_type == SOCK_DGRAM ? "UDP" : "TCP"; - kr_log_error("[system] bind to '%s@%d' (%s): %s\n", + kr_log_error(LOG_GRP_NETWORK, "[network] bind to '%s@%d' (%s): %s\n", str, port, stype, kr_strerror(ret)); } return false; /* failure */ @@ -775,7 +775,7 @@ static int net_tls_client(lua_State *L) ok_ca = memcmp(newcfg->pins.at[i], oldcfg->pins.at[i], TLS_SHA256_RAW_LEN) == 0; const bool ok_insecure = newcfg->insecure == oldcfg->insecure; if (!(ok_h && ok_ca && ok_pins && ok_insecure)) { - kr_log_info("[tls_client] " + kr_log_warning(LOG_GRP_TLSCLIENT, "[tls_client] " "warning: re-defining TLS authentication parameters for %s\n", addr_str); } diff --git a/daemon/engine.c b/daemon/engine.c index 28349db594447675d0fabaccb81e97405c00c494..0ad23f902da1a7d77fdd38873d4bb5c98d43021b 100644 --- a/daemon/engine.c +++ b/daemon/engine.c @@ -742,7 +742,7 @@ int engine_register(struct engine *engine, const char *name, const char *precede ret = engine_pcall(L, 1); } if (kr_fails_assert(ret == 0)) { /* probably not critical, but weird */ - kr_log_error("[system] internal error when loading C module %s: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] internal error when loading C module %s: %s\n", module->name, lua_tostring(L, -1)); lua_pop(L, 1); } @@ -751,12 +751,12 @@ int engine_register(struct engine *engine, const char *name, const char *precede /* No luck with C module, so try to load and .init() lua module. */ ret = ffimodule_register_lua(engine, module, name); if (ret != 0) { - kr_log_error("[system] failed to load module '%s'\n", name); + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to load module '%s'\n", name); } } else if (ret == kr_error(ENOTSUP)) { /* Print a more helpful message when module is linked against an old resolver ABI. */ - kr_log_error("[system] module '%s' links to unsupported ABI, please rebuild it\n", name); + kr_log_error(LOG_GRP_SYSTEM, "[system] module '%s' links to unsupported ABI, please rebuild it\n", name); } if (ret != 0) { diff --git a/daemon/ffimodule.c b/daemon/ffimodule.c index 2c36f36b8720e24efeba89efcee6937675f16ff0..75dc183a88e8497d06df12c23ce9c1a982b14cd9 100644 --- a/daemon/ffimodule.c +++ b/daemon/ffimodule.c @@ -66,7 +66,7 @@ static int l_ffi_modcb(lua_State *L, struct kr_module *module) lua_pushpointer(L, module); if (lua_pcall(L, 2, 0, 0) == 0) return kr_ok(); - kr_log_error("error: %s\n", lua_tostring(L, -1)); + kr_log_error(LOG_GRP_SYSTEM, "[system] error: %s\n", lua_tostring(L, -1)); lua_pop(L, 1); return kr_error(1); } @@ -117,12 +117,12 @@ static int l_ffi_call_layer(kr_layer_t *ctx, int slot_ix) int state = ctx->req->state; if (ret) { /* Exception or another lua problem. */ state = KR_STATE_FAIL; - kr_log_error("error: %s\n", lua_tostring(L, -1)); + kr_log_error(LOG_GRP_SYSTEM, "[system] error: %s\n", lua_tostring(L, -1)); } else if (lua_isnumber(L, -1)) { /* Explicitly returned state. */ state = lua_tointeger(L, -1); if (!kr_state_consistent(state)) { - kr_log_error("error: nonsense state returned from lua module layer: %d\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] error: nonsense state returned from lua module layer: %d\n", state); state = KR_STATE_FAIL; } @@ -136,7 +136,7 @@ static int l_ffi_call_layer(kr_layer_t *ctx, int slot_ix) } else { /* Nonsense returned. */ state = KR_STATE_FAIL; - kr_log_error("error: nonsense returned from lua module layer: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] error: nonsense returned from lua module layer: %s\n", lua_tostring(L, -1)); /* Unfortunately we can't easily get name of the module/function here. */ } @@ -278,7 +278,7 @@ int ffimodule_register_lua(struct engine *engine, struct kr_module *module, cons lua_getglobal(L, "require"); lua_pushfstring(L, "kres_modules.%s", name); if (lua_pcall(L, 1, LUA_MULTRET, 0) != 0) { - kr_log_error("error: %s\n", lua_tostring(L, -1)); + kr_log_error(LOG_GRP_SYSTEM, "[system] error: %s\n", lua_tostring(L, -1)); lua_pop(L, 1); return kr_error(ENOENT); } diff --git a/daemon/http.c b/daemon/http.c index e21b0db1408f5a48447c120f2254e8c8e60ae9e8..944ca4e00bc69e8c2dd5bcb8d93a464578a5d6b9 100644 --- a/daemon/http.c +++ b/daemon/http.c @@ -409,7 +409,7 @@ static int data_chunk_recv_callback(nghttp2_session *h2, uint8_t flags, int32_t required += sizeof(uint16_t); if (required > remaining) { - kr_log_error("[http] insufficient space in buffer\n"); + kr_log_error(LOG_GRP_DOH, "[http] insufficient space in buffer\n"); ctx->incomplete_stream = -1; return NGHTTP2_ERR_CALLBACK_FAILURE; } diff --git a/daemon/io.c b/daemon/io.c index 056115f5944cc67c5fc9e64568398171f88b4b9f..065063a2575dec86de91b0f3a4261aaa46c7f3e6 100644 --- a/daemon/io.c +++ b/daemon/io.c @@ -165,8 +165,8 @@ int io_bind(const struct sockaddr *addr, int type, const endpoint_flags_t *flags int omit = IP_PMTUDISC_OMIT; if (type == SOCK_DGRAM && addr->sa_family == AF_INET && setsockopt(fd, IPPROTO_IP, IP_MTU_DISCOVER, &omit, sizeof(omit))) { - kr_log_error( - "[ io ] failed to disable Path MTU discovery for %s UDP: %s\n", + kr_log_error(LOG_GRP_IO, "[ io ]" + "failed to disable Path MTU discovery for %s UDP: %s\n", kr_straddr(addr), strerror(errno)); } #endif @@ -199,7 +199,7 @@ int io_listen_udp(uv_loop_t *loop, uv_udp_t *handle, int fd) int socklen = sizeof(union inaddr); ret = uv_udp_getsockname(handle, session_get_sockname(s), &socklen); if (ret) { - kr_log_error("ERROR: getsockname failed: %s\n", uv_strerror(ret)); + kr_log_error(LOG_GRP_IO, "[ io ] ERROR: getsockname failed: %s\n", uv_strerror(ret)); abort(); /* It might be nontrivial not to leak something here. */ } @@ -517,7 +517,7 @@ int io_listen_tcp(uv_loop_t *loop, uv_tcp_t *handle, int fd, int tcp_backlog, bo #if ENABLE_DOH2 connection = https_accept; #else - kr_log_error("[ io ] kresd was compiled without libnghttp2 support\n"); + kr_log_error(LOG_GRP_IO, "[ io ] kresd was compiled without libnghttp2 support\n"); return kr_error(ENOPROTOOPT); #endif } else if (has_tls) { @@ -536,7 +536,7 @@ int io_listen_tcp(uv_loop_t *loop, uv_tcp_t *handle, int fd, int tcp_backlog, bo #ifdef TCP_DEFER_ACCEPT val = KR_CONN_RTT_MAX/1000; if (setsockopt(fd, IPPROTO_TCP, TCP_DEFER_ACCEPT, &val, sizeof(val))) { - kr_log_error("[ io ] listen TCP (defer_accept): %s\n", strerror(errno)); + kr_log_error(LOG_GRP_IO, "[ io ] listen TCP (defer_accept): %s\n", strerror(errno)); } #endif @@ -553,7 +553,7 @@ int io_listen_tcp(uv_loop_t *loop, uv_tcp_t *handle, int fd, int tcp_backlog, bo val = 1; /* Accepts on/off */ #endif if (setsockopt(fd, IPPROTO_TCP, TCP_FASTOPEN, &val, sizeof(val))) { - kr_log_error("[ io ] listen TCP (fastopen): %s%s\n", strerror(errno), + kr_log_error(LOG_GRP_IO, "[ io ] listen TCP (fastopen): %s%s\n", strerror(errno), (errno != EPERM ? "" : ". This may be caused by TCP Fast Open being disabled in the OS.")); } @@ -686,7 +686,7 @@ void io_tty_process_input(uv_stream_t *stream, ssize_t nread, const uv_buf_t *bu if (data->mode == io_mode_binary) { /* Leader expects length field in all cases */ if (!message || len_s > UINT32_MAX) { - kr_log_error("[io] unrepresentable respose on control socket, " + kr_log_error(LOG_GRP_IO, "[ io ] unrepresentable respose on control socket, " "sending back empty block (command '%s')\n", cmd); len_s = 0; } @@ -798,11 +798,11 @@ static void xdp_rx(uv_poll_t* handle, int status, int events) { const int XDP_RX_BATCH_SIZE = 64; if (status < 0) { - kr_log_error("[xdp] poll status %d: %s\n", status, uv_strerror(status)); + kr_log_error(LOG_GRP_XDP, "[xdp] poll status %d: %s\n", status, uv_strerror(status)); return; } if (events != UV_READABLE) { - kr_log_error("[xdp] poll unexpected events: %d\n", events); + kr_log_error(LOG_GRP_XDP, "[xdp] poll unexpected events: %d\n", events); return; } @@ -815,9 +815,10 @@ static void xdp_rx(uv_poll_t* handle, int status, int events) , NULL #endif ); + if (kr_fails_assert(ret == KNOT_EOK)) { /* ATM other error codes can only be returned when called incorrectly */ - kr_log_error("[xdp] knot_xdp_recv(): %d, %s\n", ret, knot_strerror(ret)); + kr_log_error(LOG_GRP_XDP, "[xdp] knot_xdp_recv(): %d, %s\n", ret, knot_strerror(ret)); return; } kr_log_verbose("[xdp] poll triggered, processing a batch of %d packets\n", (int)rcvd); @@ -849,7 +850,7 @@ static void xdp_warn_mode(const char *ifname) const unsigned if_index = if_nametoindex(ifname); if (!if_index) { - kr_log_info("[xdp] warning: interface %s, unexpected error when converting its name: %s\n", + kr_log_warning(LOG_GRP_XDP, "[xdp] warning: interface %s, unexpected error when converting its name: %s\n", ifname, strerror(errno)); return; } @@ -859,13 +860,13 @@ static void xdp_warn_mode(const char *ifname) case KNOT_XDP_MODE_FULL: return; case KNOT_XDP_MODE_EMUL: - kr_log_info("[xdp] warning: interface %s running only with XDP emulation\n", + kr_log_warning(LOG_GRP_XDP, "[xdp] warning: interface %s running only with XDP emulation\n", ifname); return; case KNOT_XDP_MODE_NONE: // enum warnings from compiler break; } - kr_log_info("[xdp] warning: interface %s running in unexpected XDP mode %d\n", + kr_log_warning(LOG_GRP_XDP, "[xdp] warning: interface %s running in unexpected XDP mode %d\n", ifname, (int)mode); } int io_listen_xdp(uv_loop_t *loop, struct endpoint *ep, const char *ifname) diff --git a/daemon/main.c b/daemon/main.c index f7e18896bda512d1e6002cee88b853583c20d092..cfff0d0cb52dc5e8325d7fdc7738a9c9bc52b7b0 100644 --- a/daemon/main.c +++ b/daemon/main.c @@ -56,7 +56,7 @@ static void signal_handler(uv_signal_t *handle, int signum) while (waitpid(-1, NULL, WNOHANG) > 0); break; default: - kr_log_error("unhandled signal: %d\n", signum); + kr_log_error(LOG_GRP_SYSTEM, "unhandled signal: %d\n", signum); break; } } @@ -153,8 +153,8 @@ static int run_worker(uv_loop_t *loop, struct engine *engine, bool leader, struc case UV_NAMED_PIPE: /* echo 'quit()' | kresd ... */ break; default: - kr_log_error( - "[system] error: standard input is not a terminal or pipe; " + kr_log_error(LOG_GRP_SYSTEM, "[system] " + "error: standard input is not a terminal or pipe; " "use '-n' if you want non-interactive mode. " "Commands can be simply added to your configuration file or sent over the control socket.\n" ); @@ -249,12 +249,12 @@ static int parse_args(int argc, char **argv, struct args *args) kr_require(optarg); args->forks = strtol(optarg, NULL, 10); if (args->forks == 1) { - kr_log_deprecate("use --noninteractive instead of --forks=1\n"); + kr_log_deprecate(LOG_GRP_SYSTEM, "use --noninteractive instead of --forks=1\n"); } else { - kr_log_deprecate("support for running multiple --forks will be removed\n"); + kr_log_deprecate(LOG_GRP_SYSTEM, "support for running multiple --forks will be removed\n"); } if (args->forks <= 0) { - kr_log_error("[system] error '-f' requires a positive" + kr_log_error(LOG_GRP_SYSTEM, "error '-f' requires a positive" " number, not '%s'\n", optarg); return EXIT_FAILURE; } @@ -294,7 +294,7 @@ static int parse_args(int argc, char **argv, struct args *args) /* Some other kind; no checks here. */ ffd.flags.kind = strdup(endptr + 1); } else { - kr_log_error("[system] incorrect value passed to '-S/--fd': %s\n", + kr_log_error(LOG_GRP_SYSTEM, "incorrect value passed to '-S/--fd': %s\n", optarg); return EXIT_FAILURE; } @@ -353,7 +353,7 @@ static int bind_sockets(addr_array_t *addrs, bool tls, flagged_fd_array_t *fds) } free(sa); if (ret != 0) { - kr_log_error("[system] bind to '%s'%s: %s\n", + kr_log_error(LOG_GRP_NETWORK, "[network] bind to '%s'%s: %s\n", addrs->at[i], tls ? " (TLS)" : "", kr_strerror(ret)); has_error = true; } @@ -372,7 +372,7 @@ static int start_listening(struct network *net, flagged_fd_array_t *fds) { /* TODO: try logging address@port. It's not too important, * because typical problems happen during binding already. * (invalid address, permission denied) */ - kr_log_error("[system] listen on fd=%d: %s\n", + kr_log_error(LOG_GRP_NETWORK, "[network] listen on fd=%d: %s\n", ffd->fd, kr_strerror(ret)); /* Continue printing all of these before exiting. */ } else { @@ -396,7 +396,7 @@ static void drop_capabilities(void) /* Apply. */ if (capng_apply(CAPNG_SELECT_BOTH) < 0) { - kr_log_error("[system] failed to set process capabilities: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to set process capabilities: %s\n", strerror(errno)); } else { kr_log_verbose("[system] all capabilities dropped\n"); @@ -411,12 +411,12 @@ static void drop_capabilities(void) int main(int argc, char **argv) { if (setvbuf(stdout, NULL, _IONBF, 0) || setvbuf(stderr, NULL, _IONBF, 0)) { - kr_log_error("[system] failed to to set output buffering (ignored): %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to to set output buffering (ignored): %s\n", strerror(errno)); fflush(stderr); } if (strcmp("linux", OPERATING_SYSTEM) != 0) - kr_log_info("[warn] Knot Resolver is tested on Linux, other platforms might exhibit bugs.\n" + kr_log_warning(LOG_GRP_SYSTEM, "Knot Resolver is tested on Linux, other platforms might exhibit bugs.\n" "Please report issues to https://gitlab.nic.cz/knot/knot-resolver/issues/\n" "Thank you for your time and interest!\n"); @@ -436,7 +436,7 @@ int main(int argc, char **argv) /* FIXME: access isn't a good way if we start as root and drop privileges later */ if (access(the_args->rundir, W_OK) != 0 || chdir(the_args->rundir) != 0) { - kr_log_error("[system] rundir '%s': %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] rundir '%s': %s\n", the_args->rundir, strerror(errno)); return EXIT_FAILURE; } @@ -454,7 +454,7 @@ int main(int argc, char **argv) } else if (access(config, R_OK) != 0) { char cwd[PATH_MAX]; get_workdir(cwd, sizeof(cwd)); - kr_log_error("[system] config '%s' (workdir '%s'): %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] config '%s' (workdir '%s'): %s\n", config, cwd, strerror(errno)); return EXIT_FAILURE; } @@ -475,10 +475,10 @@ int main(int argc, char **argv) ret = setrlimit(RLIMIT_NOFILE, &rlim); } if (ret) { - kr_log_error("[system] failed to get or set file-descriptor limit: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to get or set file-descriptor limit: %s\n", strerror(errno)); } else if (rlim.rlim_cur < 512*1024) { - kr_log_info("[system] warning: hard limit for number of file-descriptors is only %ld but recommended value is 524288\n", + kr_log_warning(LOG_GRP_SYSTEM, "[system] warning: hard limit for number of file-descriptors is only %ld but recommended value is 524288\n", (long)rlim.rlim_cur); } @@ -496,13 +496,13 @@ int main(int argc, char **argv) static struct engine engine; ret = engine_init(&engine, &pool); if (ret != 0) { - kr_log_error("[system] failed to initialize engine: %s\n", kr_strerror(ret)); + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to initialize engine: %s\n", kr_strerror(ret)); return EXIT_FAILURE; } /* Initialize the worker */ ret = worker_init(&engine, the_args->forks); if (ret != 0) { - kr_log_error("[system] failed to initialize worker: %s\n", kr_strerror(ret)); + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to initialize worker: %s\n", kr_strerror(ret)); return EXIT_FAILURE; } @@ -529,7 +529,7 @@ int main(int argc, char **argv) } } if (ret) { - kr_log_error("[system] failed to set up signal handlers: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to set up signal handlers: %s\n", strerror(abs(errno))); ret = EXIT_FAILURE; goto cleanup; @@ -538,7 +538,7 @@ int main(int argc, char **argv) * (of the usual type) may skew results, e.g. epoll_pwait() taking lots of time. */ ret = uv_loop_configure(loop, UV_LOOP_BLOCK_SIGNAL, SIGPROF); if (ret) { - kr_log_info("[system] failed to block SIGPROF in event loop, ignoring: %s\n", + kr_log_info(LOG_GRP_SYSTEM, "[system] failed to block SIGPROF in event loop, ignoring: %s\n", uv_strerror(ret)); } @@ -550,7 +550,7 @@ int main(int argc, char **argv) ret = udp_queue_init_global(loop); if (ret) { - kr_log_error("[system] failed to initialize UDP queue: %s\n", + kr_log_error(LOG_GRP_SYSTEM, "[system] failed to initialize UDP queue: %s\n", kr_strerror(ret)); ret = EXIT_FAILURE; goto cleanup; diff --git a/daemon/network.c b/daemon/network.c index 6b7017a577d8c260cc597720931ee51dbc8fbcd9..fc627d49d507a66a4b7471a6e9243e2337bd0c34 100644 --- a/daemon/network.c +++ b/daemon/network.c @@ -46,11 +46,11 @@ static int endpoint_open_lua_cb(struct network *net, struct endpoint *ep, void **pp = trie_get_try(net->endpoint_kinds, ep->flags.kind, strlen(ep->flags.kind)); if (!pp && net->missing_kind_is_error) { - kr_log_error("error: network socket kind '%s' not handled when opening '%s", + kr_log_error(LOG_GRP_NETWORK, "[network] error: network socket kind '%s' not handled when opening '%s", ep->flags.kind, log_addr); if (ep->family != AF_UNIX) - kr_log_error("#%d", ep->port); - kr_log_error("'\n"); + kr_log_error(LOG_GRP_NETWORK, "#%d", ep->port); + kr_log_error(LOG_GRP_NETWORK, "'\n"); return kr_error(ENOENT); } if (!pp) return kr_ok(); @@ -66,7 +66,7 @@ static int endpoint_open_lua_cb(struct network *net, struct endpoint *ep, lua_pushfstring(L, "%s#%d", log_addr, ep->port); } if (lua_pcall(L, 3, 0, 0)) { - kr_log_error("error opening %s: %s\n", log_addr, lua_tostring(L, -1)); + kr_log_error(LOG_GRP_NETWORK, "[network] error opening %s: %s\n", log_addr, lua_tostring(L, -1)); return kr_error(ENOSYS); /* TODO: better value? */ } ep->engaged = true; @@ -106,7 +106,7 @@ static void endpoint_close_lua_cb(struct network *net, struct endpoint *ep) void **pp = trie_get_try(net->endpoint_kinds, ep->flags.kind, strlen(ep->flags.kind)); if (!pp && net->missing_kind_is_error) { - kr_log_error("internal error: missing kind '%s' in endpoint registry\n", + kr_log_error(LOG_GRP_NETWORK, "[network] internal error: missing kind '%s' in endpoint registry\n", ep->flags.kind); return; } @@ -118,7 +118,7 @@ static void endpoint_close_lua_cb(struct network *net, struct endpoint *ep) lua_pushpointer(L, ep); lua_pushstring(L, "FIXME:endpoint-identifier"); if (lua_pcall(L, 3, 0, 0)) { - kr_log_error("failed to close FIXME:endpoint-identifier: %s\n", + kr_log_error(LOG_GRP_NETWORK, "[nework] failed to close FIXME:endpoint-identifier: %s\n", lua_tostring(L, -1)); } } @@ -135,7 +135,7 @@ static void endpoint_close(struct network *net, struct endpoint *ep, bool force) socklen_t addr_len = sizeof(sa); if (getsockname(ep->fd, (struct sockaddr *)&sa, &addr_len) || unlink(sa.sun_path)) { - kr_log_error("error (ignored) when closing unix socket (fd = %d): %s\n", + kr_log_error(LOG_GRP_NETWORK, "[network] error (ignored) when closing unix socket (fd = %d): %s\n", ep->fd, strerror(errno)); return; } @@ -292,7 +292,7 @@ static int open_endpoint(struct network *net, const char *addr_str, if (ep->family == AF_UNIX) { /* Some parts of connection handling would need more work, * so let's support AF_UNIX only with .kind != NULL for now. */ - kr_log_error("[system] AF_UNIX only supported with set { kind = '...' }\n"); + kr_log_error(LOG_GRP_NETWORK, "[network] AF_UNIX only supported with set { kind = '...' }\n"); ret = EAFNOSUPPORT; goto finish_ret; /* @@ -549,9 +549,9 @@ void network_new_hostname(struct network *net, struct engine *engine) if (newcreds) { tls_credentials_release(net->tls_credentials); net->tls_credentials = newcreds; - kr_log_info("[tls] Updated ephemeral X.509 cert with new hostname\n"); + kr_log_info(LOG_GRP_TLS, "[tls] Updated ephemeral X.509 cert with new hostname\n"); } else { - kr_log_error("[tls] Failed to update ephemeral X.509 cert with new hostname, using existing one\n"); + kr_log_error(LOG_GRP_TLS, "[tls] Failed to update ephemeral X.509 cert with new hostname, using existing one\n"); } } } @@ -588,7 +588,7 @@ int network_set_bpf(struct network *net, int bpf_fd) return 0; } #else - kr_log_error("[network] SO_ATTACH_BPF socket option doesn't supported\n"); + kr_log_error(LOG_GRP_NETWORK, "[network] SO_ATTACH_BPF socket option doesn't supported\n"); (void)net; (void)bpf_fd; return 0; @@ -611,7 +611,7 @@ static int clear_bpf_cb(const char *key, void *val, void *ext) kr_require(sockfd != -1); if (setsockopt(sockfd, SOL_SOCKET, SO_DETACH_BPF, NULL, 0) != 0) { - kr_log_error("[network] failed to clear SO_DETACH_BPF socket option\n"); + kr_log_error(LOG_GRP_NETWORK, "[network] failed to clear SO_DETACH_BPF socket option\n"); } /* Proceed even if setsockopt() failed, * as we want to process all opened sockets. */ @@ -625,7 +625,7 @@ void network_clear_bpf(struct network *net) #ifdef SO_DETACH_BPF map_walk(&net->endpoints, clear_bpf_cb, NULL); #else - kr_log_error("[network] SO_DETACH_BPF socket option doesn't supported\n"); + kr_log_error(LOG_GRP_NETWORK, "[network] SO_DETACH_BPF socket option doesn't supported\n"); (void)net; #endif } diff --git a/daemon/tls.c b/daemon/tls.c index 4da0910848bd0677d1bd22a241ab6f6877b605ad..ef9267101810e74f3b6cf8d27c9caecb5c85b996 100644 --- a/daemon/tls.c +++ b/daemon/tls.c @@ -60,7 +60,7 @@ static int kres_gnutls_set_priority(gnutls_session_t session) { const char *errpos = NULL; int err = gnutls_priority_set_direct(session, priorities, &errpos); if (err != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] setting priority '%s' failed at character %zd (...'%s') with %s (%d)\n", + kr_log_error(LOG_GRP_TLS, "[tls] setting priority '%s' failed at character %zd (...'%s') with %s (%d)\n", priorities, errpos - priorities, errpos, gnutls_strerror_name(err), err); } return err; @@ -295,10 +295,10 @@ struct tls_ctx *tls_new(struct worker_ctx *worker) if (!net->tls_credentials) { net->tls_credentials = tls_get_ephemeral_credentials(worker->engine); if (!net->tls_credentials) { - kr_log_error("[tls] X.509 credentials are missing, and ephemeral credentials failed; no TLS\n"); + kr_log_error(LOG_GRP_TLS, "[tls] X.509 credentials are missing, and ephemeral credentials failed; no TLS\n"); return NULL; } - kr_log_info("[tls] Using ephemeral TLS credentials\n"); + kr_log_info(LOG_GRP_TLS, "[tls] Using ephemeral TLS credentials\n"); tls_credentials_log_pins(net->tls_credentials); } @@ -311,15 +311,15 @@ struct tls_ctx *tls_new(struct worker_ctx *worker) if (newcreds) { tls_credentials_release(net->tls_credentials); net->tls_credentials = newcreds; - kr_log_info("[tls] Renewed expiring ephemeral X.509 cert\n"); + kr_log_info(LOG_GRP_TLS, "[tls] Renewed expiring ephemeral X.509 cert\n"); } else { - kr_log_error("[tls] Failed to renew expiring ephemeral X.509 cert, using existing one\n"); + kr_log_error(LOG_GRP_TLS, "[tls] Failed to renew expiring ephemeral X.509 cert, using existing one\n"); } } } else { /* non-ephemeral cert: warn once when certificate expires */ if (now >= net->tls_credentials->valid_until) { - kr_log_error("[tls] X.509 certificate has expired!\n"); + kr_log_error(LOG_GRP_TLS, "[tls] X.509 certificate has expired!\n"); net->tls_credentials->valid_until = GNUTLS_X509_NO_WELL_DEFINED_EXPIRATION; } } @@ -327,13 +327,13 @@ struct tls_ctx *tls_new(struct worker_ctx *worker) struct tls_ctx *tls = calloc(1, sizeof(struct tls_ctx)); if (tls == NULL) { - kr_log_error("[tls] failed to allocate TLS context\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to allocate TLS context\n"); return NULL; } int err = gnutls_init(&tls->c.tls_session, GNUTLS_SERVER | GNUTLS_NONBLOCK); if (err != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] gnutls_init(): %s (%d)\n", gnutls_strerror_name(err), err); + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_init(): %s (%d)\n", gnutls_strerror_name(err), err); tls_free(tls); return NULL; } @@ -341,7 +341,7 @@ struct tls_ctx *tls_new(struct worker_ctx *worker) err = gnutls_credentials_set(tls->c.tls_session, GNUTLS_CRD_CERTIFICATE, tls->credentials->credentials); if (err != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] gnutls_credentials_set(): %s (%d)\n", gnutls_strerror_name(err), err); + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_credentials_set(): %s (%d)\n", gnutls_strerror_name(err), err); tls_free(tls); return NULL; } @@ -435,7 +435,7 @@ int tls_write(uv_write_t *req, uv_handle_t *handle, knot_pkt_t *pkt, uv_write_cb } if (ret != submitted) { - kr_log_error("[%s] gnutls_record_uncork didn't send all data (%d of %zd)\n", + kr_log_error(LOG_GRP_TLS, "[%s] gnutls_record_uncork didn't send all data (%d of %zd)\n", logstring, ret, submitted); return kr_error(EIO); } @@ -605,7 +605,7 @@ void tls_credentials_log_pins(struct tls_credentials *tls_credentials) index, &certs, &cert_count); if (err != GNUTLS_E_SUCCESS) { if (err != GNUTLS_E_REQUESTED_DATA_NOT_AVAILABLE) { - kr_log_error("[tls] could not get X.509 certificates (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] could not get X.509 certificates (%d) %s\n", err, gnutls_strerror_name(err)); } return; @@ -615,10 +615,10 @@ void tls_credentials_log_pins(struct tls_credentials *tls_credentials) char pin[TLS_SHA256_BASE64_BUFLEN] = { 0 }; err = get_oob_key_pin(certs[i], pin, sizeof(pin), false); if (err != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] could not calculate RFC 7858 OOB key-pin from cert %d (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] could not calculate RFC 7858 OOB key-pin from cert %d (%d) %s\n", i, err, gnutls_strerror_name(err)); } else { - kr_log_info("[tls] RFC 7858 OOB key-pin (%d): pin-sha256=\"%s\"\n", + kr_log_info(LOG_GRP_TLS, "[tls] RFC 7858 OOB key-pin (%d): pin-sha256=\"%s\"\n", i, pin); } gnutls_x509_crt_deinit(certs[i]); @@ -653,17 +653,17 @@ static time_t _get_end_entity_expiration(gnutls_certificate_credentials_t creds) time_t ret = GNUTLS_X509_NO_WELL_DEFINED_EXPIRATION; if ((err = gnutls_certificate_get_crt_raw(creds, 0, 0, &data)) != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] failed to get cert to check expiration: (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] failed to get cert to check expiration: (%d) %s\n", err, gnutls_strerror_name(err)); goto done; } if ((err = gnutls_x509_crt_init(&cert)) != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] failed to initialize cert: (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] failed to initialize cert: (%d) %s\n", err, gnutls_strerror_name(err)); goto done; } if ((err = gnutls_x509_crt_import(cert, &data, GNUTLS_X509_FMT_DER)) != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] failed to construct cert while checking expiration: (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] failed to construct cert while checking expiration: (%d) %s\n", err, gnutls_strerror_name(err)); goto done; } @@ -689,14 +689,14 @@ int tls_certificate_set(struct network *net, const char *tls_cert, const char *t int err = 0; if ((err = gnutls_certificate_allocate_credentials(&tls_credentials->credentials)) != GNUTLS_E_SUCCESS) { - kr_log_error("[tls] gnutls_certificate_allocate_credentials() failed: (%d) %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_certificate_allocate_credentials() failed: (%d) %s\n", err, gnutls_strerror_name(err)); tls_credentials_free(tls_credentials); return kr_error(ENOMEM); } if ((err = gnutls_certificate_set_x509_system_trust(tls_credentials->credentials)) < 0) { if (err != GNUTLS_E_UNIMPLEMENTED_FEATURE) { - kr_log_error("[tls] warning: gnutls_certificate_set_x509_system_trust() failed: (%d) %s\n", + kr_log_warning(LOG_GRP_TLS, "[tls] warning: gnutls_certificate_set_x509_system_trust() failed: (%d) %s\n", err, gnutls_strerror_name(err)); tls_credentials_free(tls_credentials); return err; @@ -712,7 +712,7 @@ int tls_certificate_set(struct network *net, const char *tls_cert, const char *t if ((err = gnutls_certificate_set_x509_key_file(tls_credentials->credentials, tls_cert, tls_key, GNUTLS_X509_FMT_PEM)) != GNUTLS_E_SUCCESS) { tls_credentials_free(tls_credentials); - kr_log_error("[tls] gnutls_certificate_set_x509_key_file(%s,%s) failed: %d (%s)\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_certificate_set_x509_key_file(%s,%s) failed: %d (%s)\n", tls_cert, tls_key, err, gnutls_strerror_name(err)); return kr_error(EINVAL); } @@ -829,7 +829,7 @@ tls_client_param_t * tls_client_param_new() e->refs = 1; int ret = gnutls_certificate_allocate_credentials(&e->credentials); if (ret != GNUTLS_E_SUCCESS) { - kr_log_error("[tls_client] error: gnutls_certificate_allocate_credentials() fails (%s)\n", + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] error: gnutls_certificate_allocate_credentials() fails (%s)\n", gnutls_strerror_name(ret)); free(e); return NULL; @@ -961,12 +961,12 @@ static int client_verify_pin(const unsigned int cert_list_size, params->pins.len); } - kr_log_error("[tls_client] no pin matched: %zu pins * %d certificates\n", + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] no pin matched: %zu pins * %d certificates\n", params->pins.len, cert_list_size); return GNUTLS_E_CERTIFICATE_ERROR; #else /* TLS_CAN_USE_PINS */ - kr_log_error("[tls_client] internal inconsistency: TLS_CAN_USE_PINS\n"); + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] internal inconsistency: TLS_CAN_USE_PINS\n"); kr_assert(false); return GNUTLS_E_CERTIFICATE_ERROR; #endif @@ -981,7 +981,7 @@ static int client_verify_pin(const unsigned int cert_list_size, static int client_verify_certchain(gnutls_session_t tls_session, const char *hostname) { if (kr_fails_assert(hostname)) { - kr_log_error("[tls_client] internal config inconsistency: no hostname set\n"); + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] internal config inconsistency: no hostname set\n"); return GNUTLS_E_CERTIFICATE_ERROR; } @@ -996,16 +996,16 @@ static int client_verify_certchain(gnutls_session_t tls_session, const char *hos ret = gnutls_certificate_verification_status_print( status, gnutls_certificate_type_get(tls_session), &msg, 0); if (ret == GNUTLS_E_SUCCESS) { - kr_log_error("[tls_client] failed to verify peer certificate: " + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] failed to verify peer certificate: " "%s\n", msg.data); gnutls_free(msg.data); } else { - kr_log_error("[tls_client] failed to verify peer certificate: " + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] failed to verify peer certificate: " "unable to print reason: %s (%s)\n", gnutls_strerror(ret), gnutls_strerror_name(ret)); } /* gnutls_certificate_verification_status_print end */ } else { - kr_log_error("[tls_client] failed to verify peer certificate: " + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] failed to verify peer certificate: " "gnutls_certificate_verify_peers3 error: %s (%s)\n", gnutls_strerror(ret), gnutls_strerror_name(ret)); } /* gnutls_certificate_verify_peers3 end */ @@ -1029,7 +1029,7 @@ static int client_verify_certificate(gnutls_session_t tls_session) gnutls_certificate_type_t cert_type = gnutls_certificate_type_get(tls_session); if (cert_type != GNUTLS_CRT_X509) { - kr_log_error("[tls_client] invalid certificate type %i has been received\n", + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] invalid certificate type %i has been received\n", cert_type); return GNUTLS_E_CERTIFICATE_ERROR; } @@ -1037,7 +1037,7 @@ static int client_verify_certificate(gnutls_session_t tls_session) const gnutls_datum_t *cert_list = gnutls_certificate_get_peers(tls_session, &cert_list_size); if (cert_list == NULL || cert_list_size == 0) { - kr_log_error("[tls_client] empty certificate list\n"); + kr_log_error(LOG_GRP_TLSCLIENT, "[tls_client] empty certificate list\n"); return GNUTLS_E_CERTIFICATE_ERROR; } diff --git a/daemon/tls_ephemeral_credentials.c b/daemon/tls_ephemeral_credentials.c index 29128f6ef4a86d686a90c9a2e8dd7fab2cac40a3..584a892c4c2ac2b9f81eef911b44adf9fc519b08 100644 --- a/daemon/tls_ephemeral_credentials.c +++ b/daemon/tls_ephemeral_credentials.c @@ -63,12 +63,12 @@ static gnutls_x509_privkey_t get_ephemeral_privkey () * with a shared cache don't both create the same privkey: */ lock = _lock_filename(EPHEMERAL_PRIVKEY_FILENAME ".lock"); if (_lock_is_invalid(lock)) { - kr_log_error("[tls] unable to lock lockfile " EPHEMERAL_PRIVKEY_FILENAME ".lock\n"); + kr_log_error(LOG_GRP_TLS, "[tls] unable to lock lockfile " EPHEMERAL_PRIVKEY_FILENAME ".lock\n"); goto done; } if ((err = gnutls_x509_privkey_init (&privkey)) < 0) { - kr_log_error("[tls] gnutls_x509_privkey_init() failed: %d (%s)\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_x509_privkey_init() failed: %d (%s)\n", err, gnutls_strerror_name(err)); goto done; } @@ -81,22 +81,22 @@ static gnutls_x509_privkey_t get_ephemeral_privkey () struct stat stat; ssize_t bytes_read; if (fstat(datafd, &stat)) { - kr_log_error("[tls] unable to stat ephemeral private key " EPHEMERAL_PRIVKEY_FILENAME "\n"); + kr_log_error(LOG_GRP_TLS, "[tls] unable to stat ephemeral private key " EPHEMERAL_PRIVKEY_FILENAME "\n"); goto bad_data; } data.data = gnutls_malloc(stat.st_size); if (data.data == NULL) { - kr_log_error("[tls] unable to allocate memory for reading ephemeral private key\n"); + kr_log_error(LOG_GRP_TLS, "[tls] unable to allocate memory for reading ephemeral private key\n"); goto bad_data; } data.size = stat.st_size; bytes_read = read(datafd, data.data, stat.st_size); if (bytes_read != stat.st_size) { - kr_log_error("[tls] unable to read ephemeral private key\n"); + kr_log_error(LOG_GRP_TLS, "[tls] unable to read ephemeral private key\n"); goto bad_data; } if ((err = gnutls_x509_privkey_import (privkey, &data, GNUTLS_X509_FMT_PEM)) < 0) { - kr_log_error("[tls] gnutls_x509_privkey_import() failed: %d (%s)\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_x509_privkey_import() failed: %d (%s)\n", err, gnutls_strerror_name(err)); /* goto bad_data; */ bad_data: @@ -115,25 +115,25 @@ static gnutls_x509_privkey_t get_ephemeral_privkey () #else if ((err = gnutls_x509_privkey_generate(privkey, GNUTLS_PK_RSA, gnutls_sec_param_to_pk_bits(GNUTLS_PK_RSA, GNUTLS_SEC_PARAM_MEDIUM), 0)) < 0) { #endif - kr_log_error("[tls] gnutls_x509_privkey_init() failed: %d (%s)\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_x509_privkey_init() failed: %d (%s)\n", err, gnutls_strerror_name(err)); gnutls_x509_privkey_deinit(privkey); goto done; } /* ... and save */ - kr_log_info("[tls] Stashing ephemeral private key in " EPHEMERAL_PRIVKEY_FILENAME "\n"); + kr_log_info(LOG_GRP_TLS, "[tls] Stashing ephemeral private key in " EPHEMERAL_PRIVKEY_FILENAME "\n"); if ((err = gnutls_x509_privkey_export2(privkey, GNUTLS_X509_FMT_PEM, &data)) < 0) { - kr_log_error("[tls] gnutls_x509_privkey_export2() failed: %d (%s), not storing\n", + kr_log_error(LOG_GRP_TLS, "[tls] gnutls_x509_privkey_export2() failed: %d (%s), not storing\n", err, gnutls_strerror_name(err)); } else { datafd = open(EPHEMERAL_PRIVKEY_FILENAME, O_WRONLY|O_CREAT, 0600); if (datafd == -1) { - kr_log_error("[tls] failed to open " EPHEMERAL_PRIVKEY_FILENAME " to store the ephemeral key\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to open " EPHEMERAL_PRIVKEY_FILENAME " to store the ephemeral key\n"); } else { ssize_t bytes_written; bytes_written = write(datafd, data.data, data.size); if (bytes_written != data.size) - kr_log_error("[tls] failed to write %d octets to " + kr_log_error(LOG_GRP_TLS, "[tls] failed to write %d octets to " EPHEMERAL_PRIVKEY_FILENAME " (%zd written)\n", data.size, bytes_written); @@ -164,7 +164,7 @@ static gnutls_x509_crt_t get_ephemeral_cert(gnutls_x509_privkey_t privkey, const #define gtx(fn, ...) \ if ((err = fn ( __VA_ARGS__ )) != GNUTLS_E_SUCCESS) { \ - kr_log_error("[tls] " #fn "() failed: %d (%s)\n", \ + kr_log_error(LOG_GRP_TLS, "[tls] " #fn "() failed: %d (%s)\n", \ err, gnutls_strerror_name(err)); \ goto bad; } @@ -199,20 +199,20 @@ struct tls_credentials * tls_get_ephemeral_credentials(struct engine *engine) creds = calloc(1, sizeof(*creds)); if (!creds) { - kr_log_error("[tls] failed to allocate memory for ephemeral credentials\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to allocate memory for ephemeral credentials\n"); return NULL; } if ((err = gnutls_certificate_allocate_credentials(&(creds->credentials))) < 0) { - kr_log_error("[tls] failed to allocate memory for ephemeral credentials\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to allocate memory for ephemeral credentials\n"); goto failure; } creds->valid_until = now + EPHEMERAL_CERT_EXPIRATION_SECONDS; creds->ephemeral_servicename = strdup(engine_get_hostname(engine)); if (creds->ephemeral_servicename == NULL) { - kr_log_error("[tls] could not get server's hostname, using '" INVALID_HOSTNAME "' instead\n"); + kr_log_error(LOG_GRP_TLS, "[tls] could not get server's hostname, using '" INVALID_HOSTNAME "' instead\n"); if ((creds->ephemeral_servicename = strdup(INVALID_HOSTNAME)) == NULL) { - kr_log_error("[tls] failed to allocate memory for ephemeral credentials\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to allocate memory for ephemeral credentials\n"); goto failure; } } @@ -223,7 +223,7 @@ struct tls_credentials * tls_get_ephemeral_credentials(struct engine *engine) goto failure; } if ((err = gnutls_certificate_set_x509_key(creds->credentials, &cert, 1, privkey)) < 0) { - kr_log_error("[tls] failed to set up ephemeral credentials\n"); + kr_log_error(LOG_GRP_TLS, "[tls] failed to set up ephemeral credentials\n"); goto failure; } gnutls_x509_privkey_deinit(privkey); diff --git a/daemon/tls_session_ticket-srv.c b/daemon/tls_session_ticket-srv.c index 2ac91f8f17d4cf60078d689f66151efa8017eafe..bc30707e49d04c8dee62f7ccbc478c356537f4e7 100644 --- a/daemon/tls_session_ticket-srv.c +++ b/daemon/tls_session_ticket-srv.c @@ -80,7 +80,7 @@ static tst_ctx_t * tst_key_create(const char *secret, size_t secret_len, uv_loop return NULL; #if !TLS_SESSION_RESUMPTION_SYNC if (secret_len) { - kr_log_error("[tls] session ticket: secrets were not enabled at compile-time (your GnuTLS version is not supported)\n"); + kr_log_error(LOG_GRP_TLS, "[tls] session ticket: secrets were not enabled at compile-time (your GnuTLS version is not supported)\n"); return NULL; /* ENOTSUP */ } #endif @@ -166,7 +166,7 @@ static void tst_key_check(uv_timer_t *timer, bool force_update) /* Compute the current epoch. */ struct timeval now; if (gettimeofday(&now, NULL)) { - kr_log_error("[tls] session ticket: gettimeofday failed, %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] session ticket: gettimeofday failed, %s\n", strerror(errno)); return; } @@ -177,7 +177,7 @@ static void tst_key_check(uv_timer_t *timer, bool force_update) * for gnutls_session_ticket_enable_server() doesn't say. */ int err = tst_key_update(stst, epoch, force_update); if (err) { - kr_log_error("[tls] session ticket: failed rotation, %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] session ticket: failed rotation, %s\n", kr_strerror(err)); if (kr_fails_assert(err != kr_error(EINVAL))) return; @@ -195,7 +195,7 @@ static void tst_key_check(uv_timer_t *timer, bool force_update) (uint64_t)epoch, remain_ms); err = uv_timer_start(timer, &tst_timer_callback, remain_ms, 0); if (kr_fails_assert(err == 0)) { - kr_log_error("[tls] session ticket: failed to schedule, %s\n", + kr_log_error(LOG_GRP_TLS, "[tls] session ticket: failed to schedule, %s\n", uv_strerror(err)); return; } @@ -213,7 +213,7 @@ void tls_session_ticket_enable(struct tls_session_ticket_ctx *ctx, gnutls_sessio }; int err = gnutls_session_ticket_enable_server(session, &gd); if (err) { - kr_log_error("[tls] failed to enable session tickets: %s (%d)\n", + kr_log_error(LOG_GRP_TLS, "[tls] failed to enable session tickets: %s (%d)\n", gnutls_strerror_name(err), err); /* but continue without tickets */ } diff --git a/daemon/udp_queue.c b/daemon/udp_queue.c index f899d7c20c30f9dfd82c2f69ac726cb87fe0fc50..d59877a51f1d568170fa2684e37f5520cecd5d1d 100644 --- a/daemon/udp_queue.c +++ b/daemon/udp_queue.c @@ -101,7 +101,7 @@ int udp_queue_init_global(uv_loop_t *loop) void udp_queue_push(int fd, struct kr_request *req, struct qr_task *task) { if (fd < 0) { - kr_log_error("ERROR: called udp_queue_push(fd = %d, ...)\n", fd); + kr_log_error(LOG_GRP_SYSTEM, "ERROR: called udp_queue_push(fd = %d, ...)\n", fd); abort(); } worker_task_ref(task); diff --git a/daemon/worker.c b/daemon/worker.c index b97a66c2645021bf395393d6ed5f702d63af25c2..370a5ee9b0c3b7f0d354754fececc09cc3d92ba4 100644 --- a/daemon/worker.c +++ b/daemon/worker.c @@ -1276,7 +1276,7 @@ static void xdp_tx_waker(uv_idle_t *handle) { int ret = knot_xdp_send_finish(handle->data); if (ret != KNOT_EAGAIN && ret != KNOT_EOK) - kr_log_error("[xdp] check: ret = %d, %s\n", ret, knot_strerror(ret)); + kr_log_error(LOG_GRP_XDP, "[xdp] check: ret = %d, %s\n", ret, knot_strerror(ret)); /* Apparently some drivers need many explicit wake-up calls * even if we push no additional packets (in case they accumulated a lot) */ if (ret != KNOT_EAGAIN) diff --git a/daemon/zimport.c b/daemon/zimport.c index c0ece8b3e4cb1c8106e7d2f931ec235af2f0cd54..51181c057f3bb6f9f4e34b7191b7ec0cd9f9d93b 100644 --- a/daemon/zimport.c +++ b/daemon/zimport.c @@ -465,14 +465,14 @@ static void zi_zone_process(uv_timer_t* handle) KR_DNAME_GET_STR(zone_name_str, z_import->origin); if (strcmp(".", zone_name_str) != 0) { - kr_log_error("[zimport] unexpected zone name `%s` (root zone expected), fail\n", + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] unexpected zone name `%s` (root zone expected), fail\n", zone_name_str); failed = 1; goto finish; } if (z_import->rrset_sorted.len <= 0) { - kr_log_error("[zimport] zone `%s` is empty\n", zone_name_str); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] zone `%s` is empty\n", zone_name_str); goto finish; } @@ -490,7 +490,7 @@ static void zi_zone_process(uv_timer_t* handle) knot_rrset_t *rr_key = map_get(&z_import->rrset_indexed, key); if (!rr_key) { /* DNSKEY MUST be here. If not found - fail. */ - kr_log_error("[zimport] DNSKEY not found for `%s`, fail\n", zone_name_str); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] DNSKEY not found for `%s`, fail\n", zone_name_str); failed = 1; goto finish; } @@ -499,7 +499,7 @@ static void zi_zone_process(uv_timer_t* handle) map_t *trust_anchors = &z_import->worker->engine->resolver.trust_anchors; knot_rrset_t *rr_ta = kr_ta_get(trust_anchors, z_import->origin); if (!rr_ta) { - kr_log_error("[zimport] error: TA for zone `%s` vanished, fail", zone_name_str); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] error: TA for zone `%s` vanished, fail", zone_name_str); failed = 1; goto finish; } @@ -519,7 +519,7 @@ static void zi_zone_process(uv_timer_t* handle) int res = zi_rrset_import(z_import, rr_key); if (res != 0) { - kr_log_error("[zimport] import failed: qname: '%s' type: '%s'\n", + kr_log_error(LOG_GRP_ZIMPORT, "import failed: qname: '%s' type: '%s'\n", kname_str, ktype_str); failed = 1; goto finish; @@ -596,7 +596,7 @@ static void zi_zone_process(uv_timer_t* handle) if (failed != 0) { if (ns_imported == 0 && other_imported == 0) { import_state = -1; - kr_log_error("[zimport] import failed; zone `%s` \n", zone_name_str); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] import failed; zone `%s` \n", zone_name_str); } else { import_state = 1; } @@ -615,13 +615,13 @@ static int zi_record_store(zs_scanner_t *s) { if (s->r_data_length > UINT16_MAX) { /* Due to knot_rrset_add_rdata(..., const uint16_t size, ...); */ - kr_log_error("[zscanner] line %"PRIu64": rdata is too long\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64": rdata is too long\n", s->line_counter); return -1; } if (knot_dname_size(s->r_owner) != strlen((const char *)(s->r_owner)) + 1) { - kr_log_error("[zscanner] line %"PRIu64 + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64 ": owner name contains zero byte, skip\n", s->line_counter); return 0; @@ -632,14 +632,14 @@ static int zi_record_store(zs_scanner_t *s) knot_rrset_t *new_rr = knot_rrset_new(s->r_owner, s->r_type, s->r_class, s->r_ttl, &z_import->pool); if (!new_rr) { - kr_log_error("[zscanner] line %"PRIu64": error creating rrset\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64": error creating rrset\n", s->line_counter); return -1; } int res = knot_rrset_add_rdata(new_rr, s->r_data, s->r_data_length, &z_import->pool); if (res != KNOT_EOK) { - kr_log_error("[zscanner] line %"PRIu64": error adding rdata to rrset\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64": error adding rdata to rrset\n", s->line_counter); return -1; } @@ -653,7 +653,7 @@ static int zi_record_store(zs_scanner_t *s) res = kr_rrkey(key, new_rr->rclass, new_rr->owner, new_rr->type, additional_key_field); if (res <= 0) { - kr_log_error("[zscanner] line %"PRIu64": error constructing rrkey\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64": error constructing rrkey\n", s->line_counter); return -1; } @@ -666,7 +666,7 @@ static int zi_record_store(zs_scanner_t *s) res = map_set(&z_import->rrset_indexed, key, new_rr); } if (res != 0) { - kr_log_error("[zscanner] line %"PRIu64": error saving parsed rrset\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line %"PRIu64": error saving parsed rrset\n", s->line_counter); return -1; } @@ -692,29 +692,29 @@ static int zi_state_parsing(zs_scanner_t *s) } break; case ZS_STATE_ERROR: - kr_log_error("[zscanner] line: %"PRIu64 + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line: %"PRIu64 ": parse error; code: %i ('%s')\n", s->line_counter, s->error.code, zs_strerror(s->error.code)); return -1; case ZS_STATE_INCLUDE: - kr_log_error("[zscanner] line: %"PRIu64 + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] line: %"PRIu64 ": INCLUDE is not supported\n", s->line_counter); return -1; case ZS_STATE_EOF: case ZS_STATE_STOP: if (empty) { - kr_log_error("[zimport] empty zone file\n"); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] empty zone file\n"); return -1; } if (!((zone_import_ctx_t *) s->process.data)->origin) { - kr_log_error("[zimport] zone file doesn't contain SOA record\n"); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] zone file doesn't contain SOA record\n"); return -1; } return (s->error.counter == 0) ? 0 : -1; default: - kr_log_error("[zscanner] line: %"PRIu64 + kr_log_error(LOG_GRP_ZSCANNER, "[zimport] line: %"PRIu64 ": unexpected parse state: %i\n", s->line_counter, s->state); return -1; @@ -733,7 +733,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, zs_scanner_t *s = malloc(sizeof(zs_scanner_t)); if (s == NULL) { - kr_log_error("[zscanner] error creating instance of zone scanner (malloc() fails)\n"); + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] error creating instance of zone scanner (malloc() fails)\n"); return -1; } @@ -741,7 +741,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, * so don't print error code as it meaningless. */ int res = zs_init(s, origin, rclass, ttl); if (res != 0) { - kr_log_error("[zscanner] error initializing zone scanner instance, error: %i (%s)\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] error initializing zone scanner instance, error: %i (%s)\n", s->error.code, zs_strerror(s->error.code)); free(s); return -1; @@ -749,7 +749,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, res = zs_set_input_file(s, zone_file); if (res != 0) { - kr_log_error("[zscanner] error opening zone file `%s`, error: %i (%s)\n", + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] error opening zone file `%s`, error: %i (%s)\n", zone_file, s->error.code, zs_strerror(s->error.code)); zs_deinit(s); free(s); @@ -760,7 +760,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, * Parsing as well error processing will be performed in zi_state_parsing(). * Store pointer to zone import context for further use. */ if (zs_set_processing(s, NULL, NULL, (void *)z_import) != 0) { - kr_log_error("[zscanner] zs_set_processing() failed for zone file `%s`, " + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] zs_set_processing() failed for zone file `%s`, " "error: %i (%s)\n", zone_file, s->error.code, zs_strerror(s->error.code)); zs_deinit(s); @@ -784,7 +784,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, /* For now - fail. * TODO - query DS and continue after answer had been obtained. */ KR_DNAME_GET_STR(zone_name_str, z_import->origin); - kr_log_error("[zimport] no TA found for `%s`, fail\n", zone_name_str); + kr_log_error(LOG_GRP_ZIMPORT, "[zimport] no TA found for `%s`, fail\n", zone_name_str); ret = 1; } elapsed = kr_now() - z_import->start_timestamp; @@ -795,7 +795,7 @@ int zi_zone_import(struct zone_import_ctx *z_import, free(s); if (ret != 0) { - kr_log_error("[zscanner] error parsing zone file `%s`\n", zone_file); + kr_log_error(LOG_GRP_ZSCANNER, "[zscanner] error parsing zone file `%s`\n", zone_file); z_import->started = false; return ret; } diff --git a/lib/cache/api.c b/lib/cache/api.c index c1acce2c9c8709a9bc99abe995b88012ac0600e7..ad7606f894f5e802e86400049f37a5c150ccce62 100644 --- a/lib/cache/api.c +++ b/lib/cache/api.c @@ -81,7 +81,7 @@ static int assert_right_version(struct kr_cache *cache) * Recreate cache and write version key. */ ret = cache_op(cache, count); if (ret != 0) { /* Log for non-empty cache to limit noise on fresh start. */ - kr_log_info("[cache] incompatible cache database detected, purging\n"); + kr_log_info(LOG_GRP_CACHE, "[cache] incompatible cache database detected, purging\n"); if (oldret) { kr_log_verbose("[cache] reading version returned: %d\n", oldret); } else if (val.len != sizeof(CACHE_VERSION)) { @@ -142,7 +142,7 @@ int kr_cache_open(struct kr_cache *cache, const struct kr_cdb_api *api, struct k if (ret == 0 && opts->maxsize) { size_t maxsize = cache->api->get_maxsize(cache->db); - if (maxsize > opts->maxsize) kr_log_info( + if (maxsize > opts->maxsize) kr_log_warning(LOG_GRP_CACHE, "[cache] Warning: real cache size is %zu instead of the requested %zu bytes." " To reduce the size you need to remove the file '%s' by hand.\n", maxsize, opts->maxsize, fpath); @@ -690,7 +690,7 @@ static int stash_rrarray_entry(ranked_rr_array_t *arr, int arr_i, ssize_t written = stash_rrset(cache, qry, rr, rr_sigs, qry->timestamp.tv_sec, entry->rank, nsec_pmap, needs_pkt); if (written < 0) { - kr_log_error("[%05u.%02u][cach] stash failed, ret = %d\n", qry->request->uid, + kr_log_error(LOG_GRP_CACHE, "[%05u.%02u][cach] stash failed, ret = %d\n", qry->request->uid, qry->uid, ret); return (int) written; } diff --git a/lib/cache/cdb_lmdb.c b/lib/cache/cdb_lmdb.c index 427ec45650691fa2c3ed48c6cc4e68b96e616013..b9a4f62a862f696418c070e60c097dcf3ae10d7a 100644 --- a/lib/cache/cdb_lmdb.c +++ b/lib/cache/cdb_lmdb.c @@ -87,7 +87,7 @@ static int lmdb_error(int error) case MDB_TXN_FULL: return kr_error(ENOSPC); default: - kr_log_error("[cache] LMDB error: %s\n", mdb_strerror(error)); + kr_log_error(LOG_GRP_CACHE, "[cache] LMDB error: %s\n", mdb_strerror(error)); return kr_error(error); } } @@ -116,7 +116,7 @@ static int refresh_mapsize(struct lmdb_env *env) env->mapsize = info.me_mapsize; if (env->mapsize != env->st_size) { - kr_log_info("[cache] suspicious size of cache file '%s'" + kr_log_info(LOG_GRP_CACHE, "[cache] suspicious size of cache file '%s'" ": file size %zu != LMDB map size %zu\n", env->mdb_data_path, (size_t)env->st_size, env->mapsize); } @@ -128,10 +128,10 @@ static void clear_stale_readers(struct lmdb_env *env) int cleared; int ret = mdb_reader_check(env->env, &cleared); if (ret != MDB_SUCCESS) { - kr_log_error("[cache] failed to clear stale reader locks: " + kr_log_error(LOG_GRP_CACHE, "[cache] failed to clear stale reader locks: " "LMDB error %d %s\n", ret, mdb_strerror(ret)); } else if (cleared != 0) { - kr_log_info("[cache] cleared %d stale reader locks\n", cleared); + kr_log_info(LOG_GRP_CACHE, "[cache] cleared %d stale reader locks\n", cleared); } } @@ -160,7 +160,7 @@ static int txn_get_noresize(struct lmdb_env *env, unsigned int flag, MDB_txn **t } if (unlikely(ret == MDB_MAP_RESIZED)) { - kr_log_info("[cache] detected size increased by another process\n"); + kr_log_info(LOG_GRP_CACHE, "[cache] detected size increased by another process\n"); ret = refresh_mapsize(env); if (ret == 0) goto retry; @@ -384,7 +384,7 @@ static int cdb_open_env(struct lmdb_env *env, const char *path, const size_t map if (ret == EINVAL) { /* POSIX says this can happen when the feature isn't supported by the FS. * We haven't seen this happen on Linux+glibc but it was reported on FreeBSD.*/ - kr_log_info("[cache] space pre-allocation failed and ignored; " + kr_log_info(LOG_GRP_CACHE, "[cache] space pre-allocation failed and ignored; " "your (file)system probably doesn't support it.\n"); } else if (ret != 0) { mdb_txn_abort(txn); @@ -495,7 +495,7 @@ static int cdb_check_health(kr_cdb_pt db, struct kr_cdb_stats *stats) * contrary to methods based on mdb_env_info(). */ if (st.st_size == env->st_size) return kr_ok(); - kr_log_info("[cache] detected size change (by another instance?) of file '%s'" + kr_log_info(LOG_GRP_CACHE, "[cache] detected size change (by another instance?) of file '%s'" ": file size %zu -> file size %zu\n", env->mdb_data_path, (size_t)env->st_size, (size_t)st.st_size); env->st_size = st.st_size; // avoid retrying in cycle even if we fail @@ -558,7 +558,7 @@ static int cdb_clear(kr_cdb_pt db, struct kr_cdb_stats *stats) return ret; } } - kr_log_info("[cache] clearing error, falling back\n"); + kr_log_info(LOG_GRP_CACHE, "[cache] clearing error, falling back\n"); } /* Fallback: we'll remove the database files and reopen. * Other instances can continue to use the removed lmdb, @@ -582,7 +582,7 @@ static int cdb_clear(kr_cdb_pt db, struct kr_cdb_stats *stats) /* Find if we get a lock on lockfile. */ const int lockfile_fd = lockfile_get(lockfile); if (lockfile_fd < 0) { - kr_log_error("[cache] clearing failed to get ./krcachelock (%s); retry later\n", + kr_log_error(LOG_GRP_CACHE, "[cache] clearing failed to get ./krcachelock (%s); retry later\n", kr_strerror(lockfile_fd)); /* As we're out of space (almost certainly - mdb_drop didn't work), * we will retry on the next failing write operation. */ @@ -608,7 +608,7 @@ static int cdb_clear(kr_cdb_pt db, struct kr_cdb_stats *stats) /* Environment updated, release lockfile. */ int lrerr = lockfile_release(lockfile_fd); if (lrerr) { - kr_log_error("[cache] failed to release ./krcachelock: %s\n", + kr_log_error(LOG_GRP_CACHE, "[cache] failed to release ./krcachelock: %s\n", kr_strerror(lrerr)); } return ret; diff --git a/lib/cache/entry_list.c b/lib/cache/entry_list.c index 85432133e4cd9109b9014295ebde31cf20f00fd8..fb6c457c1e5c06d9246ca718d0b160f47b7eae6a 100644 --- a/lib/cache/entry_list.c +++ b/lib/cache/entry_list.c @@ -185,7 +185,7 @@ static int cache_write_or_clear(struct kr_cache *cache, const knot_db_val_t *key */ const uint64_t now = kr_now(); if (!ignoring_errors_until) { // First error after a success. - kr_log_info("[cache] LMDB refusing writes (ignored for 5-9s): %s\n", + kr_log_info(LOG_GRP_CACHE, "[cache] LMDB refusing writes (ignored for 5-9s): %s\n", kr_strerror(ret)); ignoring_errors_until = now + 5000 + kr_rand_bytes(2)/16; return kr_error(ret); @@ -198,11 +198,11 @@ static int cache_write_or_clear(struct kr_cache *cache, const knot_db_val_t *key ret = kr_cache_clear(cache); switch (ret) { default: - kr_log_error("CRITICAL: clearing cache failed: %s; fatal error, aborting\n", + kr_log_fatal(LOG_GRP_CACHE, "CRITICAL: clearing cache failed: %s; fatal error, aborting\n", kr_strerror(ret)); abort(); case 0: - kr_log_info("[cache] stuck cache cleared\n"); + kr_log_info(LOG_GRP_CACHE, "[cache] stuck cache cleared\n"); ignoring_errors_until = 0; case -EAGAIN: // fall-through; krcachelock race -> retry later return kr_error(ENOSPC); diff --git a/lib/cache/entry_rr.c b/lib/cache/entry_rr.c index ac82db322e359f4b3f16cc970fa87347fe2a63d8..0699726406a6d2b393c6c19b0176ab55fd78d326 100644 --- a/lib/cache/entry_rr.c +++ b/lib/cache/entry_rr.c @@ -98,7 +98,7 @@ int entry2answer(struct answer *ans, int id, /* Sanity check: we consumed exactly all data. */ int unused_bytes = eh_bound - (uint8_t *)eh->data - data_off - ret; if (kr_fails_assert(unused_bytes == 0)) { - kr_log_error("[cach] entry2answer ERROR: unused bytes: %d\n", + kr_log_error(LOG_GRP_CACHE, "[cach] entry2answer ERROR: unused bytes: %d\n", unused_bytes); ret = kr_error(EILSEQ); goto fail; /* to be on the safe side */ diff --git a/lib/dnssec/ta.c b/lib/dnssec/ta.c index 9d8ffee72c977568a2af0e53ae149a12e068d0a1..bfcfc8e0eebb574fa5abb452ddeb61149ea8e0d9 100644 --- a/lib/dnssec/ta.c +++ b/lib/dnssec/ta.c @@ -58,14 +58,14 @@ static int dnskey2ds(dnssec_binary_t *dst, const knot_dname_t *owner, const uint const bool flags_ok = kr_dnssec_key_zsk(rdata) && !kr_dnssec_key_revoked(rdata); if (!flags_ok) { auto_free char *owner_str = kr_dname_text(owner); - kr_log_error("[ ta ] refusing to trust %s DNSKEY because of flags %d\n", + kr_log_error(LOG_GRP_TA, "[ ta ] refusing to trust %s DNSKEY because of flags %d\n", owner_str, dnssec_key_get_flags(key)); ret = kr_error(EILSEQ); goto cleanup; } else if (!kr_dnssec_key_ksk(rdata)) { auto_free char *owner_str = kr_dname_text(owner); int flags = dnssec_key_get_flags(key); - kr_log_info("[ ta ] warning: %s DNSKEY is missing the SEP bit; " + kr_log_warning(LOG_GRP_TA, "[ ta ] warning: %s DNSKEY is missing the SEP bit; " "flags %d instead of %d\n", owner_str, flags, flags + 1/*a little ugly*/); } diff --git a/lib/log.c b/lib/log.c index 90228f2a97d43df4259eb79acb67d01c1455682b..29d903b31290c46e15bf9fbf1445902bb24d0f52 100644 --- a/lib/log.c +++ b/lib/log.c @@ -18,6 +18,8 @@ int use_journal = 0; log_level_t kr_log_level = LOG_CRIT; log_target_t kr_log_target = LOG_TARGET_STDOUT; +log_groups_t kr_log_groups = 0; + #ifndef SYSLOG_NAMES syslog_code_t prioritynames[] = { { "alert", LOG_ALERT }, @@ -32,11 +34,19 @@ syslog_code_t prioritynames[] = { }; #endif -void kr_log_fmt(log_level_t level, const char *fmt, ...) +int group_is_set(log_groups_t group) +{ + return kr_log_groups & (group); +} + +void kr_log_fmt(log_groups_t group, log_level_t level, const char *fmt, ...) { va_list args; if (kr_log_target == LOG_TARGET_SYSLOG) { + if (group_is_set(group)) + setlogmask(LOG_UPTO(LOG_DEBUG)); + va_start(args, fmt); #if ENABLE_LIBSYSTEMD if (use_journal) { @@ -56,8 +66,11 @@ void kr_log_fmt(log_level_t level, const char *fmt, ...) vsyslog(level, fmt, args); #endif va_end(args); + + if (group_is_set(group)) + setlogmask(LOG_UPTO(kr_log_level)); } else { - if (!KR_LOG_LEVEL_IS(level)) + if (!(KR_LOG_LEVEL_IS(level) || group_is_set(group))) return; FILE *stream; @@ -75,7 +88,7 @@ void kr_log_fmt(log_level_t level, const char *fmt, ...) static void kres_gnutls_log(int level, const char *message) { - kr_log_debug("[gnutls] (%d) %s", level, message); + kr_log_debug(LOG_GRP_GNUTLS, "[gnutls] (%d) %s", level, message); } char *kr_log_level2name(log_level_t level) @@ -125,9 +138,20 @@ log_level_t kr_log_level_get(void) return kr_log_level; } +void kr_log_add_group(log_groups_t mask) +{ + kr_log_groups |= mask; +} + +void kr_log_del_group(log_groups_t mask) +{ + kr_log_groups &= (~mask); +} + void kr_log_init(log_level_t level, log_target_t target) { kr_log_target = target; + kr_log_groups = 0; #if ENABLE_LIBSYSTEMD use_journal = sd_booted(); diff --git a/lib/log.h b/lib/log.h index 3395e83f37109792588374d4f7cf76467df18f76..4f624b580a3016c2c85b3e6255166d3500d9ae82 100644 --- a/lib/log.h +++ b/lib/log.h @@ -11,43 +11,76 @@ #define LOG_DEFAULT_LEVEL LOG_WARNING -typedef int log_level_t; +/* Targets */ +typedef int log_level_t; typedef enum { LOG_TARGET_SYSLOG = 0, LOG_TARGET_STDERR = 1, LOG_TARGET_STDOUT = 2, } log_target_t; +/* Groups */ + +typedef uint32_t log_groups_t; + +/* Don't forget add name to log_group_names[] (log.c) */ +#define LOG_GRP_SYSTEM (1 << 1) +#define LOG_GRP_CACHE (1 << 2) +#define LOG_GRP_IO (1 << 3) +#define LOG_GRP_NETWORK (1 << 4) +#define LOG_GRP_TA (1 << 5) +#define LOG_GRP_TLS (1 << 6) +#define LOG_GRP_GNUTLS (1 << 7) +#define LOG_GRP_TLSCLIENT (1 << 8) +#define LOG_GRP_XDP (1 << 9) +#define LOG_GRP_ZIMPORT (1 << 10) +#define LOG_GRP_ZSCANNER (1 << 11) +#define LOG_GRP_DOH (1 << 12) +#define LOG_GRP_DNSSEC (1 << 13) +#define LOG_GRP_HINT (1 << 14) + +KR_EXPORT +extern log_groups_t kr_log_groups; +KR_EXPORT +void kr_log_add_group(log_groups_t mask); +KR_EXPORT +void kr_log_del_group(log_groups_t mask); + +/* Log */ + KR_EXPORT extern log_level_t kr_log_level; KR_EXPORT extern log_target_t kr_log_target; -KR_EXPORT KR_PRINTF(2) -void kr_log_fmt(log_level_t level, const char *fmt, ...); +KR_EXPORT KR_PRINTF(3) +void kr_log_fmt(log_groups_t group, log_level_t level, const char *fmt, ...); KR_EXPORT int kr_log_level_set(log_level_t level); KR_EXPORT log_level_t kr_log_level_get(void); KR_EXPORT void kr_log_init(log_level_t level, log_target_t target); -KR_EXPORT -char *kr_log_level2name(log_level_t level); -KR_EXPORT -log_level_t kr_log_name2level(const char *name); -#define kr_log_debug(fmt, ...) kr_log_fmt(LOG_DEBUG, fmt, ## __VA_ARGS__) -#define kr_log_info(fmt, ...) kr_log_fmt(LOG_INFO, fmt, ## __VA_ARGS__) -#define kr_log_notice(fmt, ...) kr_log_fmt(LOG_NOTICE, fmt, ## __VA_ARGS__) -#define kr_log_warning(fmt, ...) kr_log_fmt(LOG_WARNING, fmt, ## __VA_ARGS__) -#define kr_log_error(fmt, ...) kr_log_fmt(LOG_ERR, fmt, ## __VA_ARGS__) -#define kr_log_fatal(fmt, ...) kr_log_fmt(LOG_CRIT, fmt, ## __VA_ARGS__) +#define kr_log_debug(grp, fmt, ...) kr_log_fmt(grp, LOG_DEBUG, fmt, ## __VA_ARGS__) +#define kr_log_info(grp, fmt, ...) kr_log_fmt(grp, LOG_INFO, fmt, ## __VA_ARGS__) +#define kr_log_notice(grp, fmt, ...) kr_log_fmt(grp, LOG_NOTICE, fmt, ## __VA_ARGS__) +#define kr_log_warning(grp, fmt, ...) kr_log_fmt(grp, LOG_WARNING, fmt, ## __VA_ARGS__) +#define kr_log_error(grp, fmt, ...) kr_log_fmt(grp, LOG_ERR, fmt, ## __VA_ARGS__) +#define kr_log_fatal(grp, fmt, ...) kr_log_fmt(grp, LOG_CRIT, fmt, ## __VA_ARGS__) -#define kr_log_deprecate(fmt, ...) kr_log_fmt(LOG_WARNING, "deprecation WARNING: " fmt, ## __VA_ARGS__) +#define kr_log_deprecate(grp, fmt, ...) kr_log_fmt(grp, LOG_WARNING, "deprecation WARNING: " fmt, ## __VA_ARGS__) #define KR_LOG_LEVEL_IS(exp) ((kr_log_level >= (exp)) ? true : false) +/* Syslog */ + +KR_EXPORT +char *kr_log_level2name(log_level_t level); +KR_EXPORT +log_level_t kr_log_name2level(const char *name); + #ifndef SYSLOG_NAMES typedef struct _code { char *c_name; diff --git a/lib/module.c b/lib/module.c index 98d2799bccf30598fbcbedc43663bd019f2f0247..e351d9f5e63e1000d04e5212449722b91d960105 100644 --- a/lib/module.c +++ b/lib/module.c @@ -87,7 +87,7 @@ static int load_sym_c(struct kr_module *module, uint32_t api_required) || load_symbol(module->lib, m_prefix, "props")) { /* In case someone re-compiled against new kresd * but haven't actually changed the symbols. */ - kr_log_error("[system] module %s requires upgrade. Please refer to " + kr_log_error(LOG_GRP_SYSTEM, "[system] module %s requires upgrade. Please refer to " "https://knot-resolver.readthedocs.io/en/stable/upgrading.html", module->name); return kr_error(ENOTSUP); diff --git a/lib/utils.c b/lib/utils.c index be6f21cadbb9123ceb3ad84b7b0e9a36ecd18b3b..db5988bdb3c6230edfb1077b0f38e64c25649d85 100644 --- a/lib/utils.c +++ b/lib/utils.c @@ -39,9 +39,9 @@ void kr_fail(bool is_fatal, const char *expr, const char *func, const char *file { const int errno_orig = errno; if (is_fatal) - kr_log_critical("requirement \"%s\" failed in %s@%s:%d\n", expr, func, file, line); + kr_log_fatal(LOG_GRP_SYSTEM, "requirement \"%s\" failed in %s@%s:%d\n", expr, func, file, line); else - kr_log_error("assertion \"%s\" failed in %s@%s:%d\n", expr, func, file, line); + kr_log_error(LOG_GRP_SYSTEM, "assertion \"%s\" failed in %s@%s:%d\n", expr, func, file, line); if (is_fatal || (kr_dbg_assertion_abort && !kr_dbg_assertion_fork)) abort(); @@ -1157,7 +1157,7 @@ static void rnd_noerror(void *data, uint size) { int ret = gnutls_rnd(GNUTLS_RND_NONCE, data, size); if (ret) { - kr_log_error("gnutls_rnd(): %s\n", gnutls_strerror(ret)); + kr_log_error(LOG_GRP_TLS, "gnutls_rnd(): %s\n", gnutls_strerror(ret)); abort(); } } diff --git a/lib/utils.h b/lib/utils.h index f28b65e17abaa72aec4352182314e743bc3f74d6..4e9c7699d17516276ab4b36f031cc1abdd592200 100644 --- a/lib/utils.h +++ b/lib/utils.h @@ -230,7 +230,7 @@ static inline uint64_t kr_rand_bytes(unsigned int size) { uint64_t result; if (size <= 0 || size > sizeof(result)) { - kr_log_error("kr_rand_bytes(): EINVAL\n"); + kr_log_error(LOG_GRP_SYSTEM, "kr_rand_bytes(): EINVAL\n"); abort(); } uint8_t data[sizeof(result)]; diff --git a/modules/bogus_log/bogus_log.c b/modules/bogus_log/bogus_log.c index 6237c14575b27ad6c6bdcf59e7c0efb4a448f784..3a4e6fc68e5c9fdc074ca9554dcabec7038a99b8 100644 --- a/modules/bogus_log/bogus_log.c +++ b/modules/bogus_log/bogus_log.c @@ -38,7 +38,7 @@ static int consume(kr_layer_t *ctx, knot_pkt_t *pkt) auto_free char *qname_text = kr_dname_text(knot_pkt_qname(pkt)); auto_free char *qtype_text = kr_rrtype_text(knot_pkt_qtype(pkt)); - kr_log_error("DNSSEC validation failure %s %s\n", qname_text, qtype_text); + kr_log_error(LOG_GRP_DNSSEC, "DNSSEC validation failure %s %s\n", qname_text, qtype_text); /* log of most frequent bogus queries */ uint16_t type = knot_pkt_qtype(pkt); diff --git a/modules/hints/hints.c b/modules/hints/hints.c index 10890e1893d9c3c621edbf9231d585a4ce633596..740999000dd8a07175b3737b1b22aae4c4d7d0e3 100644 --- a/modules/hints/hints.c +++ b/modules/hints/hints.c @@ -26,7 +26,7 @@ /* Defaults */ #define VERBOSE_MSG(qry, ...) QRVERBOSE(qry, "hint", __VA_ARGS__) -#define ERR_MSG(...) kr_log_error("[ ][hint] " __VA_ARGS__) +#define ERR_MSG(...) kr_log_error(LOG_GRP_HINT, "[ ][hint]" __VA_ARGS__) struct hints_data { struct kr_zonecut hints;