Home Research Papers Posters Manuals Talks Download People Help Wiki Internal

ck-perf/trace-projections.C

Go to the documentation of this file.

/*****************************************************************************
 * $Source: /cvsroot/charm/src/ck-perf/trace-projections.C,v $
 * $Author: idooley2 $
 * $Date: 2008-02-04 22:20:48 $
 * $Revision: 2.126 $
 *****************************************************************************/



#include <string.h>

#include "charm++.h"
#include "trace-projections.h"
#include "trace-projectionsBOC.h"

#define DEBUGF(x)           // CmiPrintf x

#define DefaultLogBufSize      1000000

// **CW** Simple delta encoding implementation
// delta encoding is on by default. It may be turned off later in
// the runtime.
int deltaLog;
int nonDeltaLog;

int checknested=0;              // check illegal nested begin/end execute 

CkGroupID traceProjectionsGID;

CkpvStaticDeclare(TraceProjections*, _trace);
CtvStaticDeclare(int,curThreadEvent);

CkpvDeclare(bool, useOutlierAnalysis);
CkpvDeclare(int, CtrLogBufSize);

typedef CkVec<char *>  usrEventVec;
CkpvStaticDeclare(usrEventVec, usrEventlist);
class UsrEvent {
public:
  int e;
  char *str;
  UsrEvent(int _e, char* _s): e(_e),str(_s) {}
};
CkpvStaticDeclare(CkVec<UsrEvent *>*, usrEvents);

#ifdef CMK_OPTIMIZE
static int warned=0;
#define OPTIMIZED_VERSION       \
        if (!warned) { warned=1;        \
        CmiPrintf("\n\n!!!! Warning: traceUserEvent not available in optimized version!!!!\n\n\n"); }
#else
#define OPTIMIZED_VERSION /*empty*/
#endif

/*
On T3E, we need to have file number control by open/close files only when needed.
*/
#if CMK_TRACE_LOGFILE_NUM_CONTROL
  #define OPEN_LOG openLog("a");
  #define CLOSE_LOG closeLog();
#else
  #define OPEN_LOG
  #define CLOSE_LOG
#endif

#if CMK_HAS_COUNTER_PAPI
int numPAPIEvents = 2;
int papiEvents[] = { PAPI_L3_DCM, PAPI_FP_OPS };
char *papiEventNames[] = {"PAPI_L3_DCM", "PAPI_FP_OPS"};
#endif

void _createTraceprojections(char **argv)
{
  DEBUGF(("%d createTraceProjections\n", CkMyPe()));
  CkpvInitialize(CkVec<char *>, usrEventlist);
  CkpvInitialize(CkVec<UsrEvent *>*, usrEvents);
  CkpvAccess(usrEvents) = new CkVec<UsrEvent *>();
#if CMK_BLUEGENE_CHARM
  // CthRegister does not call the constructor
//  CkpvAccess(usrEvents) = CkVec<UsrEvent *>();
#endif
  CkpvInitialize(TraceProjections*, _trace);
  CkpvAccess(_trace) = new  TraceProjections(argv);
  CkpvAccess(_traces)->addTrace(CkpvAccess(_trace));
}
 
/* ****** CW TEMPORARY LOCATION ***** Support for thread listeners */

struct TraceThreadListener {
  struct CthThreadListener base;
  int event;
  int msgType;
  int ep;
  int srcPe;
  int ml;
  CmiObjId idx;
};


extern "C"
void traceThreadListener_suspend(struct CthThreadListener *l)
{
  TraceThreadListener *a=(TraceThreadListener *)l;
  /* here, we activate the appropriate trace codes for the appropriate
     registered modules */
  traceSuspend();
}

extern "C"
void traceThreadListener_resume(struct CthThreadListener *l) 
{
  TraceThreadListener *a=(TraceThreadListener *)l;
  /* here, we activate the appropriate trace codes for the appropriate
     registered modules */
  _TRACE_BEGIN_EXECUTE_DETAILED(a->event,a->msgType,a->ep,a->srcPe,a->ml,
                                CthGetThreadID(a->base.thread));
  a->event=-1;
  a->srcPe=CkMyPe(); /* potential lie to migrated threads */
  a->ml=0;
}

extern "C"
void traceThreadListener_free(struct CthThreadListener *l) 
{
  TraceThreadListener *a=(TraceThreadListener *)l;
  delete a;
}

