Summary: Profiling additions.

Keywords:

* Added an eventRun profiler hook.
* Added a store_client profiler hook, surrounding kick_reads.
  Prevented reentrancy.
* Added a storeDirCallback profiler hook.
  Refactored to reduce variable scope.
* Added a profiler hook to comm_calliocallback.
  Refactored to reduce variable scope.
* Added surrounding hooks to the read,accept,write and fill
  comm callback callers.
* Added profiling hook around HttpStateData::readReply.
* Added profiling hook around HttpStateData::processReplyData.
* Added profiling hook around StoreEntry::write.
* Added profiling hook around storeGetMemSpace.
* Added profiling hook around MemObject::write.
* Added profiling hook around storeWriteComplete.
* Added profiling hook around mem_hdr::write.

diff --git a/include/profiling.h b/include/profiling.h
index 27188fb735a7c5d3f0b1de54b151622c20e27ef6..159720433c6ae26b89750d8c23dec98ec4aa839c 100644 (file)
--- a/include/profiling.h
+++ b/include/profiling.h
@@ -105,6 +105,20 @@ typedef enum {
     XPROF_esiProcessing,
     XPROF_esiParsing,
 #endif
+    XPROF_storeClient_kickReads,
+    XPROF_eventRun,
+    XPROF_comm_calliocallback,
+    XPROF_CommReadCallbackData_callCallback,
+    XPROF_CommAcceptCallbackData_callCallback,
+    XPROF_CommWriteCallbackData_callCallback,
+    XPROF_CommFillCallbackData_callCallback,
+    XPROF_HttpStateData_readReply,
+    XPROF_HttpStateData_processReplyData,
+    XPROF_StoreEntry_write,
+    XPROF_storeGetMemSpace,
+    XPROF_MemObject_write,
+    XPROF_storeWriteComplete,
+    XPROF_mem_hdr_write,
     XPROF_LAST
 } xprof_type;
 

diff --git a/src/MemObject.cc b/src/MemObject.cc
index d846ef1b127424f668950d66e8e5958f1886fe04..73fa2cd752cc7284675aa08d248c15edb877c84d 100644 (file)
--- a/src/MemObject.cc
+++ b/src/MemObject.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: MemObject.cc,v 1.7 2003/06/24 12:30:59 robertc Exp $
+ * $Id: MemObject.cc,v 1.8 2003/06/24 12:42:25 robertc Exp $
  *
  * DEBUG: section 19    Store Memory Primitives
  * AUTHOR: Robert Collins
