From 6b9308d14b8e59307082c87b0974fcc28a2774e0 Mon Sep 17 00:00:00 2001 From: Tom Gundersen Date: Tue, 11 Aug 2015 20:05:53 +0200 Subject: [PATCH 1/4] resolved: packet - fix typo in read_rr() --- src/resolve/resolved-dns-packet.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/resolve/resolved-dns-packet.c b/src/resolve/resolved-dns-packet.c index 39951a362c..35ad899544 100644 --- a/src/resolve/resolved-dns-packet.c +++ b/src/resolve/resolved-dns-packet.c @@ -1712,7 +1712,7 @@ int dns_packet_read_rr(DnsPacket *p, DnsResourceRecord **ret, size_t *start) { if (r < 0) goto fail; - r = dns_packet_read_type_windows(p, &rr->nsec.types, offset + rdlength - p->rindex, NULL); + r = dns_packet_read_type_windows(p, &rr->nsec3.types, offset + rdlength - p->rindex, NULL); if (r < 0) goto fail; From 74998408530501c3309bb15c383573b382164197 Mon Sep 17 00:00:00 2001 From: Tom Gundersen Date: Tue, 11 Aug 2015 22:37:23 +0200 Subject: [PATCH 2/4] resolve-host: print RTT --- src/resolve-host/resolve-host.c | 28 ++++++++++++++++++++++++---- 1 file changed, 24 insertions(+), 4 deletions(-) diff --git a/src/resolve-host/resolve-host.c b/src/resolve-host/resolve-host.c index 4d557bdf02..7525d7c32f 100644 --- a/src/resolve-host/resolve-host.c +++ b/src/resolve-host/resolve-host.c @@ -41,7 +41,8 @@ static uint16_t arg_class = 0; static bool arg_legend = true; static uint64_t arg_flags = 0; -static void print_source(int ifindex, uint64_t flags) { +static void print_source(int ifindex, uint64_t flags, usec_t rtt) { + char rtt_str[FORMAT_TIMESTAMP_MAX]; if (!arg_legend) return; @@ -62,6 +63,10 @@ static void print_source(int ifindex, uint64_t flags) { printf(" interface %s", strna(if_indextoname(ifindex, ifname))); } + assert_se(format_timespan(rtt_str, sizeof(rtt_str), rtt, 100)); + + printf(" in %s", rtt_str); + fputc('.', stdout); fputc('\n', stdout); } @@ -74,6 +79,7 @@ static int resolve_host(sd_bus *bus, const char *name) { unsigned c = 0; int r, ifindex; uint64_t flags; + usec_t ts; assert(name); @@ -93,12 +99,16 @@ static int resolve_host(sd_bus *bus, const char *name) { if (r < 0) return bus_log_create_error(r); + ts = now(CLOCK_MONOTONIC); + r = sd_bus_call(bus, req, DNS_CALL_TIMEOUT_USEC, &error, &reply); if (r < 0) { log_error("%s: resolve call failed: %s", name, bus_error_message(&error, r)); return r; } + ts = now(CLOCK_MONOTONIC) - ts; + r = sd_bus_message_read(reply, "i", &ifindex); if (r < 0) return bus_log_parse_error(r); @@ -182,7 +192,7 @@ static int resolve_host(sd_bus *bus, const char *name) { return -ESRCH; } - print_source(ifindex, flags); + print_source(ifindex, flags, ts); return 0; } @@ -195,6 +205,7 @@ static int resolve_address(sd_bus *bus, int family, const union in_addr_union *a uint64_t flags; unsigned c = 0; const char *n; + usec_t ts; int r; assert(bus); @@ -243,12 +254,16 @@ static int resolve_address(sd_bus *bus, int family, const union in_addr_union *a if (r < 0) return bus_log_create_error(r); + ts = now(CLOCK_MONOTONIC); + r = sd_bus_call(bus, req, DNS_CALL_TIMEOUT_USEC, &error, &reply); if (r < 0) { log_error("%s: resolve call failed: %s", pretty, bus_error_message(&error, r)); return r; } + ts = now(CLOCK_MONOTONIC) - ts; + r = sd_bus_message_read(reply, "i", &ifindex); if (r < 0) return bus_log_parse_error(r); @@ -283,7 +298,7 @@ static int resolve_address(sd_bus *bus, int family, const union in_addr_union *a return -ESRCH; } - print_source(ifindex, flags); + print_source(ifindex, flags, ts); return 0; } @@ -321,6 +336,7 @@ static int resolve_record(sd_bus *bus, const char *name) { unsigned n = 0; uint64_t flags; int r, ifindex; + usec_t ts; assert(name); @@ -341,12 +357,16 @@ static int resolve_record(sd_bus *bus, const char *name) { if (r < 0) return bus_log_create_error(r); + ts = now(CLOCK_MONOTONIC); + r = sd_bus_call(bus, req, DNS_CALL_TIMEOUT_USEC, &error, &reply); if (r < 0) { log_error("%s: resolve call failed: %s", name, bus_error_message(&error, r)); return r; } + ts = now(CLOCK_MONOTONIC) - ts; + r = sd_bus_message_read(reply, "i", &ifindex); if (r < 0) return bus_log_parse_error(r); @@ -414,7 +434,7 @@ static int resolve_record(sd_bus *bus, const char *name) { return -ESRCH; } - print_source(ifindex, flags); + print_source(ifindex, flags, ts); return 0; } From 17018c3cc7ba3dcb4e6aeb8a77203b08fd09f726 Mon Sep 17 00:00:00 2001 From: Tom Gundersen Date: Wed, 12 Aug 2015 17:29:53 +0200 Subject: [PATCH 3/4] TODO --- TODO | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/TODO b/TODO index 8b6692ed1b..14a95177aa 100644 --- a/TODO +++ b/TODO @@ -354,7 +354,9 @@ Features: - avahi compat - DNS-SD service registration from socket units - edns0 - - dname + - dname: Not necessary for plain DNS as synthesized cname is handed out instead if we do not + announce dname support. However, for DNSSEC it is necessary as the synthesized cname + will not be signed. - cname on PTR (?) * Allow multiple ExecStart= for all Type= settings, so that we can cover rescue.service nicely From 6b34a6c995493dc6efaa245ff021476b70662f9a Mon Sep 17 00:00:00 2001 From: Tom Gundersen Date: Wed, 12 Aug 2015 18:18:31 +0200 Subject: [PATCH 4/4] resolved: cache - add more detailed cache debug logging --- src/resolve/resolved-dns-cache.c | 64 ++++++++++++++++++++++++-- src/resolve/resolved-dns-transaction.c | 3 -- 2 files changed, 60 insertions(+), 7 deletions(-) diff --git a/src/resolve/resolved-dns-cache.c b/src/resolve/resolved-dns-cache.c index 9ffaf4b19f..81ea1cafcb 100644 --- a/src/resolve/resolved-dns-cache.c +++ b/src/resolve/resolved-dns-cache.c @@ -95,14 +95,19 @@ void dns_cache_flush(DnsCache *c) { c->by_expiry = prioq_free(c->by_expiry); } -static void dns_cache_remove(DnsCache *c, DnsResourceKey *key) { +static bool dns_cache_remove(DnsCache *c, DnsResourceKey *key) { DnsCacheItem *i; + bool exist = false; assert(c); assert(key); - while ((i = hashmap_get(c->by_key, key))) + while ((i = hashmap_get(c->by_key, key))) { dns_cache_item_remove_and_free(c, i); + exist = true; + } + + return exist; } static void dns_cache_make_space(DnsCache *c, unsigned add) { @@ -263,6 +268,7 @@ static int dns_cache_put_positive( const union in_addr_union *owner_address) { _cleanup_(dns_cache_item_freep) DnsCacheItem *i = NULL; + _cleanup_free_ char *key_str = NULL; DnsCacheItem *existing; int r; @@ -272,7 +278,14 @@ static int dns_cache_put_positive( /* New TTL is 0? Delete the entry... */ if (rr->ttl <= 0) { - dns_cache_remove(c, rr->key); + if (dns_cache_remove(c, rr->key)) { + r = dns_resource_key_to_string(rr->key, &key_str); + if (r < 0) + return r; + + log_debug("Removed zero TTL entry from cache: %s", key_str); + } + return 0; } @@ -311,6 +324,12 @@ static int dns_cache_put_positive( if (r < 0) return r; + r = dns_resource_key_to_string(i->key, &key_str); + if (r < 0) + return r; + + log_debug("Added cache entry for %s", key_str); + i = NULL; return 0; } @@ -325,6 +344,7 @@ static int dns_cache_put_negative( const union in_addr_union *owner_address) { _cleanup_(dns_cache_item_freep) DnsCacheItem *i = NULL; + _cleanup_free_ char *key_str = NULL; int r; assert(c); @@ -337,8 +357,15 @@ static int dns_cache_put_negative( return 0; if (key->type == DNS_TYPE_ANY) return 0; - if (soa_ttl <= 0) + if (soa_ttl <= 0) { + r = dns_resource_key_to_string(key, &key_str); + if (r < 0) + return r; + + log_debug("Ignored negative cache entry with zero SOA TTL: %s", key_str); + return 0; + } if (!IN_SET(rcode, DNS_RCODE_SUCCESS, DNS_RCODE_NXDOMAIN)) return 0; @@ -364,6 +391,12 @@ static int dns_cache_put_negative( if (r < 0) return r; + r = dns_resource_key_to_string(i->key, &key_str); + if (r < 0) + return r; + + log_debug("Added %s cache entry for %s", i->type == DNS_CACHE_NODATA ? "NODATA" : "NXDOMAIN", key_str); + i = NULL; return 0; } @@ -468,11 +501,19 @@ int dns_cache_lookup(DnsCache *c, DnsQuestion *q, int *rcode, DnsAnswer **ret) { } for (i = 0; i < q->n_keys; i++) { + _cleanup_free_ char *key_str = NULL; DnsCacheItem *j; if (q->keys[i]->type == DNS_TYPE_ANY || q->keys[i]->class == DNS_CLASS_ANY) { /* If we have ANY lookups we simply refresh */ + + r = dns_resource_key_to_string(q->keys[i], &key_str); + if (r < 0) + return r; + + log_debug("Ignoring cache for ANY lookup: %s", key_str); + *ret = NULL; *rcode = 0; return 0; @@ -481,9 +522,24 @@ int dns_cache_lookup(DnsCache *c, DnsQuestion *q, int *rcode, DnsAnswer **ret) { j = hashmap_get(c->by_key, q->keys[i]); if (!j) { /* If one question cannot be answered we need to refresh */ + + r = dns_resource_key_to_string(q->keys[i], &key_str); + if (r < 0) + return r; + + log_debug("Cache miss for %s", key_str); + *ret = NULL; *rcode = 0; return 0; + } else { + r = dns_resource_key_to_string(j->key, &key_str); + if (r < 0) + return r; + + log_debug("%s cache hit for %s", + j->type == DNS_CACHE_POSITIVE ? "Positive" : + (j->type == DNS_CACHE_NODATA ? "NODATA" : "NXDOMAIN"), key_str); } LIST_FOREACH(by_key, j, j) { diff --git a/src/resolve/resolved-dns-transaction.c b/src/resolve/resolved-dns-transaction.c index 53779f3372..2d9d1a47ee 100644 --- a/src/resolve/resolved-dns-transaction.c +++ b/src/resolve/resolved-dns-transaction.c @@ -624,7 +624,6 @@ int dns_transaction_go(DnsTransaction *t) { if (r < 0) return r; if (r > 0) { - log_debug("Cache hit!"); if (t->cached_rcode == DNS_RCODE_SUCCESS) dns_transaction_complete(t, DNS_TRANSACTION_SUCCESS); else @@ -661,8 +660,6 @@ int dns_transaction_go(DnsTransaction *t) { return 0; } - log_debug("Cache miss!"); - /* Otherwise, we need to ask the network */ r = dns_transaction_make_packet(t); if (r == -EDOM) {