void TraceProjections::traceAddThreadListeners(CthThread tid, envelope *e)
{
#ifndef CMK_OPTIMIZE
  /* strip essential information from the envelope */
  TraceThreadListener *a= new TraceThreadListener;
  
  a->base.suspend=traceThreadListener_suspend;
  a->base.resume=traceThreadListener_resume;
  a->base.free=traceThreadListener_free;
  a->event=e->getEvent();
  a->msgType=e->getMsgtype();
  a->ep=e->getEpIdx();
  a->srcPe=e->getSrcPe();
  a->ml=e->getTotalsize();

  CthAddListener(tid, (CthThreadListener *)a);
#endif
}

void LogPool::openLog(const char *mode)
{
#if CMK_PROJECTIONS_USE_ZLIB
  if(compressed) {
    if (nonDeltaLog) {
      do {
        zfp = gzopen(fname, mode);
      } while (!zfp && (errno == EINTR || errno == EMFILE));
      if(!zfp) CmiAbort("Cannot open Projections Compressed Non Delta Trace File for writing...\n");
    }
    if (deltaLog) {
      do {
        deltazfp = gzopen(dfname, mode);
      } while (!deltazfp && (errno == EINTR || errno == EMFILE));
      if (!deltazfp) 
        CmiAbort("Cannot open Projections Compressed Delta Trace File for writing...\n");
    }
  } else {
    if (nonDeltaLog) {
      do {
        fp = fopen(fname, mode);
      } while (!fp && (errno == EINTR || errno == EMFILE));
      if (!fp) {
        CkPrintf("[%d] Attempting to open file [%s]\n",CkMyPe(),fname);
        CmiAbort("Cannot open Projections Non Delta Trace File for writing...\n");
      }
    }
    if (deltaLog) {
      do {
        deltafp = fopen(dfname, mode);
      } while (!deltafp && (errno == EINTR || errno == EMFILE));
      if (!deltafp) 
        CmiAbort("Cannot open Projections Delta Trace File for writing...\n");
    }
  }
#else
  if (nonDeltaLog) {
    do {
      fp = fopen(fname, mode);
    } while (!fp && (errno == EINTR || errno == EMFILE));
    if (!fp) {
      CkPrintf("[%d] Attempting to open file [%s]\n",CkMyPe(),fname);
      CmiAbort("Cannot open Projections Non Delta Trace File for writing...\n");
    }
  }
  if (deltaLog) {
    do {
      deltafp = fopen(dfname, mode);
    } while (!deltafp && (errno == EINTR || errno == EMFILE));
    if(!deltafp) 
      CmiAbort("Cannot open Projections Delta Trace File for writing...\n");
  }
#endif
}

void LogPool::closeLog(void)
{
#if CMK_PROJECTIONS_USE_ZLIB
  if(compressed) {
    if (nonDeltaLog) gzclose(zfp);
    if (deltaLog) gzclose(deltazfp);
    return;
  }
#endif
  if (nonDeltaLog) { 
#if !defined(_WIN32) || defined(__CYGWIN__)
    fsync(fileno(fp)); 
#endif
    fclose(fp); 
  }
  if (deltaLog)  { 
#if !defined(_WIN32) || defined(__CYGWIN__)
    fsync(fileno(deltafp)); 
#endif
    fclose(deltafp);  
  }
}

LogPool::LogPool(char *pgm) {
  pool = new LogEntry[CkpvAccess(CtrLogBufSize)];
  // defaults to writing data (no outlier changes)
  writeData = true;
  numEntries = 0;
  // **CW** for simple delta encoding
  prevTime = 0.0;
  timeErr = 0.0;
  globalEndTime = 0.0;
  headerWritten = 0;
  fileCreated = false;
  poolSize = CkpvAccess(CtrLogBufSize);
  pgmname = new char[strlen(pgm)+1];
  strcpy(pgmname, pgm);
}