@@ -157,6 +157,7 @@ MemObject::unlinkRequest()
 void
 MemObject::write ( StoreIOBuffer writeBuffer, STMCB *callback, void *callbackData)
 {
+    PROF_start(MemObject_write);
     debug(19, 6) ("memWrite: offset %lu len %ld\n", (unsigned long)writeBuffer.offset, (long)writeBuffer.length);
 
     /* the offset is into the content, not the headers */
@@ -169,6 +170,7 @@ MemObject::write ( StoreIOBuffer writeBuffer, STMCB *callback, void *callbackDat
 
     assert (data_hdr.write (writeBuffer));
     callback (callbackData, writeBuffer);
+    PROF_stop(MemObject_write);
 }
 
 void

diff --git a/src/comm.cc b/src/comm.cc
index a2de29718d48c126c4449cb1d341726d6e87bf22..12d0bfd7412b48581dbde218eeb1bbce6f150838 100644 (file)
--- a/src/comm.cc
+++ b/src/comm.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: comm.cc,v 1.378 2003/06/23 14:13:03 robertc Exp $
+ * $Id: comm.cc,v 1.379 2003/06/24 12:42:25 robertc Exp $
  *
  * DEBUG: section 5     Socket Functions
  * AUTHOR: Harvest Derived
@@ -510,25 +510,33 @@ comm_add_write_callback(int fd, size_t retval, comm_err_t errcode, int xerrno)
 void
 CommReadCallbackData::callCallback()
 {
+    PROF_start(CommReadCallbackData_callCallback);
     callback.handler(result.fd, buf, retval, result.errcode, result.xerrno, callback.data);
+    PROF_stop(CommReadCallbackData_callCallback);
 }
 
 void
 CommAcceptCallbackData::callCallback()
 {
+    PROF_start(CommAcceptCallbackData_callCallback);
     callback.handler(result.fd, newfd, &details, result.errcode, result.xerrno, callback.data);
+    PROF_stop(CommAcceptCallbackData_callCallback);
 }
 
 void
 CommWriteCallbackData::callCallback()
 {
+    PROF_start(CommWriteCallbackData_callCallback);
     callback.handler(result.fd, buf, retval, result.errcode, result.xerrno, callback.data);
+    PROF_stop(CommWriteCallbackData_callCallback);
 }
 
 void
 CommFillCallbackData::callCallback()
 {
+    PROF_start(CommFillCallbackData_callCallback);
     callback.handler(result.fd, sb, result.errcode, result.xerrno, callback.data);
+    PROF_stop(CommFillCallbackData_callCallback);
 }
 
 void
@@ -561,18 +569,25 @@ void
 comm_calliocallback(void)
 {
     CommCallbackData *cio;
-    dlink_node *node;
     int oldseqnum = CommCallbackSeqnum++;
 
     /* Call our callbacks until we hit NULL or the seqnum changes */
 
-    while (CommCallbackList.head != NULL && oldseqnum != ((CommCallbackData *)CommCallbackList.head->data)->result.seqnum) {
+    /* This will likely rap other counts - again, thats ok (for now)
+     * What we should see is the total of the various callback subclasses
+     * equaling this counter.
+     * If they don't, someone has added a class but not profiled it.
+     */
+    PROF_start(comm_calliocallback);
 
-        node = (dlink_node *)CommCallbackList.head;
+    while (CommCallbackList.head != NULL && oldseqnum != ((CommCallbackData *)CommCallbackList.head->data)->result.seqnum) {
+        dlink_node *node = (dlink_node *)CommCallbackList.head;
         cio = (CommCallbackData *)node->data;
         cio->callACallback();
         cio->deleteSelf();
     }
+
+    PROF_stop(comm_calliocallback);
 }
 
 void

diff --git a/src/event.cc b/src/event.cc
index 2b57e918a8d31b7d70b781f472f4d68b21721422..89fe23b82ea5bbd94fbb55ee57236cfa96fea474 100644 (file)
--- a/src/event.cc
+++ b/src/event.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: event.cc,v 1.37 2003/05/18 00:34:49 robertc Exp $
+ * $Id: event.cc,v 1.38 2003/06/24 12:42:25 robertc Exp $
  *
  * DEBUG: section 41    Event Processing
  * AUTHOR: Henrik Nordstrom
@@ -139,6 +139,8 @@ eventRun(void)
     if (tasks->when > current_dtime)
         return;
 
+    PROF_start(eventRun);
+
     run_id++;
 
     debug(41, 5) ("eventRun: RUN ID %d\n", run_id);
@@ -173,6 +175,8 @@ eventRun(void)
 
         memFree(event, MEM_EVENT);
     }
+
+    PROF_stop(eventRun);
 }
 
 int

diff --git a/src/http.cc b/src/http.cc
index 89461127e9a43a70298cbe5ec6dec805cf190745..caad3027f66d69095f693c2a1a454f17b7dcc78c 100644 (file)
--- a/src/http.cc
+++ b/src/http.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: http.cc,v 1.415 2003/06/19 13:47:25 hno Exp $
+ * $Id: http.cc,v 1.416 2003/06/24 12:42:25 robertc Exp $
  *
  * DEBUG: section 11    Hypertext Transfer Protocol (HTTP)
  * AUTHOR: Harvest Derived
