commit cde5f3228cb2f334232bbe11e6fcffd1af01bdbe
author Alan Zhang <alanjz@google.com> Wed Jul 13 12:47:06 2016 -0400
committer Alan Zhang <alanjz@google.com> Mon Jul 18 15:16:33 2016 -0400
tree 25f8c7329e32b486372a9ba769054b565aea87c5
parent 4db6944ce8c26b4599f8e7125ada8ecaa3627559

Fixed request timing miscalculation & format. Only sends request through
UDP socket when cache warming is active. Only logs request timings when
DNS timing log is active.

Change-Id: Ie41c209c1b82c7539e0f5cda625de3951bc24153

src/forward.c

diff --git a/src/forward.c b/src/forward.c
index e19b513..8004340 100644
--- a/src/forward.c
+++ b/src/forward.c
@@ -540,7 +540,7 @@
 
   if (time64 >= 0)
     {
-      int64_t milliseconds = time64/1000000;
+      double milliseconds = ((double)time64)/1000000;
       int bucket = TIMING_BUCKET_ZEROES;
       if (milliseconds < 2)        bucket = TIMING_BUCKET_1_MILLIS;
       else if (milliseconds <   5) bucket = TIMING_BUCKET_2_MILLIS;
@@ -551,8 +551,18 @@
       else  bucket = TIMING_BUCKET_500_MILLIS;
       daemon->forward_timings[bucket]++;
 
-      prettyprint_addr(&server->addr, daemon->namebuff);
-      my_syslog(LOG_INFO, _("upstream server %s handled request in %" PRId64 " ms"), daemon->namebuff, milliseconds);
+      int DNS_timing_log_active = 0;
+      FILE *fp = fopen("/config/experiments/DNSTimingLog.active", "r");
+      if (fp != NULL)
+        {
+          DNS_timing_log_active = 1;
+          fclose(fp);
+        }
+      if (DNS_timing_log_active)
+        {
+          prettyprint_addr(&server->addr, daemon->namebuff);
+          my_syslog(LOG_INFO, _("upstream server %s handled request in %.2f ms"), daemon->namebuff, milliseconds);
+        }
     }
 
 #ifdef HAVE_IPSET
@@ -1308,7 +1318,14 @@
 	log_query(F_QUERY | F_IPV6 | F_FORWARD, daemon->namebuff, 
 		  (struct all_addr *)&source_addr.in6.sin6_addr, types);
 #endif
-	  if (strcmp("127.0.0.1", daemon->addrbuff) != 0)
+	  int cache_warming_active = 0;
+	  FILE *fp = fopen("/config/experiments/CacheWarming.active", "r");
+	  if (fp != NULL)
+		{
+		  cache_warming_active = 1;
+		  fclose(fp);
+		}
+	  if (strcmp("127.0.0.1", daemon->addrbuff) != 0 && cache_warming_active)
 		{
 		  int sock;
 		  if ((sock = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0)
@@ -1319,7 +1336,7 @@
 		  char msg[128];
 		  sprintf(msg, "%lu %s", now, daemon->namebuff);
 		  if (sendto(sock, msg, strlen(msg), 0, (struct sockaddr *)&server_address,
-		  			sizeof(server_address)) < 0)
+					sizeof(server_address)) < 0)
 			{
 			  my_syslog(LOG_ERR, "failed to send message on socket: %s", strerror(errno));
 			}
@@ -1371,8 +1388,18 @@
 		    (char *)header, m, &source_addr, &dst_addr, if_index);
 	  daemon->local_answer++;
 
-	  float milliseconds = ((float)(dnsmasq_time64() - now64))/100000;
-	  my_syslog(LOG_INFO, _("handled request by cache response in %.2f ms"), milliseconds);
+	  int DNS_timing_log_active = 0;
+	  FILE *fp = fopen("/config/experiments/DNSTimingLog.active", "r");
+	  if (fp != NULL)
+		{
+		  DNS_timing_log_active = 1;
+		  fclose(fp);
+		}
+	  if (DNS_timing_log_active)
+		{
+		  double milliseconds = ((double)(dnsmasq_time64() - now64))/1000000;
+		  my_syslog(LOG_INFO, _("cache response handled request in %.2f ms"), milliseconds);
+		}
 	}
       else if (forward_query(listen->fd, &source_addr, &dst_addr, if_index,
 			     header, (size_t)n, now, NULL, ad_reqd, do_bit))