Be less aggressive about maintaining timing information.
In particular, don't time code paths that would not otherwise
perform any system calls.

This cuts the system calls under load from about 70k/second to 3k/second.

Also a few fixes to fixarenas.c.


Reference: /n/sources/patch/applied/venti2
Date: Thu Nov 29 20:03:14 CET 2007
Signed-off-by: rsc@swtch.com

--- /sys/src/cmd/venti/srv/bloom.c	Thu Nov 29 20:01:02 2007
+++ /sys/src/cmd/venti/srv/bloom.c	Thu Nov 29 20:01:02 2007
@@ -198,7 +198,6 @@
 inbloomfilter(Bloom *b, u8int *score)
 {
 	int r;
-	uint ms;
 
 	if(b == nil || b->data == nil)
 		return 1;
@@ -206,12 +205,10 @@
 	if(ignorebloom)
 		return 1;
 	
-	ms = msec();
 	rlock(&b->lk);
 	r = _inbloomfilter(b, score);
 	runlock(&b->lk);
-	ms = ms - msec();
-	addstat2(StatBloomLookup, 1, StatBloomLookupTime, ms);
+	addstat(StatBloomLookup, 1);
 	if(r)
 		addstat(StatBloomMiss, 1);
 	else
--- /sys/src/cmd/venti/srv/dat.h	Thu Nov 29 20:01:03 2007
+++ /sys/src/cmd/venti/srv/dat.h	Thu Nov 29 20:01:02 2007
@@ -637,7 +637,6 @@
 	StatBloomLookup,
 	StatBloomOnes,
 	StatBloomBits,
-	StatBloomLookupTime,
 
 	StatApartRead,
 	StatApartReadBytes,
--- /sys/src/cmd/venti/srv/dcache.c	Thu Nov 29 20:01:04 2007
+++ /sys/src/cmd/venti/srv/dcache.c	Thu Nov 29 20:01:03 2007
@@ -134,16 +134,12 @@
 getdblock(Part *part, u64int addr, int mode)
 {
 	DBlock *b;
-	uint ms;
 	
-	ms = msec();
 	b = _getdblock(part, addr, mode, 1);
 	if(mode == OREAD || mode == ORDWR)
 		addstat(StatDcacheRead, 1);
 	if(mode == OWRITE || mode == ORDWR)
 		addstat(StatDcacheWrite, 1);
-	ms = msec() - ms;
-	addstat2(StatDcacheLookup, 1, StatDcacheLookupTime, ms);
 	return b;
 }
 
@@ -151,12 +147,15 @@
 _getdblock(Part *part, u64int addr, int mode, int load)
 {
 	DBlock *b;
-	u32int h, size;
+	u32int h, size, ms;
 
+	ms = 0;
 	trace(TraceBlock, "getdblock enter %s 0x%llux", part->name, addr);
 	size = part->blocksize;
 	if(size > dcache.size){
 		seterr(EAdmin, "block size %d too big for cache with size %d", size, dcache.size);
+		if(load)
+			addstat(StatDcacheLookup, 1);
 		return nil;
 	}
 	h = pbhash(addr);
@@ -169,7 +168,7 @@
 	for(b = dcache.heads[h]; b != nil; b = b->next){
 		if(b->part == part && b->addr == addr){
 			if(load)
-				addstat(StatDcacheHit, 1);
+				addstat2(StatDcacheHit, 1, StatDcacheLookup, 1);
 			goto found;
 		}
 	}
@@ -183,7 +182,12 @@
 		return nil;
 	}
 
-	addstat(StatDcacheMiss, 1);
+	/*
+	 * Only start timer here, on cache miss - calling msec() on plain cache hits
+	 * makes cache hits system-call bound.
+	 */
+	ms = msec();
+	addstat2(StatDcacheLookup, 1, StatDcacheMiss, 1);
 
 	b = bumpdblock();
 	if(b == nil){
@@ -272,6 +276,8 @@
 
 	b->mode = mode;
 	trace(TraceBlock, "getdblock exit");
+	if(ms)
+		addstat(StatDcacheLookupTime, msec() - ms);
 	return b;
 }
 
--- /sys/src/cmd/venti/srv/fixarenas.c	Thu Nov 29 20:01:06 2007
+++ /sys/src/cmd/venti/srv/fixarenas.c	Thu Nov 29 20:01:05 2007
@@ -661,7 +661,7 @@
 	return u32(pagein(0, Block)) == ArenaHeadMagic;
 }
 
-static int tabsizes[] = { 16*1024, 64*1024, 512*1024, };
+static int tabsizes[] = { 16*1024, 64*1024, 512*1024, 768*1024, };
 /*
  * Poke around on the disk to guess what the ArenaPart numbers are.
  */
