Adding optional support for critical path detection(currently disabled by default...
authorIsaac Dooley <idooley2@illinois.edu>
Thu, 4 Dec 2008 00:22:35 +0000 (00:22 +0000)
committerIsaac Dooley <idooley2@illinois.edu>
Thu, 4 Dec 2008 00:22:35 +0000 (00:22 +0000)
src/ck-core/ck.C
src/ck-core/cklocation.C
src/ck-core/envelope.h
src/ck-core/msgalloc.C
src/ck-cp/controlPoints.C
src/ck-cp/controlPoints.ci
src/ck-cp/controlPoints.h
src/ck-perf/trace-controlPoints.C
src/ck-perf/trace-controlPoints.h
src/scripts/Make.depends

index 3673107e71c3172af41e14ce48a3212aee3a27f8..9708d31fdae92dc2d3ebd6903a0483553aec9d4d 100644 (file)
@@ -22,6 +22,49 @@ clients, including the rest of Charm++, are actually C++.
 
 #define CK_MSG_SKIP_OR_IMM    (CK_MSG_EXPEDITED | CK_MSG_IMMEDIATE)
 
+
+
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+// store the pointer to the currently executing msg
+// see envelope.h
+// TODO: convert to CkPv
+envelope * currentlyExecutingMsg = NULL;
+bool thisMethodSentAMessage = false;
+double timeEntryMethodStarted = 0.0;
+
+void resetCricitalPathDetection(){
+  CkAbort("shouldn't be called anymore. Deprecated");
+  
+  // First we should register this currently executing message as a path, because it is likely an important one to consider.
+  registerTerminalEntryMethod();
+
+  // Print the Critical path known to this PE
+  if(CkMyPe() == 0){
+    CkPrintf("[pe=%d] Critical paths discovered on this pe (in resetCriticalPathCounts() ):\n", CkMyPe());
+    printPECriticalPath();
+  }
+  
+  // Reset the counts for the critical path on this PE
+  resetPECriticalPath();
+  
+  // Reset the counts for the currently executing message
+  resetThisEntryPath();
+  
+}
+
+void resetThisEntryPath(){
+  // Reset the counts for the currently executing message
+  if(currentlyExecutingMsg != NULL){
+    currentlyExecutingMsg->resetEpIdxHistory();
+  }
+}
+
+
+#endif
+
+
 VidBlock::VidBlock() { state = UNFILLED; msgQ = new PtrQ(); _MEMCHECK(msgQ); }
 
 int CMessage_CkMessage::__idx=-1;
@@ -444,6 +487,24 @@ static inline void _invokeEntryNoTrace(int epIdx,envelope *env,void *obj)
 
 static inline void _invokeEntry(int epIdx,envelope *env,void *obj)
 {
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  // store the pointer to the currently executing msg
+  currentlyExecutingMsg = env; 
+  thisMethodSentAMessage = false;
+
+  // Increase the counts for the entry that we are about to execute
+  env->updateCounts();
+  
+  // Increase the reference count for the message so the user won't delete it
+  CmiReference(env);
+  timeEntryMethodStarted = CmiWallTimer();
+
+#endif
+
+
+
 #ifndef CMK_OPTIMIZE /* Consider tracing: */
   if (_entryTable[epIdx]->traceEnabled) {
     _TRACE_BEGIN_EXECUTE(env);
@@ -453,6 +514,23 @@ static inline void _invokeEntry(int epIdx,envelope *env,void *obj)
   else
 #endif
     _invokeEntryNoTrace(epIdx,env,obj);
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+ double timeEntryMethodEnded = CmiWallTimer();
+ env->pathHistory.incrementTotalTime(timeEntryMethodEnded-timeEntryMethodStarted);
+ if(!thisMethodSentAMessage){
+    registerTerminalEntryMethod();
+  }
+
+  CmiFree(env); // free the message, because we incremented its reference count above
+
+  // set to NULL the pointer to the currently executing msg
+  currentlyExecutingMsg = NULL; 
+  //  CkPrintf("This entry method is %s\n", (int)thisMethodSentAMessage?"non-terminal":"terminal");
+
+#endif
+
 }
 
 /********************* Creation ********************/
index 77db978f37236ba5b65a5b733b3ea8179fb8f4cb..fc4bd4843242e1bb4777e1d3a9bcfe548860aa24 100644 (file)
@@ -1004,13 +1004,17 @@ void CkMigratable::timingAfterCall(LDObjHandle objHandle,int *objstopped){
 }
 /****************************************************************************/
 
+
 CmiBool CkLocRec_local::invokeEntry(CkMigratable *obj,void *msg,
        int epIdx,CmiBool doFree) 
 {
+
        DEBS((AA"   Invoking entry %d on element %s\n"AB,epIdx,idx2str(idx)));
        CmiBool isDeleted=CmiFalse; //Enables us to detect deletion during processing
        deletedMarker=&isDeleted;
        startTiming();
+
+
 #ifndef CMK_OPTIMIZE
        if (msg) { /* Tracing: */
                envelope *env=UsrToEnv(msg);
@@ -1024,7 +1028,8 @@ CmiBool CkLocRec_local::invokeEntry(CkMigratable *obj,void *msg,
           CkDeliverMessageFree(epIdx,msg,obj);
        else /* !doFree */
           CkDeliverMessageReadonly(epIdx,msg,obj);
-       
+
+
 #ifndef CMK_OPTIMIZE
        if (msg) { /* Tracing: */
                if (_entryTable[epIdx]->traceEnabled)
@@ -1042,6 +1047,7 @@ CmiBool CkLocRec_local::invokeEntry(CkMigratable *obj,void *msg,
 
 CmiBool CkLocRec_local::deliver(CkArrayMessage *msg,CkDeliver_t type,int opts)
 {
+
        if (type==CkDeliver_queue) { /*Send via the message queue */
                if (opts & CK_MSG_KEEP)
                        msg = (CkArrayMessage *)CkCopyMsg((void **)&msg);
@@ -1082,7 +1088,47 @@ CmiBool CkLocRec_local::deliver(CkArrayMessage *msg,CkDeliver_t type,int opts)
                CpvAccess(CkGridObject) = obj;
 #endif
 
-               CmiBool status = invokeEntry(obj,(void *)msg,msg->array_ep(),doFree);
+
+
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+       // store the pointer to the currently executing msg
+       envelope *env = UsrToEnv(msg);
+       currentlyExecutingMsg = env; 
+       thisMethodSentAMessage = false;
+
+       // Increase the counts for the entry that we are about to execute
+       env->updateCounts();
+       
+       // Increase the reference count for the message so the user won't delete it
+       CmiReference(env);
+
+       // Store the current time
+       timeEntryMethodStarted = CmiWallTimer();
+#endif
+
+       CmiBool status = invokeEntry(obj,(void *)msg,msg->array_ep(),doFree);
+       
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  double timeEntryMethodEnded = CmiWallTimer();
+  env->pathHistory.incrementTotalTime(timeEntryMethodEnded-timeEntryMethodStarted);
+  if(!thisMethodSentAMessage){
+    registerTerminalEntryMethod();
+  }
+
+  CmiFree(env); // free the message, because we incremented its reference count above
+
+  // set to NULL the pointer to the currently executing msg
+  currentlyExecutingMsg = NULL;
+  //  CkPrintf("This entry method is %s\n", (int)thisMethodSentAMessage?"non-terminal":"terminal");
+#endif
+
+
+
+
+
 
 #if CMK_GRID_QUEUE_AVAILABLE
                CpvAccess(CkGridObject) = NULL;
@@ -1092,6 +1138,9 @@ CmiBool CkLocRec_local::deliver(CkArrayMessage *msg,CkDeliver_t type,int opts)
 #endif
                return status;
        }
+
+
+
 }
 
 #if CMK_LBDB_ON
@@ -1644,6 +1693,8 @@ void CkLocMgr::deliver(CkMessage *m,CkDeliver_t type,int opts) {
        DEBS((AA"deliver \n"AB));
        CK_MAGICNUMBER_CHECK
        CkArrayMessage *msg=(CkArrayMessage *)m;
+
+
        const CkArrayIndex &idx=msg->array_index();
        DEBS((AA"deliver %s\n"AB,idx2str(idx)));
        if (type==CkDeliver_queue)
@@ -1757,6 +1808,7 @@ void CkLocMgr::deliver(CkMessage *m,CkDeliver_t type,int opts) {
                        msg = (CkArrayMessage *)CkCopyMsg((void **)&msg);
                deliverUnknown(msg,type,opts);
        }
+
 }
 
 /// This index is not hashed-- somehow figure out what to do.
index e0dec79706a94255e30f14d00c61b664197f9553..676d0307b9de3c694b168acb6dabc496c6f49cef 100644 (file)
 // silly ancient name: for backward compatability only.
 #define PW(x) CkPriobitsToInts(x) 
 
+
+
+// #define USE_CRITICAL_PATH_HEADER_ARRAY
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+// This critical path detection is still experimental
+// Added by Isaac (Dec 2008)
+
+// stores the pointer to the currently executing msg
+// used in cklocation.C, ck.C
+// TODO: convert to CkPv
+
+extern envelope * currentlyExecutingMsg;
+extern bool thisMethodSentAMessage;
+extern double timeEntryMethodStarted;
+
+// The methods provided by the control point framework to access 
+// the most Critical path seen by this PE. 
+// These ought not to be called by the user program.
+// (defined in controlPoints.C)
+extern void resetPECriticalPath();
+extern void printPECriticalPath();
+extern void registerTerminalEntryMethod();
+
+// Reset the counts for the currently executing message, 
+// and also reset the PE's critical path detection
+// To be called by the user program
+extern void resetCricitalPathDetection();
+
+// Reset the counts for the currently executing message
+extern void resetThisEntryPath();
+
+#endif
+
+
+/** static sizes for arrays in PathHistory objects */
+#define numEpIdxs 150
+#define numArrayIds 20
+
+/** A class that is used to track the entry points and other information 
+    about a critical path as a charm++ program executes.
+
+    This class won't do useful things unless USE_CRITICAL_PATH_HEADER_ARRAY is defined
+
+*/
+class PathHistory {
+ private:
+  int epIdxCount[numEpIdxs];
+  int arrayIdxCount[numArrayIds];
+  double totalTime;
+
+ public:
+  
+  const int* getEpIdxCount(){
+    return epIdxCount;
+  }
+  
+  const int* getArrayIdxCount(){
+    return arrayIdxCount;
+  }
+
+  int getEpIdxCount(int i) const {
+    return epIdxCount[i];
+  }
+  
+  int getArrayIdxCount(int i) const {
+    return arrayIdxCount[i];
+  }
+
+
+  double getTotalTime() const{
+    return totalTime;
+  }
+
+  
+  PathHistory(){
+    reset();
+  }
+
+  void pup(PUP::er &p) {
+    for(int i=0;i<numEpIdxs;i++)
+      p|epIdxCount[i];
+    for(int i=0;i<numArrayIds;i++)
+      p|arrayIdxCount[i];
+    p | totalTime;
+  } 
+  
+  double getTime(){
+    return totalTime;
+  }
+  
+  void reset(){
+    // CkPrintf("reset() currentlyExecutingMsg=%p\n", currentlyExecutingMsg);
+    
+    totalTime = 0.0;
+    
+    for(int i=0;i<numEpIdxs;i++){
+      epIdxCount[i] = 0;
+    }
+    for(int i=0;i<numArrayIds;i++){
+      arrayIdxCount[i]=0;
+    }
+  }
+  
+  int updateMax(const PathHistory & other){
+    if(other.totalTime > totalTime){
+      //         CkPrintf("[%d] Found a longer terminal path:\n", CkMyPe());
+      //         other.print();
+      
+      totalTime = other.totalTime;
+      for(int i=0;i<numEpIdxs;i++){
+       epIdxCount[i] = other.epIdxCount[i];
+      }
+      for(int i=0;i<numArrayIds;i++){
+       arrayIdxCount[i]=other.arrayIdxCount[i];
+      }
+      return 1;
+    }
+    return 0;
+  }
+  
+  
+  void print() const {
+    CkPrintf("Critical Path Time=%lf : ", (double)totalTime);
+    for(int i=0;i<numEpIdxs;i++){
+      if(epIdxCount[i]>0){
+       CkPrintf("EP %d count=%d : ", i, (int)epIdxCount[i]);
+      }
+    }
+    for(int i=0;i<numArrayIds;i++){
+      if(arrayIdxCount[i]>0){
+       CkPrintf("Array %d count=%d : ", i, (int)arrayIdxCount[i]);
+      }
+    }
+    CkPrintf("\n");
+  }
+  
+  void incrementTotalTime(double time){
+    totalTime += time;
+  }
+  
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  void createPath(PathHistory *parentPath){
+    // Note that we are likely sending a message
+    // FIXME: (this should be moved to the actual send point)
+    thisMethodSentAMessage = true;
+    double timeNow = CmiWallTimer();
+    
+    if(parentPath != NULL){
+      //         CkPrintf("createPath() totalTime = %lf + %lf\n",(double)currentlyExecutingMsg->pathHistory.totalTime, (double)timeNow-timeEntryMethodStarted);
+      totalTime = parentPath->totalTime + (timeNow-timeEntryMethodStarted);
+      
+      for(int i=0;i<numEpIdxs;i++){
+       epIdxCount[i] = parentPath->epIdxCount[i];
+      }
+      for(int i=0;i<numArrayIds;i++){
+       arrayIdxCount[i] = parentPath->arrayIdxCount[i];
+      }
+      
+    }
+    else {
+      totalTime = 0.0;
+      
+      for(int i=0;i<numEpIdxs;i++){
+       epIdxCount[i] = 0;
+      } 
+      for(int i=0;i<numArrayIds;i++){
+       arrayIdxCount[i]=0;
+      }
+    }
+       
+  }
+#endif
+      
+  void incrementEpIdxCount(int ep){
+    epIdxCount[ep]++;
+  }
+
+  void incrementArrayIdxCount(int arr){
+    arrayIdxCount[arr]++;
+  }
+      
+};
+
+
+
+
 /**
  This set of message type (mtype) constants
  defines the basic class of charm++ message.
@@ -74,10 +262,17 @@ what to do with it on the receiving side.
 
 A Charm++ message's memory layout has the 
 Charm envelope ("envelope" class) first, which includes
-a Converse envelope as its first field.  After the 
+a Converse envelope as its **first** field.  After the 
 Charm envelope is a variable-length amount of user 
 data, and finally the priority data stored as ints.
 
+The converse layers modify the beginning of the envelope
+without referencing the "envelope::core" member. The
+envelope is treated as a void*, and the first 
+CmiReservedHeaderSize bytes are available for the 
+converse functions. Therefore, do not put any members
+at the beginning of the envelope class.
+
 <pre>
  Envelope pointer        \
  Converse message pointer -> [ [ Converse envelope ]       ]
@@ -106,7 +301,7 @@ user message pointers.
 */
 class envelope {
   private:
-    /// Converse message envelope
+    /// Converse message envelope, Must be first field in this class
     char   core[CmiReservedHeaderSize];
 public:
  /**
@@ -279,6 +474,41 @@ private:
     int *getsetArrayListenerData(void) {return type.array.listenerData;}
     CkArrayIndexMax &getsetArrayIndex(void) 
        {return *(CkArrayIndexMax *)&type.array.index;}
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+ public:
+
+    /// The information regarding the entry methods that executed along the path to this one.
+    PathHistory pathHistory;
+
+    void resetEpIdxHistory(){
+      pathHistory.reset();
+    }
+
+    /** Fill in the values for the path When creating a message in an entry method, 
+       deriving the values from the entry method's creation message */
+    void setEpIdxHistory(){
+      if(currentlyExecutingMsg){
+       pathHistory.createPath(& currentlyExecutingMsg->pathHistory);
+      } else {
+       pathHistory.createPath(NULL);
+      }
+    }
+
+    void printEpIdxHistory(){
+      pathHistory.print();
+    }
+      
+    /// Called when beginning to execute an entry method 
+    void updateCounts(){
+      pathHistory.incrementEpIdxCount(getEpIdx());
+      if(attribs.mtype==ForArrayEltMsg){
+       CkGroupID &a = type.array.arr;
+       pathHistory.incrementArrayIdxCount(a.idx);
+      }
+    }
+#endif
+
 };
 
 inline envelope *UsrToEnv(const void *const msg) {
@@ -317,4 +547,6 @@ public:
 
 CkpvExtern(MsgPool*, _msgPool);
 
+
+
 #endif
index 467c58c9c844e218abc3435b128078e7759c2156..8b8edece3f308418bcbf15d9d4fb70f503c9fc07 100644 (file)
@@ -29,6 +29,11 @@ void* CkAllocMsg(int msgIdx, int msgBytes, int prioBits)
 
   env->setQueueing(_defaultQueueing);
   env->setMsgIdx(msgIdx);
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  env->setEpIdxHistory();
+#endif
+
   return EnvToUsr(env);
 }
 
@@ -46,6 +51,11 @@ void* CkAllocBuffer(void *msg, int bufsize)
   packbuf->setTotalsize(size);
   packbuf->setPacked(!env->isPacked());
   CmiMemcpy(packbuf->getPrioPtr(), env->getPrioPtr(), packbuf->getPrioBytes());
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  env->setEpIdxHistory();
+#endif
+
   return EnvToUsr(packbuf);;
 }
 
@@ -108,6 +118,9 @@ CkMarshallMsg *CkAllocateMarshallMsgNoninline(int size,const CkEntryOptions *opt
        CmiMemcpy(env->getPrioPtr(),opts->getPriorityPtr(),env->getPrioBytes());
        //Set the message's queueing type
        env->setQueueing((unsigned char)opts->getQueueing());
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+       env->setEpIdxHistory();
+#endif
        return m;
 }
 
index 00bdb32a1ddb62683ce41b86d92642e81678a8a8..dd710a68f5d19afe7434ff3752b3fb9864d9e0b0 100644 (file)
 #include <sys/time.h>
 
 #include "ControlPoints.decl.h"
-
+#include "trace-controlPoints.h"
 #include "LBDatabase.h"
 #include "controlPoints.h"
 
+
 using namespace std;
 
-#define CONTROL_POINT_PERIOD 8000
+#define CONTROL_POINT_SAMPLE_PERIOD 4000
+#define NUM_SAMPLES_BEFORE_TRANSISTION 5
 #define OPTIMIZER_TRANSITION 5
 
 static void periodicProcessControlPoints(void* ptr, double currWallTime);
@@ -30,13 +32,73 @@ static void periodicProcessControlPoints(void* ptr, double currWallTime);
 /* readonly */ int random_seed;
 
 
+// A reduction to take min/sum/avg
+CkReduction::reducerType idleTimeReductionType;
+CkReductionMsg *idleTimeReduction(int nMsg,CkReductionMsg **msgs){
+  double ret[3];
+  if(nMsg > 0){
+    CkAssert(msgs[0]->getSize()==3*sizeof(double));
+    double *m=(double *)msgs[0]->getData();
+    ret[0]=m[0];
+    ret[1]=m[1];
+    ret[2]=m[2];
+  }
+  for (int i=1;i<nMsg;i++) {
+    CkAssert(msgs[i]->getSize()==3*sizeof(double));
+    double *m=(double *)msgs[i]->getData();
+    ret[0]=min(ret[0],m[0]);
+    ret[1]+=m[1];
+    ret[2]=max(ret[2],m[2]);
+  }  
+  return CkReductionMsg::buildNew(3*sizeof(double),ret);   
+}
+/*initcall*/ void registerIdleTimeReduction(void) {
+  idleTimeReductionType=CkReduction::addReducer(idleTimeReduction);
+}
+
+
+
+
+class idleTimeContainer {
+public:
+  double min;
+  double avg;
+  double max;
+  
+  idleTimeContainer(){
+    min = -1.0;
+    max = -1.0;
+    avg = -1.0;
+  }
+  
+  bool isValid() const{
+    return (min >= 0.0 && avg >= min && max >= avg && max <= 1.0);
+  }
+  
+  void print() const{
+    if(isValid())
+      CkPrintf("[%d] Idle Time is Min=%.2lf%% Avg=%.2lf%% Max=%.2lf%%\n", CkMyPe(), min*100.0, avg*100.0, max*100.0);    
+    else
+      CkPrintf("[%d] Idle Time is invalid\n", CkMyPe(), min*100.0, avg*100.0, max*100.0);
+  }
+  
+}; 
+
+
+
+
 class instrumentedPhase {
 public:
   std::map<string,int> controlPoints; // The control point values for this phase(don't vary within the phase)
-  std::multiset<double> times;  // A list of times observed for iterations in this phase
+  std::vector<double> times;  // A list of times observed for iterations in this phase
+
+  std::vector<PathHistory> criticalPaths;
+
   
   int memoryUsageMB;
-  
+
+  idleTimeContainer idleTime;
+
   instrumentedPhase(){
     memoryUsageMB = -1;
   }
@@ -44,6 +106,7 @@ public:
   void clear(){
     controlPoints.clear();
     times.clear();
+    criticalPaths.clear();
   }
 
   // Provide a previously computed value, or a value from a previous run
@@ -262,7 +325,7 @@ public:
        s << "     ";
 
        // Print the times
-       std::multiset<double>::iterator titer;
+       std::vector<double>::iterator titer;
        for(titer = runiter->times.begin(); titer != runiter->times.end(); titer++){
          s << *titer << " ";
        }
@@ -311,7 +374,7 @@ public:
        int phase_count = 0;
 
        // iterate over all times for this control point configuration
-       std::multiset<double>::iterator titer;
+       std::vector<double>::iterator titer;
        for(titer = iter->times.begin(); titer != iter->times.end(); titer++){
          total_count++;
          total_time += *titer;
@@ -342,7 +405,7 @@ public:
     double sumx=0.0;
     for(iter = phases.begin();iter!=phases.end();iter++){
       if(iter->hasValidControlPointValues()){
-       std::multiset<double>::iterator titer;
+       std::vector<double>::iterator titer;
        for(titer = iter->times.begin(); titer != iter->times.end(); titer++){
          sumx += (avg - *titer)*(avg - *titer);
        } 
@@ -415,6 +478,10 @@ public:
 
   std::set<string> staticControlPoints;
 
+  std::map<string, std::set<int> > affectsPrioritiesEP;
+  std::map<string, std::set<int> > affectsPrioritiesArray;
+
+
 
   CkCallback granularityCallback;
   bool haveGranularityCallback;
@@ -423,9 +490,17 @@ public:
   int phase_id;
 
   bool alreadyRequestedMemoryUsage;
+  bool alreadyRequestedIdleTime;
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  PathHistory maxTerminalPathHistory;
+#endif
 
   controlPointManager(){
-    alreadyRequestedMemoryUsage = false;
+
+    alreadyRequestedMemoryUsage = false;   
+    alreadyRequestedIdleTime = false;
     
     dataFilename = (char*)malloc(128);
     sprintf(dataFilename, "controlPointData.txt");
@@ -445,7 +520,7 @@ public:
     }
     
     if(CkMyPe() == 0)
-      CcdCallFnAfterOnPE((CcdVoidFn)periodicProcessControlPoints, (void*)NULL, CONTROL_POINT_PERIOD, CkMyPe());
+      CcdCallFnAfterOnPE((CcdVoidFn)periodicProcessControlPoints, (void*)NULL, CONTROL_POINT_SAMPLE_PERIOD, CkMyPe());
 
   }
   
@@ -507,7 +582,7 @@ public:
       double time;
 
       while(iss >> time){
-       ips.times.insert(time);
+       ips.times.push_back(time);
 #if DEBUG > 5
        CkPrintf("read time %lf from file\n", time);
 #endif
@@ -542,9 +617,10 @@ public:
   /// Called periodically by the runtime to handle the control points
   /// Currently called on each PE
   void processControlPoints(){
-#if DEBUG
-    CkPrintf("[%d] processControlPoints()\n", CkMyPe());
-#endif
+
+    CkPrintf("[%d] processControlPoints() haveGranularityCallback=%d frameworkShouldAdvancePhase=%d\n", CkMyPe(), (int)haveGranularityCallback, (int)frameworkShouldAdvancePhase);
+
+    
     if(haveGranularityCallback){
       if(frameworkShouldAdvancePhase){
        gotoNextPhase();        
@@ -553,17 +629,95 @@ public:
       controlPointMsg *msg = new(0) controlPointMsg;
       granularityCallback.send(msg); 
     }
-
-
+    
+    
     if(CkMyPe() == 0 && !alreadyRequestedMemoryUsage){
       alreadyRequestedMemoryUsage = true;
       CkCallback *cb = new CkCallback(CkIndex_controlPointManager::gatherMemoryUsage(NULL), 0, thisProxy);
-      //      thisProxy.requestMemoryUsage(*cb);
+      // thisProxy.requestMemoryUsage(*cb);
       delete cb;
     }
+    
+    if(CkMyPe() == 0 && !alreadyRequestedIdleTime){
+      alreadyRequestedIdleTime = true;
+      CkCallback *cb = new CkCallback(CkIndex_controlPointManager::gatherIdleTime(NULL), 0, thisProxy);
+      thisProxy.requestIdleTime(*cb);
+      delete cb;
+    }
+    
+    
+    int s = allData.phases.size();
+    
+    CkPrintf("\n\nExamining critical paths and priorities and idle times (num phases=%d)\n", s );
+    
+    for(int p=0;p<s;++p){
+      const instrumentedPhase &phase = allData.phases[p];
+      const idleTimeContainer &idle = phase.idleTime;
+      vector<PathHistory> const &criticalPaths = phase.criticalPaths;
+      vector<double> const &times = phase.times;
+
+      CkPrintf("Phase %d:\n", p);
+      idle.print();
+      CkPrintf("critical paths: (* affected by control point)\n");
+      for(int i=0;i<criticalPaths.size(); i++){
+       // If affected by a control point
+       //      criticalPaths[i].print();
+
+
+       CkPrintf("Critical Path Time=%lf : ", (double)criticalPaths[i].getTotalTime());
+       for(int e=0;e<numEpIdxs;e++){
+
+         if(criticalPaths[i].getEpIdxCount(e)>0){
+           if(controlPointAffectsThisEP(e))
+             CkPrintf("* ");
+           CkPrintf("EP %d count=%d : ", e, (int)criticalPaths[i].getEpIdxCount(e));
+         }
+       }
+       for(int a=0;a<numArrayIds;a++){
+         if(criticalPaths[i].getArrayIdxCount(a)>0){
+           if(controlPointAffectsThisArray(a))
+             CkPrintf("* ");
+           CkPrintf("Array %d count=%d : ", a, (int)criticalPaths[i].getArrayIdxCount(a));
+         }
+       }
+       CkPrintf("\n");
+       
+
+      }
+      CkPrintf("Timings:\n");
+      for(int i=0;i<times.size(); i++){
+       CkPrintf("%lf ", times[i]);
+      }
+      CkPrintf("\n");
+
+    }
+    
+    CkPrintf("\n\n");
 
   }
   
+  bool controlPointAffectsThisEP(int ep){
+    std::map<string, std::set<int> >::iterator iter;
+    for(iter=affectsPrioritiesEP.begin(); iter!= affectsPrioritiesEP.end(); ++iter){
+      if(iter->second.count(ep)>0){
+       return true;
+      }
+    }
+    return false;    
+  }
+  
+  
+  bool controlPointAffectsThisArray(int array){
+    std::map<string, std::set<int> >::iterator iter;
+    for(iter=affectsPrioritiesArray.begin(); iter!= affectsPrioritiesArray.end(); ++iter){
+      if(iter->second.count(array)>0){
+       return true;
+      }
+    }
+    return false;   
+  }
+  
   instrumentedPhase *previousPhaseData(){
     int s = allData.phases.size();
     if(s >= 1 && phase_id > 0) {
@@ -609,7 +763,7 @@ public:
     
     CkPrintf("Now in phase %d\n", phase_id);
     
-    // save the timing information from this phase
+    // save a copy of the timing information from this phase
     allData.phases.push_back(thisPhaseData);
         
     // clear the timing information that will be used for the next phase
@@ -619,11 +773,64 @@ public:
 
   // The application can set the instrumented time for this phase
   void setTiming(double time){
-     thisPhaseData.times.insert(time);
+    thisPhaseData.times.push_back(time);
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+       
+    // First we should register this currently executing message as a path, because it is likely an important one to consider.
+    registerTerminalEntryMethod();
+    
+    // save the critical path for this phase
+    thisPhaseData.criticalPaths.push_back(maxTerminalPathHistory);
+    maxTerminalPathHistory.reset();
+    
+    
+    // Reset the counts for the currently executing message
+    resetThisEntryPath();
+    
+    
+#endif
+    
+  }
+  
+  // Entry method called on all PEs to request memory usage
+  void requestIdleTime(CkCallback cb){
+    double i = localControlPointTracingInstance()->idleRatio();
+    double idle[3];
+    idle[0] = i;
+    idle[1] = i;
+    idle[2] = i;
+    
+    localControlPointTracingInstance()->resetTimings();
+
+    //   CkPrintf("PE %d Idle Time is %lf\n",CkMyPe(), idle);
+    contribute(3*sizeof(double),idle,idleTimeReductionType, cb);
+  }
+  
+  // All processors reduce their memory usages to this method
+  void gatherIdleTime(CkReductionMsg *msg){
+    int size=msg->getSize() / sizeof(double);
+    CkAssert(size==3);
+    double *r=(double *) msg->getData();
+        
+    instrumentedPhase* prevPhase = previousPhaseData();
+    if(prevPhase != NULL){
+      CkPrintf("Storing idle time measurements\n");
+      prevPhase->idleTime.min = r[0];
+      prevPhase->idleTime.avg = r[1]/CkNumPes();
+      prevPhase->idleTime.max = r[2];
+      prevPhase->idleTime.print();
+      CkPrintf("Stored idle time min=%lf in prevPhase=%p\n", prevPhase->idleTime.min, prevPhase);
+    } else {
+      CkPrintf("No place to store idle time measurements\n");
+    }
+    
+    alreadyRequestedIdleTime = false;
+    delete msg;
   }
   
 
 
+  // Entry method called on all PEs to request memory usage
   void requestMemoryUsage(CkCallback cb){
     int m = CmiMaxMemoryUsage() / 1024 / 1024;
     CmiResetMaxMemory();
@@ -631,6 +838,7 @@ public:
     contribute(sizeof(int),&m,CkReduction::max_int, cb);
   }
 
+  // All processors reduce their memory usages to this method
   void gatherMemoryUsage(CkReductionMsg *msg){
     int size=msg->getSize() / sizeof(int);
     CkAssert(size==1);
@@ -651,6 +859,97 @@ public:
 
 
 
+  void registerTerminalPath(PathHistory &path){
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+  
+    double beginTime = CmiWallTimer();
+        
+    if(maxTerminalPathHistory.updateMax(path) ) {
+      // The new path is more critical than the previous one
+      // propogate it towards processor 0 in a binary tree
+      if(CkMyPe() > 0){
+       int dest = (CkMyPe() -1) / 2;
+       //      CkPrintf("Forwarding better critical path from PE %d to %d\n", CkMyPe(), dest);
+
+       // This is part of a reduction-like propagation of the maximum back to PE 0
+       resetThisEntryPath();
+
+       thisProxy[dest].registerTerminalPath(path);
+      }
+    }
+
+    traceRegisterUserEvent("registerTerminalPath", 100); 
+    traceUserBracketEvent(100, beginTime, CmiWallTimer());
+#endif
+  }
+
+  void printTerminalPath(){
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+    maxTerminalPathHistory.print();
+#endif
+  }
+  
+  void resetTerminalPath(){
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+    maxTerminalPathHistory.reset();
+#endif
+  }
+  
+  void associatePriorityArray(const char *name, int groupIdx){
+    CkPrintf("Associating control point \"%s\" affects priority of array id=%d\n", name, groupIdx );
+    
+    if(affectsPrioritiesArray.count(std::string(name)) > 0 ) {
+      affectsPrioritiesArray[std::string(name)].insert(groupIdx);
+    } else {
+      std::set<int> s;
+      s.insert(groupIdx);
+      affectsPrioritiesArray[std::string(name)] = s;
+    }
+    
+#if DEBUG   
+    std::map<string, std::set<int> >::iterator f;
+    for(f=affectsPrioritiesArray.begin(); f!=affectsPrioritiesArray.end();++f){
+      std::string name = f->first;
+      std::set<int> &vals = f->second;
+      cout << "Control point " << name << " affects arrays: ";
+      std::set<int>::iterator i;
+      for(i=vals.begin(); i!=vals.end();++i){
+       cout << *i << " ";
+      }
+      cout << endl;
+    }
+#endif
+    
+  }
+  
+  void associatePriorityEntry(const char *name, int idx){
+    CkPrintf("Associating control point \"%s\" with EP id=%d\n", name, idx);
+
+      if(affectsPrioritiesEP.count(std::string(name)) > 0 ) {
+      affectsPrioritiesEP[std::string(name)].insert(idx);
+    } else {
+      std::set<int> s;
+      s.insert(idx);
+      affectsPrioritiesEP[std::string(name)] = s;
+    }
+    
+#if DEBUG
+    std::map<string, std::set<int> >::iterator f;
+    for(f=affectsPrioritiesEP.begin(); f!=affectsPrioritiesEP.end();++f){
+      std::string name = f->first;
+      std::set<int> &vals = f->second;
+      cout << "Control point " << name << " affects EP: ";
+      std::set<int>::iterator i;
+      for(i=vals.begin(); i!=vals.end();++i){
+       cout << *i << " ";
+      }
+      cout << endl;
+    }
+#endif
+
+
+  }
+  
 };
 
 
@@ -707,7 +1006,7 @@ static void periodicProcessControlPoints(void* ptr, double currWallTime){
   CkPrintf("[%d] periodicProcessControlPoints()\n", CkMyPe());
 #endif
   localControlPointManagerProxy.ckLocalBranch()->processControlPoints();
-  CcdCallFnAfterOnPE((CcdVoidFn)periodicProcessControlPoints, (void*)NULL, CONTROL_POINT_PERIOD, CkMyPe());
+  CcdCallFnAfterOnPE((CcdVoidFn)periodicProcessControlPoints, (void*)NULL, CONTROL_POINT_SAMPLE_PERIOD, CkMyPe());
 }
 
 
@@ -839,12 +1138,14 @@ int valueProvidedByOptimizer(const char * name){
   for(iter = controlPointSpace.begin(); iter != controlPointSpace.end(); iter++){
     //    CkPrintf("Examining dimension %d\n", d);
 
+#if DEBUG
     string name = iter->first;
     if(staticControlPoints.count(name) >0 ){
       cout << " control point " << name << " is static " << endl;
     } else{
       cout << " control point " << name << " is not static " << endl;
     }
+#endif
 
     lowerBounds[d] = iter->second.first;
     upperBounds[d] = iter->second.second;
@@ -1031,6 +1332,26 @@ int controlPoint(const char *name, std::vector<int>& values){
 
 
 
+
+void controlPointPriorityArray(const char *name, CProxy_ArrayBase &arraybase){
+  CkGroupID aid = arraybase.ckGetArrayID();
+  int groupIdx = aid.idx;
+  localControlPointManagerProxy.ckLocalBranch()->associatePriorityArray(name, groupIdx);
+  //  CkPrintf("Associating control point \"%s\" with array id=%d\n", name, groupIdx );
+}
+
+
+
+void controlPointPriorityEntry(const char *name, int idx){
+  localControlPointManagerProxy.ckLocalBranch()->associatePriorityEntry(name, idx);
+  //  CkPrintf("Associating control point \"%s\" with EP id=%d\n", name, idx);
+}
+
+
+
+
+
+
 // The index in the global array for my top row  
 int redistributor2D::top_data_idx(){ 
   return (data_height * thisIndex.y) / y_chares; 
@@ -1083,4 +1404,29 @@ int redistributor2D::myheight(){
 
 
 
+
+
+
+
+#ifdef USE_CRITICAL_PATH_HEADER_ARRAY
+
+
+
+void registerTerminalEntryMethod(){
+  localControlPointManagerProxy.ckLocalBranch()->registerTerminalPath(currentlyExecutingMsg->pathHistory);
+}
+
+void printPECriticalPath(){
+  localControlPointManagerProxy.ckLocalBranch()->printTerminalPath();
+}
+
+void resetPECriticalPath(){
+  localControlPointManagerProxy.ckLocalBranch()->resetTerminalPath();
+}
+
+#endif
+
+
+
+
 #include "ControlPoints.def.h"
index 917362e94ace43219f194a38c4ce5406e95dba2b..c14a4c81a15a9dfe7c48e23fd36b7b8a036aaeef 100644 (file)
@@ -3,17 +3,29 @@ module ControlPoints {
   readonly CProxy_controlPointManager localControlPointManagerProxy;
   readonly int random_seed;
 
+
+
+  initcall void registerIdleTimeReduction(void);       
+
+
+
   mainchare controlPointMain {
     entry controlPointMain(CkArgMsg*);
   };
 
  initnode void controlPointInitNode();
 
nodegroup controlPointManager {
+ group controlPointManager {
     entry controlPointManager();
 
     entry void requestMemoryUsage(CkCallback cb);
     entry void gatherMemoryUsage(CkReductionMsg *msg);
+
+    entry void requestIdleTime(CkCallback cb);
+    entry void gatherIdleTime(CkReductionMsg *msg);
+
+    entry void registerTerminalPath(PathHistory &path);
+
  }   
 
 
index a65e6a6e0a58bda9b9842c7aedba307fd84bb568..079d832ea9ca1efcd767858de32a7a32c5429a36 100644 (file)
@@ -36,14 +36,26 @@ int controlPoint(const char *name, int lb, int ub);
 /// The value returned will likely change between subsequent invocations
 int controlPoint(const char *name, std::vector<int>& values);
 
-/// Return an integral power of 2 between c1 and c2
-/// The value returned is static throughout the life of the program
-//int beginPoint2Pow(const char *name, int c1, int c2);
-
 /// Return an integer between lb and ub inclusive
 /// The value returned is static throughout the life of the program
 int staticPoint(const char *name, int lb, int ub);
 
+
+/// Associate a control point as affecting priorities for an array
+void controlPointPriorityArray(const char *name, CProxy_ArrayBase &arraybase);
+
+/// Associate a control point with an entry method, whose priorities are affected by the control point
+void controlPointPriorityEntry(const char *name, int idx);
+
+
+
+// The application specifies that it is ready to proceed to a new set of control point values.
+// This should be called after registerControlPointTiming()
+// This should be called before calling controlPoint()
+void gotoNextPhase();
+
+
+
 /// Return an integer from the provided vector of values
 /// The value returned is static throughout the life of the program
 //int beginPoint(const char *name, std::vector<int>& values);
@@ -63,7 +75,6 @@ static int mini(int a, int b){
 }
 
 
-
 class controlPointMsg : public CMessage_controlPointMsg {
  public:
   char *data;
index daa8f6905d65fc154eef2d8242bada16fc066912..ab18e567e1be576861a3099e2d54733af9e23e92 100644 (file)
@@ -22,6 +22,9 @@ void _createTracecontrolPoints(char **argv)
 
 TraceControlPoints::TraceControlPoints(char **argv)
 {
+
+  resetTimings();
+
   if (CkpvAccess(traceOnPe) == 0) return;
 
   // Process runtime arguments intended for the module
@@ -63,7 +66,7 @@ void TraceControlPoints::beginExecute(CmiObjId *tid)
   lastBeginExecuteTime = CmiWallTimer();
   lastbeginMessageSize = -1;
 
-  CkPrintf("[%d] WARNING ignoring TraceControlPoints::beginExecute(CmiObjId *tid)\n", CkMyPe());
+  //  CkPrintf("[%d] TraceControlPoints::beginExecute(CmiObjId *tid)\n", CkMyPe());
 }
 
 void TraceControlPoints::beginExecute(envelope *e)
@@ -71,7 +74,7 @@ void TraceControlPoints::beginExecute(envelope *e)
   lastBeginExecuteTime = CmiWallTimer();
   lastbeginMessageSize = e->getTotalsize();
 
-  CkPrintf("[%d] WARNING ignoring TraceControlPoints::beginExecute(envelope *e)\n", CkMyPe());
+  //  CkPrintf("[%d] WARNING ignoring TraceControlPoints::beginExecute(envelope *e)\n", CkMyPe());
 
   // no message means thread execution
   //  if (e != NULL) {
@@ -79,6 +82,8 @@ void TraceControlPoints::beginExecute(envelope *e)
   //        CkMyPe(), e->getEpIdx(), e->getMsgtype(), e->getSrcPe(), e->getTotalsize() );
   //}  
 
+  //  CkPrintf("[%d] TraceControlPoints::beginExecute(envelope *e=%p)\n", CkMyPe(), e);
+
 }
 
 void TraceControlPoints::beginExecute(int event,int msgType,int ep,int srcPe, 
@@ -87,25 +92,31 @@ void TraceControlPoints::beginExecute(int event,int msgType,int ep,int srcPe,
   lastBeginExecuteTime = CmiWallTimer();
   lastbeginMessageSize = mlen;
   //  CkPrintf("[%d] TraceControlPoints::beginExecute event=%d, msgType=%d, ep=%d, srcPe=%d, mlen=%d CmiObjId is also avaliable\n", CkMyPe(), event, msgType, ep, srcPe, mlen);
+  //  CkPrintf("[%d] TraceControlPoints::beginExecute(int event,int msgType,int ep,int srcPe, int mlen, CmiObjId *idx)\n", CkMyPe());
+
 }
 
 void TraceControlPoints::endExecute(void)
 {
   double executionTime = CmiWallTimer() - lastBeginExecuteTime;
-  CkPrintf("[%d] Previously executing Entry Method completes. lastbeginMessageSize=%d executionTime=%lf\n", CkMyPe(), lastbeginMessageSize, executionTime);
+  totalEntryMethodTime += executionTime;
+  
+  //  CkPrintf("[%d] Previously executing Entry Method completes. lastbeginMessageSize=%d executionTime=%lf\n", CkMyPe(), lastbeginMessageSize, executionTime);
 }
 
 void TraceControlPoints::beginIdle(double curWallTime) {
+  lastBeginIdle = CmiWallTimer();
   // CkPrintf("[%d] Scheduler has no useful user-work\n", CkMyPe());
 }
 
 void TraceControlPoints::endIdle(double curWallTime) {
+  totalIdleTime += CmiWallTimer() - lastBeginIdle;
   //  CkPrintf("[%d] Scheduler now has useful user-work\n", CkMyPe());
 }
-  
+
 void TraceControlPoints::beginComputation(void)
 {
-  CkPrintf("[%d] Computation Begins\n", CkMyPe());
+  //  CkPrintf("[%d] Computation Begins\n", CkMyPe());
   // Code Below shows what trace-summary would do.
   // initialze arrays because now the number of entries is known.
   // _logPool->initMem();
@@ -132,6 +143,18 @@ void TraceControlPoints::traceClose(void)
   CkpvAccess(_traces)->removeTrace(this);
 }
 
+void TraceControlPoints::resetTimings(){
+  totalIdleTime = 0.0;
+  totalEntryMethodTime = 0.0;
+  lastResetTime = CmiWallTimer();
+}
+
+TraceControlPoints *localControlPointTracingInstance(){
+  return CkpvAccess(_trace);
+}
+
+
+
 extern "C" void traceControlPointsExitFunction() {
   // The exit function of any Charm++ module must call CkExit() or
   // the entire exit process will hang if multiple modules are linked.
index c3268c711903064d3e0c8f36d5dc1260c926113e..7671a9e59995f9559e824517f40d7f132ab82148 100644 (file)
@@ -21,6 +21,18 @@ class TraceControlPoints : public Trace {
   double lastBeginExecuteTime;
   int lastbeginMessageSize;
 
+  /** The amount of time spent executing entry methods */
+  double totalEntryMethodTime;
+
+  /** The start of the idle region */
+  double lastBeginIdle;
+  
+  /** The amount of time spent idle */
+  double totalIdleTime;
+  
+  /** The time we last rest the idle/entry totals */
+  double lastResetTime;
+
  public:
   TraceControlPoints(char **argv);
   
@@ -65,8 +77,27 @@ class TraceControlPoints : public Trace {
   
   // do any clean-up necessary for tracing
   void traceClose();
+
+
+
+
+  // ==================================================================
+  // The following methods are not required for a tracing module
+
+  /** reset the idle time and entry method execution time accumulators */
+  void resetTimings();
+
+  /** What fraction of the time is spent idle */
+  double idleRatio(){
+    return (totalIdleTime) / (CmiWallTimer() - lastResetTime);
+  }
+
 };
 
+
+TraceControlPoints *localControlPointTracingInstance();
+
+
 #endif
 
 /*@}*/
index a0bb6b32ddfceac1b3c42fef408879417e93b24b..f5e1ba3ee63cc302f7be2e102af338427cba2990 100644 (file)
@@ -93,7 +93,7 @@ ccs-builtins.o: ccs-builtins.C converse.h conv-config.h conv-autoconfig.h \
   conv-cpath.h conv-qd.h conv-random.h conv-lists.h conv-trace.h \
   persistent.h debug-conv.h ckhashtable.h pup.h converse.h \
   pup_toNetwork.h debug-charm.h cklists.h conv-ccs.h sockRoutines.h \
-  ccs-server.h queueing.h
+  ccs-server.h queueing.h ccs-builtins.h
        $(CHARMC) -c -I. ccs-builtins.C
 
 traceCore.o: traceCore.C converse.h conv-config.h conv-autoconfig.h \
@@ -2006,12 +2006,12 @@ bigsim_read.o: bigsim_read.C blue.h converse.h conv-config.h \
   bigsim_logs.h blue_defs.h bigsim_network.h
        $(CHARMC) -c -I. bigsim_read.C
 
-bigsim_logs.o: bigsim_logs.C blue_impl.h conv-mach.h ckliststring.h \
-  blue_types.h bigsim_timing.h cklists.h pup.h converse.h conv-config.h \
+bigsim_logs.o: bigsim_logs.C blue.h converse.h conv-config.h \
   conv-autoconfig.h conv-common.h conv-mach.h conv-mach-opt.h pup_c.h \
-  conv-cpm.h converse.h conv-cpath.h conv-qd.h conv-random.h conv-lists.h \
-  conv-trace.h persistent.h debug-conv.h bigsim_logs.h blue.h converse.h \
-  blue-conv.h blue_defs.h bigsim_network.h
+  conv-cpm.h conv-cpath.h conv-qd.h conv-random.h conv-lists.h \
+  conv-trace.h persistent.h debug-conv.h blue-conv.h blue_impl.h \
+  ckliststring.h blue_types.h bigsim_timing.h cklists.h pup.h converse.h \
+  bigsim_logs.h blue_defs.h bigsim_network.h
        $(CHARMC) -c -I. bigsim_logs.C
 
 bigsim_api.o: bigsim_api.C blue.h converse.h conv-config.h \
@@ -2714,6 +2714,8 @@ controlPoints.o: controlPoints.C charm++.h charm.h converse.h \
   charisma.h charisma.decl.h tempo.h tempo.decl.h waitqd.h waitqd.decl.h \
   sdag.h ckcheckpoint.h CkCheckpoint.decl.h ckevacuation.h \
   ckarrayreductionmgr.h trace.h trace-bluegene.h ControlPoints.decl.h \
-  charm++.h LBDatabase.h controlPoints.h pup_stl.h ControlPoints.def.h
+  charm++.h trace-controlPoints.h trace.h envelope.h register.h \
+  trace-common.h LBDatabase.h controlPoints.h pup_stl.h \
+  ControlPoints.def.h
        $(CHARMC) -c -I. controlPoints.C