From: Vítězslav Kříž Date: Thu, 30 Nov 2017 16:35:27 +0000 (+0100) Subject: use monotonic time X-Git-Tag: v1.5.1~3^2~1 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=0abbe1f46e9d88536424358a40b98ee81cf0c198;p=thirdparty%2Fknot-resolver.git use monotonic time Monotonic time from libuv function uv_now (wrapped in kr_now) is used for query timeout, stats and RTT in reputation cache. Cache, DNSSEC Validation and Cookies use real time. --- diff --git a/daemon/lua/kres-gen.lua b/daemon/lua/kres-gen.lua index 4dc309d5b..20277e10d 100644 --- a/daemon/lua/kres-gen.lua +++ b/daemon/lua/kres-gen.lua @@ -187,7 +187,8 @@ struct kr_query { uint32_t secret; uint16_t fails; uint16_t reorder; - struct timeval creation_time; + uint64_t creation_time_mono; + uint64_t timestamp_mono; struct timeval timestamp; struct kr_zonecut zone_cut; struct kr_nsrep ns; diff --git a/lib/cache.c b/lib/cache.c index 3ba98f2f2..6a9cb43ca 100644 --- a/lib/cache.c +++ b/lib/cache.c @@ -50,6 +50,13 @@ static inline int cache_purge(struct kr_cache *cache) return cache_op(cache, clear); } +/** @internal Set time when clearing cache. */ +static void reset_time(struct kr_cache *cache) +{ + cache->last_clear_monotime = kr_now(); + gettimeofday(&cache->last_clear_timestamp, NULL); +} + /** @internal Open cache db transaction and check internal data version. */ static int assert_right_version(struct kr_cache *cache) { diff --git a/lib/resolve.c b/lib/resolve.c index 3ecf5aa2c..eb2ad9ed8 100644 --- a/lib/resolve.c +++ b/lib/resolve.c @@ -15,6 +15,7 @@ */ #include +#include #include #include #include @@ -791,10 +792,9 @@ static void update_nslist_rtt(struct kr_context *ctx, struct kr_query *qry, cons } /* Calculate total resolution time from the time the query was generated. */ - struct timeval now; - gettimeofday(&now, NULL); - long elapsed = time_diff(&qry->timestamp, &now); - + uint64_t elapsed = kr_now() - qry->timestamp_mono; + elapsed = elapsed > UINT_MAX ? UINT_MAX : elapsed; + /* NSs in the preference list prior to the one who responded will be penalised * with the RETRY timer interval. This is because we know they didn't respond * for N retries, so their RTT must be at least N * RETRY. @@ -812,7 +812,7 @@ static void update_nslist_rtt(struct kr_context *ctx, struct kr_query *qry, cons WITH_VERBOSE { char addr_str[INET6_ADDRSTRLEN]; inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str)); - VERBOSE_MSG(qry, "<= server: '%s' rtt: %ld ms\n", addr_str, elapsed); + VERBOSE_MSG(qry, "<= server: '%s' rtt: "PRIu64" ms\n", addr_str, elapsed); } } else { /* Response didn't come from this IP, but we know the RTT must be at least @@ -824,7 +824,7 @@ static void update_nslist_rtt(struct kr_context *ctx, struct kr_query *qry, cons WITH_VERBOSE { char addr_str[INET6_ADDRSTRLEN]; inet_ntop(addr->sa_family, kr_inaddr(addr), addr_str, sizeof(addr_str)); - VERBOSE_MSG(qry, "<= server: '%s' rtt: >=%ld ms\n", addr_str, elapsed); + VERBOSE_MSG(qry, "<= server: '%s' rtt: >="PRIu64" ms\n", addr_str, elapsed); } } /* Subtract query start time from elapsed time */ @@ -861,16 +861,16 @@ static void update_nslist_score(struct kr_request *request, struct kr_query *qry } } -bool check_resolution_time(struct kr_query *qry, struct timeval *now) +bool resolution_time_exceeded(struct kr_query *qry, uint64_t now) { - long resolving_time = time_diff(&qry->creation_time, now); + uint64_t resolving_time = now - qry->creation_time_mono; if (resolving_time > KR_RESOLVE_TIME_LIMIT) { WITH_VERBOSE { VERBOSE_MSG(qry, "query resolution time limit exceeded\n"); } - return false; + return true; } - return true; + return false; } int kr_resolve_consume(struct kr_request *request, const struct sockaddr *src, knot_pkt_t *packet) @@ -887,10 +887,8 @@ int kr_resolve_consume(struct kr_request *request, const struct sockaddr *src, k /* Different processing for network error */ struct kr_query *qry = array_tail(rplan->pending); - struct timeval now; - gettimeofday(&now, NULL); /* Check overall resolution time */ - if (!check_resolution_time(qry, &now)) { + if (resolution_time_exceeded(qry, kr_now())) { return KR_STATE_FAIL; } bool tried_tcp = (qry->flags.TCP); @@ -911,7 +909,7 @@ int kr_resolve_consume(struct kr_request *request, const struct sockaddr *src, k ITERATE_LAYERS(request, qry, consume, packet); } else { /* Fill in source and latency information. */ - request->upstream.rtt = time_diff(&qry->timestamp, &now); + request->upstream.rtt = kr_now() - qry->timestamp_mono; request->upstream.addr = src; ITERATE_LAYERS(request, qry, consume, packet); /* Clear temporary information */ @@ -1447,8 +1445,7 @@ ns_election: * Additional query is going to be finalised when calling * kr_resolve_checkout(). */ - - gettimeofday(&qry->timestamp, NULL); + qry->timestamp_mono = kr_now(); *dst = &qry->ns.addr[0].ip; *type = (qry->flags.TCP) ? SOCK_STREAM : SOCK_DGRAM; return request->state; diff --git a/lib/rplan.c b/lib/rplan.c index c4a327992..31940bb19 100644 --- a/lib/rplan.c +++ b/lib/rplan.c @@ -175,7 +175,8 @@ static struct kr_query *kr_rplan_push_query(struct kr_rplan *rplan, qry->ns.ctx = rplan->request->ctx; qry->ns.addr[0].ip.sa_family = AF_UNSPEC; gettimeofday(&qry->timestamp, NULL); - qry->creation_time = parent ? parent->creation_time : qry->timestamp; + qry->timestamp_mono = kr_now(); + qry->creation_time_mono = parent ? parent->creation_time_mono : qry->timestamp_mono; kr_zonecut_init(&qry->zone_cut, (const uint8_t *)"", rplan->pool); qry->reorder = qry->flags.REORDER_RR ? knot_wire_get_id(rplan->request->answer->wire) diff --git a/lib/rplan.h b/lib/rplan.h index f87d7f253..6b7487c5b 100644 --- a/lib/rplan.h +++ b/lib/rplan.h @@ -84,9 +84,11 @@ struct kr_query { uint32_t secret; uint16_t fails; uint16_t reorder; /**< Seed to reorder (cached) RRs in answer or zero. */ - struct timeval creation_time; /* The time of query's creation. - * Or time of creation of an oldest - * ancestor if it is a subquery. */ + uint64_t creation_time_mono; /* The time of query's creation. + * Or time of creation of an oldest + * ancestor if it is a subquery. */ + uint64_t timestamp_mono; /**< Time of query created or time of + query to upstream resolver */ struct timeval timestamp; struct kr_zonecut zone_cut; struct kr_nsrep ns; diff --git a/lib/utils.c b/lib/utils.c index a9061c104..bb4b50e1e 100644 --- a/lib/utils.c +++ b/lib/utils.c @@ -805,3 +805,8 @@ void kr_qry_print(const struct kr_query *qry, const char *prefix, const char *po kr_rrtype_print(qry->stype, " ", postfix); } +uint64_t kr_now() +{ + return uv_now(uv_default_loop()); +} + diff --git a/lib/utils.h b/lib/utils.h index 140cbde01..d68809892 100644 --- a/lib/utils.h +++ b/lib/utils.h @@ -300,3 +300,6 @@ static inline const char *lua_push_printf(lua_State *L, const char *fmt, ...) return ret; } +KR_EXPORT +uint64_t kr_now(); + diff --git a/modules/stats/stats.c b/modules/stats/stats.c index c5727cc08..f6173ad0f 100644 --- a/modules/stats/stats.c +++ b/modules/stats/stats.c @@ -197,9 +197,7 @@ static int collect(kr_layer_t *ctx) if (rplan->resolved.len > 0) { /* Histogram of answer latency. */ struct kr_query *first = rplan->resolved.at[0]; - struct timeval now; - gettimeofday(&now, NULL); - long elapsed = time_diff(&first->timestamp, &now); + uint64_t elapsed = kr_now() - first->timestamp_mono; if (elapsed <= 1) { stat_const_add(data, metric_answer_1ms, 1); } else if (elapsed <= 10) {