@@ -821,7 +821,9 @@ httpReadReply(int fd, char *buf, size_t len, comm_err_t flag, int xerrno,void *d
 {
     HttpStateData *httpState = static_cast<HttpStateData *>(data);
     assert (fd == httpState->fd);
+    PROF_start(HttpStateData_readReply);
     httpState->readReply (fd, buf, len, flag, xerrno, data);
+    PROF_stop(HttpStateData_readReply);
 }
 
 void
@@ -952,7 +954,9 @@ HttpStateData::readReply (int fd, char *readBuf, size_t len, comm_err_t flag, in
             }
         }
 
+        PROF_start(HttpStateData_processReplyData);
         processReplyData(buf, len);
+        PROF_stop(HttpStateData_processReplyData);
     }
 }
 

diff --git a/src/stmem.cc b/src/stmem.cc
index 176d97f314b31a05b4cd949f289208c88662e2a5..c0068f623fd886117ebfed5764dfe056e1001d8f 100644 (file)
--- a/src/stmem.cc
+++ b/src/stmem.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: stmem.cc,v 1.77 2003/06/24 12:30:59 robertc Exp $
+ * $Id: stmem.cc,v 1.78 2003/06/24 12:42:25 robertc Exp $
  *
  * DEBUG: section 19    Store Memory Primitives
  * AUTHOR: Harvest Derived
@@ -372,11 +372,13 @@ mem_hdr::nodeToRecieve(off_t offset)
 bool
 mem_hdr::write (StoreIOBuffer const &writeBuffer)
 {
+    PROF_start(mem_hdr_write);
     //    mem_node *tempNode;
     debug(19, 6) ("mem_hdr::write: offset %lu len %ld, object end %lu\n", (unsigned long)writeBuffer.offset, (long)writeBuffer.length, (unsigned long)endOffset());
 
     if (unionNotEmpty(writeBuffer)) {
         fatal("Attempt to overwrite already in-memory data\n");
+        PROF_stop(mem_hdr_write);
         return false;
     }
 
@@ -395,6 +397,7 @@ mem_hdr::write (StoreIOBuffer const &writeBuffer)
         currentSource += wrote;
     }
 
+    PROF_stop(mem_hdr_write);
     return true;
 }
 

diff --git a/src/store.cc b/src/store.cc
index 5822cb88133e0c52836dfb159299c34ad329ed7a..7618a27d35bdefa22329fe8478510af0c2911526 100644 (file)
--- a/src/store.cc
+++ b/src/store.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: store.cc,v 1.568 2003/06/23 16:49:13 wessels Exp $
+ * $Id: store.cc,v 1.569 2003/06/24 12:42:27 robertc Exp $
  *
  * DEBUG: section 20    Storage Manager
  * AUTHOR: Harvest Derived
@@ -763,12 +763,16 @@ storeExpireNow(StoreEntry * e)
 void
 storeWriteComplete (void *data, StoreIOBuffer wroteBuffer)
 {
+    PROF_start(storeWriteComplete);
     StoreEntry *e = (StoreEntry *)data;
 
-    if (EBIT_TEST(e->flags, DELAY_SENDING))
+    if (EBIT_TEST(e->flags, DELAY_SENDING)) {
+        PROF_stop(storeWriteComplete);
         return;
+    }
 
     InvokeHandlers(e);
+    PROF_stop(storeWriteComplete);
 }
 
 void
@@ -782,12 +786,16 @@ StoreEntry::write (StoreIOBuffer writeBuffer)
     if (!writeBuffer.length)
         return;
 
+    PROF_start(StoreEntry_write);
+
     debug(20, 5) ("storeWrite: writing %u bytes for '%s'\n",
                   writeBuffer.length, getMD5Text());
 
     storeGetMemSpace(writeBuffer.length);
 
     mem_obj->write (writeBuffer, storeWriteComplete, this);
+
+    PROF_stop(StoreEntry_write);
 }
 
 /* Append incoming data from a primary server to an entry. */
@@ -1095,21 +1103,26 @@ storeAbort(StoreEntry * e)
 static void
 storeGetMemSpace(int size)
 {
+    PROF_start(storeGetMemSpace);
     StoreEntry *e = NULL;
     int released = 0;
     static time_t last_check = 0;
     size_t pages_needed;
     RemovalPurgeWalker *walker;
 
-    if (squid_curtime == last_check)
+    if (squid_curtime == last_check) {
+        PROF_stop(storeGetMemSpace);
         return;
+    }
 
     last_check = squid_curtime;
 
     pages_needed = (size / SM_PAGE_SIZE) + 1;
 
-    if (mem_node::InUseCount() + pages_needed < store_pages_max)
+    if (mem_node::InUseCount() + pages_needed < store_pages_max) {
+        PROF_stop(storeGetMemSpace);
         return;
+    }
 
     debug(20, 2) ("storeGetMemSpace: Starting, need %d pages\n", pages_needed);
 
@@ -1128,6 +1141,7 @@ storeGetMemSpace(int size)
     debug(20, 3) ("storeGetMemSpace stats:\n");
     debug(20, 3) ("  %6d HOT objects\n", hot_obj_count);
     debug(20, 3) ("  %6d were released\n", released);
+    PROF_stop(storeGetMemSpace);
 }
 
 /* The maximum objects to scan for maintain storage space */

diff --git a/src/store_client.cc b/src/store_client.cc
index c7ae00562bf7670474779854d45f3f41cd755413..5f0826d13741b4d69548568a955f67033ab243b4 100644 (file)
--- a/src/store_client.cc
+++ b/src/store_client.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: store_client.cc,v 1.127 2003/05/19 23:16:48 robertc Exp $
+ * $Id: store_client.cc,v 1.128 2003/06/24 12:42:27 robertc Exp $
  *
  * DEBUG: section 90    Storage Manager Client-Side Interface
  * AUTHOR: Duane Wessels
@@ -249,10 +249,16 @@ store_client::copy(StoreEntry * anEntry,
     copyInto.length = copyRequest.length;
     copyInto.offset = copyRequest.offset;
 
+    static bool copying (false);
+    assert (!copying);
+    copying = true;
+    PROF_start(storeClient_kickReads);
     /* we might be blocking comm reads due to readahead limits
      * now we have a new offset, trigger those reads...
      */
     entry->mem_obj->kickReads();
+    PROF_stop(storeClient_kickReads);
+    copying = false;
 
     storeClientCopy2(entry, this);
 }

diff --git a/src/store_dir.cc b/src/store_dir.cc
index 76debfa0c40f5cb02d117c2ee0f3b82dbcde1721..31c65031d7e14263a1f96b378d45bd7c3163192a 100644 (file)
--- a/src/store_dir.cc
+++ b/src/store_dir.cc
@@ -1,6 +1,6 @@
 
 /*
- * $Id: store_dir.cc,v 1.145 2003/02/21 22:50:12 robertc Exp $
+ * $Id: store_dir.cc,v 1.146 2003/06/24 12:42:27 robertc Exp $
  *
  * DEBUG: section 47    Store Directory Routines
  * AUTHOR: Duane Wessels
@@ -522,23 +522,25 @@ storeDirSync(void)
 }
 
 /*
- * handle callbacks all avaliable fs'es ..
+ * handle callbacks all avaliable fs'es 
  */
 void
 storeDirCallback(void)
 {
-    int i, j;
-    SwapDir *SD;
+    int j;
     static int ndir = 0;
 
+    /* This will likely double count. Thats ok. */
+    PROF_start(storeDirCallback);
+
     do {
         j = 0;
 
-        for (i = 0; i < Config.cacheSwap.n_configured; i++) {
+        for (int i = 0; i < Config.cacheSwap.n_configured; i++) {
             if (ndir >= Config.cacheSwap.n_configured)
                 ndir = ndir % Config.cacheSwap.n_configured;
 
-            SD = INDEXSD(ndir);
+            SwapDir *SD = INDEXSD(ndir);
 
             ++ndir;
 
@@ -547,6 +549,8 @@ storeDirCallback(void)
     } while (j > 0);
 
     ndir++;
+
+    PROF_stop(storeDirCallback);
 }
 
 int