void LogPool::createFile(char *fix)
{
  if (fileCreated) {
    return;
  }
  char pestr[10];
  sprintf(pestr, "%d", CkMyPe());
#if CMK_PROJECTIONS_USE_ZLIB
  int len;
  if(compressed)
    len = strlen(pgmname)+strlen(fix)+strlen(".logold")+strlen(pestr)+strlen(".gz")+3;
  else
    len = strlen(pgmname)+strlen(fix)+strlen(".logold")+strlen(pestr)+3;
#else
  int len = strlen(pgmname)+strlen(fix)+strlen(".logold")+strlen(pestr)+3;
#endif
  if (nonDeltaLog) {
    fname = new char[len];
  }
  if (deltaLog) {
    dfname = new char[len];
  }
#if CMK_PROJECTIONS_USE_ZLIB
  if(compressed) {
    if (deltaLog && nonDeltaLog) {
      sprintf(fname, "%s%s.%s.logold.gz", pgmname, fix, pestr);
      sprintf(dfname, "%s%s.%s.log.gz", pgmname, fix, pestr);
    } else {
      if (nonDeltaLog) {
        sprintf(fname, "%s%s.%s.log.gz", pgmname, fix, pestr);
      } else {
        sprintf(dfname, "%s%s.%s.log.gz", pgmname, fix, pestr);
      }
    }
  } else {
    if (deltaLog && nonDeltaLog) {
      sprintf(fname, "%s%s.%s.logold", pgmname, fix, pestr);
      sprintf(dfname, "%s%s.%s.log", pgmname, fix, pestr);
    } else {
      if (nonDeltaLog) {
        sprintf(fname, "%s%s.%s.log", pgmname, fix, pestr);
      } else {
        sprintf(dfname, "%s%s.%s.log", pgmname, fix, pestr);
      }
    }
  }
#else
  if (deltaLog && nonDeltaLog) {
    sprintf(fname, "%s%s.%s.logold", pgmname, fix, pestr);
    sprintf(dfname, "%s%s.%s.log", pgmname, fix, pestr);
  } else {
    if (nonDeltaLog) {
      sprintf(fname, "%s%s.%s.log", pgmname, fix, pestr);
    } else {
      sprintf(dfname, "%s%s.%s.log", pgmname, fix, pestr);
    }
  }
#endif
  fileCreated = true;
  openLog("w+");
  CLOSE_LOG 
}

void LogPool::createSts(char *fix)
{
  CkAssert(CkMyPe() == 0);
  // create the sts file
  char *fname = new char[strlen(CkpvAccess(traceRoot))+strlen(fix)+strlen(".sts")+2];
  sprintf(fname, "%s%s.sts", CkpvAccess(traceRoot), fix);
  do
    {
      stsfp = fopen(fname, "w");
    } while (!stsfp && (errno == EINTR || errno == EMFILE));
  if(stsfp==0)
    CmiAbort("Cannot open projections sts file for writing.\n");
  delete[] fname;
}  

void LogPool::createRC()
{
  // create the projections rc file.
  fname = 
    new char[strlen(CkpvAccess(traceRoot))+strlen(".projrc")+1];
  sprintf(fname, "%s.projrc", CkpvAccess(traceRoot));
  do {
    rcfp = fopen(fname, "w");
  } while (!rcfp && (errno == EINTR || errno == EMFILE));
  if (rcfp==0) {
    CmiAbort("Cannot open projections configuration file for writing.\n");
  }
  delete[] fname;
}

LogPool::~LogPool() 
{
  if (writeData) {
    writeLog();
#if !CMK_TRACE_LOGFILE_NUM_CONTROL
    closeLog();
#endif
  }

#if CMK_BLUEGENE_CHARM
  extern int correctTimeLog;
  if (correctTimeLog) {
    createFile("-bg");
    if (CkMyPe() == 0) {
      createSts("-bg");
    }
    writeHeader();
    if (CkMyPe() == 0) writeSts(NULL);
    postProcessLog();
  }
#endif

  delete[] pool;
  delete [] fname;
}

void LogPool::writeHeader()
{
  if (headerWritten) return;
  headerWritten = 1;
  if(!binary) {
#if CMK_PROJECTIONS_USE_ZLIB
    if(compressed) {
      if (nonDeltaLog) {
        gzprintf(zfp, "PROJECTIONS-RECORD %d\n", numEntries);
      }
      if (deltaLog) {
        gzprintf(deltazfp, "PROJECTIONS-RECORD %d DELTA\n", numEntries);
      }
    } 
    else /* else clause is below... */
#endif
    /*... may hang over from else above */ {
      if (nonDeltaLog) {
        fprintf(fp, "PROJECTIONS-RECORD %d\n", numEntries);
      }
      if (deltaLog) {
        fprintf(deltafp, "PROJECTIONS-RECORD %d DELTA\n", numEntries);
      }
    }
  }
  else { // binary
      if (nonDeltaLog) {
        fwrite(&numEntries,sizeof(numEntries),1,fp);
      }
      if (deltaLog) {
        fwrite(&numEntries,sizeof(numEntries),1,deltafp);
      }
  }
}

