Commit 0abbe1f4 authored by Vitezslav Kriz's avatar Vitezslav Kriz Committed by Petr Špaček

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.
parent 03683b3d
......@@ -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;
......
......@@ -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)
{
......
......@@ -15,6 +15,7 @@
*/
#include <ctype.h>
#include <inttypes.h>
#include <stdio.h>
#include <fcntl.h>
#include <assert.h>
......@@ -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 @@ int kr_resolve_produce(struct kr_request *request, struct sockaddr **dst, int *t
* 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;
......
......@@ -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)
......
......@@ -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;
......
......@@ -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());
}
......@@ -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();
......@@ -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) {
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment