From: wessels <>
Date: Wed, 18 Feb 1998 16:38:14 +0000 (+0000)
Subject: Added service-time histograms for client_http and icp
X-Git-Tag: SQUID_3_0_PRE1~4071
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=7ae52c25f84164f6d9bb0c9963671df30992dd8e;p=thirdparty%2Fsquid.git

Added service-time histograms for client_http and icp
---

diff --git a/src/client_side.cc b/src/client_side.cc
index db15196135..e9f6e9af38 100644
--- a/src/client_side.cc
+++ b/src/client_side.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: client_side.cc,v 1.208 1998/02/17 18:15:22 wessels Exp $
+ * $Id: client_side.cc,v 1.209 1998/02/18 09:38:14 wessels Exp $
  *
  * DEBUG: section 33    Client-side Routines
  * AUTHOR: Duane Wessels
@@ -524,6 +524,8 @@ clientUpdateCounters(clientHttpRequest * http)
     }
     if (http->request->err_type != ERR_NONE)
 	Counter.client_http.errors++;
+    statLogHistCount(&Counter.client_http.svc_time,
+	tvSubMsec(http->start, current_time));
 }
 
 static void
diff --git a/src/icp_v2.cc b/src/icp_v2.cc
index 2d0f9b114a..09a05565d9 100644
--- a/src/icp_v2.cc
+++ b/src/icp_v2.cc
@@ -50,8 +50,11 @@ icpUdpReply(int fd, void *data)
 	    kb_incr(&Counter.icp.kbytes_sent, (size_t) x);
 	}
 	UdpQueueHead = queue->next;
-	if (queue->logcode)
+	if (queue->logcode) {
 	    icpLogIcp(queue);
+	    statLogHistCount(&Counter.icp.svc_time,
+		tvSubUsec(queue->start, current_time));
+	}
 	safe_free(queue->msg);
 	safe_free(queue);
     }
diff --git a/src/protos.h b/src/protos.h
index 0e07f57947..f1d2bd8c10 100644
--- a/src/protos.h
+++ b/src/protos.h
@@ -372,6 +372,8 @@ extern void identStart(int, ConnStateData *, IDCB * callback);
 extern void statInit(void);
 extern void pconnHistCount(int, int);
 extern int statMemoryAccounted(void);
+extern void statLogHistCount(StatLogHist * H, double val);
+
 
 extern void memInit(void);
 extern void memFreeMemory(void);
diff --git a/src/stat.cc b/src/stat.cc
index 5908983029..14e0330e97 100644
--- a/src/stat.cc
+++ b/src/stat.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: stat.cc,v 1.196 1998/02/12 23:52:16 wessels Exp $
+ * $Id: stat.cc,v 1.197 1998/02/18 09:38:16 wessels Exp $
  *
  * DEBUG: section 18    Cache Manager Statistics
  * AUTHOR: Harvest Derived
@@ -114,6 +114,13 @@ static const char *describeTimestamps(const StoreEntry *);
 static void statAvgTick(void *notused);
 static void statAvgDump(StoreEntry *, int minutes);
 static void statCountersDump(StoreEntry * sentry);
+static void statLogHistInit(StatLogHist * H, int n, DTOI *, DTOD);
+static DTOI statIcpSvcTimeBin;
+static DTOI statHttpSvcTimeBin;
+static DTOD statIcpSvcTimeVal;
+static DTOD statHttpSvcTimeVal;
+static void statCounterInit(StatCounters *);
+static double statLogHistDeltaMedian(StatLogHist * A, StatLogHist * B);
 
 #ifdef XMALLOC_STATISTICS
 static void info_get_mallstat(int, int, StoreEntry *);
@@ -674,6 +681,7 @@ statAvgDump(StoreEntry * sentry, int minutes)
     StatCounters *l;
     double dt;
     double ct;
+    double x;
     assert(N_COUNT_HIST > 1);
     assert(minutes > 0);
     f = &CountHist[0];
@@ -692,6 +700,9 @@ statAvgDump(StoreEntry * sentry, int minutes)
 	XAVG(client_http.kbytes_in.kb));
     storeAppendPrintf(sentry, "client_http.kbytes_out = %f/sec\n",
 	XAVG(client_http.kbytes_out.kb));
+    x =	statLogHistDeltaMedian(&l->client_http.svc_time, &f->client_http.svc_time);
+    storeAppendPrintf(sentry, "client_http.median_svc_time = %f seconds\n",
+	x / 1000.0);
     storeAppendPrintf(sentry, "icp.pkts_sent = %f/sec\n",
 	XAVG(icp.pkts_sent));
     storeAppendPrintf(sentry, "icp.pkts_recv = %f/sec\n",
@@ -700,6 +711,9 @@ statAvgDump(StoreEntry * sentry, int minutes)
 	XAVG(icp.kbytes_sent.kb));
     storeAppendPrintf(sentry, "icp.kbytes_recv = %f/sec\n",
 	XAVG(icp.kbytes_recv.kb));
+    x = statLogHistDeltaMedian(&l->icp.svc_time, &f->icp.svc_time);
+    storeAppendPrintf(sentry, "icp.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",
@@ -711,6 +725,26 @@ statAvgDump(StoreEntry * sentry, int minutes)
     storeAppendPrintf(sentry, "cpu_usage = %f%%\n", dpercent(ct, dt));
 }
 
+static void
+statCounterInit(StatCounters * C)
+{
+    C->timestamp = current_time;
+    /*
+     * HTTP svc_time hist is kept in milli-seconds
+     */
+    statLogHistInit(&C->client_http.svc_time,
+	statHttpSvcTimeBin(3600000.0 * 3.0),
+	statHttpSvcTimeBin,
+	statHttpSvcTimeVal);
+    /*
+     * ICP svc_time hist is kept in micro-seconds
+     */
+    statLogHistInit(&C->icp.svc_time,
+	statIcpSvcTimeBin(1000000.0 * 60.0),
+	statIcpSvcTimeBin,
+	statIcpSvcTimeVal);
+}
+
 void
 statInit(void)
 {
@@ -722,8 +756,8 @@ statInit(void)
     }
     memset(CountHist, '\0', N_COUNT_HIST * sizeof(StatCounters));
     for (i = 0; i < N_COUNT_HIST; i++)
-	CountHist[i].timestamp = current_time;
-    Counter.timestamp = current_time;
+	statCounterInit(&CountHist[i]);
+    statCounterInit(&Counter);
     eventAdd("statAvgTick", statAvgTick, NULL, 60);
 }
 
@@ -804,3 +838,104 @@ statAvg60min(StoreEntry * e)
 {
     statAvgDump(e, 60);
 }