void LogPool::writeLog(void)
{
  createFile();
  OPEN_LOG
  writeHeader();
  if (nonDeltaLog) write(0);
  if (deltaLog) write(1);
  CLOSE_LOG
}

void LogPool::write(int writedelta) 
{
  // **CW** Simple delta encoding implementation
  // prevTime has to be maintained as an object variable because
  // LogPool::write may be called several times depending on the
  // +logsize value.
  PUP::er *p = NULL;
  if (binary) {
    p = new PUP::toDisk(writedelta?deltafp:fp);
  }
#if CMK_PROJECTIONS_USE_ZLIB
  else if (compressed) {
    p = new toProjectionsGZFile(writedelta?deltazfp:zfp);
  }
#endif
  else {
    p = new toProjectionsFile(writedelta?deltafp:fp);
  }
  CmiAssert(p);
  for(UInt i=0; i<numEntries; i++) {
    if (!writedelta) {
      pool[i].pup(*p);
    }
    else {      // delta
      double time = pool[i].time;
      if (pool[i].type != BEGIN_COMPUTATION && pool[i].type != END_COMPUTATION)
      {
        double timeDiff = (time-prevTime)*1.0e6;
        UInt intTimeDiff = (UInt)timeDiff;
        timeErr += timeDiff - intTimeDiff; /* timeErr is never >= 2.0 */
        if (timeErr > 1.0) {
          timeErr -= 1.0;
          intTimeDiff++;
        }
        pool[i].time = intTimeDiff/1.0e6;
      }
      pool[i].pup(*p);
      pool[i].time = time;      // restore time value
      prevTime = time;
    }
  }
  delete p;
}

void LogPool::writeSts(void)
{
  // for whining compilers
  int i;
  char name[30];
  // generate an automatic unique ID for each log
  fprintf(stsfp, "PROJECTIONS_ID %s\n", "");
  fprintf(stsfp, "VERSION %s\n", PROJECTION_VERSION);
#if CMK_HAS_COUNTER_PAPI
  fprintf(stsfp, "TOTAL_PAPI_EVENTS %d\n", numPAPIEvents);
  // for now, use i, next time use papiEvents[i].
  // **CW** papi event names is a hack.
  for (i=0;i<numPAPIEvents;i++) {
    fprintf(stsfp, "PAPI_EVENT %d %s\n", i, papiEventNames[i]);
  }
#endif
  traceWriteSTS(stsfp,CkpvAccess(usrEvents)->length());
  for(i=0;i<CkpvAccess(usrEvents)->length();i++){
    fprintf(stsfp, "EVENT %d %s\n", (*CkpvAccess(usrEvents))[i]->e, (*CkpvAccess(usrEvents))[i]->str);
  }     
}

void LogPool::writeSts(TraceProjections *traceProj){
  writeSts();
  if (traceProj != NULL) {
    CkHashtableIterator  *funcIter = traceProj->getfuncIterator();
    funcIter->seekStart();
    int numFuncs = traceProj->getFuncNumber();
    fprintf(stsfp,"TOTAL_FUNCTIONS %d \n",numFuncs);
    while(funcIter->hasNext()) {
      StrKey *key;
      int *obj = (int *)funcIter->next((void **)&key);
      fprintf(stsfp,"FUNCTION %d %s \n",*obj,key->getStr());
    }
  }
  fprintf(stsfp, "END\n");
  fclose(stsfp);
}

void LogPool::writeRC(void)
{
  CkAssert(CkMyPe() == 0);
  fprintf(rcfp,"RC_GLOBAL_END_TIME %lld\n",
          (CMK_TYPEDEF_UINT8)(1.0e6*globalEndTime));
  if (CkpvAccess(useOutlierAnalysis)) {
    fprintf(rcfp,"RC_OUTLIER_FILTERED true\n");
  } else {
    fprintf(rcfp,"RC_OUTLIER_FILTERED false\n");
  }       
  fclose(rcfp);
}


