Rationalise query-reply logging.

Try and log exactly what was returned, rather than just what
got cached. Also give validation status of RRsets if extra logging specified.

This commit also fixes a long-standing bug in caching of CNAME chains
leading to a PTR record.

Based on and inspired by a patch from Dominik DL6ER <dl6er@dl6er.de>

src/cache.c

@@ -488,8 +488,6 @@ struct crec *cache_insert(char *name, union all_addr *addr, unsigned short class
   else
 #endif
     {
-      /* Don't log DNSSEC records here, done elsewhere */
-      log_query(flags | F_UPSTREAM, name, addr, NULL);
       if (daemon->max_cache_ttl != 0 && daemon->max_cache_ttl < ttl)
 	ttl = daemon->max_cache_ttl;
       if (daemon->min_cache_ttl != 0 && daemon->min_cache_ttl > ttl)
@@ -1897,17 +1895,24 @@ static char *edestr(int ede)
 
 void log_query(unsigned int flags, char *name, union all_addr *addr, char *arg)
 {
-  char *source, *dest = daemon->addrbuff;
+  char *source, *dest = arg;
   char *verb = "is";
   char *extra = "";
   
   if (!option_bool(OPT_LOG))
     return;
   
+#ifdef HAVE_DNSSEC
+  if ((flags & F_DNSSECOK) && option_bool(OPT_EXTRALOG))
+    extra = " (DNSSEC signed)";
+#endif
+
   name = sanitise(name);
 
   if (addr)
     {
+      dest = daemon->addrbuff;
+
       if (flags & F_KEYTAG)
 	sprintf(daemon->addrbuff, arg, addr->log.keytag, addr->log.algo, addr->log.digest);
       else if (flags & F_RCODE)
@@ -1929,13 +1934,12 @@ void log_query(unsigned int flags, char *name, union all_addr *addr, char *arg)
 	      sprintf(extra, " (EDE: %s)", edestr(addr->log.ede));
 	    }
 	}
-      else
+      else if (flags & (F_IPV4 | F_IPV6))
 	inet_ntop(flags & F_IPV4 ? AF_INET : AF_INET6,
 		  addr, daemon->addrbuff, ADDRSTRLEN);
-      
-    }
       else
 	dest = arg;
+    }
 
   if (flags & F_REVERSE)
     {

src/rfc1035.c

@@ -394,18 +394,13 @@ static int private_net6(struct in6_addr *a, int ban_localhost)
     ((u32 *)a)[0] == htonl(0x20010db8); /* RFC 6303 4.6 */
 }
 
