fix papi_perror compile error
[charm.git] / src / ck-perf / trace-projections.C
1 /**
2  * \addtogroup CkPerf
3 */
4 /*@{*/
5
6 #include <string.h>
7
8 #include "charm++.h"
9 #include "trace-projections.h"
10 #include "trace-projectionsBOC.h"
11 #include "TopoManager.h"
12
13 #if DEBUG_PROJ
14 #define DEBUGF(...) CkPrintf(__VA_ARGS__)
15 #else
16 #define DEBUGF(...)
17 #endif
18 #define DEBUGN(...)  // easy way to selectively disable DEBUGs
19
20 #define DefaultLogBufSize      1000000
21
22 // **CW** Simple delta encoding implementation
23 // delta encoding is on by default. It may be turned off later in
24 // the runtime.
25 int deltaLog;
26 int nonDeltaLog;
27
28 int checknested=0;              // check illegal nested begin/end execute 
29
30 #ifdef PROJ_ANALYSIS
31 // BOC operations readonlys
32 CkGroupID traceProjectionsGID;
33 CkGroupID kMeansGID;
34
35 // New reduction type for Outlier Analysis purposes. This is allowed to be
36 // a global variable according to the Charm++ manual.
37 CkReductionMsg *outlierReduction(int nMsgs,
38                                  CkReductionMsg **msgs);
39 CkReductionMsg *minMaxReduction(int nMsgs,
40                                 CkReductionMsg **msgs);
41 CkReduction::reducerType outlierReductionType;
42 CkReduction::reducerType minMaxReductionType;
43 #endif // PROJ_ANALYSIS
44
45 CkpvStaticDeclare(TraceProjections*, _trace);
46 CtvStaticDeclare(int,curThreadEvent);
47
48 CkpvDeclare(CmiInt8, CtrLogBufSize);
49
50 typedef CkVec<char *>  usrEventVec;
51 CkpvStaticDeclare(usrEventVec, usrEventlist);
52 class UsrEvent {
53 public:
54   int e;
55   char *str;
56   UsrEvent(int _e, char* _s): e(_e),str(_s) {}
57 };
58 CkpvStaticDeclare(CkVec<UsrEvent *>*, usrEvents);
59
60 // When tracing is disabled, these are defined as empty static inlines
61 // in the header, to minimize overhead
62 #if CMK_TRACE_ENABLED
63 /// Disable the outputting of the trace logs
64 void disableTraceLogOutput()
65
66   CkpvAccess(_trace)->setWriteData(false);
67 }
68
69 /// Enable the outputting of the trace logs
70 void enableTraceLogOutput()
71 {
72   CkpvAccess(_trace)->setWriteData(true);
73 }
74
75 /// Force the log files to be flushed
76 void flushTraceLog()
77 {
78   CkpvAccess(_trace)->traceFlushLog();
79 }
80 #endif
81
82 #if ! CMK_TRACE_ENABLED
83 static int warned=0;
84 #define OPTIMIZED_VERSION       \
85         if (!warned) { warned=1;        \
86         CmiPrintf("\n\n!!!! Warning: traceUserEvent not available in optimized version!!!!\n\n\n"); }
87 #else
88 #define OPTIMIZED_VERSION /*empty*/
89 #endif // CMK_TRACE_ENABLED
90
91 /*
92 On T3E, we need to have file number control by open/close files only when needed.
93 */
94 #if CMK_TRACE_LOGFILE_NUM_CONTROL
95   #define OPEN_LOG openLog("a");
96   #define CLOSE_LOG closeLog();
97 #else
98   #define OPEN_LOG
99   #define CLOSE_LOG
100 #endif //CMK_TRACE_LOGFILE_NUM_CONTROL
101
102 #if CMK_HAS_COUNTER_PAPI
103 #ifdef USE_SPP_PAPI
104 int papiEvents[NUMPAPIEVENTS];
105 #else
106 int papiEvents[NUMPAPIEVENTS] = { PAPI_L2_DCM, PAPI_FP_OPS };
107 #endif
108 #endif // CMK_HAS_COUNTER_PAPI
109
110 /**
111   For each TraceFoo module, _createTraceFoo() must be defined.
112   This function is called in _createTraces() generated in moduleInit.C
113 */
114 void _createTraceprojections(char **argv)
115 {
116   DEBUGF("%d createTraceProjections\n", CkMyPe());
117   CkpvInitialize(CkVec<char *>, usrEventlist);
118   CkpvInitialize(CkVec<UsrEvent *>*, usrEvents);
119   CkpvAccess(usrEvents) = new CkVec<UsrEvent *>();
120 #if CMK_BIGSIM_CHARM
121   // CthRegister does not call the constructor
122 //  CkpvAccess(usrEvents) = CkVec<UsrEvent *>();
123 #endif //CMK_BIGSIM_CHARM
124   CkpvInitialize(TraceProjections*, _trace);
125   CkpvAccess(_trace) = new  TraceProjections(argv);
126   CkpvAccess(_traces)->addTrace(CkpvAccess(_trace));
127   if (CkMyPe()==0) CkPrintf("Charm++: Tracemode Projections enabled.\n");
128 }
129  
130 /* ****** CW TEMPORARY LOCATION ***** Support for thread listeners */
131
132 struct TraceThreadListener {
133   struct CthThreadListener base;
134   int event;
135   int msgType;
136   int ep;
137   int srcPe;
138   int ml;
139   CmiObjId idx;
140 };
141
142 extern "C"
143 void traceThreadListener_suspend(struct CthThreadListener *l)
144 {
145   TraceThreadListener *a=(TraceThreadListener *)l;
146   /* here, we activate the appropriate trace codes for the appropriate
147      registered modules */
148   traceSuspend();
149 }
150
151 extern "C"
152 void traceThreadListener_resume(struct CthThreadListener *l) 
153 {
154   TraceThreadListener *a=(TraceThreadListener *)l;
155   /* here, we activate the appropriate trace codes for the appropriate
156      registered modules */
157   _TRACE_BEGIN_EXECUTE_DETAILED(a->event,a->msgType,a->ep,a->srcPe,a->ml,
158                                 CthGetThreadID(a->base.thread));
159   a->event=-1;
160   a->srcPe=CkMyPe(); /* potential lie to migrated threads */
161   a->ml=0;
162 }
163
164 extern "C"
165 void traceThreadListener_free(struct CthThreadListener *l) 
166 {
167   TraceThreadListener *a=(TraceThreadListener *)l;
168   delete a;
169 }
170
171 void TraceProjections::traceAddThreadListeners(CthThread tid, envelope *e)
172 {
173 #if CMK_TRACE_ENABLED
174   /* strip essential information from the envelope */
175   TraceThreadListener *a= new TraceThreadListener;
176   
177   a->base.suspend=traceThreadListener_suspend;
178   a->base.resume=traceThreadListener_resume;
179   a->base.free=traceThreadListener_free;
180   a->event=e->getEvent();
181   a->msgType=e->getMsgtype();
182   a->ep=e->getEpIdx();
183   a->srcPe=e->getSrcPe();
184   a->ml=e->getTotalsize();
185
186   CthAddListener(tid, (CthThreadListener *)a);
187 #endif
188 }
189
190 void LogPool::openLog(const char *mode)
191 {
192 #if CMK_PROJECTIONS_USE_ZLIB
193   if(compressed) {
194     if (nonDeltaLog) {
195       do {
196         zfp = gzopen(fname, mode);
197       } while (!zfp && (errno == EINTR || errno == EMFILE));
198       if(!zfp) CmiAbort("Cannot open Projections Compressed Non Delta Trace File for writing...\n");
199     }
200     if (deltaLog) {
201       do {
202         deltazfp = gzopen(dfname, mode);
203       } while (!deltazfp && (errno == EINTR || errno == EMFILE));
204       if (!deltazfp) 
205         CmiAbort("Cannot open Projections Compressed Delta Trace File for writing...\n");
206     }
207   } else {
208     if (nonDeltaLog) {
209       do {
210         fp = fopen(fname, mode);
211       } while (!fp && (errno == EINTR || errno == EMFILE));
212       if (!fp) {
213         CkPrintf("[%d] Attempting to open file [%s]\n",CkMyPe(),fname);
214         CmiAbort("Cannot open Projections Non Delta Trace File for writing...\n");
215       }
216     }
217     if (deltaLog) {
218       do {
219         deltafp = fopen(dfname, mode);
220       } while (!deltafp && (errno == EINTR || errno == EMFILE));
221       if (!deltafp) 
222         CmiAbort("Cannot open Projections Delta Trace File for writing...\n");
223     }
224   }
225 #else
226   if (nonDeltaLog) {
227     do {
228       fp = fopen(fname, mode);
229     } while (!fp && (errno == EINTR || errno == EMFILE));
230     if (!fp) {
231       CkPrintf("[%d] Attempting to open file [%s]\n",CkMyPe(),fname);
232       CmiAbort("Cannot open Projections Non Delta Trace File for writing...\n");
233     }
234   }
235   if (deltaLog) {
236     do {
237       deltafp = fopen(dfname, mode);
238     } while (!deltafp && (errno == EINTR || errno == EMFILE));
239     if(!deltafp) 
240       CmiAbort("Cannot open Projections Delta Trace File for writing...\n");
241   }
242 #endif
243 }
244
245 void LogPool::closeLog(void)
246 {
247 #if CMK_PROJECTIONS_USE_ZLIB
248   if(compressed) {
249     if (nonDeltaLog) gzclose(zfp);
250     if (deltaLog) gzclose(deltazfp);
251     return;
252   }
253 #endif
254   if (nonDeltaLog) { 
255 #if !defined(_WIN32) || defined(__CYGWIN__)
256     fsync(fileno(fp)); 
257 #endif
258     fclose(fp); 
259   }
260   if (deltaLog)  { 
261 #if !defined(_WIN32) || defined(__CYGWIN__)
262     fsync(fileno(deltafp)); 
263 #endif
264     fclose(deltafp);  
265   }
266 }
267
268 LogPool::LogPool(char *pgm) {
269   pool = new LogEntry[CkpvAccess(CtrLogBufSize)];
270   // defaults to writing data (no outlier changes)
271   writeSummaryFiles = 0;
272   writeData = true;
273   numEntries = 0;
274   // **CW** for simple delta encoding
275   prevTime = 0.0;
276   timeErr = 0.0;
277   globalStartTime = 0.0;
278   globalEndTime = 0.0;
279   headerWritten = 0;
280   numPhases = 0;
281   hasFlushed = false;
282
283   keepPhase = NULL;
284
285   fileCreated = false;
286   poolSize = CkpvAccess(CtrLogBufSize);
287   pgmname = new char[strlen(pgm)+1];
288   strcpy(pgmname, pgm);
289
290   //statistic init
291   statisLastProcessTimer = 0;
292   statisLastIdleTimer = 0;
293   statisLastPackTimer = 0;
294   statisLastUnpackTimer = 0;
295   statisTotalExecutionTime  = 0;
296   statisTotalIdleTime = 0;
297   statisTotalPackTime = 0;
298   statisTotalUnpackTime = 0;
299   statisTotalCreationMsgs = 0;
300   statisTotalCreationBytes = 0;
301   statisTotalMCastMsgs = 0;
302   statisTotalMCastBytes = 0;
303   statisTotalEnqueueMsgs = 0;
304   statisTotalDequeueMsgs = 0;
305   statisTotalRecvMsgs = 0;
306   statisTotalRecvBytes = 0;
307   statisTotalMemAlloc = 0;
308   statisTotalMemFree = 0;
309
310 }
311
312 void LogPool::createFile(const char *fix)
313 {
314   if (fileCreated) {
315     return;
316   }
317   
318   if(CmiNumPartitions() > 1) {
319     CmiMkdir(CkpvAccess(partitionRoot));
320   }
321
322   char* filenameLastPart = strrchr(pgmname, PATHSEP) + 1; // Last occurrence of path separator
323   char *pathPlusFilePrefix = new char[1024];
324  
325   if(nSubdirs > 0){
326     int sd = CkMyPe() % nSubdirs;
327     char *subdir = new char[1024];
328     sprintf(subdir, "%s.projdir.%d", pgmname, sd);
329     CmiMkdir(subdir);
330     sprintf(pathPlusFilePrefix, "%s%c%s%s", subdir, PATHSEP, filenameLastPart, fix);
331     delete[] subdir;
332   } else {
333     sprintf(pathPlusFilePrefix, "%s%s", pgmname, fix);
334   }
335
336   char pestr[10];
337   sprintf(pestr, "%d", CkMyPe());
338 #if CMK_PROJECTIONS_USE_ZLIB
339   int len;
340   if(compressed)
341     len = strlen(pathPlusFilePrefix)+strlen(".logold")+strlen(pestr)+strlen(".gz")+3;
342   else
343     len = strlen(pathPlusFilePrefix)+strlen(".logold")+strlen(pestr)+3;
344 #else
345   int len = strlen(pathPlusFilePrefix)+strlen(".logold")+strlen(pestr)+3;
346 #endif
347
348   if (nonDeltaLog) {
349     fname = new char[len];
350   }
351   if (deltaLog) {
352     dfname = new char[len];
353   }
354 #if CMK_PROJECTIONS_USE_ZLIB
355   if(compressed) {
356     if (deltaLog && nonDeltaLog) {
357       sprintf(fname, "%s.%s.logold.gz",  pathPlusFilePrefix, pestr);
358       sprintf(dfname, "%s.%s.log.gz", pathPlusFilePrefix, pestr);
359     } else {
360       if (nonDeltaLog) {
361         sprintf(fname, "%s.%s.log.gz", pathPlusFilePrefix,pestr);
362       } else {
363         sprintf(dfname, "%s.%s.log.gz", pathPlusFilePrefix, pestr);
364       }
365     }
366   } else {
367     if (deltaLog && nonDeltaLog) {
368       sprintf(fname, "%s.%s.logold", pathPlusFilePrefix, pestr);
369       sprintf(dfname, "%s.%s.log", pathPlusFilePrefix, pestr);
370     } else {
371       if (nonDeltaLog) {
372         sprintf(fname, "%s.%s.log", pathPlusFilePrefix, pestr);
373       } else {
374         sprintf(dfname, "%s.%s.log", pathPlusFilePrefix, pestr);
375       }
376     }
377   }
378 #else
379   if (deltaLog && nonDeltaLog) {
380     sprintf(fname, "%s.%s.logold", pathPlusFilePrefix, pestr);
381     sprintf(dfname, "%s.%s.log", pathPlusFilePrefix, pestr);
382   } else {
383     if (nonDeltaLog) {
384       sprintf(fname, "%s.%s.log", pathPlusFilePrefix, pestr);
385     } else {
386       sprintf(dfname, "%s.%s.log", pathPlusFilePrefix, pestr);
387     }
388   }
389 #endif
390   fileCreated = true;
391   delete[] pathPlusFilePrefix;
392   openLog("w");
393   CLOSE_LOG 
394 }
395
396 void LogPool::createSts(const char *fix)
397 {
398   CkAssert(CkMyPe() == 0);
399   if(CmiNumPartitions() > 1) {
400     CmiMkdir(CkpvAccess(partitionRoot));
401   }
402
403   // create the sts file
404   char *fname = new char[strlen(CkpvAccess(traceRoot))+strlen(fix)+strlen(".sts")+2];
405   sprintf(fname, "%s%s.sts", CkpvAccess(traceRoot), fix);
406   do
407     {
408       stsfp = fopen(fname, "w");
409     } while (!stsfp && (errno == EINTR || errno == EMFILE));
410   if(stsfp==0){
411     CmiPrintf("Cannot open projections sts file for writing due to %s\n", strerror(errno));
412     CmiAbort("Error!!\n");
413   }
414   delete[] fname;
415 }  
416
417 void LogPool::createTopo(const char *fix)
418 {
419   CkAssert(CkMyPe() == 0);
420   // create the topo file
421   char *fname = new char[strlen(CkpvAccess(traceRoot))+strlen(fix)+strlen(".topo")+2];
422   sprintf(fname, "%s%s.topo", CkpvAccess(traceRoot), fix);
423   do
424     {
425       topofp = fopen(fname, "w");
426     } while (!stsfp && (errno == EINTR || errno == EMFILE));
427   if(stsfp==0){
428     CmiPrintf("Cannot open projections topo file for writing due to %s\n", strerror(errno));
429     CmiAbort("Error!!\n");
430   }
431   delete[] fname;
432 }  
433
434 void LogPool::createRC()
435 {
436   // create the projections rc file.
437   fname = 
438     new char[strlen(CkpvAccess(traceRoot))+strlen(".projrc")+1];
439   sprintf(fname, "%s.projrc", CkpvAccess(traceRoot));
440   do {
441     rcfp = fopen(fname, "w");
442   } while (!rcfp && (errno == EINTR || errno == EMFILE));
443   if (rcfp==0) {
444     CmiAbort("Cannot open projections configuration file for writing.\n");
445   }
446   delete[] fname;
447 }
448
449 LogPool::~LogPool() 
450 {
451   if (writeData) {
452       if(writeSummaryFiles)
453           writeStatis();
454     writeLog();
455 #if !CMK_TRACE_LOGFILE_NUM_CONTROL
456     closeLog();
457 #endif
458   }
459
460 #if CMK_BIGSIM_CHARM
461   extern int correctTimeLog;
462   if (correctTimeLog) {
463     createFile("-bg");
464     if (CkMyPe() == 0) {
465       createSts("-bg");
466     }
467     writeHeader();
468     if (CkMyPe() == 0) writeSts(NULL);
469     postProcessLog();
470   }
471 #endif
472
473   delete[] pool;
474   delete [] fname;
475 }
476
477 void LogPool::writeHeader()
478 {
479   if (headerWritten) return;
480   headerWritten = 1;
481   if(!binary) {
482 #if CMK_PROJECTIONS_USE_ZLIB
483     if(compressed) {
484       if (nonDeltaLog) {
485         gzprintf(zfp, "PROJECTIONS-RECORD %d\n", numEntries);
486       }
487       if (deltaLog) {
488         gzprintf(deltazfp, "PROJECTIONS-RECORD %d DELTA\n", numEntries);
489       }
490     } 
491     else /* else clause is below... */
492 #endif
493     /*... may hang over from else above */ {
494       if (nonDeltaLog) {
495         fprintf(fp, "PROJECTIONS-RECORD %d\n", numEntries);
496       }
497       if (deltaLog) {
498         fprintf(deltafp, "PROJECTIONS-RECORD %d DELTA\n", numEntries);
499       }
500     }
501   }
502   else { // binary
503       if (nonDeltaLog) {
504         fwrite(&numEntries,sizeof(numEntries),1,fp);
505       }
506       if (deltaLog) {
507         fwrite(&numEntries,sizeof(numEntries),1,deltafp);
508       }
509   }
510 }
511
512 void LogPool::writeLog(void)
513 {
514   createFile();
515   OPEN_LOG
516   writeHeader();
517   if (nonDeltaLog) write(0);
518   if (deltaLog) write(1);
519   CLOSE_LOG
520 }
521
522 void LogPool::write(int writedelta) 
523 {
524   // **CW** Simple delta encoding implementation
525   // prevTime has to be maintained as an object variable because
526   // LogPool::write may be called several times depending on the
527   // +logsize value.
528   PUP::er *p = NULL;
529   if (binary) {
530     p = new PUP::toDisk(writedelta?deltafp:fp);
531   }
532 #if CMK_PROJECTIONS_USE_ZLIB
533   else if (compressed) {
534     p = new toProjectionsGZFile(writedelta?deltazfp:zfp);
535   }
536 #endif
537   else {
538     p = new toProjectionsFile(writedelta?deltafp:fp);
539   }
540   CmiAssert(p);
541   int curPhase = 0;
542   // **FIXME** - Should probably consider a more sophisticated bounds-based
543   //   approach for selective writing instead of making multiple if-checks
544   //   for every single event.
545   for(UInt i=0; i<numEntries; i++) {
546     if (!writedelta) {
547       if (keepPhase == NULL) {
548         // default case, when no phase selection is required.
549         pool[i].pup(*p);
550       } else {
551         // **FIXME** Might be a good idea to create a "filler" event block for
552         //   all the events taken out by phase filtering.
553         if (pool[i].type == END_PHASE) {
554           // always write phase markers
555           pool[i].pup(*p);
556           curPhase++;
557         } else if (pool[i].type == BEGIN_COMPUTATION ||
558                    pool[i].type == END_COMPUTATION) {
559           // always write BEGIN and END COMPUTATION markers
560           pool[i].pup(*p);
561         } else if (keepPhase[curPhase]) {
562           pool[i].pup(*p);
563         }
564       }
565     }
566     else {      // delta
567       // **FIXME** Implement phase-selective writing for delta logs
568       //   eventually
569       double time = pool[i].time;
570       if (pool[i].type != BEGIN_COMPUTATION && pool[i].type != END_COMPUTATION)
571       {
572         double timeDiff = (time-prevTime)*1.0e6;
573         UInt intTimeDiff = (UInt)timeDiff;
574         timeErr += timeDiff - intTimeDiff; /* timeErr is never >= 2.0 */
575         if (timeErr > 1.0) {
576           timeErr -= 1.0;
577           intTimeDiff++;
578         }
579         pool[i].time = intTimeDiff/1.0e6;
580       }
581       pool[i].pup(*p);
582       pool[i].time = time;      // restore time value
583       prevTime = time;
584     }
585   }
586   delete p;
587   delete [] keepPhase;
588 }
589
590 void LogPool::writeSts(void)
591 {
592   // for whining compilers
593   int i;
594   // generate an automatic unique ID for each log
595   fprintf(stsfp, "PROJECTIONS_ID %s\n", "");
596   fprintf(stsfp, "VERSION %s\n", PROJECTION_VERSION);
597   fprintf(stsfp, "TOTAL_PHASES %d\n", numPhases);
598 #if CMK_HAS_COUNTER_PAPI
599   fprintf(stsfp, "TOTAL_PAPI_EVENTS %d\n", NUMPAPIEVENTS);
600   // for now, use i, next time use papiEvents[i].
601   // **CW** papi event names is a hack.
602   char eventName[PAPI_MAX_STR_LEN];
603   for (i=0;i<NUMPAPIEVENTS;i++) {
604     PAPI_event_code_to_name(papiEvents[i], eventName);
605     fprintf(stsfp, "PAPI_EVENT %d %s\n", i, eventName);
606   }
607 #endif
608   traceWriteSTS(stsfp,CkpvAccess(usrEvents)->length());
609   for(i=0;i<CkpvAccess(usrEvents)->length();i++){
610     fprintf(stsfp, "EVENT %d %s\n", (*CkpvAccess(usrEvents))[i]->e, (*CkpvAccess(usrEvents))[i]->str);
611   }     
612 }
613
614 void LogPool::writeSts(TraceProjections *traceProj){
615   writeSts();
616   if (traceProj != NULL) {
617     CkHashtableIterator  *funcIter = traceProj->getfuncIterator();
618     funcIter->seekStart();
619     int numFuncs = traceProj->getFuncNumber();
620     fprintf(stsfp,"TOTAL_FUNCTIONS %d \n",numFuncs);
621     while(funcIter->hasNext()) {
622       StrKey *key;
623       int *obj = (int *)funcIter->next((void **)&key);
624       fprintf(stsfp,"FUNCTION %d %s \n",*obj,key->getStr());
625     }
626   }
627   fprintf(stsfp, "END\n");
628   fclose(stsfp);
629 }
630
631 void LogPool::writeRC(void)
632 {
633     //CkPrintf("write RC is being executed\n");
634 #ifdef PROJ_ANALYSIS  
635     CkAssert(CkMyPe() == 0);
636     fprintf(rcfp,"RC_GLOBAL_START_TIME %lld\n",
637             (CMK_PUP_LONG_LONG)(1.0e6*globalStartTime));
638     fprintf(rcfp,"RC_GLOBAL_END_TIME   %lld\n",
639             (CMK_PUP_LONG_LONG)(1.0e6*globalEndTime));
640     /* //Yanhua comment it because isOutlierAutomatic is not a variable in trace
641     if (CkpvAccess(_trace)->isOutlierAutomatic()) {
642       fprintf(rcfp,"RC_OUTLIER_FILTERED true\n");
643     } else {
644       fprintf(rcfp,"RC_OUTLIER_FILTERED false\n");
645     }
646     */
647 #endif //PROJ_ANALYSIS
648   fclose(rcfp);
649 }
650
651 void LogPool::writeTopo(void)
652 {
653   TopoManager tmgr;
654   tmgr.printAllocation(topofp);
655   fclose(topofp);
656 }
657
658 void LogPool::writeStatis(void)
659 {
660     
661    // create the statis file
662   char *fname = new char[strlen(CkpvAccess(traceRoot))+strlen(".statis")+10];
663   sprintf(fname, "%s.%d.statis", CkpvAccess(traceRoot), CkMyPe());
664   do
665   {
666       statisfp = fopen(fname, "w");
667   } while (!statisfp && (errno == EINTR || errno == EMFILE));
668   if(statisfp==0){
669       CmiPrintf("Cannot open projections statistic file for writing due to %s\n", strerror(errno));
670       CmiAbort("Error!!\n");
671   }
672   delete[] fname;
673   double totaltime = endComputationTime - beginComputationTime;
674   fprintf(statisfp, "time(sec) percentage\n");
675   fprintf(statisfp, "Time:    \t%f\n", totaltime);
676   fprintf(statisfp, "Idle :\t%f\t %.1f\n", statisTotalIdleTime, statisTotalIdleTime/totaltime * 100); 
677   fprintf(statisfp, "Overhead:    \t%f\t %.1f\n", totaltime - statisTotalIdleTime - statisTotalExecutionTime , (totaltime - statisTotalIdleTime - statisTotalExecutionTime)/totaltime * 100); 
678   fprintf(statisfp, "Exeuction:\t%f\t %.1f\n", statisTotalExecutionTime, statisTotalExecutionTime/totaltime*100); 
679   fprintf(statisfp, "Pack:     \t%f\t %.2f\n", statisTotalPackTime, statisTotalPackTime/totaltime*100); 
680   fprintf(statisfp, "Unpack:   \t%f\t %.2f\n", statisTotalUnpackTime, statisTotalUnpackTime/totaltime*100); 
681   fprintf(statisfp, "Creation Msgs Numbers, Bytes, Avg:   \t%lld\t %lld\t %lld \n", statisTotalCreationMsgs, statisTotalCreationBytes, (statisTotalCreationMsgs>0)?statisTotalCreationBytes/statisTotalCreationMsgs:statisTotalCreationMsgs); 
682   fprintf(statisfp, "Multicast Msgs Numbers, Bytes, Avg:   \t%lld\t %lld\t %lld \n", statisTotalMCastMsgs, statisTotalMCastBytes, (statisTotalMCastMsgs>0)?statisTotalMCastBytes/statisTotalMCastMsgs:statisTotalMCastMsgs); 
683   fprintf(statisfp, "Received Msgs Numbers, Bytes, Avg:   \t%lld\t %lld\t %lld \n", statisTotalRecvMsgs, statisTotalRecvBytes, (statisTotalRecvMsgs>0)?statisTotalRecvBytes/statisTotalRecvMsgs:statisTotalRecvMsgs); 
684   fclose(statisfp);
685 }
686
687 #if CMK_BIGSIM_CHARM
688 static void updateProjLog(void *data, double t, double recvT, void *ptr)
689 {
690   LogEntry *log = (LogEntry *)data;
691   FILE *fp = *(FILE **)ptr;
692   log->time = t;
693   log->recvTime = recvT<0.0?0:recvT;
694 //  log->write(fp);
695   toProjectionsFile p(fp);
696   log->pup(p);
697 }
698 #endif
699
700 // flush log entries to disk
701 void LogPool::flushLogBuffer()
702 {
703   if (numEntries) {
704     double writeTime = TraceTimer();
705     writeLog();
706     hasFlushed = true;
707     numEntries = 0;
708     new (&pool[numEntries++]) LogEntry(writeTime, BEGIN_INTERRUPT);
709     new (&pool[numEntries++]) LogEntry(TraceTimer(), END_INTERRUPT);
710     //CkPrintf("Warning: Projections log flushed to disk on PE %d.\n", CkMyPe());
711     if (!traceProjectionsGID.isZero()) {    // report flushing events to PE 0
712       CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
713       bocProxy[0].flush_warning(CkMyPe());
714     }
715   }
716 }
717
718 void LogPool::add(UChar type, UShort mIdx, UShort eIdx,
719                   double time, int event, int pe, int ml, CmiObjId *id, 
720                   double recvT, double cpuT, int numPe)
721 {
722     switch(type)
723     {
724         case BEGIN_COMPUTATION:
725             beginComputationTime = time;
726             break;
727         case END_COMPUTATION:
728             endComputationTime = time;
729             break;
730         case CREATION:
731             statisTotalCreationMsgs++;
732             statisTotalCreationBytes += ml;
733             break;
734         case CREATION_MULTICAST:
735             statisTotalMCastMsgs++;
736             statisTotalMCastBytes += ml;
737             break;
738         case ENQUEUE:
739             statisTotalEnqueueMsgs++;
740             break;
741         case DEQUEUE:
742             statisTotalDequeueMsgs++;
743             break;
744         case MESSAGE_RECV:
745             statisTotalRecvMsgs++;
746             statisTotalRecvBytes += ml;
747             break;
748         case MEMORY_MALLOC:
749             statisTotalMemAlloc++;
750             break;
751         case MEMORY_FREE:
752             statisTotalMemFree++;
753             break;
754         case BEGIN_PROCESSING:
755             statisLastProcessTimer = time;
756             break;
757         case BEGIN_UNPACK:
758             statisLastUnpackTimer = time;
759             break;
760         case BEGIN_PACK:
761             statisLastPackTimer = time;
762             break;
763         case BEGIN_IDLE:
764             statisLastIdleTimer = time;
765             break;
766         case END_PROCESSING:
767             statisTotalExecutionTime += (time - statisLastProcessTimer);
768             break;
769         case END_UNPACK:
770             statisTotalUnpackTime += (time - statisLastUnpackTimer);
771             break;
772         case END_PACK:
773             statisTotalPackTime += (time - statisLastPackTimer);
774             break;
775         case END_IDLE:
776             statisTotalIdleTime += (time - statisLastIdleTimer);
777             break;
778         default:
779             break;
780     }
781   new (&pool[numEntries++])
782     LogEntry(time, type, mIdx, eIdx, event, pe, ml, id, recvT, cpuT, numPe);
783   if ((type == END_PHASE) || (type == END_COMPUTATION)) {
784     numPhases++;
785   }
786   if(poolSize==numEntries) {
787     flushLogBuffer();
788 #if CMK_BIGSIM_CHARM
789     extern int correctTimeLog;
790     if (correctTimeLog) CmiAbort("I/O interrupt!\n");
791 #endif
792   }
793 #if CMK_BIGSIM_CHARM
794   switch (type) {
795     case BEGIN_PROCESSING:
796       pool[numEntries-1].recvTime = BgGetRecvTime();
797     case END_PROCESSING:
798     case BEGIN_COMPUTATION:
799     case END_COMPUTATION:
800     case CREATION:
801     case BEGIN_PACK:
802     case END_PACK:
803     case BEGIN_UNPACK:
804     case END_UNPACK:
805     case USER_EVENT_PAIR:
806       bgAddProjEvent(&pool[numEntries-1], numEntries-1, time, updateProjLog, &fp, BG_EVENT_PROJ);
807   }
808 #endif
809 }
810
811 void LogPool::add(UChar type,double time,UShort funcID,int lineNum,char *fileName){
812 #ifndef CMK_BIGSIM_CHARM
813   new (&pool[numEntries++])
814         LogEntry(time,type,funcID,lineNum,fileName);
815   if(poolSize == numEntries){
816     flushLogBuffer();
817   }
818 #endif  
819 }
820
821
822   
823 void LogPool::addMemoryUsage(unsigned char type,double time,double memUsage){
824 #ifndef CMK_BIGSIM_CHARM
825   new (&pool[numEntries++])
826         LogEntry(type,time,memUsage);
827   if(poolSize == numEntries){
828     flushLogBuffer();
829   }
830 #endif  
831         
832 }  
833
834
835
836 void LogPool::addUserSupplied(int data){
837         // add an event
838         add(USER_SUPPLIED, 0, 0, TraceTimer(), -1, -1, 0, 0, 0, 0, 0 );
839
840         // set the user supplied value for the previously created event 
841         pool[numEntries-1].setUserSuppliedData(data);
842   }
843
844
845 void LogPool::addUserSuppliedNote(char *note){
846         // add an event
847         add(USER_SUPPLIED_NOTE, 0, 0, TraceTimer(), -1, -1, 0, 0, 0, 0, 0 );
848
849         // set the user supplied note for the previously created event 
850         pool[numEntries-1].setUserSuppliedNote(note);
851   }
852
853 void LogPool::addUserSuppliedBracketedNote(char *note, int eventID, double bt, double et){
854   //CkPrintf("LogPool::addUserSuppliedBracketedNote eventID=%d\n", eventID);
855 #ifndef CMK_BIGSIM_CHARM
856 #if MPI_TRACE_MACHINE_HACK
857   //This part of code is used  to combine the contiguous
858   //MPI_Test and MPI_Iprobe events to reduce the number of
859   //entries
860 #define MPI_TEST_EVENT_ID 60
861 #define MPI_IPROBE_EVENT_ID 70 
862   int lastEvent = pool[numEntries-1].event;
863   if((eventID==MPI_TEST_EVENT_ID || eventID==MPI_IPROBE_EVENT_ID) && (eventID==lastEvent)){
864     //just replace the endtime of last event
865     //CkPrintf("addUserSuppliedBracketNote: for event %d\n", lastEvent);
866     pool[numEntries].endTime = et;
867   }else{
868     new (&pool[numEntries++])
869       LogEntry(bt, et, USER_SUPPLIED_BRACKETED_NOTE, note, eventID);
870   }
871 #else
872   new (&pool[numEntries++])
873     LogEntry(bt, et, USER_SUPPLIED_BRACKETED_NOTE, note, eventID);
874 #endif
875   if(poolSize == numEntries){
876     flushLogBuffer();
877   }
878 #endif  
879 }
880
881
882 /* **CW** Not sure if this is the right thing to do. Feels more like
883    a hack than a solution to Sameer's request to add the destination
884    processor information to multicasts and broadcasts.
885
886    In the unlikely event this method is used for Broadcasts as well,
887    pelist == NULL will be used to indicate a global broadcast with 
888    num PEs.
889 */
890 void LogPool::addCreationMulticast(UShort mIdx, UShort eIdx, double time,
891                                    int event, int pe, int ml, CmiObjId *id,
892                                    double recvT, int numPe, int *pelist)
893 {
894   new (&pool[numEntries++])
895     LogEntry(time, mIdx, eIdx, event, pe, ml, id, recvT, numPe, pelist);
896   if(poolSize==numEntries) {
897     flushLogBuffer();
898   }
899 }
900
901 void LogPool::postProcessLog()
902 {
903 #if CMK_BIGSIM_CHARM
904   bgUpdateProj(1);   // event type
905 #endif
906 }
907
908 void LogPool::modLastEntryTimestamp(double ts)
909 {
910   pool[numEntries-1].time = ts;
911   //pool[numEntries-1].cputime = ts;
912 }
913
914 // /** Constructor for a multicast log entry */
915 // 
916 //  THIS WAS MOVED TO trace-projections.h with the other constructors
917 // 
918 // LogEntry::LogEntry(double tm, unsigned short m, unsigned short e, int ev, int p,
919 //           int ml, CmiObjId *d, double rt, int numPe, int *pelist) 
920 // {
921 //     type = CREATION_MULTICAST; mIdx = m; eIdx = e; event = ev; pe = p; time = tm; msglen = ml;
922 //     if (d) id = *d; else {id.id[0]=id.id[1]=id.id[2]=id.id[3]=-1; };
923 //     recvTime = rt; 
924 //     numpes = numPe;
925 //     userSuppliedNote = NULL;
926 //     if (pelist != NULL) {
927 //      pes = new int[numPe];
928 //      for (int i=0; i<numPe; i++) {
929 //        pes[i] = pelist[i];
930 //      }
931 //     } else {
932 //      pes= NULL;
933 //     }
934 // }
935
936 //void LogEntry::addPapi(LONG_LONG_PAPI *papiVals)
937 //{
938 //#if CMK_HAS_COUNTER_PAPI
939 //   memcpy(papiValues, papiVals, sizeof(LONG_LONG_PAPI)*NUMPAPIEVENTS);
940 //#endif
941 //}
942
943
944
945 void LogEntry::pup(PUP::er &p)
946 {
947   int i;
948   CMK_TYPEDEF_UINT8 itime, iEndTime, irecvtime, icputime;
949   char ret = '\n';
950
951   p|type;
952   if (p.isPacking()) itime = (CMK_TYPEDEF_UINT8)(1.0e6*time);
953   if (p.isPacking()) iEndTime = (CMK_TYPEDEF_UINT8)(1.0e6*endTime);
954
955   switch (type) {
956     case USER_EVENT:
957     case USER_EVENT_PAIR:
958       p|mIdx; p|itime; p|event; p|pe;
959       break;
960     case BEGIN_IDLE:
961     case END_IDLE:
962     case BEGIN_PACK:
963     case END_PACK:
964     case BEGIN_UNPACK:
965     case END_UNPACK:
966       p|itime; p|pe; 
967       break;
968     case BEGIN_PROCESSING:
969       if (p.isPacking()) {
970         irecvtime = (CMK_TYPEDEF_UINT8)(recvTime==-1?-1:1.0e6*recvTime);
971         icputime = (CMK_TYPEDEF_UINT8)(1.0e6*cputime);
972       }
973       p|mIdx; p|eIdx; p|itime; p|event; p|pe; 
974       p|msglen; p|irecvtime; 
975       p|id.id[0]; p|id.id[1]; p|id.id[2]; p|id.id[3];
976       p|icputime;
977 #if CMK_HAS_COUNTER_PAPI
978       //p|numPapiEvents;
979       for (i=0; i<NUMPAPIEVENTS; i++) {
980         // not yet!!!
981         //      p|papiIDs[i]; 
982         p|papiValues[i];
983         
984       }
985 #else
986       //p|numPapiEvents;     // non papi version has value 0
987 #endif
988       if (p.isUnpacking()) {
989         recvTime = irecvtime/1.0e6;
990         cputime = icputime/1.0e6;
991       }
992       break;
993     case END_PROCESSING:
994       if (p.isPacking()) icputime = (CMK_TYPEDEF_UINT8)(1.0e6*cputime);
995       p|mIdx; p|eIdx; p|itime; p|event; p|pe; p|msglen; p|icputime;
996 #if CMK_HAS_COUNTER_PAPI
997       //p|numPapiEvents;
998       for (i=0; i<NUMPAPIEVENTS; i++) {
999         // not yet!!!
1000         //      p|papiIDs[i];
1001         p|papiValues[i];
1002       }
1003 #else
1004       //p|numPapiEvents;  // non papi version has value 0
1005 #endif
1006       if (p.isUnpacking()) cputime = icputime/1.0e6;
1007       break;
1008     case USER_SUPPLIED:
1009           p|userSuppliedData;
1010           p|itime;
1011         break;
1012     case USER_SUPPLIED_NOTE:
1013           p|itime;
1014           int length;
1015           if (p.isPacking()) length = strlen(userSuppliedNote);
1016           p | length;
1017           char space;
1018           space = ' ';
1019           p | space;
1020           if (p.isUnpacking()) {
1021             userSuppliedNote = new char[length+1];
1022             userSuppliedNote[length] = '\0';
1023           }
1024           PUParray(p,userSuppliedNote, length);
1025           break;
1026     case USER_SUPPLIED_BRACKETED_NOTE:
1027       //CkPrintf("Writting out a USER_SUPPLIED_BRACKETED_NOTE\n");
1028           p|itime;
1029           p|iEndTime;
1030           p|event;
1031           int length2;
1032           if (p.isPacking()) length2 = strlen(userSuppliedNote);
1033           p | length2;
1034           char space2;
1035           space2 = ' ';
1036           p | space2;
1037           if (p.isUnpacking()) {
1038             userSuppliedNote = new char[length+1];
1039             userSuppliedNote[length] = '\0';
1040           }
1041           PUParray(p,userSuppliedNote, length2);
1042           break;
1043     case MEMORY_USAGE_CURRENT:
1044       p | memUsage;
1045       p | itime;
1046         break;
1047     case CREATION:
1048       if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
1049       p|mIdx; p|eIdx; p|itime;
1050       p|event; p|pe; p|msglen; p|irecvtime;
1051       if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
1052       break;
1053     case CREATION_BCAST:
1054       if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
1055       p|mIdx; p|eIdx; p|itime;
1056       p|event; p|pe; p|msglen; p|irecvtime; p|numpes;
1057       if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
1058       break;
1059     case CREATION_MULTICAST:
1060       if (p.isPacking()) irecvtime = (CMK_TYPEDEF_UINT8)(1.0e6*recvTime);
1061       p|mIdx; p|eIdx; p|itime;
1062       p|event; p|pe; p|msglen; p|irecvtime; p|numpes;
1063       if (p.isUnpacking()) pes = numpes?new int[numpes]:NULL;
1064       for (i=0; i<numpes; i++) p|pes[i];
1065       if (p.isUnpacking()) recvTime = irecvtime/1.0e6;
1066       break;
1067     case MESSAGE_RECV:
1068       p|mIdx; p|eIdx; p|itime; p|event; p|pe; p|msglen;
1069       break;
1070
1071     case ENQUEUE:
1072     case DEQUEUE:
1073       p|mIdx; p|itime; p|event; p|pe;
1074       break;
1075
1076     case BEGIN_INTERRUPT:
1077     case END_INTERRUPT:
1078       p|itime; p|event; p|pe;
1079       break;
1080
1081       // **CW** absolute timestamps are used here to support a quick
1082       // way of determining the total time of a run in projections
1083       // visualization.
1084     case BEGIN_COMPUTATION:
1085     case END_COMPUTATION:
1086     case BEGIN_TRACE:
1087     case END_TRACE:
1088       p|itime;
1089       break;
1090     case BEGIN_FUNC:
1091         p | itime;
1092         p | mIdx;
1093         p | event;
1094         if(!p.isUnpacking()){
1095                 p(fName,flen-1);
1096         }
1097         break;
1098     case END_FUNC:
1099         p | itime;
1100         p | mIdx;
1101         break;
1102     case END_PHASE:
1103       p|eIdx; // FIXME: actually the phase ID
1104       p|itime;
1105       break;
1106     default:
1107       CmiError("***Internal Error*** Wierd Event %d.\n", type);
1108       break;
1109   }
1110   if (p.isUnpacking()) time = itime/1.0e6;
1111   p|ret;
1112 }
1113
1114 TraceProjections::TraceProjections(char **argv): 
1115   curevent(0), inEntry(0), computationStarted(0), 
1116         converseExit(0), endTime(0.0), traceNestedEvents(0),
1117         currentPhaseID(0), lastPhaseEvent(NULL)
1118 {
1119   //  CkPrintf("Trace projections dummy constructor called on %d\n",CkMyPe());
1120
1121   if (CkpvAccess(traceOnPe) == 0) return;
1122
1123   CtvInitialize(int,curThreadEvent);
1124   CkpvInitialize(CmiInt8, CtrLogBufSize);
1125   CkpvAccess(CtrLogBufSize) = DefaultLogBufSize;
1126   CtvAccess(curThreadEvent)=0;
1127   if (CmiGetArgLongDesc(argv,"+logsize",&CkpvAccess(CtrLogBufSize), 
1128                        "Log entries to buffer per I/O")) {
1129     if (CkMyPe() == 0) {
1130       CmiPrintf("Trace: logsize: %ld\n", CkpvAccess(CtrLogBufSize));
1131     }
1132   }
1133   checknested = 
1134     CmiGetArgFlagDesc(argv,"+checknested",
1135                       "check projections nest begin end execute events");
1136   traceNestedEvents = 
1137     CmiGetArgFlagDesc(argv,"+tracenested",
1138               "trace projections nest begin/end execute events");
1139   int binary = 
1140     CmiGetArgFlagDesc(argv,"+binary-trace",
1141                       "Write log files in binary format");
1142
1143   CmiInt8 nSubdirs = 0;
1144   CmiGetArgLongDesc(argv,"+trace-subdirs", &nSubdirs, "Number of subdirectories into which traces will be written");
1145
1146
1147 #if CMK_PROJECTIONS_USE_ZLIB
1148   int compressed = true;
1149   CmiGetArgFlagDesc(argv,"+gz-trace","Write log files pre-compressed with gzip");
1150   int disableCompressed = CmiGetArgFlagDesc(argv,"+no-gz-trace","Disable writing log files pre-compressed with gzip");
1151   compressed = compressed && !disableCompressed;
1152 #else
1153   // consume the flag so there's no confusing
1154   CmiGetArgFlagDesc(argv,"+gz-trace",
1155                     "Write log files pre-compressed with gzip");
1156   if(CkMyPe() == 0) CkPrintf("Warning> gz-trace is not supported on this machine!\n");
1157 #endif
1158
1159   int writeSummaryFiles = CmiGetArgFlagDesc(argv,"+write-analysis-file","Enable writing summary files "); 
1160   
1161   // **CW** default to non delta log encoding. The user may choose to do
1162   // create both logs (for debugging) or just the old log timestamping
1163   // (for compatibility).
1164   // Generating just the non delta log takes precedence over generating
1165   // both logs (if both arguments appear on the command line).
1166
1167   // switch to OLD log format until everything works // Gengbin
1168   nonDeltaLog = 1;
1169   deltaLog = 0;
1170   deltaLog = CmiGetArgFlagDesc(argv, "+logDelta",
1171                                   "Generate Delta encoded and simple timestamped log files");
1172
1173   _logPool = new LogPool(CkpvAccess(traceRoot));
1174   _logPool->setNumSubdirs(nSubdirs);
1175   _logPool->setBinary(binary);
1176   _logPool->setWriteSummaryFiles(writeSummaryFiles);
1177 #if CMK_PROJECTIONS_USE_ZLIB
1178   _logPool->setCompressed(compressed);
1179 #endif
1180   if (CkMyPe() == 0) {
1181     _logPool->createSts();
1182     _logPool->createRC();
1183     _logPool->createTopo();
1184   }
1185   funcCount=1;
1186
1187 #if CMK_HAS_COUNTER_PAPI
1188   // We initialize and create the event sets for use with PAPI here.
1189   int papiRetValue;
1190   if(CkMyRank()==0){
1191     papiRetValue = PAPI_library_init(PAPI_VER_CURRENT);
1192     if (papiRetValue != PAPI_VER_CURRENT) {
1193       CmiAbort("PAPI Library initialization failure!\n");
1194     }
1195 #if CMK_SMP
1196     if(PAPI_thread_init(pthread_self) != PAPI_OK){
1197       CmiAbort("PAPI could not be initialized in SMP mode!\n");
1198     }
1199 #endif
1200   }
1201
1202 #if CMK_SMP
1203   //PAPI_thread_init has to finish before calling PAPI_create_eventset
1204   #if CMK_SMP_TRACE_COMMTHREAD
1205       CmiNodeAllBarrier();
1206   #else
1207       CmiNodeBarrier();
1208   #endif
1209 #endif
1210   // PAPI 3 mandates the initialization of the set to PAPI_NULL
1211   papiEventSet = PAPI_NULL; 
1212   if (PAPI_create_eventset(&papiEventSet) != PAPI_OK) {
1213     CmiAbort("PAPI failed to create event set!\n");
1214   }
1215 #ifdef USE_SPP_PAPI
1216   //  CmiPrintf("Using SPP counters for PAPI\n");
1217   if(PAPI_query_event(PAPI_FP_OPS)==PAPI_OK) {
1218     papiEvents[0] = PAPI_FP_OPS;
1219   }else{
1220     if(CmiMyPe()==0){
1221       CmiAbort("WARNING: PAPI_FP_OPS doesn't exist on this platform!");
1222     }
1223   }
1224   if(PAPI_query_event(PAPI_TOT_INS)==PAPI_OK) {
1225     papiEvents[1] = PAPI_TOT_INS;
1226   }else{
1227     CmiAbort("WARNING: PAPI_TOT_INS doesn't exist on this platform!");
1228   }
1229   int EventCode;
1230   int ret;
1231   ret=PAPI_event_name_to_code("perf::PERF_COUNT_HW_CACHE_LL:MISS",&EventCode);
1232   if(PAPI_query_event(EventCode)==PAPI_OK) {
1233     papiEvents[2] = EventCode;
1234   }else{
1235     CmiAbort("WARNING: perf::PERF_COUNT_HW_CACHE_LL:MISS doesn't exist on this platform!");
1236   }
1237   ret=PAPI_event_name_to_code("DATA_PREFETCHER:ALL",&EventCode);
1238   if(PAPI_query_event(EventCode)==PAPI_OK) {
1239     papiEvents[3] = EventCode;
1240   }else{
1241     CmiAbort("WARNING: DATA_PREFETCHER:ALL doesn't exist on this platform!");
1242   }
1243   if(PAPI_query_event(PAPI_L1_DCA)==PAPI_OK) {
1244     papiEvents[4] = PAPI_L1_DCA;
1245   }else{
1246     CmiAbort("WARNING: PAPI_L1_DCA doesn't exist on this platform!");
1247   }
1248   if(PAPI_query_event(PAPI_TOT_CYC)==PAPI_OK) {
1249     papiEvents[5] = PAPI_TOT_CYC;
1250   }else{
1251     CmiAbort("WARNING: PAPI_TOT_CYC doesn't exist on this platform!");
1252   }
1253 #else
1254   // just uses { PAPI_L2_DCM, PAPI_FP_OPS } the 2 initialized PAPI_EVENTS
1255 #endif
1256   papiRetValue = PAPI_add_events(papiEventSet, papiEvents, NUMPAPIEVENTS);
1257   if (papiRetValue < 0) {
1258     if (papiRetValue == PAPI_ECNFLCT) {
1259       CmiAbort("PAPI events conflict! Please re-assign event types!\n");
1260     } else {
1261       char error_str[PAPI_MAX_STR_LEN];
1262       PAPI_perror(error_str);
1263       //PAPI_perror(papiRetValue,error_str,PAPI_MAX_STR_LEN);
1264       CmiPrintf("PAPI failed with error %s val %d\n",error_str,papiRetValue);
1265       CmiAbort("PAPI failed to add designated events!\n");
1266     }
1267   }
1268   if(CkMyPe()==0)
1269     {
1270       CmiPrintf("Registered %d PAPI counters:",NUMPAPIEVENTS);
1271       char nameBuf[PAPI_MAX_STR_LEN];
1272       for(int i=0;i<NUMPAPIEVENTS;i++)
1273         {
1274           PAPI_event_code_to_name(papiEvents[i], nameBuf);
1275           CmiPrintf("%s ",nameBuf);
1276         }
1277       CmiPrintf("\n");
1278     }
1279   memset(papiValues, 0, NUMPAPIEVENTS*sizeof(LONG_LONG_PAPI));
1280 #endif
1281 }
1282
1283 int TraceProjections::traceRegisterUserEvent(const char* evt, int e)
1284 {
1285   OPTIMIZED_VERSION
1286   CkAssert(e==-1 || e>=0);
1287   CkAssert(evt != NULL);
1288   int event;
1289   int biggest = -1;
1290   for (int i=0; i<CkpvAccess(usrEvents)->length(); i++) {
1291     int cur = (*CkpvAccess(usrEvents))[i]->e;
1292     if (cur == e) {
1293       //CmiPrintf("%s %s\n", (*CkpvAccess(usrEvents))[i]->str, evt);
1294       if (strcmp((*CkpvAccess(usrEvents))[i]->str, evt) == 0) 
1295         return e;
1296       else
1297         CmiAbort("UserEvent double registered!");
1298     }
1299     if (cur > biggest) biggest = cur;
1300   }
1301   // if no user events have so far been registered. biggest will be -1
1302   // and hence newly assigned event numbers will begin from 0.
1303   if (e==-1) event = biggest+1;  // automatically assign new event number
1304   else event = e;
1305   CkpvAccess(usrEvents)->push_back(new UsrEvent(event,(char *)evt));
1306   return event;
1307 }
1308
1309 void TraceProjections::traceClearEps(void)
1310 {
1311   // In trace-summary, this zeros out the EP bins, to eliminate noise
1312   // from startup.  Here, this isn't useful, since we can do that in
1313   // post-processing
1314 }
1315
1316 void TraceProjections::traceWriteSts(void)
1317 {
1318   if(CkMyPe()==0)
1319     _logPool->writeSts(this);
1320 }
1321
1322 /** 
1323  * **IMPT NOTES**:
1324  *
1325  * This is called when Converse closes during ConverseCommonExit().
1326  * **FIXME**(?) - is this also exposed as a tracing-framework API call?
1327  *
1328  * Some programs bypass CkExit() (like NAMD, which eventually calls
1329  * ConverseExit()), modules like traces will have to pretend to shutdown
1330  * as if CkExit() was called but at the same time avoid making
1331  * subsequent CkExit() calls (which is usually required for allowing
1332  * other modules to shutdown).
1333  *
1334  * Note that we can only get here if CkExit() was not called, since the
1335  * trace module will un-register itself from TraceArray if it did.
1336  *
1337  */
1338 void TraceProjections::traceClose(void)
1339 {
1340 #ifdef PROJ_ANALYSIS
1341   // CkPrintf("CkExit was not called on shutdown on [%d]\n", CkMyPe());
1342
1343   // sets the flag that tells the code not to make the CkExit call later
1344   converseExit = 1;
1345   if (CkMyPe() == 0) {
1346     CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
1347     bocProxy.traceProjectionsParallelShutdown(-1);
1348   }
1349   if(CkMyRank() == CkMyNodeSize()){ //communication thread
1350     CkpvAccess(_trace)->endComputation();
1351     delete _logPool;              // will write
1352     // remove myself from traceArray so that no tracing will be called.
1353     CkpvAccess(_traces)->removeTrace(this);
1354   }
1355 #else
1356   // we've already deleted the logpool, so multiple calls to traceClose
1357   // are tolerated.
1358   if (_logPool == NULL) {
1359     return;
1360   }
1361   if(CkMyPe()==0){
1362     _logPool->writeSts(this);
1363   }
1364   CkpvAccess(_trace)->endComputation();
1365   delete _logPool;              // will write
1366   // remove myself from traceArray so that no tracing will be called.
1367   CkpvAccess(_traces)->removeTrace(this);
1368
1369   CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
1370   bocProxy.ckLocalBranch()->print_warning();
1371 #endif
1372 }
1373
1374 /**
1375  *  **IMPT NOTES**:
1376  *
1377  *  This is meant to be called internally by the tracing framework.
1378  *
1379  */
1380 void TraceProjections::closeTrace() {
1381   //  CkPrintf("Close Trace called on [%d]\n", CkMyPe());
1382   if (CkMyPe() == 0) {
1383     // CkPrintf("Pe 0 will now write sts and projrc files\n");
1384     _logPool->writeSts(this);
1385     _logPool->writeRC();
1386     _logPool->writeTopo();
1387     // CkPrintf("Pe 0 has now written sts and projrc files\n");
1388
1389     CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
1390     bocProxy.ckLocalBranch()->print_warning();
1391   }
1392   delete _logPool;       // will write logs to file
1393
1394 }
1395
1396 #if CMK_SMP_TRACE_COMMTHREAD
1397 void TraceProjections::traceBeginOnCommThread()
1398 {
1399   if (!computationStarted) return;
1400   _logPool->add(BEGIN_TRACE, 0, 0, TraceTimer(), curevent++, CmiNumPes()+CmiMyNode());
1401 }
1402
1403 void TraceProjections::traceEndOnCommThread()
1404 {
1405   _logPool->add(END_TRACE, 0, 0, TraceTimer(), curevent++, CmiNumPes()+CmiMyNode());
1406 }
1407 #endif
1408
1409 void TraceProjections::traceBegin(void)
1410 {
1411   if (!computationStarted) return;
1412   _logPool->add(BEGIN_TRACE, 0, 0, TraceTimer(), curevent++, CkMyPe());
1413 }
1414
1415 void TraceProjections::traceEnd(void)
1416 {
1417   _logPool->add(END_TRACE, 0, 0, TraceTimer(), curevent++, CkMyPe());
1418 }
1419
1420 void TraceProjections::userEvent(int e)
1421 {
1422   if (!computationStarted) return;
1423   _logPool->add(USER_EVENT, e, 0, TraceTimer(),curevent++,CkMyPe());
1424 }
1425
1426 void TraceProjections::userBracketEvent(int e, double bt, double et)
1427 {
1428   if (!computationStarted) return;
1429   // two events record Begin/End of event e.
1430   _logPool->add(USER_EVENT_PAIR, e, 0, TraceTimer(bt), curevent, CkMyPe());
1431   _logPool->add(USER_EVENT_PAIR, e, 0, TraceTimer(et), curevent++, CkMyPe());
1432 }
1433
1434 void TraceProjections::userSuppliedData(int d)
1435 {
1436   if (!computationStarted) return;
1437   _logPool->addUserSupplied(d);
1438 }
1439
1440 void TraceProjections::userSuppliedNote(char *note)
1441 {
1442   if (!computationStarted) return;
1443   _logPool->addUserSuppliedNote(note);
1444 }
1445
1446
1447 void TraceProjections::userSuppliedBracketedNote(char *note, int eventID, double bt, double et)
1448 {
1449   if (!computationStarted) return;
1450   _logPool->addUserSuppliedBracketedNote(note,  eventID,  bt, et);
1451 }
1452
1453 void TraceProjections::memoryUsage(double m)
1454 {
1455   if (!computationStarted) return;
1456   _logPool->addMemoryUsage(MEMORY_USAGE_CURRENT, TraceTimer(), m );
1457   
1458 }
1459
1460
1461 void TraceProjections::creation(envelope *e, int ep, int num)
1462 {
1463   double curTime = TraceTimer();
1464   if (e == 0) {
1465     CtvAccess(curThreadEvent) = curevent;
1466     _logPool->add(CREATION, ForChareMsg, ep, curTime,
1467                   curevent++, CkMyPe(), 0, NULL, 0, 0.0);
1468   } else {
1469     int type=e->getMsgtype();
1470     e->setEvent(curevent);
1471     if (num > 1) {
1472       _logPool->add(CREATION_BCAST, type, ep, curTime,
1473                     curevent++, CkMyPe(), e->getTotalsize(), 
1474                     NULL, 0, 0.0, num);
1475     } else {
1476       _logPool->add(CREATION, type, ep, curTime,
1477                     curevent++, CkMyPe(), e->getTotalsize(), 
1478                     NULL, 0, 0.0);
1479     }
1480   }
1481 }
1482
1483 //This function is only called from a comm thread in SMP mode. 
1484 void TraceProjections::creation(char *msg)
1485 {
1486 #if CMK_SMP_TRACE_COMMTHREAD
1487         // msg must be a charm message
1488     envelope *e = (envelope *)msg;
1489     int ep = e->getEpIdx();
1490     if(_entryTable[ep]->traceEnabled) {
1491         creation(e, ep, 1);
1492         e->setSrcPe(CkMyPe());              // pretend I am the sender
1493     }
1494 #endif
1495 }
1496
1497 void TraceProjections::traceCommSetMsgID(char *msg)
1498 {
1499 #if CMK_SMP_TRACE_COMMTHREAD
1500     // msg must be a charm message
1501     envelope *e = (envelope *)msg;
1502     int ep = e->getEpIdx();
1503     if(_entryTable[ep]->traceEnabled) {
1504         e->setSrcPe(CkMyPe());              // pretend I am the sender
1505         e->setEvent(curevent);
1506     }
1507 #endif
1508 }
1509
1510 void TraceProjections::traceGetMsgID(char *msg, int *pe, int *event)
1511 {
1512     // msg must be a charm message
1513     *pe = *event = -1;
1514     envelope *e = (envelope *)msg;
1515     int ep = e->getEpIdx();
1516     if(_entryTable[ep]->traceEnabled) {
1517         *pe = e->getSrcPe();
1518         *event = e->getEvent();
1519     }
1520 }
1521
1522 void TraceProjections::traceSetMsgID(char *msg, int pe, int event)
1523 {
1524        // msg must be a charm message
1525     envelope *e = (envelope *)msg;
1526     int ep = e->getEpIdx();
1527     if(ep<=0 || ep>=_entryTable.size()) return;
1528     if (e->getSrcPe()<0 || e->getSrcPe()>=CkNumPes()+CkNumNodes()) return;
1529     if (e->getMsgtype()<=0 || e->getMsgtype()>=LAST_CK_ENVELOPE_TYPE) return;
1530     if(_entryTable[ep]->traceEnabled) {
1531         e->setSrcPe(pe);
1532         e->setEvent(event);
1533     }
1534 }
1535
1536 /* **CW** Non-disruptive attempt to add destination PE knowledge to
1537    Communication Library-specific Multicasts via new event 
1538    CREATION_MULTICAST.
1539 */
1540
1541 void TraceProjections::creationMulticast(envelope *e, int ep, int num,
1542                                          int *pelist)
1543 {
1544   double curTime = TraceTimer();
1545   if (e==0) {
1546     CtvAccess(curThreadEvent)=curevent;
1547     _logPool->addCreationMulticast(ForChareMsg, ep, curTime, curevent++,
1548                                    CkMyPe(), 0, 0, 0.0, num, pelist);
1549   } else {
1550     int type=e->getMsgtype();
1551     e->setEvent(curevent);
1552     _logPool->addCreationMulticast(type, ep, curTime, curevent++, CkMyPe(),
1553                                    e->getTotalsize(), 0, 0.0, num, pelist);
1554   }
1555 }
1556
1557 void TraceProjections::creationDone(int num)
1558 {
1559   // modified the creation done time of the last num log entries
1560   // FIXME: totally a hack
1561   double curTime = TraceTimer();
1562   int idx = _logPool->numEntries-1;
1563   while (idx >=0 && num >0 ) {
1564     LogEntry &log = _logPool->pool[idx];
1565     if ((log.type == CREATION) ||
1566         (log.type == CREATION_BCAST) ||
1567         (log.type == CREATION_MULTICAST)) {
1568       log.recvTime = curTime - log.time;
1569       num --;
1570     }
1571     idx--;
1572   }
1573 }
1574
1575 void TraceProjections::beginExecute(CmiObjId *tid)
1576 {
1577 #if CMK_HAS_COUNTER_PAPI
1578   if (PAPI_read(papiEventSet, papiValues) != PAPI_OK) {
1579     CmiAbort("PAPI failed to read at begin execute!\n");
1580   }
1581 #endif
1582   if (checknested && inEntry) CmiAbort("Nested Begin Execute!\n");
1583   execEvent = CtvAccess(curThreadEvent);
1584   execEp = (-1);
1585   _logPool->add(BEGIN_PROCESSING,ForChareMsg,_threadEP, TraceTimer(),
1586                 execEvent,CkMyPe(), 0, tid);
1587 #if CMK_HAS_COUNTER_PAPI
1588   _logPool->addPapi(papiValues);
1589 #endif
1590   inEntry = 1;
1591 }
1592
1593 void TraceProjections::beginExecute(envelope *e)
1594 {
1595   if(e==0) {
1596 #if CMK_HAS_COUNTER_PAPI
1597     if (PAPI_read(papiEventSet, papiValues) != PAPI_OK) {
1598       CmiAbort("PAPI failed to read at begin execute!\n");
1599     }
1600 #endif
1601     if (checknested && inEntry) CmiAbort("Nested Begin Execute!\n");
1602     execEvent = CtvAccess(curThreadEvent);
1603     execEp = (-1);
1604     _logPool->add(BEGIN_PROCESSING,ForChareMsg,_threadEP, TraceTimer(),
1605                   execEvent,CkMyPe(), 0, NULL, 0.0, TraceCpuTimer());
1606 #if CMK_HAS_COUNTER_PAPI
1607     _logPool->addPapi(papiValues);
1608 #endif
1609     inEntry = 1;
1610   } else {
1611     beginExecute(e->getEvent(),e->getMsgtype(),e->getEpIdx(),
1612                  e->getSrcPe(),e->getTotalsize());
1613   }
1614 }
1615
1616 void TraceProjections::beginExecute(char *msg){
1617 #if CMK_SMP_TRACE_COMMTHREAD
1618         //This function is called from comm thread in SMP mode
1619     envelope *e = (envelope *)msg;
1620     int ep = e->getEpIdx();
1621     if(_entryTable[ep]->traceEnabled)
1622                 beginExecute(e);
1623 #endif
1624 }
1625
1626 void TraceProjections::beginExecute(int event, int msgType, int ep, int srcPe,
1627                                     int mlen, CmiObjId *idx)
1628 {
1629   if (traceNestedEvents) {
1630     if (! nestedEvents.isEmpty()) {
1631       endExecuteLocal();
1632     }
1633     nestedEvents.enq(NestedEvent(event, msgType, ep, srcPe, mlen, idx));
1634   }
1635   beginExecuteLocal(event, msgType, ep, srcPe, mlen, idx);
1636 }
1637
1638 void TraceProjections::changeLastEntryTimestamp(double ts)
1639 {
1640   _logPool->modLastEntryTimestamp(ts);
1641 }
1642
1643 void TraceProjections::beginExecuteLocal(int event, int msgType, int ep, int srcPe,
1644                                     int mlen, CmiObjId *idx)
1645 {
1646 #if CMK_HAS_COUNTER_PAPI
1647   if (PAPI_read(papiEventSet, papiValues) != PAPI_OK) {
1648     CmiAbort("PAPI failed to read at begin execute!\n");
1649   }
1650 #endif
1651   if (checknested && inEntry) CmiAbort("Nested Begin Execute!\n");
1652   execEvent=event;
1653   execEp=ep;
1654   execPe=srcPe;
1655   _logPool->add(BEGIN_PROCESSING,msgType,ep, TraceTimer(),event,
1656                 srcPe, mlen, idx, 0.0, TraceCpuTimer());
1657 #if CMK_HAS_COUNTER_PAPI
1658   _logPool->addPapi(papiValues);
1659 #endif
1660   inEntry = 1;
1661 }
1662
1663 void TraceProjections::endExecute(void)
1664 {
1665   if (traceNestedEvents) nestedEvents.deq();
1666   endExecuteLocal();
1667   if (traceNestedEvents) {
1668     if (! nestedEvents.isEmpty()) {
1669       NestedEvent &ne = nestedEvents.peek();
1670       beginExecuteLocal(ne.event, ne.msgType, ne.ep, ne.srcPe, ne.ml, ne.idx);
1671     }
1672   }
1673 }
1674
1675 void TraceProjections::endExecute(char *msg)
1676 {
1677 #if CMK_SMP_TRACE_COMMTHREAD
1678         //This function is called from comm thread in SMP mode
1679     envelope *e = (envelope *)msg;
1680     int ep = e->getEpIdx();
1681     if(_entryTable[ep]->traceEnabled)
1682                 endExecute();
1683 #endif  
1684 }
1685
1686 void TraceProjections::endExecuteLocal(void)
1687 {
1688 #if CMK_HAS_COUNTER_PAPI
1689   if (PAPI_read(papiEventSet, papiValues) != PAPI_OK) {
1690     CmiAbort("PAPI failed to read at end execute!\n");
1691   }
1692 #endif
1693   if (checknested && !inEntry) CmiAbort("Nested EndExecute!\n");
1694   double cputime = TraceCpuTimer();
1695   double now = TraceTimer();
1696   if(execEp == (-1)) {
1697     _logPool->add(END_PROCESSING, 0, _threadEP, now,
1698                   execEvent, CkMyPe(), 0, NULL, 0.0, cputime);
1699   } else {
1700     _logPool->add(END_PROCESSING, 0, execEp, now,
1701                   execEvent, execPe, 0, NULL, 0.0, cputime);
1702   }
1703 #if CMK_HAS_COUNTER_PAPI
1704   _logPool->addPapi(papiValues);
1705 #endif
1706   inEntry = 0;
1707 }
1708
1709 void TraceProjections::messageRecv(char *env, int pe)
1710 {
1711 #if 0
1712   envelope *e = (envelope *)env;
1713   int msgType = e->getMsgtype();
1714   int ep = e->getEpIdx();
1715 #if 0
1716   if (msgType==NewChareMsg || msgType==NewVChareMsg
1717           || msgType==ForChareMsg || msgType==ForVidMsg
1718           || msgType==BocInitMsg || msgType==NodeBocInitMsg
1719           || msgType==ForBocMsg || msgType==ForNodeBocMsg)
1720     ep = e->getEpIdx();
1721   else
1722     ep = _threadEP;
1723 #endif
1724   _logPool->add(MESSAGE_RECV, msgType, ep, TraceTimer(),
1725                 curevent++, e->getSrcPe(), e->getTotalsize());
1726 #endif
1727 }
1728
1729 void TraceProjections::beginIdle(double curWallTime)
1730 {
1731     _logPool->add(BEGIN_IDLE, 0, 0, TraceTimer(curWallTime), 0, CkMyPe());
1732 }
1733
1734 void TraceProjections::endIdle(double curWallTime)
1735 {
1736     _logPool->add(END_IDLE, 0, 0, TraceTimer(curWallTime), 0, CkMyPe());
1737 }
1738
1739 void TraceProjections::beginPack(void)
1740 {
1741     _logPool->add(BEGIN_PACK, 0, 0, TraceTimer(), 0, CkMyPe());
1742 }
1743
1744 void TraceProjections::endPack(void)
1745 {
1746     _logPool->add(END_PACK, 0, 0, TraceTimer(), 0, CkMyPe());
1747 }
1748
1749 void TraceProjections::beginUnpack(void)
1750 {
1751     _logPool->add(BEGIN_UNPACK, 0, 0, TraceTimer(), 0, CkMyPe());
1752 }
1753
1754 void TraceProjections::endUnpack(void)
1755 {
1756     _logPool->add(END_UNPACK, 0, 0, TraceTimer(), 0, CkMyPe());
1757 }
1758
1759 void TraceProjections::enqueue(envelope *) {}
1760
1761 void TraceProjections::dequeue(envelope *) {}
1762
1763 void TraceProjections::beginComputation(void)
1764 {
1765   computationStarted = 1;
1766   // Executes the callback function provided by the machine
1767   // layer. This is the proper method to register user events in a
1768   // machine layer because projections is a charm++ module.
1769   if (CkpvAccess(traceOnPe) != 0) {
1770     void (*ptr)() = registerMachineUserEvents();
1771     if (ptr != NULL) {
1772       ptr();
1773     }
1774   }
1775 //  CkpvAccess(traceInitTime) = TRACE_TIMER();
1776 //  CkpvAccess(traceInitCpuTime) = TRACE_CPUTIMER();
1777   _logPool->add(BEGIN_COMPUTATION, 0, 0, TraceTimer(), -1, -1);
1778 #if CMK_HAS_COUNTER_PAPI
1779   // we start the counters here
1780   if (PAPI_start(papiEventSet) != PAPI_OK) {
1781     CmiAbort("PAPI failed to start designated counters!\n");
1782   }
1783 #endif
1784 }
1785
1786 void TraceProjections::endComputation(void)
1787 {
1788 #if CMK_HAS_COUNTER_PAPI
1789   // we stop the counters here. A silent failure is alright since we
1790   // are already at the end of the program.
1791   if (PAPI_stop(papiEventSet, papiValues) != PAPI_OK) {
1792     CkPrintf("Warning: PAPI failed to stop correctly!\n");
1793   }
1794   // NOTE: We should not do a complete close of PAPI until after the
1795   // sts writer is done.
1796 #endif
1797   endTime = TraceTimer();
1798   _logPool->add(END_COMPUTATION, 0, 0, endTime, -1, -1);
1799   /*
1800   CkPrintf("End Computation [%d] records time as %lf\n", CkMyPe(), 
1801            endTime*1e06);
1802   */
1803 }
1804
1805 int TraceProjections::idxRegistered(int idx)
1806 {
1807     int idxVecLen = idxVec.size();
1808     for(int i=0; i<idxVecLen; i++)
1809     {
1810         if(idx == idxVec[i])
1811             return 1;
1812     }
1813     return 0;
1814 }
1815
1816 void TraceProjections::regFunc(const char *name, int &idx, int idxSpecifiedByUser){
1817     StrKey k((char*)name,strlen(name));
1818     int num = funcHashtable.get(k);
1819     
1820     if(num!=0) {
1821         return;
1822         //as for mpi programs, the same function may be registered for several times
1823         //CmiError("\"%s has been already registered! Please change the name!\"\n", name);
1824     }
1825     
1826     int isIdxExisting=0;
1827     if(idxSpecifiedByUser)
1828         isIdxExisting=idxRegistered(idx);
1829     if(isIdxExisting){
1830         return;
1831         //same reason with num!=0
1832         //CmiError("The identifier %d for the trace function has been already registered!", idx);
1833     }
1834
1835     if(idxSpecifiedByUser) {
1836         char *st = new char[strlen(name)+1];
1837         memcpy(st,name,strlen(name)+1);
1838         StrKey *newKey = new StrKey(st,strlen(st));
1839         int &ref = funcHashtable.put(*newKey);
1840         ref=idx;
1841         funcCount++;
1842         idxVec.push_back(idx);  
1843     } else {
1844         char *st = new char[strlen(name)+1];
1845         memcpy(st,name,strlen(name)+1);
1846         StrKey *newKey = new StrKey(st,strlen(st));
1847         int &ref = funcHashtable.put(*newKey);
1848         ref=funcCount;
1849         num = funcCount;
1850         funcCount++;
1851         idx = num;
1852         idxVec.push_back(idx);
1853     }
1854 }
1855
1856 void TraceProjections::beginFunc(char *name,char *file,int line){
1857         StrKey k(name,strlen(name));    
1858         unsigned short  num = (unsigned short)funcHashtable.get(k);
1859         beginFunc(num,file,line);
1860 }
1861
1862 void TraceProjections::beginFunc(int idx,char *file,int line){
1863         if(idx <= 0){
1864                 CmiError("Unregistered function id %d being used in %s:%d \n",idx,file,line);
1865         }       
1866         _logPool->add(BEGIN_FUNC,TraceTimer(),idx,line,file);
1867 }
1868
1869 void TraceProjections::endFunc(char *name){
1870         StrKey k(name,strlen(name));    
1871         int num = funcHashtable.get(k);
1872         endFunc(num);   
1873 }
1874
1875 void TraceProjections::endFunc(int num){
1876         if(num <= 0){
1877                 printf("endFunc without start :O\n");
1878         }
1879         _logPool->add(END_FUNC,TraceTimer(),num,0,NULL);
1880 }
1881
1882 // specialized PUP:ers for handling trace projections logs
1883 void toProjectionsFile::bytes(void *p,int n,size_t itemSize,dataType t)
1884 {
1885   for (int i=0;i<n;i++) 
1886     switch(t) {
1887     case Tchar: CheckAndFPrintF(f,"%c",((char *)p)[i]); break;
1888     case Tuchar:
1889     case Tbyte: CheckAndFPrintF(f,"%d",((unsigned char *)p)[i]); break;
1890     case Tshort: CheckAndFPrintF(f," %d",((short *)p)[i]); break;
1891     case Tushort: CheckAndFPrintF(f," %u",((unsigned short *)p)[i]); break;
1892     case Tint: CheckAndFPrintF(f," %d",((int *)p)[i]); break;
1893     case Tuint: CheckAndFPrintF(f," %u",((unsigned int *)p)[i]); break;
1894     case Tlong: CheckAndFPrintF(f," %ld",((long *)p)[i]); break;
1895     case Tulong: CheckAndFPrintF(f," %lu",((unsigned long *)p)[i]); break;
1896     case Tfloat: CheckAndFPrintF(f," %.7g",((float *)p)[i]); break;
1897     case Tdouble: CheckAndFPrintF(f," %.15g",((double *)p)[i]); break;
1898 #ifdef CMK_PUP_LONG_LONG
1899     case Tlonglong: CheckAndFPrintF(f," %lld",((CMK_PUP_LONG_LONG *)p)[i]); break;
1900     case Tulonglong: CheckAndFPrintF(f," %llu",((unsigned CMK_PUP_LONG_LONG *)p)[i]); break;
1901 #endif
1902     default: CmiAbort("Unrecognized pup type code!");
1903     };
1904 }
1905
1906 void fromProjectionsFile::bytes(void *p,int n,size_t itemSize,dataType t)
1907 {
1908   for (int i=0;i<n;i++) 
1909     switch(t) {
1910     case Tchar: { 
1911       char c = fgetc(f);
1912       if (c==EOF)
1913         parseError("Could not match character");
1914       else
1915         ((char *)p)[i] = c;
1916       break;
1917     }
1918     case Tuchar:
1919     case Tbyte: ((unsigned char *)p)[i]=(unsigned char)readInt("%d"); break;
1920     case Tshort:((short *)p)[i]=(short)readInt(); break;
1921     case Tushort: ((unsigned short *)p)[i]=(unsigned short)readUint(); break;
1922     case Tint:  ((int *)p)[i]=readInt(); break;
1923     case Tuint: ((unsigned int *)p)[i]=readUint(); break;
1924     case Tlong: ((long *)p)[i]=readInt(); break;
1925     case Tulong:((unsigned long *)p)[i]=readUint(); break;
1926     case Tfloat: ((float *)p)[i]=(float)readDouble(); break;
1927     case Tdouble:((double *)p)[i]=readDouble(); break;
1928 #ifdef CMK_PUP_LONG_LONG
1929     case Tlonglong: ((CMK_PUP_LONG_LONG *)p)[i]=readLongInt(); break;
1930     case Tulonglong: ((unsigned CMK_PUP_LONG_LONG *)p)[i]=readLongInt(); break;
1931 #endif
1932     default: CmiAbort("Unrecognized pup type code!");
1933     };
1934 }
1935
1936 #if CMK_PROJECTIONS_USE_ZLIB
1937 void toProjectionsGZFile::bytes(void *p,int n,size_t itemSize,dataType t)
1938 {
1939   for (int i=0;i<n;i++) 
1940     switch(t) {
1941     case Tchar: gzprintf(f,"%c",((char *)p)[i]); break;
1942     case Tuchar:
1943     case Tbyte: gzprintf(f,"%d",((unsigned char *)p)[i]); break;
1944     case Tshort: gzprintf(f," %d",((short *)p)[i]); break;
1945     case Tushort: gzprintf(f," %u",((unsigned short *)p)[i]); break;
1946     case Tint: gzprintf(f," %d",((int *)p)[i]); break;
1947     case Tuint: gzprintf(f," %u",((unsigned int *)p)[i]); break;
1948     case Tlong: gzprintf(f," %ld",((long *)p)[i]); break;
1949     case Tulong: gzprintf(f," %lu",((unsigned long *)p)[i]); break;
1950     case Tfloat: gzprintf(f," %.7g",((float *)p)[i]); break;
1951     case Tdouble: gzprintf(f," %.15g",((double *)p)[i]); break;
1952 #ifdef CMK_PUP_LONG_LONG
1953     case Tlonglong: gzprintf(f," %lld",((CMK_PUP_LONG_LONG *)p)[i]); break;
1954     case Tulonglong: gzprintf(f," %llu",((unsigned CMK_PUP_LONG_LONG *)p)[i]); break;
1955 #endif
1956     default: CmiAbort("Unrecognized pup type code!");
1957     };
1958 }
1959 #endif
1960
1961 void TraceProjections::endPhase() {
1962   double currentPhaseTime = TraceTimer();
1963   if (lastPhaseEvent != NULL) {
1964   } else {
1965     if (_logPool->pool != NULL) {
1966       // assumed to be BEGIN_COMPUTATION
1967     } else {
1968       CkPrintf("[%d] Warning: End Phase encountered in an empty log. Inserting BEGIN_COMPUTATION event\n", CkMyPe());
1969       _logPool->add(BEGIN_COMPUTATION, 0, 0, currentPhaseTime, -1, -1);
1970     }
1971   }
1972
1973   /* Insert endPhase event here. */
1974   /* FIXME: Format should be TYPE, PHASE#, TimeStamp, [StartTime] */
1975   /*        We currently "borrow" from the standard add() method. */
1976   /*        It should really be its own add() method.             */
1977   /* NOTE: assignment to lastPhaseEvent is "pre-emptive".         */
1978   lastPhaseEvent = &(_logPool->pool[_logPool->numEntries]);
1979   _logPool->add(END_PHASE, 0, currentPhaseID, currentPhaseTime, -1, CkMyPe());
1980   currentPhaseID++;
1981 }
1982
1983 #ifdef PROJ_ANALYSIS
1984 // ***** FROM HERE, ALL BOC-BASED FUNCTIONALITY IS DEFINED *******
1985
1986
1987 // ***@@@@ REGISTRATION FUNCTIONS/METHODS @@@@***
1988
1989 void registerOutlierReduction() {
1990   outlierReductionType =
1991     CkReduction::addReducer(outlierReduction);
1992   minMaxReductionType =
1993     CkReduction::addReducer(minMaxReduction);
1994 }
1995
1996 /**
1997  * **IMPT NOTES**:
1998  *
1999  * This is the C++ code that is registered to be activated at module
2000  * shutdown. This is called exactly once on processor 0. Module shutdown
2001  * is initiated as a result of a CkExit() call by the application code
2002  * 
2003  * The exit function must ultimately call CkExit() again to
2004  * so that other module exit functions may proceed after this module is
2005  * done.
2006  *
2007  */
2008 // FIXME: WHY extern "C"???
2009 extern "C" void TraceProjectionsExitHandler()
2010 {
2011 #if CMK_TRACE_ENABLED
2012   // CkPrintf("[%d] TraceProjectionsExitHandler called!\n", CkMyPe());
2013   CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
2014   bocProxy.traceProjectionsParallelShutdown(CkMyPe());
2015 #else
2016   CkExit();
2017 #endif
2018 }
2019
2020 // This is called once on each processor but the idiom of use appears
2021 // to be to only have processor 0 register the function.
2022 //
2023 // See initnode in trace-projections.ci
2024 void initTraceProjectionsBOC()
2025 {
2026   // CkPrintf("[%d] Trace Projections initialization called!\n", CkMyPe());
2027 #ifdef __BIGSIM__
2028   if (BgNodeRank() == 0) {
2029 #else
2030     if (CkMyRank() == 0) {
2031 #endif
2032       registerExitFn(TraceProjectionsExitHandler);
2033     }
2034 #if 0
2035   } // this is so indentation does not get messed up
2036 #endif
2037 }
2038
2039 // mainchare for trace-projections BOC-operations. 
2040 // Instantiated at processor 0 and ONLY resides on processor 0 for the 
2041 // rest of its life.
2042 //
2043 // Responsible for:
2044 //   1. Handling commandline arguments
2045 //   2. Creating any objects required for proper BOC operations.
2046 //
2047 TraceProjectionsInit::TraceProjectionsInit(CkArgMsg *msg) {
2048   /** Options for Outlier Analysis */
2049   // defaults. Things will change with support for interactive analysis.
2050   bool findOutliers = false;
2051   bool outlierAutomatic = true;
2052   int numKSeeds = 10; 
2053
2054   int peNumKeep = CkNumPes();  // used as a default
2055   double entryThreshold = 0.0;
2056   bool outlierUsePhases = false;
2057   if (outlierAutomatic) {
2058     CmiGetArgIntDesc(msg->argv, "+outlierNumSeeds", &numKSeeds,
2059                      "Number of cluster seeds to apply at outlier analysis.");
2060     CmiGetArgIntDesc(msg->argv, "+outlierPeNumKeep", 
2061                      &peNumKeep, "Number of Processors to retain data");
2062     CmiGetArgDoubleDesc(msg->argv, "+outlierEpThresh", &entryThreshold,
2063                         "Minimum significance of entry points to be considered for clustering (%).");
2064     findOutliers =
2065       CmiGetArgFlagDesc(msg->argv,"+outlier", "Find Outliers.");
2066     outlierUsePhases = 
2067       CmiGetArgFlagDesc(msg->argv,"+outlierUsePhases",
2068                         "Apply automatic outlier analysis to any available phases.");
2069     if (outlierUsePhases) {
2070       // if the user wants to use an outlier feature, it is assumed outlier
2071       //    analysis is desired.
2072       findOutliers = true;
2073     }
2074   }
2075   bool findStartTime = (CmiTimerAbsolute()==1);
2076   traceProjectionsGID = CProxy_TraceProjectionsBOC::ckNew(findOutliers, findStartTime);
2077   if (findOutliers) {
2078     kMeansGID = CProxy_KMeansBOC::ckNew(outlierAutomatic,
2079                                         numKSeeds,
2080                                         peNumKeep,
2081                                         entryThreshold,
2082                                         outlierUsePhases);
2083   }
2084
2085   delete msg;
2086 }
2087
2088 // Called on every processor.
2089 void TraceProjectionsBOC::traceProjectionsParallelShutdown(int pe) {
2090   //CmiPrintf("[%d] traceProjectionsParallelShutdown called from . \n", CkMyPe(), pe);
2091   endPe = pe;                // the pe that starts CkExit()
2092   if (CkMyPe() == 0) {
2093     analysisStartTime = CmiWallTimer();
2094   }
2095   CkpvAccess(_trace)->endComputation();
2096   // no more tracing for projections on this processor after this point. 
2097   // Note that clear must be called after remove, or bad things will happen.
2098   CkpvAccess(_traces)->removeTrace(CkpvAccess(_trace));
2099   CkpvAccess(_traces)->clearTrace();
2100
2101   // From this point, we start multiple chains of reductions and broadcasts to
2102   // perform final online analysis activities.
2103
2104   // Start all parallel operations at once. 
2105   //   These MUST NOT modify base performance data in LogPool. If they must,
2106   //   then the parallel operations must be phased (and this code to be
2107   //   restructured as necessary)
2108   CProxy_KMeansBOC kMeansProxy(kMeansGID);
2109   CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
2110   if (findOutliers) {
2111     parModulesRemaining++;
2112     kMeansProxy[CkMyPe()].startKMeansAnalysis();
2113   }
2114   parModulesRemaining++;
2115   if (findStartTime) 
2116   bocProxy[CkMyPe()].startTimeAnalysis();
2117   else
2118   bocProxy[CkMyPe()].startEndTimeAnalysis();
2119 }
2120
2121 // handle flush log warnings
2122 void TraceProjectionsBOC::flush_warning(int pe) 
2123 {
2124     CmiAssert(CkMyPe() == 0);
2125     std::set<int>::iterator it;
2126     it = list.find(pe);
2127     if (it == list.end())    list.insert(pe);
2128     flush_count++;
2129 }
2130
2131 void TraceProjectionsBOC::print_warning() 
2132 {
2133     CmiAssert(CkMyPe() == 0);
2134     if (flush_count == 0) return;
2135     std::set<int>::iterator it;
2136     CkPrintf("*************************************************************\n");
2137     CkPrintf("Warning: Projections log flushed to disk %d times on %d cores: ", flush_count, list.size());
2138     for (it=list.begin(); it!=list.end(); it++)
2139       CkPrintf("%d ", *it);
2140     CkPrintf(".\n");
2141     CkPrintf("Warning: The performance data is likely invalid, unless the flushes have been explicitly synchronized by your program. \n");
2142     CkPrintf("*************************************************************\n");
2143 }
2144
2145 // Called on each processor
2146 void KMeansBOC::startKMeansAnalysis() {
2147   // Initialize all necessary structures
2148   LogPool *pool = CkpvAccess(_trace)->_logPool;
2149
2150  if(CkMyPe()==0)     CkPrintf("[%d] KMeansBOC::startKMeansAnalysis time=\t%g\n", CkMyPe(), CkWallTimer() );
2151   int flushInt = 0;
2152   if (pool->hasFlushed) {
2153     flushInt = 1;
2154   }
2155   
2156   CkCallback cb(CkIndex_KMeansBOC::flushCheck(NULL), 
2157                 0, thisProxy);
2158   contribute(sizeof(int), &flushInt, CkReduction::logical_or, cb);  
2159 }
2160
2161 // Called on processor 0
2162 void KMeansBOC::flushCheck(CkReductionMsg *msg) {
2163   int someFlush = *((int *)msg->getData());
2164
2165   // if(CkMyPe()==0) CkPrintf("[%d] KMeansBOC::flushCheck time=\t%g\n", CkMyPe(), CkWallTimer() );
2166   
2167   if (someFlush == 0) {
2168     // Data intact proceed with KMeans analysis
2169     CProxy_KMeansBOC kMeansProxy(kMeansGID);
2170     kMeansProxy.flushCheckDone();
2171   } else {
2172     // Some processor had flushed it data at some point, abandon KMeans
2173     CkPrintf("Warning: Some processor has flushed its data. No KMeans will be conducted\n");
2174     // terminate KMeans
2175     CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
2176     bocProxy[0].kMeansDone();
2177   }
2178 }
2179
2180 // Called on each processor
2181 void KMeansBOC::flushCheckDone() {
2182   // **FIXME** - more flexible metric collection scheme may be necessary
2183   //   in the future for production use.
2184   LogPool *pool = CkpvAccess(_trace)->_logPool;
2185
2186   // if(CkMyPe()==0)     CkPrintf("[%d] KMeansBOC::flushCheckDone time=\t%g\n", CkMyPe(), CkWallTimer() );
2187
2188   numEntryMethods = _entryTable.size();
2189   numMetrics = numEntryMethods + 2; // EPtime + idle and overhead
2190
2191   // maintained across phases
2192   markedBegin = false;
2193   markedIdle = false;
2194   beginBlockTime = 0.0;
2195   beginIdleBlockTime = 0.0;
2196   lastBeginEPIdx = -1; // none
2197
2198   lastPhaseIdx = 0;
2199   currentExecTimes = NULL;
2200   currentPhase = 0;
2201   selected = false;
2202
2203   pool->initializePhases();
2204
2205   // incoming K Seeds and the per-phase filter
2206   incKSeeds = new double[numK*numMetrics];
2207   keepMetric = new bool[numMetrics];
2208
2209   //  Something wrong when call thisProxy[CkMyPe()].getNextPhaseMetrics() !??!
2210   //  CProxy_KMeansBOC kMeansProxy(kMeansGID);
2211   //  kMeansProxy[CkMyPe()].getNextPhaseMetrics();
2212   thisProxy[CkMyPe()].getNextPhaseMetrics();
2213 }
2214
2215 // Called on each processor.
2216 void KMeansBOC::getNextPhaseMetrics() {
2217   // Assumes the presence of the complete logs on this processor.
2218   // Assumes first event is always BEGIN_COMPUTATION
2219   // Assumes each processor sees the same number of phases.
2220   //
2221   // In this code, we collect performance data for this processor.
2222   // All times are in seconds.
2223
2224   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::getNextPhaseMetrics time=\t%g\n", CkMyPe(), CkWallTimer() );  
2225
2226   if (usePhases) {
2227     DEBUGF("[%d] Using Phases\n", CkMyPe());
2228   } else {
2229     DEBUGF("[%d] NOT using Phases\n", CkMyPe());
2230   }
2231   
2232   if (currentExecTimes != NULL) {
2233     delete [] currentExecTimes;
2234   }
2235   currentExecTimes = new double[numMetrics];
2236   for (int i=0; i<numMetrics; i++) {
2237     currentExecTimes[i] = 0.0;
2238   }
2239
2240   int numEventMethods = _entryTable.size();
2241   LogPool *pool = CkpvAccess(_trace)->_logPool;
2242   
2243   CkAssert(pool->numEntries > lastPhaseIdx);
2244   double totalPhaseTime = 0.0;
2245   double totalActiveTime = 0.0; // entry method + idle
2246
2247   for (int i=lastPhaseIdx; i<pool->numEntries; i++) {
2248     if (pool->pool[i].type == BEGIN_PROCESSING) {
2249       // check pairing
2250       if (!markedBegin) {
2251         markedBegin = true;
2252       }
2253       beginBlockTime = pool->pool[i].time;
2254       lastBeginEPIdx = pool->pool[i].eIdx;
2255     } else if (pool->pool[i].type == END_PROCESSING) {
2256       // check pairing
2257       // if End without a begin, just ignore
2258       //   this event. If a phase-boundary is crossed, the Begin
2259       //   event would be maintained in beginBlockTime, so it is 
2260       //   not a problem.
2261       if (markedBegin) {
2262         markedBegin = false;
2263         if (pool->pool[i].event < 0)
2264         {
2265           // ignore dummy events. **FIXME** as they have no eIdx?
2266           continue;
2267         }
2268         currentExecTimes[pool->pool[i].eIdx] += 
2269           pool->pool[i].time - beginBlockTime;
2270         totalActiveTime += pool->pool[i].time - beginBlockTime;
2271         lastBeginEPIdx = -1;
2272       }
2273     } else if (pool->pool[i].type == BEGIN_IDLE) {
2274       // check pairing
2275       if (!markedIdle) {
2276         markedIdle = true;
2277       }
2278       beginIdleBlockTime = pool->pool[i].time;
2279     } else if (pool->pool[i].type == END_IDLE) {
2280       // check pairing
2281       if (markedIdle) {
2282         markedIdle = false;
2283         currentExecTimes[numEventMethods] += 
2284           pool->pool[i].time - beginIdleBlockTime;
2285         totalActiveTime += pool->pool[i].time - beginIdleBlockTime;
2286       }
2287     } else if (pool->pool[i].type == END_PHASE) {
2288       // ignored when not using phases
2289       if (usePhases) {
2290         // when we've not visited this node before
2291         if (i != lastPhaseIdx) { 
2292           totalPhaseTime = 
2293             pool->pool[i].time - pool->pool[lastPhaseIdx].time;
2294           // it is important that proper accounting of time take place here.
2295           // Note that END_PHASE events inevitably occur in the context of
2296           //   some entry method by the way the tracing API is designed.
2297           if (markedBegin) {
2298             CkAssert(lastBeginEPIdx >= 0);
2299             currentExecTimes[lastBeginEPIdx] += 
2300               pool->pool[i].time - beginBlockTime;
2301             totalActiveTime += pool->pool[i].time - beginBlockTime;
2302             // this is so the remainder contributes to the next phase
2303             beginBlockTime = pool->pool[i].time;
2304           }
2305           // The following is unlikely, but stranger things have happened.
2306           if (markedIdle) {
2307             currentExecTimes[numEventMethods] +=
2308               pool->pool[i].time - beginIdleBlockTime;
2309             totalActiveTime += pool->pool[i].time - beginIdleBlockTime;
2310             // this is so the remainder contributes to the next phase
2311             beginIdleBlockTime = pool->pool[i].time;
2312           }
2313           if (totalActiveTime <= totalPhaseTime) {
2314             currentExecTimes[numEventMethods+1] = 
2315               totalPhaseTime - totalActiveTime;
2316           } else {
2317             currentExecTimes[numEventMethods+1] = 0.0;
2318             CkPrintf("[%d] Warning: Overhead found to be negative for Phase %d!\n",
2319                      CkMyPe(), currentPhase);
2320           }
2321           collectKMeansData();
2322           // end the loop (and method) and defer the work till the next call
2323           lastPhaseIdx = i;
2324           break; 
2325         }
2326       }
2327     } else if (pool->pool[i].type == END_COMPUTATION) {
2328       if (markedBegin) {
2329         CkAssert(lastBeginEPIdx >= 0);
2330         currentExecTimes[lastBeginEPIdx] += 
2331           pool->pool[i].time - beginBlockTime;
2332         totalActiveTime += pool->pool[i].time - beginBlockTime;
2333       }
2334       if (markedIdle) {
2335         currentExecTimes[numEventMethods] +=
2336           pool->pool[i].time - beginIdleBlockTime;
2337         totalActiveTime += pool->pool[i].time - beginIdleBlockTime;
2338       }
2339       totalPhaseTime = 
2340         pool->pool[i].time - pool->pool[lastPhaseIdx].time;
2341       if (totalActiveTime <= totalPhaseTime) {
2342         currentExecTimes[numEventMethods+1] = totalPhaseTime - totalActiveTime;
2343       } else {
2344         currentExecTimes[numEventMethods+1] = 0.0;
2345         CkPrintf("[%d] Warning: Overhead found to be negative!\n",
2346                  CkMyPe());
2347       }
2348       collectKMeansData();
2349     }
2350   }
2351 }
2352
2353 /**
2354  *  Through a reduction, collectKMeansData aggregates each processors' data
2355  *  in order for global properties to be determined:
2356  *  
2357  *  1. min & max to determine normalization factors.
2358  *  2. sum to determine global EP averages for possible metric reduction
2359  *       through thresholding.
2360  *  3. sum of squares to compute stddev which may be useful in the future.
2361  *
2362  *  collectKMeansData will also keep the processor's data for the current
2363  *    phase so that it may be normalized and worked on subsequently.
2364  *
2365  **/
2366 void KMeansBOC::collectKMeansData() {
2367   int minOffset = numMetrics;
2368   int maxOffset = 2*numMetrics;
2369   int sosOffset = 3*numMetrics; // sos = Sum Of Squares
2370
2371   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::collectKMeansData time=\tg\n", CkMyPe(), CkWallTimer() );
2372
2373   double *reductionMsg = new double[numMetrics*4];
2374
2375   for (int i=0; i<numMetrics; i++) {
2376     reductionMsg[i] = currentExecTimes[i];
2377     // duplicate the event times for max and min sections of the reduction
2378     reductionMsg[minOffset + i] = currentExecTimes[i];
2379     reductionMsg[maxOffset + i] = currentExecTimes[i];
2380     // compute squares
2381     reductionMsg[sosOffset + i] = currentExecTimes[i]*currentExecTimes[i];
2382   }
2383
2384   CkCallback cb(CkIndex_KMeansBOC::globalMetricRefinement(NULL), 
2385                 0, thisProxy);
2386   contribute((numMetrics*4)*sizeof(double), reductionMsg, 
2387              outlierReductionType, cb);  
2388 }
2389
2390 // The purpose is mainly to initialize the k seeds and generate
2391 //   normalization parameters for each of the metrics. The k seeds
2392 //   and normalization parameters are broadcast to all processors.
2393 //
2394 // Called on processor 0
2395 void KMeansBOC::globalMetricRefinement(CkReductionMsg *msg) {
2396   CkAssert(CkMyPe() == 0);
2397   
2398   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::globalMetricRefinement time=\t%g\n", CkMyPe(), CkWallTimer() );
2399
2400   int sumOffset = 0;
2401   int minOffset = numMetrics;
2402   int maxOffset = 2*numMetrics;
2403   int sosOffset = 3*numMetrics; // sos = Sum Of Squares
2404
2405   // calculate statistics & boundaries for the k seeds for clustering
2406   KMeansStatsMessage *outmsg = 
2407     new (numMetrics, numK*numMetrics, numMetrics*4) KMeansStatsMessage;
2408   outmsg->numMetrics = numMetrics;
2409   outmsg->numKPos = numK*numMetrics;
2410   outmsg->numStats = numMetrics*4;
2411
2412   // Sum | Min | Max | Sum of Squares
2413   double *totalExecTimes = (double *)msg->getData();
2414   double totalTime = 0.0;
2415
2416   for (int i=0; i<numMetrics; i++) {
2417     DEBUGN("%lf\n", totalExecTimes[i]);
2418     totalTime += totalExecTimes[i];
2419
2420     // calculate event mean over all processors
2421     outmsg->stats[sumOffset + i] = totalExecTimes[sumOffset + i]/CkNumPes();
2422
2423     // get the ranges and offsets of each metric. With this, we get
2424     //   normalization factors that can be sent back to each processor to
2425     //   be used as necessary. We reuse max for range. Min remains the offset.
2426     outmsg->stats[minOffset + i] = totalExecTimes[minOffset + i];
2427     outmsg->stats[maxOffset + i] = totalExecTimes[maxOffset + i] -
2428       totalExecTimes[minOffset + i];
2429     
2430     // calculate stddev (using biased variance)
2431     outmsg->stats[sosOffset + i] = 
2432       sqrt((totalExecTimes[sosOffset + i] - 
2433             2*(outmsg->stats[i])*totalExecTimes[i] +
2434             (outmsg->stats[i])*(outmsg->stats[i])*CkNumPes())/
2435            CkNumPes());
2436   }
2437
2438   for (int i=0; i<numMetrics; i++) {
2439     // 1) if the proportion of the max value of the entry method relative to
2440     //   the average time taken over all entry methods across all processors
2441     //   is greater than the stipulated percentage threshold ...; AND
2442     // 2) if the range of values are non-zero.
2443     //
2444     // The current assumption is totalTime > 0 (what program has zero total
2445     //   time from all work?)
2446     keepMetric[i] = ((totalExecTimes[maxOffset + i]/(totalTime/CkNumPes()) >=
2447                      entryThreshold) &&
2448       (totalExecTimes[maxOffset + i] > totalExecTimes[minOffset + i]));
2449     if (keepMetric[i]) {
2450       DEBUGF("[%d] Keep EP %d | Max = %lf | Avg Tot = %lf\n", CkMyPe(), i,
2451              totalExecTimes[maxOffset + i], totalTime/CkNumPes());
2452     } else {
2453       DEBUGN("[%d] DO NOT Keep EP %d\n", CkMyPe(), i);
2454     }
2455     outmsg->filter[i] = keepMetric[i];
2456   }
2457
2458   delete msg;
2459   
2460   // initialize k seeds for this phase
2461   kSeeds = new double[numK*numMetrics];
2462
2463   numKReported = 0;
2464   kNumMembers = new int[numK];
2465
2466   // Randomly select k processors' metric vectors for the k seeds
2467   //  srand((unsigned)(CmiWallTimer()*1.0e06));
2468   srand(11337); // for debugging purposes
2469   for (int k=0; k<numK; k++) {
2470     DEBUGF("Seed %d | ", k);
2471     for (int m=0; m<numMetrics; m++) {
2472       double factor = totalExecTimes[maxOffset + m] - 
2473         totalExecTimes[minOffset + m];
2474       // "uniform" distribution, scaled according to the normalization
2475       //   factors
2476       //      kSeeds[numMetrics*k + m] = ((1.0*(k+1))/numK)*factor;
2477       // Random distribution.
2478       kSeeds[numMetrics*k + m] =
2479         ((rand()*1.0)/RAND_MAX)*factor;
2480       if (keepMetric[m]) {
2481         DEBUGF("[%d|%lf] ", m, kSeeds[numMetrics*k + m]);
2482       }
2483       outmsg->kSeedsPos[numMetrics*k + m] = kSeeds[numMetrics*k + m];
2484     }
2485     DEBUGF("\n");
2486     kNumMembers[k] = 0;
2487   }
2488
2489   // broadcast statistical values to all processors for cluster discovery
2490   thisProxy.findInitialClusters(outmsg);
2491 }
2492
2493
2494
2495 // Called on each processor.
2496 void KMeansBOC::findInitialClusters(KMeansStatsMessage *msg) {
2497
2498  if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::findInitialClusters time=\t%g\n", CkMyPe(), CkWallTimer() );
2499
2500   phaseIter = 0;
2501
2502   // Get info from stats message
2503   CkAssert(numMetrics == msg->numMetrics);
2504   for (int i=0; i<numMetrics; i++) {
2505     keepMetric[i] = msg->filter[i];
2506   }
2507
2508   // Normalize data on local processor.
2509   // **CWL** See my thesis for detailed discussion of normalization of
2510   //    performance data.
2511   // **NOTE** This might change if we want to send data based on the filter
2512   //   instead of all the data.
2513   CkAssert(numMetrics*4 == msg->numStats);
2514   for (int i=0; i<numMetrics; i++) {
2515     currentExecTimes[i] -= msg->stats[numMetrics + i];  // take offset
2516     // **CWL** We do not normalize the range. Entry methods that exhibit
2517     //   large absolute timing variations should be allowed to contribute
2518     //   more to the Euclidean distance measure!
2519     // currentExecTimes[i] /= msg->stats[2*numMetrics + i];
2520   }
2521
2522   // **NOTE** This might change if we want to send data based on the filter
2523   //   instead of all the data.
2524   CkAssert(numK*numMetrics == msg->numKPos);
2525   for (int i=0; i<msg->numKPos; i++) {
2526     incKSeeds[i] = msg->kSeedsPos[i];
2527   }
2528
2529   // Decide which KSeed this processor belongs to.
2530   minDistance = calculateDistance(0);
2531   DEBUGN("[%d] Phase %d Iter %d | Distance from 0 = %lf \n", CkMyPe(), 
2532            currentPhase, phaseIter, minDistance);
2533   minK = 0;
2534   for (int i=1; i<numK; i++) {
2535     double distance = calculateDistance(i);
2536     DEBUGN("[%d] Phase %d Iter %d | Distance from %d = %lf \n", CkMyPe(), 
2537              currentPhase, phaseIter, i, distance);
2538     if (distance < minDistance) {
2539       minDistance = distance;
2540       minK = i;
2541     }
2542   }
2543
2544   // Set up a reduction with the modification vector to the root (0).
2545   //
2546   // The modification vector sends a negative value for each metric
2547   //   for the K this processor no longer belongs to and a positive
2548   //   value to the K the processor now belongs. In addition, a -1.0
2549   //   is sent to the K it is leaving and a +1.0 to the K it is 
2550   //   joining.
2551   //
2552   // The processor must still contribute a "zero returns" even if
2553   //   nothing changes. This will be the basis for determine
2554   //   convergence at the root.
2555   //
2556   // The addtional +1 is meant for the count-change that must be
2557   //   maintained for the special cases at the root when some K
2558   //   may be deprived of all processor points or go from 0 to a
2559   //   positive number of processors (see later comments).
2560   double *modVector = new double[numK*(numMetrics+1)];
2561   for (int i=0; i<numK; i++) {
2562     for (int j=0; j<numMetrics+1; j++) {
2563       modVector[i*(numMetrics+1) + j] = 0.0;
2564     }
2565   }
2566   for (int i=0; i<numMetrics; i++) {
2567     // for this initialization, only positive values need be sent.
2568     modVector[minK*(numMetrics+1) + i] = currentExecTimes[i];
2569   }
2570   modVector[minK*(numMetrics+1)+numMetrics] = 1.0;
2571
2572   CkCallback cb(CkIndex_KMeansBOC::updateKSeeds(NULL), 
2573                 0, thisProxy);
2574   contribute(numK*(numMetrics+1)*sizeof(double), modVector, 
2575              CkReduction::sum_double, cb);  
2576 }
2577
2578 double KMeansBOC::calculateDistance(int k) {
2579   double ret = 0.0;
2580   for (int i=0; i<numMetrics; i++) {
2581     if (keepMetric[i]) {
2582       DEBUGN("[%d] Phase %d Iter %d Metric %d Exec %lf Seed %lf \n", 
2583              CkMyPe(), currentPhase, phaseIter, i,
2584                currentExecTimes[i], incKSeeds[k*numMetrics + i]);
2585       ret += pow(currentExecTimes[i] - incKSeeds[k*numMetrics + i], 2.0);
2586     }
2587   }
2588   return sqrt(ret);
2589 }
2590
2591 void KMeansBOC::updateKSeeds(CkReductionMsg *msg) {
2592   CkAssert(CkMyPe() == 0);
2593
2594   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::updateKSeeds time=\t%g\n", CkMyPe(), CkWallTimer() );
2595
2596   double *modVector = (double *)msg->getData();
2597   // sanity check
2598   CkAssert(numK*(numMetrics+1)*sizeof(double) == msg->getSize());
2599
2600   // A quick convergence test.
2601   bool hasChanges = false;
2602   for (int i=0; i<numK; i++) {
2603     hasChanges = hasChanges || 
2604       (modVector[i*(numMetrics+1) + numMetrics] != 0.0);
2605   }
2606   if (!hasChanges) {
2607     delete msg;
2608     findRepresentatives();
2609   } else {
2610     int overallChange = 0;
2611     for (int i=0; i<numK; i++) {
2612       int change = (int)modVector[i*(numMetrics+1) + numMetrics];
2613       if (change != 0) {
2614         overallChange += change;
2615         // modify the k seeds based on the modification vectors coming in
2616         //
2617         // If a seed initially has no members, its contents do not matter and
2618         //   is simply set to the average of the incoming vector.
2619         // If the change causes a seed to lose all its members, do nothing.
2620         //   Its last-known location is kept to allow it to re-capture
2621         //   membership at the next iteration rather than apply the last
2622         //   changes (which snaps the point unnaturally to 0,0).
2623         // Otherwise, apply the appropriate vector changes.
2624         CkAssert((kNumMembers[i] + change >= 0) &&
2625                  (kNumMembers[i] + change <= CkNumPes()));
2626         if (kNumMembers[i] == 0) {
2627           CkAssert(change > 0);
2628           for (int j=0; j<numMetrics; j++) {
2629             kSeeds[i*numMetrics + j] = modVector[i*(numMetrics+1) + j]/change;
2630           }
2631         } else if (kNumMembers[i] + change == 0) {
2632           // do nothing.
2633         } else {
2634           for (int j=0; j<numMetrics; j++) {
2635             kSeeds[i*numMetrics + j] *= kNumMembers[i];
2636             kSeeds[i*numMetrics + j] += modVector[i*(numMetrics+1) + j];
2637             kSeeds[i*numMetrics + j] /= kNumMembers[i] + change;
2638           }
2639         }
2640         kNumMembers[i] += change;
2641       }
2642       DEBUGN("[%d] Phase %d Iter %d K = %d Membership Count = %d\n",
2643              CkMyPe(), currentPhase, phaseIter, i, kNumMembers[i]);
2644     }
2645     delete msg;
2646
2647     // broadcast the new seed locations.
2648     KSeedsMessage *outmsg = new (numK*numMetrics) KSeedsMessage;
2649     outmsg->numKPos = numK*numMetrics;
2650     for (int i=0; i<numK*numMetrics; i++) {
2651       outmsg->kSeedsPos[i] = kSeeds[i];
2652     }
2653
2654     thisProxy.updateSeedMembership(outmsg);
2655   }
2656 }
2657
2658 // Called on all processors
2659 void KMeansBOC::updateSeedMembership(KSeedsMessage *msg) {
2660
2661   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::updateSeedMembership time=\t%g\n", CkMyPe(), CkWallTimer() );
2662
2663   phaseIter++;
2664
2665   // **NOTE** This might change if we want to send data based on the filter
2666   //   instead of all the data.
2667   CkAssert(numK*numMetrics == msg->numKPos);
2668   for (int i=0; i<msg->numKPos; i++) {
2669     incKSeeds[i] = msg->kSeedsPos[i];
2670   }
2671
2672   // Decide which KSeed this processor belongs to.
2673   lastMinK = minK;
2674   minDistance = calculateDistance(0);
2675   DEBUGN("[%d] Phase %d Iter %d | Distance from 0 = %lf \n", CkMyPe(), 
2676          currentPhase, phaseIter, minDistance);
2677
2678   minK = 0;
2679   for (int i=1; i<numK; i++) {
2680     double distance = calculateDistance(i);
2681     DEBUGN("[%d] Phase %d Iter %d | Distance from %d = %lf \n", CkMyPe(), 
2682            currentPhase, phaseIter, i, distance);
2683     if (distance < minDistance) {
2684       minDistance = distance;
2685       minK = i;
2686     }
2687   }
2688
2689   double *modVector = new double[numK*(numMetrics+1)];
2690   for (int i=0; i<numK; i++) {
2691     for (int j=0; j<numMetrics+1; j++) {
2692       modVector[i*(numMetrics+1) + j] = 0.0;
2693     }
2694   }
2695
2696   if (minK != lastMinK) {
2697     for (int i=0; i<numMetrics; i++) {
2698       modVector[minK*(numMetrics+1) + i] = currentExecTimes[i];
2699       modVector[lastMinK*(numMetrics+1) + i] = -currentExecTimes[i];
2700     }
2701     modVector[minK*(numMetrics+1)+numMetrics] = 1.0;
2702     modVector[lastMinK*(numMetrics+1)+numMetrics] = -1.0;
2703   }
2704
2705   CkCallback cb(CkIndex_KMeansBOC::updateKSeeds(NULL), 
2706                 0, thisProxy);
2707   contribute(numK*(numMetrics+1)*sizeof(double), modVector, 
2708              CkReduction::sum_double, cb);  
2709 }
2710
2711 void KMeansBOC::findRepresentatives() {
2712
2713   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::findRepresentatives time=\t%g\n", CkMyPe(), CkWallTimer() );
2714
2715   int numNonEmptyClusters = 0;
2716   for (int i=0; i<numK; i++) {
2717     if (kNumMembers[i] > 0) {
2718       numNonEmptyClusters++;
2719     }
2720   }
2721
2722   int numRepresentatives = peNumKeep;
2723   // **FIXME**
2724   // This is fairly arbitrary. Next time, choose the centers of the top
2725   //   largest clusters.
2726   if (numRepresentatives < numNonEmptyClusters) {
2727     numRepresentatives = numNonEmptyClusters;
2728   }
2729
2730   int slotsRemaining = numRepresentatives;
2731
2732   DEBUGF("Slots = %d | Non-empty = %d \n", slotsRemaining, 
2733          numNonEmptyClusters);
2734
2735   // determine how many exemplars to select per cluster. Currently
2736   //   hardcoded to 1. Future challenge is to decide on other numbers
2737   //   or proportionality.
2738   //
2739   int exemplarsPerCluster = 1;
2740   slotsRemaining -= exemplarsPerCluster*numNonEmptyClusters;
2741
2742   int numCandidateOutliers = CkNumPes() - 
2743     exemplarsPerCluster*numNonEmptyClusters;
2744
2745   double *remainders = new double[numK];
2746   int *assigned = new int[numK];
2747   exemplarChoicesLeft = new int[numK];
2748   outlierChoicesLeft = new int[numK];
2749
2750   for (int i=0; i<numK; i++) {
2751     assigned[i] = 0;
2752     remainders[i] = 
2753       (kNumMembers[i] - exemplarsPerCluster*numNonEmptyClusters) *
2754       slotsRemaining / numCandidateOutliers;
2755     if (remainders[i] >= 0.0) {
2756       assigned[i] = (int)floor(remainders[i]);
2757       remainders[i] -= assigned[i];
2758     } else {
2759       remainders[i] = 0.0;
2760     }
2761   }
2762
2763   for (int i=0; i<numK; i++) {
2764     slotsRemaining -= assigned[i];
2765   }
2766   CkAssert(slotsRemaining >= 0);
2767
2768   // find clusters to assign the loose slots to, in order of
2769   // remainder proportion
2770   while (slotsRemaining > 0) {
2771     double max = 0.0;
2772     int winner = 0;
2773     for (int i=0; i<numK; i++) {
2774       if (remainders[i] > max) {
2775         max = remainders[i];
2776         winner = i;
2777       }
2778     }
2779     assigned[winner]++;
2780     remainders[winner] = 0.0;
2781     slotsRemaining--;
2782   }
2783
2784   // set up how many reduction cycles of min/max we need to conduct to
2785   // select the representatives.
2786   numSelectionIter = exemplarsPerCluster;
2787   for (int i=0; i<numK; i++) {
2788     if (assigned[i] > numSelectionIter) {
2789       numSelectionIter = assigned[i];
2790     }
2791   }
2792   DEBUGF("Selection Iterations = %d\n", numSelectionIter);
2793
2794   for (int i=0; i<numK; i++) {
2795     if (kNumMembers[i] > 0) {
2796       exemplarChoicesLeft[i] = exemplarsPerCluster;
2797       outlierChoicesLeft[i] = assigned[i];
2798     } else {
2799       exemplarChoicesLeft[i] = 0;
2800       outlierChoicesLeft[i] = 0;
2801     }
2802     DEBUGF("%d | Exemplar = %d | Outlier = %d\n", i, exemplarChoicesLeft[i],
2803            outlierChoicesLeft[i]);
2804   }
2805
2806   delete [] assigned;
2807   delete [] remainders;
2808
2809   // send out first broadcast
2810   KSelectionMessage *outmsg = NULL;
2811   if (numSelectionIter > 0) {
2812     outmsg = new (numK, numK, numK) KSelectionMessage;
2813     outmsg->numKMinIDs = numK;
2814     outmsg->numKMaxIDs = numK;
2815     for (int i=0; i<numK; i++) {
2816       outmsg->minIDs[i] = -1;
2817       outmsg->maxIDs[i] = -1;
2818     }
2819     thisProxy.collectDistances(outmsg);
2820   } else {
2821     CkPrintf("Warning: No selection iteration from the start!\n");
2822     // invoke phase completion on all processors
2823     thisProxy.phaseDone();
2824   }
2825 }
2826
2827 /*
2828  *  lastMin = array of minimum champions of the last tournament
2829  *  lastMax = array of maximum champions of the last tournament
2830  *  lastMaxVal = array of last encountered maximum values, allows previous
2831  *                 minimum winners to eliminate themselves from the next
2832  *                 minimum race.
2833  *
2834  *  Called on all processors.
2835  */
2836 void KMeansBOC::collectDistances(KSelectionMessage *msg) {
2837
2838   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::collectDistances time=\t%g\n", CkMyPe(), CkWallTimer() );
2839
2840   DEBUGF("[%d] %d | min = %d max = %d\n", CkMyPe(),
2841          lastMinK, msg->minIDs[lastMinK], msg->maxIDs[lastMinK]);
2842   if ((CkMyPe() == msg->minIDs[lastMinK]) || 
2843       (CkMyPe() == msg->maxIDs[lastMinK])) {
2844     CkAssert(!selected);
2845     selected = true;
2846   }
2847
2848   // build outgoing reduction structure
2849   //   format = minVal | ID | maxVal | ID
2850   double *minMaxAndIDs = NULL;
2851
2852   minMaxAndIDs = new double[numK*4];
2853   // initialize to the appropriate out-of-band values (for error checks)
2854   for (int i=0; i<numK; i++) {
2855     minMaxAndIDs[i*4] = -1.0; // out-of-band min value
2856     minMaxAndIDs[i*4+1] = -1.0; // out of band ID
2857     minMaxAndIDs[i*4+2] = -1.0; // out-of-band max value
2858     minMaxAndIDs[i*4+3] = -1.0; // out of band ID
2859   }
2860   // If I have not won before, I put myself back into the competition
2861   if (!selected) {
2862     DEBUGF("[%d] My Contribution = %lf\n", CkMyPe(), minDistance);
2863     minMaxAndIDs[lastMinK*4] = minDistance;
2864     minMaxAndIDs[lastMinK*4+1] = CkMyPe();
2865     minMaxAndIDs[lastMinK*4+2] = minDistance;
2866     minMaxAndIDs[lastMinK*4+3] = CkMyPe();
2867   }
2868   delete msg;
2869
2870   CkCallback cb(CkIndex_KMeansBOC::findNextMinMax(NULL), 
2871                 0, thisProxy);
2872   contribute(numK*4*sizeof(double), minMaxAndIDs, 
2873              minMaxReductionType, cb);  
2874 }
2875
2876 void KMeansBOC::findNextMinMax(CkReductionMsg *msg) {
2877   // incoming format:
2878   //   minVal | minID | maxVal | maxID
2879
2880   // if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::findNextMinMax time=\t%g\n", CkMyPe(), CkWallTimer() );
2881
2882   if (numSelectionIter > 0) {
2883     double *incInfo = (double *)msg->getData();
2884     
2885     KSelectionMessage *outmsg = new (numK, numK) KSelectionMessage;
2886     outmsg->numKMinIDs = numK;
2887     outmsg->numKMaxIDs = numK;
2888     
2889     for (int i=0; i<numK; i++) {
2890       DEBUGF("%d | %lf %d %lf %d \n", i, 
2891              incInfo[i*4], (int)incInfo[i*4+1], 
2892              incInfo[i*4+2], (int)incInfo[i*4+3]);
2893     }
2894
2895     for (int i=0; i<numK; i++) {
2896       if (exemplarChoicesLeft[i] > 0) {
2897         outmsg->minIDs[i] = (int)incInfo[i*4+1];
2898         exemplarChoicesLeft[i]--;
2899       } else {
2900         outmsg->minIDs[i] = -1;
2901       }
2902       if (outlierChoicesLeft[i] > 0) {
2903         outmsg->maxIDs[i] = (int)incInfo[i*4+3];
2904         outlierChoicesLeft[i]--;
2905       } else {
2906         outmsg->maxIDs[i] = -1;
2907       }
2908     }
2909     thisProxy.collectDistances(outmsg);
2910     numSelectionIter--;
2911   } else {
2912     // invoke phase completion on all processors
2913     thisProxy.phaseDone();
2914   }
2915 }
2916
2917 /**
2918  *  Completion of the K-Means clustering and data selection of one phase
2919  *    of the computation.
2920  *
2921  *  Called on every processor.
2922  */
2923 void KMeansBOC::phaseDone() {
2924
2925   //  if(CkMyPe()==0)    CkPrintf("[%d] KMeansBOC::phaseDone time=\t%g\n", CkMyPe(), CkWallTimer() );
2926
2927   LogPool *pool = CkpvAccess(_trace)->_logPool;
2928   CProxy_TraceProjectionsBOC bocProxy(traceProjectionsGID);
2929
2930   // now decide on what to do with the decision.
2931   if (!selected) {
2932     if (usePhases) {
2933       pool->keepPhase[currentPhase] = false;
2934     } else {
2935       // if not using phases, we're working on the whole log
2936       pool->setAllPhases(false);
2937     }
2938   }
2939
2940   // **FIXME** (?) - All processors have to agree on this, or the reduction
2941   //   will not be correct! The question is "is this enforcible?"
2942   if ((currentPhase == (pool->numPhases-1)) || !usePhases) {
2943     // We're done
2944     int dummy = 0;
2945     CkCallback cb(CkIndex_TraceProjectionsBOC::kMeansDone(NULL), 
2946                   0, bocProxy);
2947     contribute(sizeof(int), &dummy, CkReduction::sum_int, cb);
2948   } else {
2949     // reset all phase-based k-means data and decisions
2950
2951     // **FIXME**!!!!!    
2952     
2953     // invoke the next K-Means computation phase.
2954     currentPhase++;
2955     thisProxy[CkMyPe()].getNextPhaseMetrics();
2956   }
2957 }
2958
2959 void TraceProjectionsBOC::startTimeAnalysis()
2960 {
2961   double startTime = 0.0;
2962   if (CkpvAccess(_trace)->_logPool->numEntries>0)
2963      startTime = CkpvAccess(_trace)->_logPool->pool[0].time;
2964   CkCallback cb(CkIndex_TraceProjectionsBOC::startTimeDone(NULL), thisProxy);
2965   contribute(sizeof(double), &startTime, CkReduction::min_double, cb);  
2966 }
2967
2968 void TraceProjectionsBOC::startTimeDone(CkReductionMsg *msg)
2969 {
2970   // CkPrintf("[%d] TraceProjectionsBOC::startTimeDone time=\t%g parModulesRemaining:%d\n", CkMyPe(), CkWallTimer(), parModulesRemaining);
2971
2972   if (CkpvAccess(_trace) != NULL) {
2973     CkpvAccess(_trace)->_logPool->globalStartTime = *(double *)msg->getData();
2974     CkpvAccess(_trace)->_logPool->setNewStartTime();
2975     //if (CkMyPe() == 0) CkPrintf("Start time determined to be %lf us\n", (CkpvAccess(_trace)->_logPool->globalStartTime)*1e06);
2976   }
2977   delete msg;
2978   thisProxy[CkMyPe()].startEndTimeAnalysis();
2979 }
2980
2981 void TraceProjectionsBOC::startEndTimeAnalysis()
2982 {
2983  //CkPrintf("[%d] TraceProjectionsBOC::startEndTimeAnalysis time=\t%g\n", CkMyPe(), CkWallTimer() );
2984
2985   endTime = CkpvAccess(_trace)->endTime;
2986   // CkPrintf("[%d] End time is %lf us\n", CkMyPe(), endTime*1e06);
2987
2988   CkCallback cb(CkIndex_TraceProjectionsBOC::endTimeDone(NULL), 
2989                 0, thisProxy);
2990   contribute(sizeof(double), &endTime, CkReduction::max_double, cb);  
2991 }
2992
2993 void TraceProjectionsBOC::endTimeDone(CkReductionMsg *msg)
2994 {
2995  //if(CkMyPe()==0)    CkPrintf("[%d] TraceProjectionsBOC::endTimeDone time=\t%g parModulesRemaining:%d\n", CkMyPe(), CkWallTimer(), parModulesRemaining);
2996
2997   CkAssert(CkMyPe() == 0);
2998   parModulesRemaining--;
2999   if (CkpvAccess(_trace) != NULL) {
3000     CkpvAccess(_trace)->_logPool->globalEndTime = *(double *)msg->getData() - CkpvAccess(_trace)->_logPool->globalStartTime;
3001     // CkPrintf("End time determined to be %lf us\n",
3002     //       (CkpvAccess(_trace)->_logPool->globalEndTime)*1e06);
3003   }
3004   delete msg;
3005   if (parModulesRemaining == 0) {
3006     thisProxy[CkMyPe()].finalize();
3007   }
3008 }
3009
3010 void TraceProjectionsBOC::kMeansDone(CkReductionMsg *msg) {
3011
3012  if(CkMyPe()==0)  CkPrintf("[%d] TraceProjectionsBOC::kMeansDone time=\t%g\n", CkMyPe(), CkWallTimer() );
3013
3014   CkAssert(CkMyPe() == 0);
3015   parModulesRemaining--;
3016   CkPrintf("K-Means Analysis Time = %lf seconds\n",
3017            CmiWallTimer()-analysisStartTime);
3018   delete msg;
3019   if (parModulesRemaining == 0) {
3020     thisProxy[CkMyPe()].finalize();
3021   }
3022 }
3023
3024 /**
3025  *
3026  *  This version is called (on processor 0) only if flushCheck fails.
3027  *
3028  */
3029 void TraceProjectionsBOC::kMeansDone() {
3030   CkAssert(CkMyPe() == 0);
3031   parModulesRemaining--;
3032   CkPrintf("K-Means Analysis Aborted because of flush. Time taken = %lf seconds\n",
3033            CmiWallTimer()-analysisStartTime);
3034   if (parModulesRemaining == 0) {
3035     thisProxy[CkMyPe()].finalize();
3036   }
3037 }
3038
3039 void TraceProjectionsBOC::finalize()
3040 {
3041   CkAssert(CkMyPe() == 0);
3042   //CkPrintf("Total Analysis Time = %lf seconds\n", 
3043   //       CmiWallTimer()-analysisStartTime);
3044   thisProxy.closingTraces();
3045 }
3046
3047 // Called on every processor
3048 void TraceProjectionsBOC::closingTraces() {
3049   CkpvAccess(_trace)->closeTrace();
3050
3051     // subtle:  reduction needs to go to the PE which started CkExit()
3052   int pe = 0;
3053   if (endPe != -1) pe = endPe;
3054   CkCallback cb(CkIndex_TraceProjectionsBOC::closeParallelShutdown(NULL), 
3055                 pe, thisProxy); 
3056   contribute(0, NULL, CkReduction::sum_int, cb);  
3057 }
3058
3059 // The sole purpose of this reduction is to decide whether or not
3060 //   Projections as a module needs to call CkExit() to get other
3061 //   modules to shutdown.
3062 void TraceProjectionsBOC::closeParallelShutdown(CkReductionMsg *msg) {
3063   CkAssert(endPe == -1 && CkMyPe() ==0 || CkMyPe() == endPe);
3064   delete msg;
3065   // decide if CkExit() needs to be called
3066   if (!CkpvAccess(_trace)->converseExit) {
3067     CkExit();
3068   }
3069 }
3070 /*
3071  *  Registration and definition of the Outlier Reduction callback.
3072  *  Format: Sum | Min | Max | Sum of Squares
3073  */
3074 CkReductionMsg *outlierReduction(int nMsgs,
3075                                  CkReductionMsg **msgs) {
3076   int numBytes = 0;
3077   int numMetrics = 0;
3078   double *ret = NULL;
3079
3080   if (nMsgs == 1) {
3081     // nothing to do, just pass it on
3082     return CkReductionMsg::buildNew(msgs[0]->getSize(),msgs[0]->getData());
3083   }
3084
3085   if (nMsgs > 1) {
3086     numBytes = msgs[0]->getSize();
3087     // sanity checks
3088     if (numBytes%sizeof(double) != 0) {
3089       CkAbort("Outlier Reduction Size incompatible with doubles!\n");
3090     }
3091     if ((numBytes/sizeof(double))%4 != 0) {
3092       CkAbort("Outlier Reduction Size Array not divisible by 4!\n");
3093     }
3094     numMetrics = (numBytes/sizeof(double))/4;
3095     ret = new double[numMetrics*4];
3096
3097     // copy the first message data into the return structure first
3098     for (int i=0; i<numMetrics*4; i++) {
3099       ret[i] = ((double *)msgs[0]->getData())[i];
3100     }
3101
3102     // Sum | Min | Max | Sum of Squares
3103     for (int msgIdx=1; msgIdx<nMsgs; msgIdx++) {
3104       for (int i=0; i<numMetrics; i++) {
3105         // Sum
3106         ret[i] += ((double *)msgs[msgIdx]->getData())[i];
3107         // Min
3108         ret[numMetrics + i] =
3109           (ret[numMetrics + i] < 
3110            ((double *)msgs[msgIdx]->getData())[numMetrics + i]) 
3111           ? ret[numMetrics + i] : 
3112           ((double *)msgs[msgIdx]->getData())[numMetrics + i];
3113         // Max
3114         ret[2*numMetrics + i] = 
3115           (ret[2*numMetrics + i] >
3116            ((double *)msgs[msgIdx]->getData())[2*numMetrics + i])
3117           ? ret[2*numMetrics + i] :
3118           ((double *)msgs[msgIdx]->getData())[2*numMetrics + i];
3119         // Sum of Squares (squaring already done at leaf)
3120         ret[3*numMetrics + i] +=
3121           ((double *)msgs[msgIdx]->getData())[3*numMetrics + i];
3122       }
3123     }
3124   }
3125   
3126   /* apparently, we do not delete the incoming messages */
3127   return CkReductionMsg::buildNew(numBytes,ret);
3128 }
3129
3130 /*
3131  * The only reason we have a user-defined reduction is to support
3132  *   identification of the "winning" processors as well as to handle
3133  *   both the min and the max of each "tournament". A simple min/max
3134  *   discovery cannot handle ties.
3135  */
3136 CkReductionMsg *minMaxReduction(int nMsgs,
3137                                 CkReductionMsg **msgs) {
3138   CkAssert(nMsgs > 0);
3139
3140   int numBytes = msgs[0]->getSize();
3141   CkAssert(numBytes%sizeof(double) == 0);
3142   int numK = (numBytes/sizeof(double))/4;
3143
3144   double *ret = new double[numK*4];
3145   // fill with out-of-band values
3146   for (int i=0; i<numK; i++) {
3147     ret[i*4] = -1.0;
3148     ret[i*4+1] = -1.0;
3149     ret[i*4+2] = -1.0;
3150     ret[i*4+3] = -1.0;
3151   }
3152
3153   // incoming format K * (minVal | minIdx | maxVal | maxIdx)
3154   for (int i=0; i<nMsgs; i++) {
3155     double *temp = (double *)msgs[i]->getData();
3156     for (int j=0; j<numK; j++) {
3157       // no previous valid min
3158       if (ret[j*4+1] < 0) {
3159         // fill it in only if the incoming min is valid
3160         if (temp[j*4+1] >= 0) {
3161           ret[j*4] = temp[j*4];      // fill min value
3162           ret[j*4+1] = temp[j*4+1];  // fill ID
3163         }
3164       } else {
3165         // find Min, only if incoming min is valid
3166         if (temp[j*4+1] >= 0) {
3167           if (temp[j*4] < ret[j*4]) {
3168             ret[j*4] = temp[j*4];      // replace min value
3169             ret[j*4+1] = temp[j*4+1];  // replace ID
3170           }
3171         }
3172       }
3173       // no previous valid max
3174       if (ret[j*4+3] < 0) {
3175         // fill only if the incoming max is valid
3176         if (temp[j*4+3] >= 0) {
3177           ret[j*4+2] = temp[j*4+2];  // fill max value
3178           ret[j*4+3] = temp[j*4+3];  // fill ID
3179         }
3180       } else {
3181         // find Max, only if incoming max is valid
3182         if (temp[j*4+3] >= 0) {
3183           if (temp[j*4+2] > ret[j*4+2]) {
3184             ret[j*4+2] = temp[j*4+2];  // replace max value
3185             ret[j*4+3] = temp[j*4+3];  // replace ID
3186           }
3187         }
3188       }
3189     }
3190   }
3191   CkReductionMsg *redmsg = CkReductionMsg::buildNew(numBytes, ret);
3192   delete [] ret;
3193   return redmsg;
3194 }
3195
3196 #include "TraceProjections.def.h"
3197 #endif //PROJ_ANALYSIS
3198
3199 /*@}*/