#if CMK_BLUEGENE_CHARM
static void updateProjLog(void *data, double t, double recvT, void *ptr)
{
  LogEntry *log = (LogEntry *)data;
  FILE *fp = *(FILE **)ptr;
  log->time = t;
  log->recvTime = recvT<0.0?0:recvT;
//  log->write(fp);
  toProjectionsFile p(fp);
  log->pup(p);
}
#endif

// flush log entries to disk
void LogPool::flushLogBuffer()
{
  if (numEntries) {
    double writeTime = TraceTimer();
    writeLog();
    numEntries = 0;
    new (&pool[numEntries++]) LogEntry(writeTime, BEGIN_INTERRUPT);
    new (&pool[numEntries++]) LogEntry(TraceTimer(), END_INTERRUPT);
  }
}

void LogPool::add(UChar type, UShort mIdx, UShort eIdx,
                  double time, int event, int pe, int ml, CmiObjId *id, 
                  double recvT, double cpuT, int numPe)
{
  new (&pool[numEntries++])
    LogEntry(time, type, mIdx, eIdx, event, pe, ml, id, recvT, cpuT, numPe);
  if(poolSize==numEntries) {
    flushLogBuffer();
#if CMK_BLUEGENE_CHARM
    extern int correctTimeLog;
    if (correctTimeLog) CmiAbort("I/O interrupt!\n");
#endif
  }
#if CMK_BLUEGENE_CHARM
  switch (type) {
    case BEGIN_PROCESSING:
      pool[numEntries-1].recvTime = BgGetRecvTime();
    case END_PROCESSING:
    case BEGIN_COMPUTATION:
    case END_COMPUTATION:
    case CREATION:
    case BEGIN_PACK:
    case END_PACK:
    case BEGIN_UNPACK:
    case END_UNPACK:
    case USER_EVENT_PAIR:
      bgAddProjEvent(&pool[numEntries-1], numEntries-1, time, updateProjLog, &fp, BG_EVENT_PROJ);
  }
#endif
}

void LogPool::add(UChar type,double time,UShort funcID,int lineNum,char *fileName){
#ifndef CMK_BLUEGENE_CHARM
  new (&pool[numEntries++])
        LogEntry(time,type,funcID,lineNum,fileName);
  if(poolSize == numEntries){
    flushLogBuffer();
  }
#endif  
}


  
void LogPool::addMemoryUsage(unsigned char type,double time,double memUsage){
#ifndef CMK_BLUEGENE_CHARM
  new (&pool[numEntries++])
        LogEntry(type,time,memUsage);
  if(poolSize == numEntries){
    flushLogBuffer();
  }
#endif  
        
}  




void LogPool::addUserSupplied(int data){
        // add an event
        add(USER_SUPPLIED, 0, 0, TraceTimer(), -1, -1, 0, 0, 0, 0, 0 );

        // set the user supplied value for the previously created event 
        pool[numEntries-1].setUserSuppliedData(data);
  }

/* **CW** Not sure if this is the right thing to do. Feels more like
   a hack than a solution to Sameer's request to add the destination
   processor information to multicasts and broadcasts.

   In the unlikely event this method is used for Broadcasts as well,
   pelist == NULL will be used to indicate a global broadcast with 
   num PEs.
*/
void LogPool::addCreationMulticast(UShort mIdx, UShort eIdx, double time,
                                   int event, int pe, int ml, CmiObjId *id,
                                   double recvT, int numPe, int *pelist)
{
  new (&pool[numEntries++])
    LogEntry(time, mIdx, eIdx, event, pe, ml, id, recvT, numPe, pelist);
  if(poolSize==numEntries) {
    flushLogBuffer();
  }
}

void LogPool::postProcessLog()
{
#if CMK_BLUEGENE_CHARM
  bgUpdateProj(1);   // event type
#endif
}

LogEntry::LogEntry(double tm, unsigned short m, unsigned short e, int ev, int p,
             int ml, CmiObjId *d, double rt, int numPe, int *pelist) 
{
    type = CREATION_MULTICAST; mIdx = m; eIdx = e; event = ev; pe = p; time = tm; msglen = ml;
    if (d) id = *d; else {id.id[0]=id.id[1]=id.id[2]=id.id[3]=-1; };
    recvTime = rt; 
    numpes = numPe;
    if (pelist != NULL) {
        pes = new int[numPe];
        for (int i=0; i<numPe; i++) {
          pes[i] = pelist[i];
        }
    } else {
        pes= NULL;
    }
}

