Added service time histogram for DNS (ipcache+fqdncache together)

Added statLogHistDump() for printing histograms

diff --git a/src/defines.h b/src/defines.h
index 5ba8e1b884c8c776d88b2979d2ce1f036848e912..d37484543af9b23744cad10de0c3fdb6716326fa 100644 (file)
--- a/src/defines.h
+++ b/src/defines.h
@@ -62,7 +62,6 @@
 
 #define FQDN_LOOKUP_IF_MISS    0x01
 #define FQDN_MAX_NAMES 5
-#define FQDNCACHE_AV_FACTOR 1000
 
 /*  
  *  Here are some good prime number choices.  It's important not to
@@ -101,8 +100,6 @@
 
 #define IP_LOOKUP_IF_MISS      0x01
 
-#define IPCACHE_AV_FACTOR 1000
-
 #define MAX_MIME 4096
 
 /* Mark a neighbor cache as dead if it doesn't answer this many pings */

diff --git a/src/fqdncache.cc b/src/fqdncache.cc
index 51988912c0228f5b05a63624fb7d6cbedec5cb95..15d90c9b697a0fd510a2165499f07ade56850e4c 100644 (file)
--- a/src/fqdncache.cc
+++ b/src/fqdncache.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: fqdncache.cc,v 1.80 1998/02/07 08:13:37 wessels Exp $
+ * $Id: fqdncache.cc,v 1.81 1998/02/18 22:53:59 wessels Exp $
  *
  * DEBUG: section 35    FQDN Cache
  * AUTHOR: Harvest Derived
@@ -131,7 +131,6 @@ static struct {
     int pending_hits;
     int negative_hits;
     int errors;
-    int avg_svc_time;
     int ghba_calls;            /* # calls to blocking gethostbyaddr() */
 } FqdncacheStats;
 
@@ -469,10 +468,8 @@ fqdncache_dnsHandleRead(int fd, void *data)
        fatal_dump("fqdncache_dnsHandleRead: bad status");
     if (strstr(dnsData->ip_inbuf, "$end\n")) {
        /* end of record found */
-       FqdncacheStats.avg_svc_time =
-           intAverage(FqdncacheStats.avg_svc_time,
-           tvSubMsec(dnsData->dispatch_time, current_time),
-           n, FQDNCACHE_AV_FACTOR);
+        statLogHistCount(&Counter.dns.svc_time,
+            tvSubMsec(dnsData->dispatch_time, current_time));
        if ((x = fqdncache_parsebuffer(dnsData->ip_inbuf, dnsData)) == NULL) {
            debug(35, 0) ("fqdncache_dnsHandleRead: fqdncache_parsebuffer failed?!\n");
        } else {
@@ -729,8 +726,6 @@ fqdnStats(StoreEntry * sentry)
        FqdncacheStats.misses);
     storeAppendPrintf(sentry, "Blocking calls to gethostbyaddr(): %d\n",
        FqdncacheStats.ghba_calls);
-    storeAppendPrintf(sentry, "dnsserver avg service time: %d msec\n",
-       FqdncacheStats.avg_svc_time);
     storeAppendPrintf(sentry, "FQDN Cache Contents:\n\n");
 
     next = (fqdncache_entry *) hash_first(fqdn_table);
@@ -747,6 +742,7 @@ fqdnStats(StoreEntry * sentry)
            (int) f->name_count);
        for (k = 0; k < (int) f->name_count; k++)
            storeAppendPrintf(sentry, " %s", f->names[k]);
+        storeAppendPrintf(sentry, "\n");
     }
 }
 

diff --git a/src/ipcache.cc b/src/ipcache.cc
index 5c94b8dd181af4697f0f118cb0436b0723c397a2..72f26d709c45ab0239344b169e0177a61669a4e7 100644 (file)
--- a/src/ipcache.cc
+++ b/src/ipcache.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: ipcache.cc,v 1.155 1998/02/07 08:13:39 wessels Exp $
+ * $Id: ipcache.cc,v 1.156 1998/02/18 22:54:00 wessels Exp $
  *
  * DEBUG: section 14    IP Cache
  * AUTHOR: Harvest Derived
@@ -125,7 +125,6 @@ static struct {
     int pending_hits;
     int negative_hits;
     int errors;
-    int avg_svc_time;
     int ghbn_calls;            /* # calls to blocking gethostbyname() */
     int release_locked;
 } IpcacheStats;
@@ -519,9 +518,8 @@ ipcache_dnsHandleRead(int fd, void *data)
     assert(i->status == IP_DISPATCHED);
     if (strstr(dnsData->ip_inbuf, "$end\n")) {
        /* end of record found */
-       IpcacheStats.avg_svc_time = intAverage(IpcacheStats.avg_svc_time,
-           tvSubMsec(dnsData->dispatch_time, current_time),
-           n, IPCACHE_AV_FACTOR);
+        statLogHistCount(&Counter.dns.svc_time,
+           tvSubMsec(dnsData->dispatch_time, current_time));
        if ((x = ipcache_parsebuffer(dnsData->ip_inbuf, dnsData)) == NULL) {
            debug(14, 0) ("ipcache_dnsHandleRead: ipcache_parsebuffer failed?!\n");
        } else {
@@ -775,6 +773,7 @@ ipcacheStatPrint(ipcache_entry * i, StoreEntry * sentry)
     for (k = 0; k < (int) i->addrs.count; k++)
        storeAppendPrintf(sentry, " %15s-%3s", inet_ntoa(i->addrs.in_addrs[k]),
            i->addrs.bad_mask[k] ? "BAD" : "OK ");
+    storeAppendPrintf(sentry, "\n");
 }
 
 /* process objects list */
@@ -800,8 +799,6 @@ stat_ipcache_get(StoreEntry * sentry)
        IpcacheStats.ghbn_calls);
     storeAppendPrintf(sentry, "Attempts to release locked entries: %d\n",
        IpcacheStats.release_locked);