+
+static void
+statLogHistInit(StatLogHist * H, int n, DTOI * val_to_bin, DTOD * bin_to_val)
+{
+    H->nbins = n;
+    H->bins = xcalloc(n, sizeof(int));
+    H->val_to_bin = val_to_bin;
+    H->bin_to_val = bin_to_val;
+}
+
+void
+statLogHistCount(StatLogHist * H, double val)
+{
+    int bin = H->val_to_bin(val);
+    if (bin >= H->nbins)
+	bin = H->nbins - 1;
+    assert(0 <= bin && bin < H->nbins);
+    H->bins[bin]++;
+}
+
+static double
+statLogHistDeltaMedian(StatLogHist * A, StatLogHist * B)
+{
+    StatLogHist D;
+    int i;
+    int s1 = 0;
+    int h = 0;
+    int a = 0;
+    int b = 0;
+    int I;
+    int J;
+    int K;
+    double f;
+    assert(A->nbins == B->nbins);
+    memset(&D, '\0', sizeof(StatLogHist));
+    D.nbins = A->nbins;
+    D.bins = xcalloc(D.nbins, sizeof(int));
+    for (i = 0; i < A->nbins; i++) {
+	assert(B->bins[i] >= A->bins[i]);
+	D.bins[i] = B->bins[i] - A->bins[i];
+    }
+    for (i = 0; i < A->nbins; i++)
+	s1 += D.bins[i];
+    h = s1 >> 1;
+    I = 0;
+    J = A->nbins;
+    for (i = 0; i < A->nbins; i++) {
+	J = i;
+	b += D.bins[J];
+	if (a <= h && h <= b)
+	    break;
+	I = i;
+	a += D.bins[I];
+    }
+    safe_free(D.bins);
+    if (s1 == 0)
+	return 0.0;
+    if (a > h) {
+	debug(0,0)("statLogHistDeltaMedian: a=%d, h=%d\n", a, h);
+	return 0.0;
+    }
+    if(a >= b) {
+	debug(0,0)("statLogHistDeltaMedian: a=%d, b=%d\n", a, b);
+	return 0.0;
+    }
+    if(I >= J) {
+	debug(0,0)("statLogHistDeltaMedian: I=%d, J=%d\n", I, J);
+	return 0.0;
+    }
+    f = (h - a) / (b - a);
+    K = f * (double) (J - I) + I;
+    return A->bin_to_val(K);
+}
+
+static int
+statHttpSvcTimeBin(double v)
+{
+    if (v <= 1.0)
+	return 0;
+    return (int) (log(v) * 10.0 + 0.5);
+}
+
+static int
+statIcpSvcTimeBin(double v)
+{
+    if (v <= 1.0)
+	return 0;
+    return (int) (log(v) * 50.0 + 0.5);
+}
+
+static double
+statHttpSvcTimeVal(double bin)
+{
+    return exp(bin / 10.0);
+}
+
+static double
+statIcpSvcTimeVal(double bin)
+{
+    return exp(bin / 50.0);
+}
diff --git a/src/store_rebuild.cc b/src/store_rebuild.cc
index 256c2a67a8..d6ff4cbc78 100644
--- a/src/store_rebuild.cc
+++ b/src/store_rebuild.cc
@@ -356,7 +356,10 @@ storeRebuildADirectory(void *unused)
     if (count < 0) {
 	xfree(d);
     } else {
-	for (D = &RebuildState.rebuild_dir; *D; D = &(*D)->next);
+	for (D = &RebuildState.rebuild_dir; *D; D = &(*D)->next) {
+		debug(0,0)("D=%p\n", D);
+		debug(0,0)("*D=%p\n", *D);
+	}
 	*D = d;
 	d->next = NULL;
     }
diff --git a/src/structs.h b/src/structs.h
index 156ac76f8f..2353f0d54c 100644
--- a/src/structs.h
+++ b/src/structs.h
@@ -924,6 +924,13 @@ struct _ErrorState {
     char *request_hdrs;
 };
 
+struct _StatLogHist {
+    int nbins;
+    int *bins;
+    DTOI *val_to_bin;
+    DTOD *bin_to_val;
+};
+
 struct _StatCounters {
     struct {
 	int requests;
@@ -932,7 +939,14 @@ struct _StatCounters {
 	kb_t kbytes_in;
 	kb_t kbytes_out;
 	kb_t hit_kbytes_out;
+	StatLogHist svc_time;
     } client_http;
+    struct {
+	int requests;
+	int errors;
+	kb_t kbytes_in;
+	kb_t kbytes_out;
+    } server;
     struct {
 	int pkts_sent;
 	int pkts_recv;
@@ -940,6 +954,7 @@ struct _StatCounters {
 	int hits_recv;
 	kb_t kbytes_sent;
 	kb_t kbytes_recv;
+	StatLogHist svc_time;
     } icp;
     struct {
 	int requests;
diff --git a/src/typedefs.h b/src/typedefs.h
index dc5e04672a..f4ee5a823f 100644
--- a/src/typedefs.h
+++ b/src/typedefs.h
@@ -79,6 +79,7 @@ typedef struct _StatCounters StatCounters;
 typedef struct _tlv tlv;
 typedef struct _storeSwapLogData storeSwapLogData;
 typedef struct _cacheSwap cacheSwap;
+typedef struct _StatLogHist StatLogHist;
 
 /* define AIOCB even without USE_ASYNC_IO */
 typedef void AIOCB(void *, int aio_return, int aio_errno);
@@ -100,6 +101,8 @@ typedef void PSC(peer *, void *);
 typedef void RH(void *data, char *);
 typedef void UH(void *data, wordlist *);
 typedef int DEFER(int fd, void *data);
+typedef int DTOI(double);
+typedef double DTOD(double);
 
 typedef void SIH(int fd, void *);	/* swap in */
 typedef int QS(const void *, const void *);	/* qsort */