Merge branch 'charm' of charmgit:charm into charm
[charm.git] / src / ck-tune / trace-perf.C
1 #if CMK_HAS_COUNTER_PAPI
2 #ifdef USE_SPP_PAPI
3 int papiEvents[NUMPAPIEVENTS];
4 #else
5 int papiEvents[NUMPAPIEVENTS] = { PAPI_L1_DCM, PAPI_L2_DCM, PAPI_L3_DCM, PAPI_TLB_DM, PAPI_L1_DCH, PAPI_L2_DCH, PAPI_L3_DCH, PAPI_FP_OPS, PAPI_TOT_CYC };
6 #endif
7 #endif // CMK_HAS_COUNTER_PAPI
8
9
10 CkpvStaticDeclare(TraceAutoPerf*, _trace);
11 //-------- group information ---------------------------
12
13 TraceAutoPerf *localAutoPerfTracingInstance()
14 {
15   return CkpvAccess(_trace);
16 }
17
18 // instrumentation and analysis 
19 TraceAutoPerf::TraceAutoPerf(char **argv) 
20 {
21     DEBUG_PRINT( CkPrintf("trace control point resetting %f\n", TraceTimer()); ) 
22     currentSummary = new perfData();  
23     resetTimings();
24     nesting_level = 0;
25     whenStoppedTracing = 0; 
26
27     //PAPI related 
28 #if CMK_HAS_COUNTER_PAPI
29   // We initialize and create the event sets for use with PAPI here.
30   int papiRetValue;
31   if(CkMyRank()==0){
32     papiRetValue = PAPI_library_init(PAPI_VER_CURRENT);
33     if (papiRetValue != PAPI_VER_CURRENT) {
34       CmiAbort("PAPI Library initialization failure!\n");
35     }
36 #if CMK_SMP
37     if(PAPI_thread_init(pthread_self) != PAPI_OK){
38       CmiAbort("PAPI could not be initialized in SMP mode!\n");
39     }
40 #endif
41   }
42
43 #if CMK_SMP
44   //PAPI_thread_init has to finish before calling PAPI_create_eventset
45   #if CMK_SMP_TRACE_COMMTHREAD
46       CmiNodeAllBarrier();
47   #else
48       CmiNodeBarrier();
49   #endif
50 #endif
51   // PAPI 3 mandates the initialization of the set to PAPI_NULL
52   papiEventSet = PAPI_NULL; 
53   if (PAPI_create_eventset(&papiEventSet) != PAPI_OK) {
54     CmiAbort("PAPI failed to create event set!\n");
55   }
56 #ifdef USE_SPP_PAPI
57   //  CmiPrintf("Using SPP counters for PAPI\n");
58   if(PAPI_query_event(PAPI_FP_OPS)==PAPI_OK) {
59     papiEvents[0] = PAPI_FP_OPS;
60   }else{
61     if(CmiMyPe()==0){
62       CmiAbort("WARNING: PAPI_FP_OPS doesn't exist on this platform!");
63     }
64   }
65   if(PAPI_query_event(PAPI_TOT_INS)==PAPI_OK) {
66     papiEvents[1] = PAPI_TOT_INS;
67   }else{
68     CmiAbort("WARNING: PAPI_TOT_INS doesn't exist on this platform!");
69   }
70   int EventCode;
71   int ret;
72   ret=PAPI_event_name_to_code("perf::PERF_COUNT_HW_CACHE_LL:ACCESS",&EventCode);
73   if(PAPI_query_event(EventCode)==PAPI_OK) {
74     papiEvents[2] = EventCode;
75   }else{
76     CmiAbort("WARNING: perf::PERF_COUNT_HW_CACHE_LL:ACCESS doesn't exist on this platform!");
77   }
78   ret=PAPI_event_name_to_code("DATA_PREFETCHER:ALL",&EventCode);
79   if(PAPI_query_event(EventCode)==PAPI_OK) {
80     papiEvents[3] = EventCode;
81   }else{
82     CmiAbort("WARNING: DATA_PREFETCHER:ALL doesn't exist on this platform!");
83   }
84   if(PAPI_query_event(PAPI_L1_DCM)==PAPI_OK) {
85     papiEvents[4] = PAPI_L1_DCM;
86   }else{
87     CmiAbort("WARNING: PAPI_L1_DCM doesn't exist on this platform!");
88   }
89   if(PAPI_query_event(PAPI_TOT_CYC)==PAPI_OK) {
90     papiEvents[5] = PAPI_TOT_CYC;
91   }else{
92     CmiAbort("WARNING: PAPI_TOT_CYC doesn't exist on this platform!");
93   }
94   if(PAPI_query_event(PAPI_L2_DCM)==PAPI_OK) {
95     papiEvents[6] = PAPI_L2_DCM;
96   }else{
97     CmiAbort("WARNING: PAPI_L2_DCM doesn't exist on this platform!");
98   }
99   if(PAPI_query_event(PAPI_L1_DCA)==PAPI_OK) {
100     papiEvents[7] = PAPI_L1_DCA;
101   }else{
102     CmiAbort("WARNING: PAPI_L1_DCA doesn't exist on this platform!");
103   }
104 #else
105   // just uses { PAPI_L2_DCM, PAPI_FP_OPS } the 2 initialized PAPI_EVENTS
106 #endif
107   papiRetValue = PAPI_add_events(papiEventSet, papiEvents, NUMPAPIEVENTS);
108   if (papiRetValue < 0) {
109     if (papiRetValue == PAPI_ECNFLCT) {
110       CmiAbort("PAPI events conflict! Please re-assign event types!\n");
111     } else {
112       char error_str[PAPI_MAX_STR_LEN];
113       PAPI_perror(error_str);
114       //PAPI_perror(papiRetValue,error_str,PAPI_MAX_STR_LEN);
115       CmiPrintf("PAPI failed with error %s val %d\n",error_str,papiRetValue);
116       CmiAbort("PAPI failed to add designated events!\n");
117     }
118   }
119   if(CkMyPe()==0)
120     {
121       CmiPrintf("Registered %d PAPI counters:",NUMPAPIEVENTS);
122       char nameBuf[PAPI_MAX_STR_LEN];
123       for(int i=0;i<NUMPAPIEVENTS;i++)
124         {
125           PAPI_event_code_to_name(papiEvents[i], nameBuf);
126           CmiPrintf("%s ",nameBuf);
127         }
128       CmiPrintf("\n");
129     }
130   memset(papiValues, 0, NUMPAPIEVENTS*sizeof(LONG_LONG_PAPI));
131   memset(previous_papiValues, 0, NUMPAPIEVENTS*sizeof(LONG_LONG_PAPI));
132 #endif
133
134
135     if (CkpvAccess(traceOnPe) == 0) return;
136 }
137
138 void TraceAutoPerf::resetTimings(){
139     totalIdleTime = 0.0;
140     totalEntryMethodTime = 0.0;
141     totalEntryMethodInvocations = 0;
142     lastBeginIdle = lastBeginExecuteTime = lastResetTime = TraceTimer();
143     totalUntracedTime = 0;
144     maxEntryMethodTime = 0;
145     if(whenStoppedTracing !=0){
146         whenStoppedTracing = TraceTimer();
147     }
148
149     currentSummary->numMsgs = 0;
150     currentSummary->numBytes = 0;
151     currentSummary->commTime = 0;
152     currentSummary->objLoadMax = 0;
153 }
154
155 void TraceAutoPerf::resetAll(){
156     totalIdleTime = 0.0;
157     totalEntryMethodTime = 0.0;
158     memUsage = 0;
159     totalEntryMethodInvocations = 0;
160     lastBeginIdle = lastBeginExecuteTime = lastResetTime = TraceTimer();
161     totalUntracedTime = 0;
162     if(whenStoppedTracing !=0){
163         whenStoppedTracing = TraceTimer();
164     }
165     currentSummary->numMsgs = 0;
166     currentSummary->numBytes = 0;
167     currentSummary->commTime = 0;
168     currentSummary->objLoadMax = 0;
169 #if CMK_HAS_COUNTER_PAPI
170     memcpy(previous_papiValues, papiValues, sizeof(LONG_LONG_PAPI)*NUMPAPIEVENTS);
171 #endif
172 }
173
174 void TraceAutoPerf::traceBegin(void){
175     if(whenStoppedTracing != 0)
176         totalUntracedTime += (TraceTimer() - whenStoppedTracing);
177     whenStoppedTracing = 0;
178 }
179
180 void TraceAutoPerf::traceEnd(void){
181   CkAssert(whenStoppedTracing == 0); // can't support nested traceEnds on one processor yet...
182   whenStoppedTracing = TraceTimer();
183 }
184
185 void TraceAutoPerf::userEvent(int eventID) { }
186 void TraceAutoPerf::userBracketEvent(int eventID, double bt, double et) { }
187 void TraceAutoPerf::creation(envelope *, int epIdx, int num) { } 
188 void TraceAutoPerf::creationMulticast(envelope *, int epIdx, int num, int *pelist) { }
189 void TraceAutoPerf::creationDone(int num) { }
190 void TraceAutoPerf::messageRecv(char *env, int pe) { }
191
192 void TraceAutoPerf::beginExecute(CmiObjId *tid)
193 {
194     //nesting_level++;
195     lastBeginExecuteTime = TraceTimer();
196     lastEvent =  BEGIN_PROCESSING;
197     lastbeginMessageSize = -1;
198     DEBUG_PRINT( CkPrintf("begin Executing tid   %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
199 }
200
201 void TraceAutoPerf::beginExecute(envelope *env)
202 {
203     //nesting_level++;
204     //if(nesting_level == 1){
205     lastBeginExecuteTime = TraceTimer();
206     lastEvent =  BEGIN_PROCESSING;
207     lastbeginMessageSize = env->getTotalsize();
208     currentSummary->numMsgs++;
209     currentSummary->numBytes += lastbeginMessageSize;
210     DEBUG_PRINT( CkPrintf("begin Executing env   %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
211 }
212
213 void TraceAutoPerf::beginExecute(envelope *env, int event,int msgType,int ep,int srcPe, int mlen, CmiObjId *idx)
214 {
215     //nesting_level++;
216     //if(nesting_level == 1){
217     lastbeginMessageSize = mlen;
218     currentSummary->numMsgs++;
219     currentSummary->numBytes += lastbeginMessageSize;
220     //`currentSummary->commTime += (env->getRecvTime() - env->getSentTime());
221     lastBeginExecuteTime = TraceTimer();
222     lastEvent =  BEGIN_PROCESSING;
223     DEBUG_PRINT( CkPrintf("begin Executing env  6  %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
224 }
225
226 void TraceAutoPerf::beginExecute(int event,int msgType,int ep,int srcPe, int mlen, CmiObjId *idx)
227 {
228     //nesting_level++;
229     //if(nesting_level == 1){
230     lastbeginMessageSize = mlen;
231     lastBeginExecuteTime = TraceTimer();
232     lastEvent =  BEGIN_PROCESSING;
233     DEBUG_PRINT( CkPrintf("begin Executing 6 no env %d  msg(%d:%d) time:%d\n", nesting_level, currentSummary->numMsgs, currentSummary->numBytes, (int)(lastBeginExecuteTime*1000000)); )
234 }
235
236 void TraceAutoPerf::endExecute(void)
237 {
238     //MAYBE a bug
239     //nesting_level--;
240     nesting_level = 0;
241     if(nesting_level == 0){
242         double endTime = TraceTimer() ;
243         double executionTime = endTime - lastBeginExecuteTime;
244         lastEvent =  -1;
245         DEBUG_PRINT( CkPrintf("end executing %d, duration %d\n", (int)(1000000*endTime), (int)(executionTime*1000000)); )
246         totalEntryMethodTime += executionTime;
247         totalEntryMethodInvocations ++;
248         if(executionTime > maxEntryMethodTime)
249             maxEntryMethodTime = executionTime;
250         double m = (double)CmiMemoryUsage();
251         if(memUsage < m){
252             memUsage = m;
253         }    
254     }
255 }
256
257 void TraceAutoPerf::beginIdle(double curWallTime) {
258     lastBeginIdle =  curWallTime; 
259     lastEvent =  BEGIN_IDLE;
260     double m = (double)CmiMemoryUsage();
261     if(memUsage < m){
262         memUsage = m;
263     }
264 }
265
266 void TraceAutoPerf::endIdle(double curWallTime) {
267     totalIdleTime += (curWallTime - lastBeginIdle) ;
268     lastEvent =  -1;
269 }
270
271 void TraceAutoPerf::beginComputation(void) {
272 #if CMK_HAS_COUNTER_PAPI
273   // we start the counters here
274   if (PAPI_start(papiEventSet) != PAPI_OK) {
275     CmiAbort("PAPI failed to start designated counters!\n");
276   }
277 #endif
278
279 }
280
281 void TraceAutoPerf::endComputation(void) { 
282 #if CMK_HAS_COUNTER_PAPI
283   // we stop the counters here. A silent failure is alright since we
284   // are already at the end of the program.
285   if (PAPI_stop(papiEventSet, papiValues) != PAPI_OK) {
286     CkPrintf("Warning: PAPI failed to stop correctly!\n");
287   }
288   //else 
289   //{
290   //    char eventName[PAPI_MAX_STR_LEN];
291   //    for (int i=0;i<NUMPAPIEVENTS;i++) {
292   //        PAPI_event_code_to_name(papiEvents[i], eventName);
293   //        CkPrintf(" EVENT  %s   counter   %lld \n", eventName, papiValues[i]);
294   //    }
295   //}
296   // NOTE: We should not do a complete close of PAPI until after the
297   // sts writer is done.
298 #endif
299
300 }
301
302 void TraceAutoPerf::malloc(void *where, int size, void **stack, int stackSize)
303 {
304     double m = (double)CmiMemoryUsage();
305     if(memUsage < m){
306         memUsage = m;
307     }
308 }
309
310 void TraceAutoPerf::free(void *where, int size) { }
311
312 void TraceAutoPerf::traceClose(void)
313 {
314     CkpvAccess(_traces)->endComputation();
315     CkpvAccess(_traces)->removeTrace(this);
316 }
317
318 void TraceAutoPerf::markStep()
319 {
320     double now = TraceTimer();
321     timerPair newpairs;
322     newpairs.beginTimer = lastResetTime;
323     newpairs.endTimer = now; 
324     phasesTimers.push_back(newpairs);
325     phaseEndTime = now;
326     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); )
327
328 }
329
330 void _createTraceautoPerf(char **argv)
331 {
332     CkpvInitialize(TraceAutoPerf*, _trace);
333     CkpvAccess(_trace) = new TraceAutoPerf(argv);
334     CkpvAccess(_traces)->addTrace(CkpvAccess(_trace));
335     //CkPrintf("##### init ####\n");
336 }