From ca55fb8840858b86d1b026f9c020e92e8350af78 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Mar 2021 17:15:55 +0100 Subject: [PATCH 1/5] resolved: don't mention confusing server switch on server-less protocols --- src/resolve/resolved-dns-transaction.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index 6eac7e9c57..f084a70e45 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -510,7 +510,7 @@ static void dns_transaction_retry(DnsTransaction *t, bool next_server) { /* Retries the transaction as it is, possibly on a different server */ - if (next_server) + if (next_server && t->scope->protocol == DNS_PROTOCOL_DNS) log_debug("Retrying transaction %" PRIu16 ", after switching servers.", t->id); else log_debug("Retrying transaction %" PRIu16 ".", t->id); From 9ee18bf473cdaa8128e898da3cf297b596cc9b99 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Mar 2021 17:17:17 +0100 Subject: [PATCH 2/5] resolved: use random_u64_range() for randomizing initial transaction jitter --- src/resolve/resolved-dns-transaction.c | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index f084a70e45..edce586e69 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -1941,23 +1941,20 @@ int dns_transaction_go(DnsTransaction *t) { IN_SET(t->scope->protocol, DNS_PROTOCOL_LLMNR, DNS_PROTOCOL_MDNS)) { usec_t jitter, accuracy; - /* RFC 4795 Section 2.7 suggests all queries should be - * delayed by a random time from 0 to JITTER_INTERVAL. */ + /* RFC 4795 Section 2.7 suggests all queries should be delayed by a random time from 0 to + * JITTER_INTERVAL. */ t->initial_jitter_scheduled = true; - random_bytes(&jitter, sizeof(jitter)); - switch (t->scope->protocol) { case DNS_PROTOCOL_LLMNR: - jitter %= LLMNR_JITTER_INTERVAL_USEC; + jitter = random_u64_range(LLMNR_JITTER_INTERVAL_USEC); accuracy = LLMNR_JITTER_INTERVAL_USEC; break; case DNS_PROTOCOL_MDNS: - jitter %= MDNS_JITTER_RANGE_USEC; - jitter += MDNS_JITTER_MIN_USEC; + jitter = usec_add(random_u64_range(MDNS_JITTER_RANGE_USEC), MDNS_JITTER_MIN_USEC); accuracy = MDNS_JITTER_RANGE_USEC; break; default: From 2f9c3b2ab4dbce435f19d782d19c7f4ea5768453 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Mar 2021 17:18:02 +0100 Subject: [PATCH 3/5] resolved: mention transaction ID in jitter log message --- src/resolve/resolved-dns-transaction.c | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index edce586e69..b357710a94 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -1976,7 +1976,10 @@ int dns_transaction_go(DnsTransaction *t) { t->next_attempt_after = ts; t->state = DNS_TRANSACTION_PENDING; - log_debug("Delaying %s transaction for " USEC_FMT "us.", dns_protocol_to_string(t->scope->protocol), jitter); + log_debug("Delaying %s transaction %" PRIu16 " for " USEC_FMT "us.", + dns_protocol_to_string(t->scope->protocol), + t->id, + jitter); return 1; } From 213cb4f7e443241ef942cfbd0263cde33b4672c1 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Mar 2021 18:45:35 +0100 Subject: [PATCH 4/5] resolved: reset initial_jitter_elapsed properly This fixes resetting of initial_jitter_elapsed: the first time the timer hits after initial_jitter_scheduled is set we need to mark things as elapsed. (Also improve log messages around this while we are at it) --- src/resolve/resolved-dns-transaction.c | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index b357710a94..877b9bee0f 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -1510,7 +1510,10 @@ static int on_transaction_timeout(sd_event_source *s, usec_t usec, void *userdat assert(s); assert(t); - if (!t->initial_jitter_scheduled || t->initial_jitter_elapsed) { + if (t->initial_jitter_scheduled && !t->initial_jitter_elapsed) { + log_debug("Initial jitter phase for transaction %" PRIu16 " elapsed.", t->id); + t->initial_jitter_elapsed = true; + } else { /* Timeout reached? Increase the timeout for the server used */ switch (t->scope->protocol) { @@ -1528,14 +1531,12 @@ static int on_transaction_timeout(sd_event_source *s, usec_t usec, void *userdat assert_not_reached("Invalid DNS protocol."); } - if (t->initial_jitter_scheduled) - t->initial_jitter_elapsed = true; + log_debug("Timeout reached on transaction %" PRIu16 ".", t->id); } - log_debug("Timeout reached on transaction %" PRIu16 ".", t->id); - - dns_transaction_retry(t, true); /* try a different server, but given this means packet loss, let's do - * so even if we already tried a bunch */ + dns_transaction_retry(t, /* next_server= */ true); /* try a different server, but given this means + * packet loss, let's do so even if we already + * tried a bunch */ return 0; } @@ -1928,8 +1929,8 @@ int dns_transaction_go(DnsTransaction *t) { if (r <= 0) return r; - log_debug("%s transaction %" PRIu16 " for <%s> scope %s on %s/%s (validate=%s).", - t->bypass ? "Bypass" : "Regular", + log_debug("Firing %s transaction %" PRIu16 " for <%s> scope %s on %s/%s (validate=%s).", + t->bypass ? "bypass" : "regular", t->id, dns_resource_key_to_string(dns_transaction_key(t), key_str, sizeof key_str), dns_protocol_to_string(t->scope->protocol), From 6d660692f2f5e402e98a5951c62eafb82d0a99f3 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Mar 2021 18:45:55 +0100 Subject: [PATCH 5/5] resolved: use sd_event_add_time_relative() where appropriate --- src/resolve/resolved-dns-transaction.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index 877b9bee0f..b6da513399 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -1962,11 +1962,13 @@ int dns_transaction_go(DnsTransaction *t) { assert_not_reached("bad protocol"); } - r = sd_event_add_time( + assert(!t->timeout_event_source); + + r = sd_event_add_time_relative( t->scope->manager->event, &t->timeout_event_source, clock_boottime_or_monotonic(), - ts + jitter, accuracy, + jitter, accuracy, on_transaction_timeout, t); if (r < 0) return r;