void LogEntry::addPapi(int numPapiEvts, int *papi_ids, LONG_LONG_PAPI *papiVals)
{
#if CMK_HAS_COUNTER_PAPI
  numPapiEvents = numPapiEvts;
  if (papiVals != NULL) {
    papiIDs = new int[numPapiEvents];
    papiValues = new LONG_LONG_PAPI[numPapiEvents];
    for (int i=0; i<numPapiEvents; i++) {
      papiIDs[i] = papi_ids[i];
      papiValues[i] = papiVals[i];
    }
  }
#endif
}



void LogEntry::pup(PUP::er &p)
{
  int i;
  CMK_TYPEDEF_UINT8 itime, irecvtime, icputime;
  char ret = '\n';

  p|type;
  if (p.isPacking()) itime = (CMK_TYPEDEF_UINT8)(1.0e6*time);
  switch (type) {
    case USER_EVENT:
    case USER_EVENT_PAIR:
      p|mIdx; p|itime; p|event; p|pe;
      break;
    case BEGIN_IDLE:
    case END_IDLE:
    case BEGIN_PACK:
    case END_PACK:
    case BEGIN_UNPACK:
    case END_UNPACK:
      p|itime; p|pe; 
      break;
    case BEGIN_PROCESSING:
      if (p.isPacking()) {
        irecvtime = (CMK_TYPEDEF_UINT8)(recvTime==-1?-1:1.0e6*recvTime);
        icputime = (CMK_TYPEDEF_UINT8)(1.0e6*cputime);
      }
      p|mIdx; p|eIdx; p|itime; p|event; p|pe; 
      p|msglen; p|irecvtime; 
      p|id.id[0]; p|id.id[1]; p|id.id[2]; p|id.id[3];
      p|icputime;
#if CMK_HAS_COUNTER_PAPI
      p|numPapiEvents;
      for (i=0; i<numPapiEvents; i++) {
        // not yet!!!
        //      p|papiIDs[i]; 
        p|papiValues[i];
        
      }
#else
      p|numPapiEvents;     // non papi version has value 0
#endif
      if (p.isUnpacking()) {
        recvTime = irecvtime/1.0e6;
        cputime = icputime/1.0e6;
      }
      break;
    case END_PROCESSING:
      if (p.isPacking()) icputime = (CMK_TYPEDEF_UINT8)(1.0e6*cputime);
      p|mIdx; p|eIdx; p|itime; p|event; p|pe; p|msglen; p|icputime;
#if CMK_HAS_COUNTER_PAPI
      p|numPapiEvents;
      for (i=0; i<numPapiEvents; i++) {
        // not yet!!!
        //      p|papiIDs[i];
        p|papiValues[i];
      }
#else
      p|numPapiEvents;  // non papi version has value 0
#endif
      if (p.isUnpacking()) cputime = icputime/1.0e6;
      break;
    case USER_SUPPLIED:
          p|userSuppliedData;
          p|itime;
        break;
    case MEMORY_USAGE_CURRENT:
      p | memUsage;
      p | itime;
        break;
    case CREATION:
      if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
      p|mIdx; p|eIdx; p|itime;
      p|event; p|pe; p|msglen; p|irecvtime;
      if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
      break;
    case CREATION_BCAST:
      if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
      p|mIdx; p|eIdx; p|itime;
      p|event; p|pe; p|msglen; p|irecvtime; p|numpes;
      if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
      break;
    case CREATION_MULTICAST:
      if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
      p|mIdx; p|eIdx; p|itime;
      p|event; p|pe; p|msglen; p|irecvtime; p|numpes;
      if (p.isUnpacking()) pes = numpes?new int[numpes]:NULL;
      for (i=0; i<numpes; i++) p|pes[i];
      if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
      break;
    case MESSAGE_RECV:
      p|mIdx; p|eIdx; p|itime; p|event; p|pe; p|msglen;
      break;

    case ENQUEUE:
    case DEQUEUE:
      p|mIdx; p|itime; p|event; p|pe;
      break;

    case BEGIN_INTERRUPT:
    case END_INTERRUPT:
      p|itime; p|event; p|pe;
      break;

      // **CW** absolute timestamps are used here to support a quick
      // way of determining the total time of a run in projections
      // visualization.
    case BEGIN_COMPUTATION:
    case END_COMPUTATION:
    case BEGIN_TRACE:
    case END_TRACE:
      p|itime;
      break;
    case BEGIN_FUNC:
        p | itime;
        p | mIdx;
        p | event;
        if(!p.isUnpacking()){
                p(fName,flen-1);
        }
        break;
    case END_FUNC:
        p | itime;
        p | mIdx;
        break;
    default:
      CmiError("***Internal Error*** Wierd Event %d.\n", type);
      break;
  }
  if (p.isUnpacking()) time = itime/1.0e6;
  p|ret;
}