@@ -807,8 +807,9 @@
 	 * Fmtarenas used to use 64k tab, now uses 512k tab.
 	 */
 	if(ap.arenabase == 0){
+		print("trying standard arena bases...\n");
 		for(i=0; i<nelem(tabsizes); i++){
-			ap.arenabase = ROUNDUP(PartBlank+HeadSize, ap.blocksize);
+			ap.arenabase = ROUNDUP(PartBlank+HeadSize+tabsizes[i], ap.blocksize);
 			p = pagein(ap.arenabase, Block);
 			if(u32(p) == ArenaHeadMagic)
 				break;
@@ -1554,7 +1555,7 @@
 	bcit = cibuf;
 	ecit = cibuf+ncibuf;
 	
-	smart = 1;
+	smart = 0;	/* Somehow the smart code doesn't do corrupt clumps right. */
 Again:
 	nbad = 0;
 	ci = bci;
--- /sys/src/cmd/venti/srv/httpd.c	Thu Nov 29 20:01:07 2007
+++ /sys/src/cmd/venti/srv/httpd.c	Thu Nov 29 20:01:06 2007
@@ -915,7 +915,6 @@
 	"bloomlookup",
 	"bloomones",
 	"bloombits",
-	"bloomlookuptime",
 
 	"apartread",
 	"apartreadbyte",
--- /sys/src/cmd/venti/srv/icache.c	Thu Nov 29 20:01:07 2007
+++ /sys/src/cmd/venti/srv/icache.c	Thu Nov 29 20:03:43 2007
@@ -250,6 +250,8 @@
 {
 	ISum *s;
 
+	if(!icacheprefetch)
+		return nil;
 	s = scachelookup(addr);
 	if(s == nil){
 		/* first time: make an entry in the cache but don't populate it yet */
@@ -440,32 +442,27 @@
 	return 0;
 }
 
-static int
-lookupscore_untimed(u8int score[VtScoreSize], int type, IAddr *ia)
+int
+lookupscore(u8int score[VtScoreSize], int type, IAddr *ia)
 {
+	int ms, ret;
 	IEntry d;
 
-	if(icachelookup(score, type, ia) >= 0)
+	if(icachelookup(score, type, ia) >= 0){
+		addstat(StatIcacheRead, 1);
 		return 0;
+	}
 
+	ms = msec();
 	addstat(StatIcacheFill, 1);
 	if(loadientry(mainindex, score, type, &d) < 0)
-		return -1;
-	
-	insertscore(score, &d.ia, IEClean, nil);
-	*ia = d.ia;
-	return 0;
-}
-
-int
-lookupscore(u8int score[VtScoreSize], int type, IAddr *ia)
-{
-	int ms, ret;
-	
-	ms = msec();
-	ret = lookupscore_untimed(score, type, ia);
-	ms = msec() - ms;
-	addstat2(StatIcacheRead, 1, StatIcacheReadTime, ms);
+		ret = -1;
+	else{
+		ret = 0;
+		insertscore(score, &d.ia, IEClean, nil);
+		*ia = d.ia;
+	}
+	addstat2(StatIcacheRead, 1, StatIcacheReadTime, msec() - ms);
 	return ret;
 }
 	
--- /sys/src/cmd/venti/srv/lumpcache.c	Thu Nov 29 20:01:08 2007
+++ /sys/src/cmd/venti/srv/lumpcache.c	Thu Nov 29 20:01:08 2007
@@ -71,7 +71,7 @@
 	Lump *b;
 	u32int h;
 
-	ms = msec();
+	ms = 0;
 	trace(TraceLump, "lookuplump enter");
 	
 	h = hashbits(score, HashLog);
@@ -112,6 +112,9 @@
 		CHECK(checklumpcache());
 	}
 
+	/* start timer on cache miss to avoid system call on cache hit */
+	ms = msec();
+
 	addstat(StatLcacheMiss, 1);
 	b = lumpcache.free;
 	lumpcache.free = b->next;
@@ -151,7 +154,7 @@
 	addstat(StatLumpStall, -1);
 
 	trace(TraceLump, "lookuplump exit");
-	addstat2(StatLcacheRead, 1, StatLcacheReadTime, msec()-ms);
+	addstat2(StatLcacheRead, 1, StatLcacheReadTime, ms ? msec()-ms : 0);
 	return b;
 }
 
--- /sys/src/cmd/venti/srv/stats.c	Thu Nov 29 20:01:09 2007
+++ /sys/src/cmd/venti/srv/stats.c	Thu Nov 29 20:01:09 2007
@@ -70,7 +70,6 @@
 	{ "bloom filter lookups", },
 	{ "bloom filter ones", },
 	{ "bloom filter bits", },
-	{ "bloom filter lookup time", },
 
 	{ "arena block reads", },
 	{ "arena block read bytes", },