-static unsigned char *do_doctor(unsigned char *p, int count, struct dns_header *header, size_t qlen, char *name, int *doctored)
+static unsigned char *do_doctor(unsigned char *p, int count, struct dns_header *header, size_t qlen, int *doctored)
 {
   int i, qtype, qclass, rdlen;
 
   for (i = count; i != 0; i--)
     {
-      if (name && option_bool(OPT_LOG))
+      if (!(p = skip_name(p, header, qlen, 10)))
-	{
-	  if (!extract_name(header, qlen, &p, name, 1, 10))
-	    return 0;
-	}
-      else if (!(p = skip_name(p, header, qlen, 10)))
 	return 0; /* bad packet */
       
       GETSHORT(qtype, p); 
@@ -444,34 +439,6 @@ static unsigned char *do_doctor(unsigned char *p, int count, struct dns_header *
 	      break;
 	    }
 	}
-      else if (qtype == T_TXT && name && option_bool(OPT_LOG))
-	{
-	  unsigned char *p1 = p;
-	  if (!CHECK_LEN(header, p1, qlen, rdlen))
-	    return 0;
-	  while ((p1 - p) < rdlen)
-	    {
-	      unsigned int i, len = *p1;
-	      unsigned char *p2 = p1;
-	      if ((p1 + len - p) >= rdlen)
-	        return 0; /* bad packet */
-	      /* make counted string zero-term  and sanitise */
-	      for (i = 0; i < len; i++)
-		{
-		  if (!isprint((int)*(p2+1)))
-		    break;
-		  
-		  *p2 = *(p2+1);
-		  p2++;
-		}
-	      *p2 = 0;
-	      my_syslog(LOG_INFO, "reply %s is %s", name, p1);
-	      /* restore */
-	      memmove(p1 + 1, p1, i);
-	      *p1 = len;
-	      p1 += len+1;
-	    }
-	}		  
       
       if (!ADD_RDLEN(header, p, qlen, rdlen))
 	 return 0; /* bad packet */
@@ -480,7 +447,7 @@ static unsigned char *do_doctor(unsigned char *p, int count, struct dns_header *
   return p; 
 }
 
-static int find_soa(struct dns_header *header, size_t qlen, char *name, int *doctored)
+static int find_soa(struct dns_header *header, size_t qlen, int *doctored)
 {
   unsigned char *p;
   int qtype, qclass, rdlen;
@@ -489,7 +456,7 @@ static int find_soa(struct dns_header *header, size_t qlen, char *name, int *doc
   
   /* first move to NS section and find TTL from any SOA section */
   if (!(p = skip_questions(header, qlen)) ||
-      !(p = do_doctor(p, ntohs(header->ancount), header, qlen, name, doctored)))
+      !(p = do_doctor(p, ntohs(header->ancount), header, qlen, doctored)))
     return 0;  /* bad packet */
   
   for (i = ntohs(header->nscount); i != 0; i--)
@@ -525,7 +492,7 @@ static int find_soa(struct dns_header *header, size_t qlen, char *name, int *doc
     }
   
   /* rewrite addresses in additional section too */
-  if (!do_doctor(p, ntohs(header->arcount), header, qlen, NULL, doctored))
+  if (!do_doctor(p, ntohs(header->arcount), header, qlen, doctored))
     return 0;
   
   if (!found_soa)
@@ -534,6 +501,40 @@ static int find_soa(struct dns_header *header, size_t qlen, char *name, int *doc
   return minttl;
 }
 
+/* Print TXT reply to log */
+static int print_txt(struct dns_header *header, const size_t qlen, char *name,
+		     unsigned char *p, const int ardlen)
+{
+  unsigned char *p1 = p;
+  if (!CHECK_LEN(header, p1, qlen, ardlen))
+    return 0;
+  /* Loop over TXT payload */
+  while ((p1 - p) < ardlen)
+    {
+      unsigned int i, len = *p1;
+      unsigned char *p3 = p1;
+      if ((p1 + len - p) >= ardlen)
+	return 0; /* bad packet */
+
+      /* make counted string zero-term and sanitise */
+      for (i = 0; i < len; i++)
+	{
+	  if (!isprint((int)*(p3+1)))
+	    break;
+	  *p3 = *(p3+1);
+	  p3++;
+	}
+
+      *p3 = 0;
+      log_query(F_FORWARD | F_UPSTREAM, name, NULL, (char*)p1);
+      /* restore */
+      memmove(p1 + 1, p1, i);
+      *p1 = len;
+      p1 += len+1;
+    }
+  return 1;
+}
+
 /* Note that the following code can create CNAME chains that don't point to a real record,
    either because of lack of memory, or lack of SOA records.  These are treated by the cache code as 
    expired and cleaned out that way. 
@@ -551,15 +552,21 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 #else
   (void)ipsets; /* unused */
 #endif
-
+  int found = 0, cname_count = CNAME_CHAIN;
+  struct crec *cpp = NULL;
+  int flags = RCODE(header) == NXDOMAIN ? F_NXDOMAIN : 0;
+#ifdef HAVE_DNSSEC
+  int cname_short = 0;
+#endif
+  unsigned long cttl = ULONG_MAX, attl;
   
   cache_start_insert();
 
-  /* find_soa is needed for dns_doctor and logging side-effects, so don't call it lazily if there are any. */
+  /* find_soa is needed for dns_doctor side effects, so don't call it lazily if there are any. */
-  if (daemon->doctors || option_bool(OPT_LOG) || option_bool(OPT_DNSSEC_VALID))
+  if (daemon->doctors || option_bool(OPT_DNSSEC_VALID))
     {
       searched_soa = 1;
-      ttl = find_soa(header, qlen, name, doctored);
+      ttl = find_soa(header, qlen, doctored);
 
       if (*doctored)
 	{
@@ -574,37 +581,22 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	}
     }
   
-  /* go through the questions. */
+  namep = p = (unsigned char *)(header+1);
-  p = (unsigned char *)(header+1);
   
-  for (i = ntohs(header->qdcount); i != 0; i--)
+  if (ntohs(header->qdcount) != 1 || !extract_name(header, qlen, &p, name, 1, 4))
-    {
-      int found = 0, cname_count = CNAME_CHAIN;
-      struct crec *cpp = NULL;
-      int flags = RCODE(header) == NXDOMAIN ? F_NXDOMAIN : 0;
-#ifdef HAVE_DNSSEC
-      int cname_short = 0;
-#endif
-      unsigned long cttl = ULONG_MAX, attl;
-
-      namep = p;
-      if (!extract_name(header, qlen, &p, name, 1, 4))
     return 0; /* bad packet */
   
   GETSHORT(qtype, p); 
   GETSHORT(qclass, p);
   
   if (qclass != C_IN)
-	continue;
+    return 0;
   
   /* PTRs: we chase CNAMEs here, since we have no way to 
      represent them in the cache. */
   if (qtype == T_PTR)
     { 
-	  int name_encoding = in_arpa_name_2_addr(name, &addr);
+      int insert = 1, name_encoding = in_arpa_name_2_addr(name, &addr);
-	  
-	  if (!name_encoding)
-	    continue;
       
       if (!(flags & F_NXDOMAIN))
 	{
@@ -615,15 +607,13 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	  for (j = 0; j < ntohs(header->ancount); j++) 
 	    {
 	      int secflag = 0;
-		  unsigned char *tmp = namep;
+	      if (!(res = extract_name(header, qlen, &p1, name, 0, 10)))
-		  /* the loop body overwrites the original name, so get it back here. */
-		  if (!extract_name(header, qlen, &tmp, name, 1, 0) ||
-		      !(res = extract_name(header, qlen, &p1, name, 0, 10)))
 		return 0; /* bad packet */
 	      
 	      GETSHORT(aqtype, p1); 
 	      GETSHORT(aqclass, p1);
 	      GETLONG(attl, p1);
+	      
 	      if ((daemon->max_ttl != 0) && (attl > daemon->max_ttl) && !is_sign)
 		{
 		  (p1) -= 4;
@@ -638,14 +628,12 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	      
 	      if (aqclass == C_IN && res != 2 && (aqtype == T_CNAME || aqtype == T_PTR))
 		{
-		      if (!extract_name(header, qlen, &p1, name, 1, 0))
-			return 0;
 #ifdef HAVE_DNSSEC
 		  if (option_bool(OPT_DNSSEC_VALID) && daemon->rr_status[j] != 0)
 		    {
 		      /* validated RR anywhere in CNAME chain, don't cache. */
 		      if (cname_short || aqtype == T_CNAME)
-			    return 0;
+			insert = 0;
 		      
 		      secflag = F_DNSSECOK;
 		      /* limit TTL based on signature. */
@@ -654,6 +642,12 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		    }
 #endif
 
+		  if (aqtype == T_CNAME)
+		    log_query(secflag | F_CNAME | F_FORWARD | F_UPSTREAM, name, NULL, NULL);
+		  
+		  if (!extract_name(header, qlen, &p1, name, 1, 0))
+		    return 0;
+		  
 		  if (aqtype == T_CNAME)
 		    {
 		      if (!cname_count--)
@@ -664,8 +658,16 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		      goto cname_loop;
 		    }
 		  
-		      cache_insert(name, &addr, C_IN, now, cttl, name_encoding | secflag | F_REVERSE);
 		  found = 1; 
+		  
+		  if (!name_encoding)
+		    log_query(secflag | F_FORWARD | F_UPSTREAM, name, NULL, querystr(NULL, aqtype));
+		  else
+		    {
+		      log_query(name_encoding | secflag | F_REVERSE | F_UPSTREAM, name, &addr, NULL);
+		      if (insert)
+			cache_insert(name, &addr, C_IN, now, cttl, name_encoding | secflag | F_REVERSE);
+		    }
 		}
 
 	      p1 = endrr;
@@ -679,17 +681,24 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	  if (!searched_soa)
 	    {
 	      searched_soa = 1;
-		  ttl = find_soa(header, qlen, NULL, doctored);
+	      ttl = find_soa(header, qlen, doctored);
 	    }
-	      if (ttl)
+	  
-		cache_insert(NULL, &addr, C_IN, now, ttl, name_encoding | F_REVERSE | F_NEG | flags | (secure ?  F_DNSSECOK : 0));	
+	  flags |= F_NEG | (secure ?  F_DNSSECOK : 0);
+	  if (name_encoding && ttl)
+	    {
+	      flags |= F_REVERSE | name_encoding;
+	      cache_insert(NULL, &addr, C_IN, now, ttl, flags);
+	    }
+	  
+	  log_query(flags | F_UPSTREAM, name, &addr, NULL);
 	}
     }
   else
     {
       /* everything other than PTR */
       struct crec *newc;
-	  int addrlen = 0;
+      int addrlen = 0, insert = 1;
       
       if (qtype == T_A)
 	{
@@ -704,7 +713,7 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
       else if (qtype == T_SRV)
 	flags |= F_SRV;
       else
-	    continue;
+	insert = 0; /* NOTE: do not cache data from CNAME queries. */
       
     cname_loop1:
       if (!(p1 = skip_questions(header, qlen)))
@@ -728,8 +737,15 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	  GETSHORT(ardlen, p1);
 	  endrr = p1+ardlen;
 	  
-	      if (aqclass == C_IN && res != 2 && (aqtype == T_CNAME || aqtype == qtype))
+	  /* Not what we're looking for? */
+	  if (aqclass != C_IN || res == 2)
 	    {
+	      p1 = endrr;
+	      if (!CHECK_LEN(header, p1, qlen, 0))
+		return 0; /* bad packet */
+	      continue;
+	    }
+	  
 #ifdef HAVE_DNSSEC
 	  if (option_bool(OPT_DNSSEC_VALID) && daemon->rr_status[j] != 0)
 	    {
@@ -740,11 +756,16 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		attl = daemon->rr_status[j];
 	    }
 #endif	  
+	  
 	  if (aqtype == T_CNAME)
 	    {
 	      if (!cname_count--)
 		return 0; /* looped CNAMES */
 	      
+	      log_query(secflag | F_CNAME | F_FORWARD | F_UPSTREAM, name, NULL, NULL);
+	      
+	      if (insert)
+		{
 		  if ((newc = cache_insert(name, NULL, C_IN, now, attl, F_CNAME | F_FORWARD | secflag)))
 		    {
 		      newc->addr.cname.target.cache = NULL;
@@ -760,6 +781,7 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		  cpp = newc;
 		  if (attl < cttl)
 		    cttl = attl;
+		}
 	      
 	      namep = p1;
 	      if (!extract_name(header, qlen, &p1, name, 1, 0))
@@ -767,6 +789,13 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	      
 	      goto cname_loop1;
 	    }
+	  else if (aqtype != qtype)
+	    {
+#ifdef HAVE_DNSSEC
+	      if (!option_bool(OPT_DNSSEC_VALID) || aqtype != T_RRSIG)
+#endif
+		log_query(secflag | F_FORWARD | F_UPSTREAM, name, NULL, querystr(NULL, aqtype));
+	    }
 	  else if (!(flags & F_NXDOMAIN))
 	    {
 	      found = 1;
@@ -790,7 +819,7 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		  if (!extract_name(header, qlen, &tmp, name, 1, 0))
 		    return 0;
 		}
-		      else
+	      else if (flags & (F_IPV4 | F_IPV6))
 		{
 		  /* copy address into aligned storage */
 		  if (!CHECK_LEN(header, p1, qlen, addrlen))
@@ -822,6 +851,8 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 #endif
 		}
 	      
+	      if (insert)
+		{
 		  newc = cache_insert(name, &addr, C_IN, now, attl, flags | F_FORWARD | secflag);
 		  if (newc && cpp)
 		    {
@@ -831,6 +862,14 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 		    }
 		  cpp = NULL;
 		}
+	      
+	      if (aqtype == T_TXT)
+		{
+		  if (!print_txt(header, qlen, name, p1, ardlen))
+		    return 0;
+		}
+	      else
+		log_query(flags | F_FORWARD | secflag | F_UPSTREAM, name, &addr, querystr(NULL, aqtype));
 	    }
 	  
 	  p1 = endrr;
@@ -843,13 +882,21 @@ int extract_addresses(struct dns_header *header, size_t qlen, char *name, time_t
 	  if (!searched_soa)
 	    {
 	      searched_soa = 1;
-		  ttl = find_soa(header, qlen, NULL, doctored);
+	      ttl = find_soa(header, qlen, doctored);
 	    }
+	  
 	  /* If there's no SOA to get the TTL from, but there is a CNAME 
 	     pointing at this, inherit its TTL */
 	  if (ttl || cpp)
 	    {
-		  newc = cache_insert(name, NULL, C_IN, now, ttl ? ttl : cttl, F_FORWARD | F_NEG | flags | (secure ? F_DNSSECOK : 0));	
+	      if (ttl == 0)
+		ttl = cttl;
+	      
+	      log_query(F_UPSTREAM | F_FORWARD | F_NEG | flags | (secure ? F_DNSSECOK : 0), name, NULL, NULL);
+	      
+	      if (insert)
+		{
+		  newc = cache_insert(name, NULL, C_IN, now, ttl, F_FORWARD | F_NEG | flags | (secure ? F_DNSSECOK : 0));	
 		  if (newc && cpp)
 		    {
 		      next_uid(newc);