9179c7b04d09749a531f3d09445174d10b709fb5
[charm.git] / src / ck-tune / trace-perf.C
1
2 CkpvStaticDeclare(TraceAutoPerf*, _trace);
3 //-------- group information ---------------------------
4
5 TraceAutoPerf *localAutoPerfTracingInstance()
6 {
7   return CkpvAccess(_trace);
8 }
9
10 // instrumentation and analysis 
11 TraceAutoPerf::TraceAutoPerf(char **argv) 
12 {
13     DEBUG_PRINT( CkPrintf("trace control point resetting %f\n", TraceTimer()); ) 
14     currentSummary = new perfData();  
15     resetTimings();
16     nesting_level = 0;
17     whenStoppedTracing = 0;
18 #if CMK_HAS_COUNTER_PAPI
19     initPAPI();
20 #endif
21     if (CkpvAccess(traceOnPe) == 0) return;
22 }
23
24 void TraceAutoPerf::resetTimings(){
25     totalIdleTime = 0.0;
26     totalEntryMethodTime = 0.0;
27     totalAppTime = 0.0;
28     totalEntryMethodInvocations = 0;
29     lastBeginIdle = lastBeginExecuteTime = lastResetTime = TraceTimer();
30     totalUntracedTime = 0;
31     maxEntryMethodTime = 0;
32     if(whenStoppedTracing !=0){
33         whenStoppedTracing = TraceTimer();
34     }
35
36     currentSummary->numMsgs = 0;
37     currentSummary->numBytes = 0;
38     currentSummary->commTime = 0;
39     currentSummary->objLoadMax = 0;
40 }
41
42 void TraceAutoPerf::resetAll(){
43     totalIdleTime = 0.0;
44     totalEntryMethodTime = 0.0;
45     totalAppTime = 0.0;
46     memUsage = 0;
47     totalEntryMethodInvocations = 0;
48     lastBeginIdle = lastBeginExecuteTime = lastResetTime = TraceTimer();
49     totalUntracedTime = 0;
50     if(whenStoppedTracing !=0){
51         whenStoppedTracing = TraceTimer();
52     }
53     currentSummary->numMsgs = 0;
54     currentSummary->numBytes = 0;
55     currentSummary->commTime = 0;
56     currentSummary->objLoadMax = 0;
57 #if CMK_HAS_COUNTER_PAPI
58     memcpy(previous_papiValues, CkpvAccess(papiValues), sizeof(LONG_LONG_PAPI)*NUMPAPIEVENTS);
59 #endif
60 }
61
62 void TraceAutoPerf::traceBegin(void){
63     if(whenStoppedTracing != 0)
64         totalUntracedTime += (TraceTimer() - whenStoppedTracing);
65     whenStoppedTracing = 0;
66 }
67
68 void TraceAutoPerf::traceEnd(void){
69   CkAssert(whenStoppedTracing == 0); // can't support nested traceEnds on one processor yet...
70   whenStoppedTracing = TraceTimer();
71 }
72
73 void TraceAutoPerf::userEvent(int eventID) { }
74 void TraceAutoPerf::userBracketEvent(int eventID, double bt, double et) { }
75
76 void TraceAutoPerf::appWork(int eventID, double bt, double et) { 
77     totalAppTime += (et-bt);
78 }
79 void TraceAutoPerf::creation(envelope *, int epIdx, int num) { } 
80 void TraceAutoPerf::creationMulticast(envelope *, int epIdx, int num, int *pelist) { }
81 void TraceAutoPerf::creationDone(int num) { }
82 void TraceAutoPerf::messageRecv(char *env, int pe) { }
83
84 void TraceAutoPerf::beginExecute(CmiObjId *tid)
85 {
86     //nesting_level++;
87     lastBeginExecuteTime = TraceTimer();
88     lastEvent =  BEGIN_PROCESSING;
89     lastbeginMessageSize = -1;
90     DEBUG_PRINT( CkPrintf("begin Executing tid   %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
91 }
92
93 void TraceAutoPerf::beginExecute(envelope *env)
94 {
95     //nesting_level++;
96     //if(nesting_level == 1){
97     lastBeginExecuteTime = TraceTimer();
98     lastEvent =  BEGIN_PROCESSING;
99     lastbeginMessageSize = env->getTotalsize();
100     currentSummary->numMsgs++;
101     currentSummary->numBytes += lastbeginMessageSize;
102     DEBUG_PRINT( CkPrintf("begin Executing env   %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
103 }
104
105 void TraceAutoPerf::beginExecute(envelope *env, int event,int msgType,int ep,int srcPe, int mlen, CmiObjId *idx)
106 {
107     //nesting_level++;
108     //if(nesting_level == 1){
109     lastbeginMessageSize = mlen;
110     currentSummary->numMsgs++;
111     currentSummary->numBytes += lastbeginMessageSize;
112     //`currentSummary->commTime += (env->getRecvTime() - env->getSentTime());
113     lastBeginExecuteTime = TraceTimer();
114     lastEvent =  BEGIN_PROCESSING;
115     DEBUG_PRINT( CkPrintf("begin Executing env  6  %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
116 }
117
118 void TraceAutoPerf::beginExecute(int event,int msgType,int ep,int srcPe, int mlen, CmiObjId *idx)
119 {
120     //nesting_level++;
121     //if(nesting_level == 1){
122     lastbeginMessageSize = mlen;
123     lastBeginExecuteTime = TraceTimer();
124     lastEvent =  BEGIN_PROCESSING;
125     DEBUG_PRINT( CkPrintf("begin Executing 6 no env %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
126 }
127
128 void TraceAutoPerf::endExecute(void)
129 {
130     //MAYBE a bug
131     //nesting_level--;
132     nesting_level = 0;
133     if(nesting_level == 0){
134         double endTime = TraceTimer() ;
135         double executionTime = endTime - lastBeginExecuteTime;
136         lastEvent =  -1;
137         DEBUG_PRINT( CkPrintf("end executing %d, duration %d\n", (int)(1000000*endTime), (int)(executionTime*1000000)); )
138         totalEntryMethodTime += executionTime;
139         totalEntryMethodInvocations ++;
140         if(executionTime > maxEntryMethodTime)
141             maxEntryMethodTime = executionTime;
142         double m = (double)CmiMemoryUsage();
143         if(memUsage < m){
144             memUsage = m;
145         }    
146     }
147 }
148
149 void TraceAutoPerf::beginIdle(double curWallTime) {
150     lastBeginIdle =  curWallTime; 
151     lastEvent =  BEGIN_IDLE;
152     double m = (double)CmiMemoryUsage();
153     if(memUsage < m){
154         memUsage = m;
155     }
156 }
157
158 void TraceAutoPerf::endIdle(double curWallTime) {
159     totalIdleTime += (curWallTime - lastBeginIdle) ;
160     lastEvent =  -1;
161 }
162
163 void TraceAutoPerf::beginComputation(void) {
164 #if CMK_HAS_COUNTER_PAPI
165   // we start the counters here
166   if(CkpvAccess(papiStarted) == 0)
167   {
168       if (PAPI_start(CkpvAccess(papiEventSet)) != PAPI_OK) {
169           CmiAbort("PAPI failed to start designated counters!\n");
170       }
171       CkpvAccess(papiStarted) = 1;
172   }
173 #endif
174
175 }
176
177 void TraceAutoPerf::endComputation(void) { 
178 #if CMK_HAS_COUNTER_PAPI
179   // we stop the counters here. A silent failure is alright since we
180   // are already at the end of the program.
181   if(CkpvAccess(papiStopped) == 0) {
182       if (PAPI_stop(CkpvAccess(papiEventSet), CkpvAccess(papiValues)) != PAPI_OK) {
183           CkPrintf("Warning: PAPI failed to stop correctly!\n");
184       }
185       CkpvAccess(papiStopped) = 1;
186   }
187   //else 
188   //{
189   //    char eventName[PAPI_MAX_STR_LEN];
190   //    for (int i=0;i<NUMPAPIEVENTS;i++) {
191   //        PAPI_event_code_to_name(papiEvents[i], eventName);
192   //        CkPrintf(" EVENT  %s   counter   %lld \n", eventName, papiValues[i]);
193   //    }
194   //}
195   // NOTE: We should not do a complete close of PAPI until after the
196   // sts writer is done.
197 #endif
198
199 }
200
201 void TraceAutoPerf::malloc(void *where, int size, void **stack, int stackSize)
202 {
203     double m = (double)CmiMemoryUsage();
204     if(memUsage < m){
205         memUsage = m;
206     }
207 }
208
209 void TraceAutoPerf::free(void *where, int size) { }
210
211 void TraceAutoPerf::traceClose(void)
212 {
213     CkpvAccess(_traces)->endComputation();
214     CkpvAccess(_traces)->removeTrace(this);
215 }
216
217 void TraceAutoPerf::markStep()
218 {
219     double now = TraceTimer();
220     timerPair newpairs;
221     newpairs.beginTimer = lastResetTime;
222     newpairs.endTimer = now; 
223     phasesTimers.push_back(newpairs);
224     phaseEndTime = now;
225     DEBUG_PRINT ( CkPrintf(" PE %d marking phase  %d at timer:%f traceTimer:%f (%f:%f) \n", CmiMyPe(), phasesTimers.size(), now, TraceTimer(), newpairs.beginTimer,  newpairs.endTimer); )
226
227 }
228
229 void _createTraceautoPerf(char **argv)
230 {
231     CkpvInitialize(TraceAutoPerf*, _trace);
232     CkpvAccess(_trace) = new TraceAutoPerf(argv);
233     CkpvAccess(_traces)->addTrace(CkpvAccess(_trace));
234     //CkPrintf("##### init ####\n");
235 }