Improve efficiency of DNSSEC.

The sharing point for DNSSEC RR data used to be when it entered the
cache, having been validated. After that queries requiring the KEY or
DS records would share the cached values. There is a common case in
dual-stack hosts that queries for A and AAAA records for the same
domain are made simultaneously.  If required keys were not in the
cache, this would result in two requests being sent upstream for the
same key data (and all the subsequent chain-of-trust queries.) Now we
combine these requests and elide the duplicates, resulting in fewer
queries upstream and better performance. To keep a better handle on
what's going on, the "extra" logging mode has been modified to
associate queries and answers for DNSSEC queries in the same way as
ordinary queries. The requesting address and port have been removed
from DNSSEC logging lines, since this is no longer strictly defined.

CHANGELOG

@@ -49,6 +49,21 @@ version 2.86
 	common case, where only default servers are declared, there is
 	no effective change.
 
+	Improve efficiency of DNSSEC. The sharing point for DNSSEC RR data
+	used to be when it entered the cache, having been validated. After
+	that queries requiring the KEY or DS records would share the cached
+	values. There is a common case in dual-stack hosts that queries for
+	A and AAAA records for the same domain are made simultaneously.
+	If required keys were not in the cache, this would result in two
+	requests being sent upstream for the same key data (and all the
+	subsequent chain-of-trust queries.) Now we combine these requests
+	and elide the duplicates, resulting in fewer queries upstream
+	and better performance. To keep a better handle on what's
+	going on, the "extra" logging mode has been modified to associate
+	queries and answers  for DNSSEC queries in the same way as ordinary
+	queries. The requesting address and port have been removed from
+	DNSSEC logging lines, since this is no longer strictly defined.
+
 	
 version 2.85
         Fix problem with DNS retries in 2.83/2.84.

src/cache.c

@@ -1965,12 +1965,14 @@ void log_query(unsigned int flags, char *name, union all_addr *addr, char *arg)
 
   if (option_bool(OPT_EXTRALOG))
     {
-      int port = prettyprint_addr(daemon->log_source_addr, daemon->addrbuff2);
       if (flags & F_NOEXTRA)
-	my_syslog(LOG_INFO, "* %s/%u %s %s %s %s", daemon->addrbuff2, port, source, name, verb, dest);
+	my_syslog(LOG_INFO, "%u %s %s %s %s", daemon->log_display_id, source, name, verb, dest);
       else
+	{
+	   int port = prettyprint_addr(daemon->log_source_addr, daemon->addrbuff2);
 	   my_syslog(LOG_INFO, "%u %s/%u %s %s %s %s", daemon->log_display_id, daemon->addrbuff2, port, source, name, verb, dest);
 	}
+    }
   else
     my_syslog(LOG_INFO, "%s %s %s %s", source, name, verb, dest);
 }

src/dnsmasq.h

