diff --git a/daemon/defer.c b/daemon/defer.c index 5c89cbb4b..11a5dbfd4 100644 --- a/daemon/defer.c +++ b/daemon/defer.c @@ -3,6 +3,7 @@ */ #include +#include #include "daemon/defer.h" #include "daemon/session2.h" #include "daemon/udp_queue.h" @@ -54,8 +55,10 @@ struct defer { size_t capacity; kru_price_t max_decay; + uint32_t log_period; int cpus; bool using_avx2; + _Atomic uint32_t log_time; _Alignas(64) uint8_t kru[]; }; struct defer *defer = NULL; @@ -415,8 +418,21 @@ static inline void process_single_deferred(void) if (age_ns >= REQ_TIMEOUT) { VERBOSE_LOG(" BREAK (timeout)\n"); - kr_log_warning(DEFER, "Data from %s too long in queue, dropping.\n", - kr_straddr(ctx->comm->src_addr)); // TODO make it notice as it's intended behavior of defer? + + // notice logging according to log-period + const uint32_t time_now = kr_now(); + uint32_t log_time_orig = atomic_load_explicit(&defer->log_time, memory_order_relaxed); + if (defer->log_period) { + while (time_now - log_time_orig + 1024 >= defer->log_period + 1024) { + if (atomic_compare_exchange_weak_explicit(&defer->log_time, &log_time_orig, time_now, + memory_order_relaxed, memory_order_relaxed)) { + kr_log_notice(DEFER, "Data from %s too long in queue, dropping.\n", + kr_straddr(ctx->comm->src_addr)); + break; + } + } + } + break_query(ctx, ETIME); return; } @@ -603,7 +619,7 @@ static void defer_queues_idle(uv_idle_t *handle) /// Initialize shared memory, queues. To be called from Lua. -int defer_init(const char *mmap_file, int cpus) +int defer_init(const char *mmap_file, uint32_t log_period, int cpus) { defer_initialized = true; if (mmap_file == NULL) { @@ -620,6 +636,7 @@ int defer_init(const char *mmap_file, int cpus) struct defer header = { .capacity = KRU_CAPACITY, .max_decay = MAX_DECAY, + .log_period = log_period, .cpus = cpus, .using_avx2 = using_avx2(), }; @@ -633,6 +650,7 @@ int defer_init(const char *mmap_file, int cpus) offsetof(struct defer, using_avx2) == sizeof(header.capacity) + sizeof(header.max_decay) + + sizeof(header.log_period) + sizeof(header.cpus), "detected padding with undefined data inside mmapped header"); @@ -649,6 +667,8 @@ int defer_init(const char *mmap_file, int cpus) goto fail; } + defer->log_time = kr_now() - log_period; + ret = mmapped_init_continue(&defer_mmapped); if (ret != 0) goto fail; diff --git a/daemon/defer.h b/daemon/defer.h index b24ee70ec..06c9d56da 100644 --- a/daemon/defer.h +++ b/daemon/defer.h @@ -9,7 +9,7 @@ /// Initialize defer, incl. shared memory with KRU, excl. idle. KR_EXPORT -int defer_init(const char *mmap_file, int cpus); +int defer_init(const char *mmap_file, uint32_t log_period, int cpus); /// Initialize idle. int defer_init_idle(uv_loop_t *loop); diff --git a/daemon/lua/kres-gen-33.lua b/daemon/lua/kres-gen-33.lua index 4312d2184..3fc16df3c 100644 --- a/daemon/lua/kres-gen-33.lua +++ b/daemon/lua/kres-gen-33.lua @@ -617,7 +617,7 @@ struct qr_task *worker_resolve_start(knot_pkt_t *, struct kr_qflags); int zi_zone_import(const zi_config_t); _Bool ratelimiting_request_begin(struct kr_request *); int ratelimiting_init(const char *, size_t, uint32_t, uint32_t, uint16_t, uint32_t, _Bool); -int defer_init(const char *, int); +int defer_init(const char *, uint32_t, int); struct engine { char _stub[]; }; diff --git a/daemon/main.c b/daemon/main.c index 1600f59a2..a7b9c92b6 100644 --- a/daemon/main.c +++ b/daemon/main.c @@ -618,7 +618,7 @@ int main(int argc, char **argv) if (!defer_initialized) { kr_log_warning(SYSTEM, "Prioritization not initialized from Lua, using hardcoded default.\n"); - ret = defer_init("defer", 1); + ret = defer_init("defer", 1, 1); if (ret) { ret = EXIT_FAILURE; goto cleanup; diff --git a/doc/_static/config.schema.json b/doc/_static/config.schema.json index 2532dc4fe..0d91be050 100644 --- a/doc/_static/config.schema.json +++ b/doc/_static/config.schema.json @@ -1721,10 +1721,17 @@ "type": "boolean", "description": "Use request prioritization.", "default": true + }, + "log-period": { + "type": "string", + "pattern": "^(\\d+)(us|ms|s|m|h|d)$", + "description": "Minimal time between two log messages, or '0s' to disable.", + "default": "0s" } }, "default": { - "enabled": true + "enabled": true, + "log_period": "0s" } }, "lua": { diff --git a/python/knot_resolver/datamodel/defer_schema.py b/python/knot_resolver/datamodel/defer_schema.py index 40de04013..2e1992f84 100644 --- a/python/knot_resolver/datamodel/defer_schema.py +++ b/python/knot_resolver/datamodel/defer_schema.py @@ -1,4 +1,5 @@ from knot_resolver.utils.modeling import ConfigSchema +from knot_resolver.datamodel.types import TimeUnit class DeferSchema(ConfigSchema): @@ -7,6 +8,8 @@ class DeferSchema(ConfigSchema): --- enabled: Use request prioritization. + log_period: Minimal time between two log messages, or '0s' to disable. """ enabled: bool = True + log_period: TimeUnit = TimeUnit("0s") diff --git a/python/knot_resolver/datamodel/templates/defer.lua.j2 b/python/knot_resolver/datamodel/templates/defer.lua.j2 index 8cad0cfc1..131b71c47 100644 --- a/python/knot_resolver/datamodel/templates/defer.lua.j2 +++ b/python/knot_resolver/datamodel/templates/defer.lua.j2 @@ -3,7 +3,8 @@ {% if cfg.defer.enabled and not disable_defer -%} assert(C.defer_init( '{{ cfg.rundir }}/defer', + {{ cfg.defer.log_period.millis() }}, {{ cfg.workers }}) == 0) {% else %} -assert(C.defer_init(nil, 0) == 0) +assert(C.defer_init(nil, 0, 0) == 0) {%- endif %}