TraceProjections::TraceProjections(char **argv): 
  curevent(0), inEntry(0), computationStarted(0), 
  converseExit(0), endTime(0.0)
{
  //  CkPrintf("Trace projections dummy constructor called on %d\n",CkMyPe());

  if (CkpvAccess(traceOnPe) == 0) return;

  CtvInitialize(int,curThreadEvent);
  CkpvInitialize(int, CtrLogBufSize);
  CkpvInitialize(bool, useOutlierAnalysis);
  CkpvAccess(CtrLogBufSize) = DefaultLogBufSize;
  CtvAccess(curThreadEvent)=0;
  CkpvAccess(useOutlierAnalysis) =
    CmiGetArgFlagDesc(argv, "+outlier", "Perform Outlier Analysis");
  if (CmiGetArgIntDesc(argv,"+logsize",&CkpvAccess(CtrLogBufSize), 
                       "Log entries to buffer per I/O")) {
    if (CkMyPe() == 0) {
      CmiPrintf("Trace: logsize: %d\n", CkpvAccess(CtrLogBufSize));
    }
  }
  checknested = 
    CmiGetArgFlagDesc(argv,"+checknested",
                      "check projections nest begin end execute events");
  int binary = 
    CmiGetArgFlagDesc(argv,"+binary-trace",
                      "Write log files in binary format");
#if CMK_PROJECTIONS_USE_ZLIB
  int compressed = CmiGetArgFlagDesc(argv,"+gz-trace","Write log files pre-compressed with gzip");
#else
  // consume the flag so there's no confusing
  CmiGetArgFlagDesc(argv,"+gz-trace",
                    "Write log files pre-compressed with gzip");
  CkPrintf("Warning: gz-trace is not supported on this machine!\n");
#endif

  // **CW** default to non delta log encoding. The user may choose to do
  // create both logs (for debugging) or just the old log timestamping
  // (for compatibility).
  // Generating just the non delta log takes precedence over generating
  // both logs (if both arguments appear on the command line).

  // switch to OLD log format until everything works // Gengbin
  nonDeltaLog = 1;
  deltaLog = 0;
  deltaLog = CmiGetArgFlagDesc(argv, "+logDelta",
                                  "Generate Delta encoded and simple timestamped log files");

  _logPool = new LogPool(CkpvAccess(traceRoot));
  _logPool->setBinary(binary);
#if CMK_PROJECTIONS_USE_ZLIB
  _logPool->setCompressed(compressed);
#endif
  if (CkMyPe() == 0) {
    _logPool->createSts();
    _logPool->createRC();
  }
  funcCount=1;

#if CMK_HAS_COUNTER_PAPI
  // We initialize and create the event sets for use with PAPI here.
  int papiRetValue = PAPI_library_init(PAPI_VER_CURRENT);
  if (papiRetValue != PAPI_VER_CURRENT) {
    CmiAbort("PAPI Library initialization failure!\n");
  }
  // PAPI 3 mandates the initialization of the set to PAPI_NULL
  papiEventSet = PAPI_NULL; 
  if (PAPI_create_eventset(&papiEventSet) != PAPI_OK) {
    CmiAbort("PAPI failed to create event set!\n");
  }
  papiRetValue = PAPI_add_events(papiEventSet, papiEvents, numPAPIEvents);
  if (papiRetValue != PAPI_OK) {
    if (papiRetValue == PAPI_ECNFLCT) {
      CmiAbort("PAPI events conflict! Please re-assign event types!\n");
    } else {
      CmiAbort("PAPI failed to add designated events!\n");
    }
  }
  papiValues = new long_long[numPAPIEvents];
  memset(papiValues, 0, numPAPIEvents*sizeof(long_long));
#endif
}

int