@@ -690,7 +690,6 @@ struct hostsfile {
 #define STAT_SECURE_WILDCARD    7
 #define STAT_OK                 8
 #define STAT_ABANDONED          9
-#define STAT_INPROGRESS         10
 
 #define FREC_NOREBIND           1
 #define FREC_CHECKING_DISABLED  2
@@ -727,6 +726,7 @@ struct frec {
   struct blockdata *stash; /* Saved reply, whilst we validate */
   size_t stash_len;
   struct frec *dependent; /* Query awaiting internally-generated DNSKEY or DS query */
+  struct frec *next_dependent; /* list of above. */
   struct frec *blocking_query; /* Query which is blocking us. */
 #endif
   struct frec *next;

src/forward.c

@@ -16,14 +16,16 @@
 
 #include "dnsmasq.h"
 
-static struct frec *get_new_frec(time_t now, struct server *serv, struct frec *force);
+static struct frec *get_new_frec(time_t now, struct server *serv, int force);
 static struct frec *lookup_frec(unsigned short id, int fd, void *hash, int *firstp, int *lastp);
-static struct frec *lookup_frec_by_query(void *hash, unsigned int flags);
+static struct frec *lookup_frec_by_query(void *hash, unsigned int flags, unsigned int flagmask);
 
 static unsigned short get_id(void);
 static void free_frec(struct frec *f);
 static void query_full(time_t now, char *domain);
 
+static void return_reply(time_t now, struct frec *forward, struct dns_header *header, ssize_t n, int status);
+
 /* Send a UDP packet with its source address set as "source" 
    unless nowild is true, when we just send it with the kernel default */
 int send_from(int fd, int nowild, char *packet, size_t len, 
@@ -189,10 +191,17 @@ static int forward_query(int udpfd, union mysockaddr *udpaddr,
     fwd_flags |= FREC_DO_QUESTION;
 #endif
   
-  /* Check for retry on existing query */
+  /* Check for retry on existing query.
+     FREC_DNSKEY and FREC_DS_QUERY are never set in flags, so the test below 
+     ensures that no frec created for internal DNSSEC query can be returned here.
+     
+     Similarly FREC_NO_CACHE is never set in flags, so a query which is
+     contigent on a particular source address EDNS0 option will never be matched. */
   if (forward)
     old_src = 1;
-  else if ((forward = lookup_frec_by_query(hash, fwd_flags)))
+  else if ((forward = lookup_frec_by_query(hash, fwd_flags,
+					   FREC_CHECKING_DISABLED | FREC_AD_QUESTION | FREC_DO_QUESTION |
+					   FREC_HAS_PHEADER | FREC_DNSKEY_QUERY | FREC_DS_QUERY | FREC_NO_CACHE)))
     {
       struct frec_src *src;
       
@@ -270,7 +279,7 @@ static int forward_query(int udpfd, union mysockaddr *udpaddr,
       
       master = daemon->serverarray[first];
       
-      if (!(forward = get_new_frec(now, master, NULL)))
+      if (!(forward = get_new_frec(now, master, 0)))
 	goto reply;
       /* table full - flags == 0, return REFUSED */
       
@@ -379,12 +388,12 @@ static int forward_query(int udpfd, union mysockaddr *udpaddr,
       forward->flags |= FREC_TEST_PKTSZ;
     }
 
-  /* We may be resending a DNSSEC query here, for which the below processing is not necessary. */
-  if (!is_dnssec)
-    {
   /* If a query is retried, use the log_id for the retry when logging the answer. */
   forward->frec_src.log_id = daemon->log_id;
 
+  /* We may be resending a DNSSEC query here, for which the below processing is not necessary. */
+  if (!is_dnssec)
+    {
       header->id = htons(forward->new_id);
       
       plen = add_edns0_config(header, plen, ((unsigned char *)header) + PACKETSZ, &forward->frec_src.source, now, &subnet, &cacheable);
@@ -715,15 +724,14 @@ static size_t process_reply(struct dns_header *header, time_t now, struct server
 }
 
 #ifdef HAVE_DNSSEC
-static int dnssec_validate(struct frec **forwardp, struct dns_header *header,
+static void dnssec_validate(struct frec *forward, struct dns_header *header,
-			   ssize_t plen, struct server *server, time_t now)
+			    ssize_t plen, int status, time_t now)
 {
-  int status = 0;
+  daemon->log_display_id = forward->frec_src.log_id;
-  struct frec *forward = *forwardp;
   
   /* We've had a reply already, which we're validating. Ignore this duplicate */
   if (forward->blocking_query)
-    return STAT_INPROGRESS;
+    return;
   
   /* Truncated answer can't be validated.
      If this is an answer to a DNSSEC-generated query, we still
@@ -737,8 +745,6 @@ static int dnssec_validate(struct frec **forwardp, struct dns_header *header,
   if (RCODE(header) == REFUSED)
     status = STAT_ABANDONED;
   
-  while (1)
-    {
   /* As soon as anything returns BOGUS, we stop and unwind, to do otherwise
      would invite infinite loops, since the answers to DNSKEY and DS queries
      will not be cached, so they'll be repeated. */
@@ -755,7 +761,7 @@ static int dnssec_validate(struct frec **forwardp, struct dns_header *header,
 #ifdef HAVE_DUMPFILE
       if (status == STAT_BOGUS)
 	dump_packet((forward->flags & (FREC_DNSKEY_QUERY | FREC_DS_QUERY)) ? DUMP_SEC_BOGUS : DUMP_BOGUS,
-			header, (size_t)plen, &server->addr, NULL);
+		    header, (size_t)plen, &forward->sentto->addr, NULL);
 #endif
     }
   
@@ -763,66 +769,78 @@ static int dnssec_validate(struct frec **forwardp, struct dns_header *header,
      answer aside, whilst we get that. */     
   if (status == STAT_NEED_DS || status == STAT_NEED_KEY)
     {
-	  struct frec *new = NULL, *orig;
+      struct frec *new = NULL;
       int serverind;
-	  
+      struct blockdata *stash;
-	  /* Free any saved query */
-	  if (forward->stash)
-	    blockdata_free(forward->stash);
       
       /* Now save reply pending receipt of key data */
-	  if (!(forward->stash = blockdata_alloc((char *)header, plen)))
+      if ((serverind = dnssec_server(forward->sentto, daemon->keyname, NULL, NULL)) != -1 &&
-	    return STAT_ABANDONED;
+	  (stash = blockdata_alloc((char *)header, plen)))
+	{
+	  struct server *server = daemon->serverarray[serverind];
+	  struct frec *orig;
+	  unsigned int flags;
+	  void *hash;
+	  size_t nn;
+
+	  /* validate routines leave name of required record in daemon->keyname */
+	  nn = dnssec_generate_query(header, ((unsigned char *) header) + server->edns_pktsz,
+				     daemon->keyname, forward->class,
+				     status == STAT_NEED_KEY ? T_DNSKEY : T_DS, server->edns_pktsz);
+	  
+	  flags = (status == STAT_NEED_KEY) ? FREC_DNSKEY_QUERY : FREC_DS_QUERY;
+	  hash = hash_questions(header, nn, daemon->namebuff);
+
+	  if ((new = lookup_frec_by_query(hash, flags, FREC_DNSKEY_QUERY | FREC_DS_QUERY)))
+	    {
+	      forward->next_dependent = new->dependent;
+	      new->dependent = forward;
+	      /* Make consistent, only replace query copy with unvalidated answer
+		 when we set ->blocking_query. */
+	      if (forward->stash)
+		blockdata_free(forward->stash);
+	      forward->blocking_query = new;
 	      forward->stash_len = plen;
+	      forward->stash = stash;
+	      return;
+	    }
 	    
 	  /* Find the original query that started it all.... */
 	  for (orig = forward; orig->dependent; orig = orig->dependent);
 	  
 	  /* Make sure we don't expire and free the orig frec during the
-	     allocation of a new one. */
+	     allocation of a new one: third arg of get_new_frec() does that. */
-	  if (--orig->work_counter == 0 ||
+	  if (--orig->work_counter == 0 || !(new = get_new_frec(now, server, 1)))
-	      (serverind = dnssec_server(server, daemon->keyname, NULL, NULL)) == -1 ||
+	    blockdata_free(stash); /* don't leak this on failure. */
-	      !(server = daemon->serverarray[serverind]) ||
-	      !(new = get_new_frec(now, server, orig)))
-	    {
-	      status = STAT_ABANDONED;
-	      if (new)
-		free_frec(new);
-	    }
 	  else
 	    {
-	      int querytype, fd;
+	      int fd;
 	      struct frec *next = new->next;
-	      size_t nn;
 
 	      *new = *forward; /* copy everything, then overwrite */
 	      new->next = next;
 	      new->blocking_query = NULL;
 	      
+	      new->frec_src.log_id = daemon->log_display_id = ++daemon->log_id;
 	      new->sentto = server;
 	      new->rfds = NULL;
 	      new->frec_src.next = NULL;
 	      new->flags &= ~(FREC_DNSKEY_QUERY | FREC_DS_QUERY | FREC_HAS_EXTRADATA);
+	      new->flags |= flags;
 	      new->forwardall = 0;
 	      
+	      forward->next_dependent = NULL;
 	      new->dependent = forward; /* to find query awaiting new one. */
-	      forward->blocking_query = new; /* for garbage cleaning */
-	      /* validate routines leave name of required record in daemon->keyname */
-	      if (status == STAT_NEED_KEY)
-		{
-		  new->flags |= FREC_DNSKEY_QUERY; 
-		  querytype = T_DNSKEY;
-		}
-	      else 
-		{
-		  new->flags |= FREC_DS_QUERY;
-		  querytype = T_DS;
-		}
 
-	      nn = dnssec_generate_query(header,((unsigned char *) header) + server->edns_pktsz,
+	      /* Make consistent, only replace query copy with unvalidated answer
-					 daemon->keyname, forward->class, querytype, server->edns_pktsz);
+		 when we set ->blocking_query. */
+	      forward->blocking_query = new; 
+	      if (forward->stash)
+		blockdata_free(forward->stash);
+	      forward->stash_len = plen;
+	      forward->stash = stash;
 	      
-	      memcpy(new->hash, hash_questions(header, nn, daemon->namebuff), HASH_SIZE);
+	      memcpy(new->hash, hash, HASH_SIZE);
 	      new->new_id = get_id();
 	      header->id = htons(new->new_id);
 	      /* Save query for retransmission */
@@ -840,28 +858,38 @@ static int dnssec_validate(struct frec **forwardp, struct dns_header *header,
 #endif
 		  server_send_log(server, fd, header, nn, DUMP_SEC_QUERY,
 				  F_NOEXTRA | F_DNSSEC, daemon->keyname,
-				  querystr("dnssec-query", querytype));
+				  querystr("dnssec-query", status == STAT_NEED_KEY ? T_DNSKEY : T_DS));
 		  server->queries++;
 		}
+	      
+	      return;
 	    }
-	  return STAT_INPROGRESS;
+	}
+
+      /* sending DNSSEC query failed. */
+      status = STAT_ABANDONED;
     }
   
   /* Validated original answer, all done. */
   if (!forward->dependent)
-	break;
+    return_reply(now, forward, header, plen, status);
+  else
+    {
+      /* validated subsidiary query/queries, (and cached result)
+	 pop that and return to the previous query/queries we were working on. */
+      struct frec *prev, *nxt = forward->dependent;
       
-      /* validated subsidiary query, (and cached result)
-	 pop that and return to the previous query we were working on. */
-      struct frec *prev = forward->dependent;
       free_frec(forward);
-      *forwardp = forward = prev;
-      forward->blocking_query = NULL; /* already gone */
-      blockdata_retrieve(forward->stash, forward->stash_len, (void *)header);
-      plen = forward->stash_len;
-    }
       
-  return status;
+      while ((prev = nxt))
+	{
+	  /* ->next_dependent will have changed after return from recursive call below. */
+	  nxt = prev->next_dependent;
+	  prev->blocking_query = NULL; /* already gone */
+	  blockdata_retrieve(prev->stash, prev->stash_len, (void *)header);
+	  dnssec_validate(prev, header, prev->stash_len, status, now);
+	}
+    }
 }
 #endif
 
@@ -875,11 +903,9 @@ void reply_query(int fd, time_t now)
   struct frec *forward;
   socklen_t addrlen = sizeof(serveraddr);
   ssize_t n = recvfrom(fd, daemon->packet, daemon->packet_buff_sz, 0, &serveraddr.sa, &addrlen);
-  size_t nn;
   struct server *server;
   void *hash;
   int first, last, c;
-  int check_rebind = 0, no_cache_dnssec = 0, cache_secure = 0, bogusanswer = 0;
     
   /* packet buffer overwritten */
   daemon->srv_save = NULL;
@@ -944,10 +970,14 @@ void reply_query(int fd, time_t now)
       unsigned short udp_size =  PACKETSZ; /* default if no EDNS0 */
       size_t plen;
       int is_sign;
+      size_t nn = 0;
       
 #ifdef HAVE_DNSSEC
-      /* DNSSEC queries have a copy of the original query stashed. */
+      /* DNSSEC queries have a copy of the original query stashed. 
-      if (forward->flags & (FREC_DNSKEY_QUERY | FREC_DS_QUERY))
+	 The query MAY have got a good answer, and be awaiting
+	 the results of further queries, in which case
+	 The Stash contains something else and we don't need to retry anyway. */
+      if ((forward->flags & (FREC_DNSKEY_QUERY | FREC_DS_QUERY)) && !forward->blocking_query)
 	{
 	  blockdata_retrieve(forward->stash, forward->stash_len, (void *)header);
 	  nn = forward->stash_len;
@@ -956,8 +986,6 @@ void reply_query(int fd, time_t now)
       else
 #endif
 	{
-	  nn = 0;
-
 	  /* recreate query from reply */
 	  if ((pheader = find_pseudoheader(header, (size_t)n, &plen, &udpsz, &is_sign, NULL)))
 	    GETSHORT(udp_size, udpsz);
@@ -1015,25 +1043,36 @@ void reply_query(int fd, time_t now)
       my_syslog(LOG_WARNING, _("reducing DNS packet size for nameserver %s to %d"), daemon->addrbuff, SAFE_PKTSZ);
     }
 
+  forward->sentto = server;
+  
+#ifdef HAVE_DNSSEC
+  if ((forward->sentto->flags & SERV_DO_DNSSEC) && 
+      option_bool(OPT_DNSSEC_VALID) &&
+      !(forward->flags & FREC_CHECKING_DISABLED))
+    dnssec_validate(forward, header, n, STAT_OK, now);
+  else
+#endif
+    return_reply(now, forward, header, n, STAT_OK); 
+}
+
+static void return_reply(time_t now, struct frec *forward, struct dns_header *header, ssize_t n, int status)
+{
+  int check_rebind = 0, no_cache_dnssec = 0, cache_secure = 0, bogusanswer = 0;
+  size_t nn;
+
+  (void)status;
+
+  daemon->log_display_id = forward->frec_src.log_id;
+  daemon->log_source_addr = &forward->frec_src.source;
+  
   /* Don't cache replies where DNSSEC validation was turned off, either
      the upstream server told us so, or the original query specified it.  */
   if ((header->hb4 & HB4_CD) || (forward->flags & FREC_CHECKING_DISABLED))
     no_cache_dnssec = 1;
 
 #ifdef HAVE_DNSSEC
-  if ((forward->sentto->flags & SERV_DO_DNSSEC) && 
+  if (status != STAT_OK)
-      option_bool(OPT_DNSSEC_VALID) &&
-      !(forward->flags & FREC_CHECKING_DISABLED))
     {
-      /* Note that the value of forward may change here: 
-	 we can start with a DNSSEC query reply and 
-	 return with a query that was suspended pending
-	 that DNSSEC query. */
-      int status = dnssec_validate(&forward, header, n, server, now);
-
-      if (status == STAT_INPROGRESS)
-	return;
-      
       no_cache_dnssec = 0;
       
       if (status == STAT_TRUNCATED)
@@ -1080,7 +1119,7 @@ void reply_query(int fd, time_t now)
   if (forward->flags & FREC_NO_CACHE)
     no_cache_dnssec = 1;
   
-  if ((nn = process_reply(header, now, server, (size_t)n, check_rebind, no_cache_dnssec, cache_secure, bogusanswer, 
+  if ((nn = process_reply(header, now, forward->sentto, (size_t)n, check_rebind, no_cache_dnssec, cache_secure, bogusanswer, 
 			  forward->flags & FREC_AD_QUESTION, forward->flags & FREC_DO_QUESTION, 
 			  forward->flags & FREC_ADDED_PHEADER, forward->flags & FREC_HAS_SUBNET, &forward->frec_src.source)))
     {
@@ -1469,6 +1508,7 @@ static ssize_t tcp_talk(int first, int last, int start, unsigned char *packet,
   (void)have_mark;
 
   memcpy(hash, hash_questions(header, (unsigned int)qsize, daemon->namebuff), HASH_SIZE);
+  
   while (1) 
     {
       int data_sent = 0;
@@ -1573,6 +1613,7 @@ static int tcp_key_recurse(time_t now, int status, struct dns_header *header, si
   while (1)
     {
       size_t m;
+      int log_save;
             
       /* limit the amount of work we do, to avoid cycling forever on loops in the DNS */
       if (--(*keycount) == 0)
@@ -1613,11 +1654,16 @@ static int tcp_key_recurse(time_t now, int status, struct dns_header *header, si
 	  break;
 	}
 
+      log_save = daemon->log_display_id;
+      daemon->log_display_id = ++daemon->log_id;
+      
       log_query_mysockaddr(F_NOEXTRA | F_DNSSEC, keyname, &server->addr,
 			   querystr("dnssec-query", new_status == STAT_NEED_KEY ? T_DNSKEY : T_DS));
             
       new_status = tcp_key_recurse(now, new_status, new_header, m, class, name, keyname, server, have_mark, mark, keycount);
 
+      daemon->log_display_id = log_save;
+      
       if (new_status != STAT_OK)
 	break;
     }
@@ -2136,9 +2182,27 @@ static void free_frec(struct frec *f)
 
   /* Anything we're waiting on is pointless now, too */
   if (f->blocking_query)
+    {
+      struct frec *n, **up;
+
+      /* unlink outselves from the blocking query's dependents list. */
+      for (n = f->blocking_query->dependent, up = &f->blocking_query->dependent; n; n = n->next_dependent)
+	if (n == f)
+	  {
+	    *up = n->next_dependent;
+	    break;
+	  }
+	else
+	  up = &n->next_dependent;
+
+      /* If we were the only/last dependent, free the blocking query too. */
+      if (!f->blocking_query->dependent)
 	free_frec(f->blocking_query);
+    }
+  
   f->blocking_query = NULL;
   f->dependent = NULL;
+  f->next_dependent = NULL;
 #endif
 }
 
@@ -2146,10 +2210,11 @@ static void free_frec(struct frec *f)
 
 /* Impose an absolute
    limit of 4*TIMEOUT before we wipe things (for random sockets).
-   If force is non-NULL, always return a result, even if we have
+   If force is set, always return a result, even if we have
-   to allocate above the limit, and never free the record pointed
+   to allocate above the limit, and don'y free any records.
-   to by the force argument. */
+   This is set when allocating for DNSSEC to avoid cutting off
-static struct frec *get_new_frec(time_t now, struct server *master, struct frec *force)
+   the branch we are sitting on. */
+static struct frec *get_new_frec(time_t now, struct server *master, int force)
 {
   struct frec *f, *oldest, *target;
   int count;
@@ -2165,7 +2230,7 @@ static struct frec *get_new_frec(time_t now, struct server *master, struct frec
 	  /* Don't free DNSSEC sub-queries here, as we may end up with
 	     dangling references to them. They'll go when their "real" query 
 	     is freed. */
-	  if (!f->dependent && f != force)
+	  if (!f->dependent && !force)
 #endif
 	    {
 	      if (difftime(now, f->time) >= 4*TIMEOUT)
@@ -2173,8 +2238,7 @@ static struct frec *get_new_frec(time_t now, struct server *master, struct frec
 		  free_frec(f);
 		  target = f;
 		}
-	      
+	      else if (!oldest || difftime(f->time, oldest->time) <= 0)
-	      if (!oldest || difftime(f->time, oldest->time) <= 0)
 		oldest = f;
 	    }
 	}
@@ -2255,22 +2319,13 @@ static struct frec *lookup_frec(unsigned short id, int fd, void *hash, int *firs
   return NULL;
 }
 
-static struct frec *lookup_frec_by_query(void *hash, unsigned int flags)
+static struct frec *lookup_frec_by_query(void *hash, unsigned int flags, unsigned int flagmask)
 {
   struct frec *f;
 
-  /* FREC_DNSKEY and FREC_DS_QUERY are never set in flags, so the test below 
-     ensures that no frec created for internal DNSSEC query can be returned here.
-     
-     Similarly FREC_NO_CACHE is never set in flags, so a query which is
-     contigent on a particular source address EDNS0 option will never be matched. */
-
-#define FLAGMASK (FREC_CHECKING_DISABLED | FREC_AD_QUESTION | FREC_DO_QUESTION \
-		  | FREC_HAS_PHEADER | FREC_DNSKEY_QUERY | FREC_DS_QUERY | FREC_NO_CACHE)
-  
   for(f = daemon->frec_list; f; f = f->next)
     if (f->sentto &&
-	(f->flags & FLAGMASK) == flags &&
+	(f->flags & flagmask) == flags &&
 	memcmp(hash, f->hash, HASH_SIZE) == 0)
       return f;