change parser to match runtime changes, still some kooky issue where child events...
[IRC.git] / Robust / CoreProf / Trace.java
1 import java.io.*;
2 import java.util.*;
3
4 public class Trace {
5
6   // everything defined here should match coreprof.h
7   // definitions exactly
8   public static final int CP_EVENT_MASK           = 3;
9   public static final int CP_EVENT_BASESHIFT      = 8;
10                                                   
11   public static final int CP_EVENTTYPE_BEGIN      = 1;
12   public static final int CP_EVENTTYPE_END        = 2;
13   public static final int CP_EVENTTYPE_ONEOFF     = 3;
14
15   public static final int CP_EVENTID_MAIN          = 0x04;
16   public static final int CP_EVENTID_RUNMALLOC     = 0x10;
17   public static final int CP_EVENTID_RUNFREE       = 0x11;
18   public static final int CP_EVENTID_WORKSCHEDGRAB = 0x20;
19   public static final int CP_EVENTID_TASKDISPATCH  = 0x30;
20   public static final int CP_EVENTID_TASKEXECUTE   = 0x31;
21   public static final int CP_EVENTID_TASKRETIRE    = 0x32;
22   public static final int CP_EVENTID_TASKSTALLVAR  = 0x40;
23   public static final int CP_EVENTID_TASKSTALLMEM  = 0x41;
24
25
26   void initNames() {
27     eid2name = new Hashtable<Integer, String>();
28     eid2name.put( CP_EVENTID_MAIN,          "MAIN         " );
29     eid2name.put( CP_EVENTID_RUNMALLOC,     "RUNMALLOC    " );
30     eid2name.put( CP_EVENTID_RUNFREE,       "RUNFREE      " );
31     eid2name.put( CP_EVENTID_WORKSCHEDGRAB, "WORKSCHEDGRAB" );
32     eid2name.put( CP_EVENTID_TASKDISPATCH,  "TASKDISPATCH " );
33     eid2name.put( CP_EVENTID_TASKEXECUTE,   "TASKEXECUTE  " );
34     eid2name.put( CP_EVENTID_TASKRETIRE,    "TASKRETIRE   " );
35     eid2name.put( CP_EVENTID_TASKSTALLVAR,  "TASKSTALLVAR " );
36     eid2name.put( CP_EVENTID_TASKSTALLMEM,  "TASKSTALLMEM " );
37   }
38
39   Hashtable<Integer, String> eid2name;
40   
41
42
43   public static void main( String args[] ) {
44     if( args.length != 2 ) {
45       System.out.println( "usage: <coreprof.dat file> <trace out file>" );
46       System.exit( 0 );
47     }
48     Trace t = new Trace( args[0], args[1] );
49   }
50
51
52
53   // event IDs are a word, timestamps are long ints
54   public static final int WORD_SIZE      = 4;
55   public static final int EVENT_SIZE     = WORD_SIZE;
56   public static final int TIMESTAMP_SIZE = WORD_SIZE*2;
57
58   int          numThreads;
59   ThreadData[] threadData;
60
61
62
63   public Trace( String inFile, String outFile ) {
64
65     openInputStreams( inFile );
66
67     initNames();
68
69     for( int i = 0; i < numThreads; i++ ) {
70       readThread( i );
71     }
72
73     printStats( outFile );
74   }
75
76
77   public static int readInt( InputStream is ) {
78     try {
79       int b1 = is.read();
80       int b2 = is.read();
81       int b3 = is.read();
82       int b4 = is.read();
83
84       int retval = (b4<<24)|(b3<<16)|(b2<<8)|b1;
85
86       if( retval < 0 ) {
87         throw new Error();
88       }
89       return retval;
90
91     } catch( Exception e ) {
92       throw new Error();
93     }
94   }
95
96
97   public static long readLong( InputStream is ) {
98     try {
99       long b1 = is.read();
100       long b2 = is.read();
101       long b3 = is.read();
102       long b4 = is.read();
103       long b5 = is.read();
104       long b6 = is.read();
105       long b7 = is.read();
106       long b8 = is.read();
107
108       long retval = 
109         (b8<<56)|(b7<<48)|(b6<<40)|(b5<<32)|
110         (b4<<24)|(b3<<16)|(b2<< 8)|b1;
111       
112       if( retval < 0 ) {
113         throw new Error();
114       }
115       return retval;
116       
117     } catch( Exception e ) {
118       throw new Error();
119     }
120   }
121
122
123   protected void openInputStreams( String filename ) {
124
125     BufferedInputStream bis    = null;
126     int                 offset = 0;
127
128     try {
129       bis    = new BufferedInputStream( new FileInputStream( filename ) );
130       offset = readHeader( bis );
131       bis.close();
132     } catch( Exception e ) {
133       e.printStackTrace();
134       System.exit( -1 );
135     }
136
137     for( int i = 0; i < numThreads; ++i ) {
138       try {
139         // point a thread's event stream to the
140         // beginning of its data within the input file
141         threadData[i].dataStream = 
142           new BufferedInputStream( new FileInputStream( filename ) );
143
144         int skip = offset;
145         while( skip > 0 ) {
146           skip -= threadData[i].dataStream.skip( skip );
147         }
148
149         offset += WORD_SIZE*threadData[i].numDataWords;
150
151       } catch( Exception e ) {
152         e.printStackTrace();
153         System.exit( -1 );
154       }
155     }
156   }
157
158
159   int readHeader( BufferedInputStream bis ) {
160
161     // check version
162     int version = readInt( bis );
163     if( version != 0 ) {
164       throw new Error( "Unsupported Version" );
165     }
166     int offset = WORD_SIZE;
167     
168     // read number of threads
169     numThreads = readInt( bis );
170     offset += WORD_SIZE;
171
172     threadData = new ThreadData[numThreads];
173
174     // read number of words used for all events, per thread
175     for( int i = 0; i < numThreads; ++i ) {
176       threadData[i] = new ThreadData();
177       threadData[i].numDataWords = readInt( bis );
178       offset += WORD_SIZE;
179     }
180     return offset;
181   }
182
183   
184   public void readThread( int tNum ) {
185
186     System.out.print( "Reading thread "+tNum );
187
188     ThreadData tdata = threadData[tNum];
189     tdata.stackDepth = 0;
190     long timeStamp   = 0;
191     int  i           = 0;
192     int numProgress  = 10;
193
194     int progressChunk = tdata.numDataWords / numProgress;
195     int j;
196     boolean[] progress = new boolean[numProgress];
197     for( j = 0; j < numProgress; ++j ) {
198       progress[j] = false;
199     }
200     j = 0;
201     
202     while( i < tdata.numDataWords ) {
203       
204       if( !progress[j] && i > j*progressChunk ) {
205         System.out.print( "." );
206         progress[j] = true;
207         if( j < numProgress - 1 ) {
208           ++j;
209         }
210       }
211
212       int eventRaw = readInt ( tdata.dataStream );
213       timeStamp    = readLong( tdata.dataStream );
214       i += 3;
215
216       int eventType = eventRaw &  CP_EVENT_MASK;
217       int eventID   = eventRaw >> CP_EVENT_BASESHIFT;
218
219       switch( eventType ) {
220
221         case CP_EVENTTYPE_BEGIN: {
222           pushEvent( tdata, eventID, timeStamp );
223         } break;
224
225         case CP_EVENTTYPE_END: {
226           popEvent( tdata, eventID, timeStamp );
227         } break;    
228     
229       }
230     }
231
232     System.out.println( "" );
233
234     if( tdata.stackDepth != 0 ) {
235       // worker threads currently do not exit gracefully, and therefore
236       // never register their MAIN END event, so if the mismatch is with
237       // MAIN BEGIN then treat it as fine, otherwise warn.
238       if( tdata.stackDepth == 1 ) {
239         // the value of timestamp will be equal to whatever the last
240         // properly registered event for this thread was
241         popEvent( tdata, CP_EVENTID_MAIN, timeStamp );
242       } else {
243         System.out.println( "Warning: unmatched event begin/end\n" );
244       }
245     }
246   }
247
248
249   protected void pushEvent( ThreadData tdata,
250                             int        eventID,
251                             long       timeStamp ) {
252
253     EventSummary eventSummary = null;
254
255     if( tdata.stackDepth == 0 ) {
256       // there are no parents, so look in the rootEvents
257       // for an existing EventSummary of this type
258       for( Iterator<EventSummary> itr = tdata.rootEvents.iterator();
259            itr.hasNext();
260            ) {
261         EventSummary es = itr.next();
262         if( es.eventID == eventID ) {
263           eventSummary = es;
264           break;
265         }
266       }
267       if( eventSummary == null ) {
268         // there is no summary for this event type yet,
269         // so add it
270         eventSummary = new EventSummary( eventID );
271         tdata.rootEvents.add( eventSummary );
272       }
273
274     } else {
275       // look through the parent's children for an existing
276       // EventSummary of this type
277       EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
278       for( Iterator<EventSummary> itr = esParent.children.iterator();
279            itr.hasNext();
280            ) {
281         EventSummary es = itr.next();
282         if( es.eventID == eventID ) {
283           eventSummary = es;
284           break;
285         }
286       }
287       if( eventSummary == null ) {
288         // there is no summary for this event type yet,
289         // under this parent, so add it
290         eventSummary = new EventSummary( eventID );
291         esParent.children.add( eventSummary );
292         eventSummary.parent = esParent;
293       }
294     }
295
296     eventSummary.timeStampBeginLatestInstance = timeStamp;
297     
298     eventSummary.instanceCount++;
299
300     if( tdata.eventStack.size() <= tdata.stackDepth ) {
301       tdata.eventStack.setSize( 2*tdata.stackDepth + 20 );
302     }
303     tdata.eventStack.set( tdata.stackDepth, eventSummary );
304
305     tdata.stackDepth++;
306   }
307
308
309   protected void popEvent( ThreadData tdata,
310                            int        eventID,
311                            long       timeStamp ) {
312     tdata.stackDepth--;
313     if( tdata.stackDepth < 0 ) {
314       throw new Error( "Event stack underflow\n" );
315     }
316
317     EventSummary eventSummary = tdata.eventStack.get( tdata.stackDepth );
318     assert eventSummary != null;
319
320     long elapsedTime = 
321       timeStamp - eventSummary.timeStampBeginLatestInstance;
322
323     eventSummary.totalTime_ticks += elapsedTime;
324     eventSummary.selfTime_ticks  += elapsedTime;
325     
326     if( tdata.stackDepth - 1 >= 0 ) {
327       EventSummary esParent = tdata.eventStack.get( tdata.stackDepth-1 );
328       esParent.selfTime_ticks -= elapsedTime;
329     }
330   }
331
332
333
334   public void printStats( String filename ) {
335
336     System.out.println( "Printing..." );
337
338     try {
339       BufferedWriter bw = 
340         new BufferedWriter( new FileWriter( filename ) );
341       
342       for( int i = 0; i < numThreads; ++i ) {
343
344         ThreadData tdata = threadData[i];
345
346         bw.write( "----------------------------------\n" );
347         bw.write( "Thread "+i+"\n" );
348       
349         for( Iterator<EventSummary> itr = tdata.rootEvents.iterator();
350              itr.hasNext();
351              ) {
352           EventSummary es = itr.next();
353           printEventSummary( bw, es, 0 );
354         }
355
356         bw.write( "\n" );
357       }
358
359       bw.close();
360
361     } catch( IOException e ) {}
362   }
363   
364
365   public void printEventSummary( BufferedWriter bw,
366                                  EventSummary   es, 
367                                  int            depth ) 
368     throws IOException {
369
370     String strIndent = "";
371     for( int i = 0; i < depth; ++i ) {
372       strIndent += "--";
373     }
374
375     String strEventName = 
376       eid2name.containsKey( es.eventID ) ?
377       eid2name.get( es.eventID )         :
378       Integer.toString( es.eventID );
379         
380     float tOfParent_perc;
381     String strPercParent = "";
382     if( es.parent != null ) {
383       float divisor = new Long( es.parent.totalTime_ticks ).floatValue();
384       if( divisor <= 0.00001f ) {
385         divisor = 0.00001f;
386       }
387
388       tOfParent_perc =
389         100.0f *
390         new Long( es.totalTime_ticks        ).floatValue() /
391         divisor;
392       
393       strPercParent = String.format( " %%ofParent=%5.1f",
394                                      tOfParent_perc );
395     }
396     
397     float tSelf_perc = 
398       100.0f *
399       new Long( es.selfTime_ticks  ).floatValue() /
400       new Long( es.totalTime_ticks ).floatValue();      
401
402     String strSelfStats =
403       String.format( " total(ticks)=%12dK, %%self=%5.1f, count=%d",
404                      es.totalTime_ticks/1000,
405                      tSelf_perc,
406                      es.instanceCount );
407
408     bw.write( strIndent+
409               strEventName+
410               strPercParent+
411               strSelfStats+
412               "\n" );
413
414     for( Iterator<EventSummary> itr = es.children.iterator();
415          itr.hasNext();
416          ) {
417       EventSummary esChild = itr.next();
418       printEventSummary( bw, esChild, depth + 1 );
419     }    
420   }
421 }