-    storeAppendPrintf(sentry, "dnsserver avg service time: %d msec\n",
-       IpcacheStats.avg_svc_time);
     storeAppendPrintf(sentry, "pending queue length: %d\n", queue_length);
     storeAppendPrintf(sentry, "\n\n");
     storeAppendPrintf(sentry, "IP Cache Contents:\n\n");

diff --git a/src/stat.cc b/src/stat.cc
index fe18a3c66f5c28e870d9de34837c6084cbc11137..eb15195921ff1c4275ca56a5b0b56e9062feeb86 100644 (file)
--- a/src/stat.cc
+++ b/src/stat.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: stat.cc,v 1.198 1998/02/18 19:50:01 wessels Exp $
+ * $Id: stat.cc,v 1.199 1998/02/18 22:54:02 wessels Exp $
  *
  * DEBUG: section 18    Cache Manager Statistics
  * AUTHOR: Harvest Derived
@@ -119,6 +119,7 @@ static void statLogHistInit(StatLogHist *, double, double);
 static int statLogHistBin(StatLogHist *, double);
 static double statLogHistVal(StatLogHist *, double);
 static double statLogHistDeltaMedian(StatLogHist * A, StatLogHist * B);
+static void statLogHistDump(StoreEntry *sentry, StatLogHist * H);
 
 #ifdef XMALLOC_STATISTICS
 static void info_get_mallstat(int, int, StoreEntry *);
@@ -651,6 +652,8 @@ statCountersDump(StoreEntry * sentry)
        (int) f->client_http.kbytes_in.kb);
     storeAppendPrintf(sentry, "client_http.kbytes_out = %d\n",
        (int) f->client_http.kbytes_out.kb);
+    storeAppendPrintf(sentry, "client_http.svc_time histogram:\n");
+    statLogHistDump(sentry, &f->client_http.svc_time);
     storeAppendPrintf(sentry, "icp.pkts_sent = %d\n",
        f->icp.pkts_sent);
     storeAppendPrintf(sentry, "icp.pkts_recv = %d\n",
@@ -659,6 +662,10 @@ statCountersDump(StoreEntry * sentry)
        (int) f->icp.kbytes_sent.kb);
     storeAppendPrintf(sentry, "icp.kbytes_recv = %d\n",
        (int) f->icp.kbytes_recv.kb);
+    storeAppendPrintf(sentry, "icp.svc_time histogram:\n");
+    statLogHistDump(sentry, &f->icp.svc_time);
+    storeAppendPrintf(sentry, "dns.svc_time histogram:\n");
+    statLogHistDump(sentry, &f->dns.svc_time);
     storeAppendPrintf(sentry, "unlink.requests = %d\n",
        f->unlink.requests);
     storeAppendPrintf(sentry, "page_faults = %d\n",
@@ -712,6 +719,9 @@ statAvgDump(StoreEntry * sentry, int minutes)
     x = statLogHistDeltaMedian(&l->icp.svc_time, &f->icp.svc_time);
     storeAppendPrintf(sentry, "icp.median_svc_time = %f seconds\n",
        x / 1000000.0);
+    x = statLogHistDeltaMedian(&l->dns.svc_time, &f->dns.svc_time);
+    storeAppendPrintf(sentry, "dns.median_svc_time = %f seconds\n",
+       x / 1000000.0);
     storeAppendPrintf(sentry, "unlink.requests = %f/sec\n",
        XAVG(unlink.requests));
     storeAppendPrintf(sentry, "page_faults = %f/sec\n",
@@ -735,6 +745,10 @@ statCounterInit(StatCounters * C)
      * ICP svc_time hist is kept in micro-seconds; max of 1 minute.
      */
     statLogHistInit(&C->icp.svc_time, 0.0, 1000000.0 * 60.0);
+    /*
+     * DNS svc_time hist is kept in milli-seconds; max of 10 minutes.
+     */
+    statLogHistInit(&C->dns.svc_time, 0.0, 60000.0 * 10.0);
 }
 
 void
@@ -843,6 +857,7 @@ void
 statLogHistCount(StatLogHist * H, double val)
 {
     int bin = statLogHistBin(H, val);
+    assert(H->scale != 0.0);   /* make sure it got initialized */
     assert(0 <= bin && bin < STAT_LOG_HIST_BINS);
     H->bins[bin]++;
 }
@@ -915,3 +930,17 @@ statLogHistVal(StatLogHist * H, double bin)
 {
     return exp(bin / H->scale) + H->min - 1.0;
 }
+
+static void
+statLogHistDump(StoreEntry *sentry, StatLogHist * H)
+{
+       int i;
+       for (i=0; i<STAT_LOG_HIST_BINS; i++) {
+               if (H->bins[i] == 0)
+                       continue;
+               storeAppendPrintf(sentry, "\t%3d/%f\t%d\n",
+                       i,
+                       statLogHistVal(H, 0.5 + i),
+                       H->bins[i]);
+       }
+}

diff --git a/src/structs.h b/src/structs.h
index 573988970dfce94f5d4a513178a0371959d66a1d..6e8b31b8fe57de1759dd3bf2e56d5ec41fb724dd 100644 (file)
--- a/src/structs.h
+++ b/src/structs.h
@@ -959,6 +959,9 @@ struct _StatCounters {
     struct {
        int requests;
     } unlink;
+    struct {
+       StatLogHist svc_time;
+    } dns;
     int page_faults;
     int select_loops;
     double cputime;