6 // everything defined here should match coreprof.h
8 public static final int CP_EVENT_MASK = 3;
9 public static final int CP_EVENT_BASESHIFT = 8;
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;
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_POOLALLOC = 0x14;
19 public static final int CP_EVENTID_COUNT_POOLALLOC = 0x15;
20 public static final int CP_EVENTID_COUNT_POOLREUSE = 0x16;
21 public static final int CP_EVENTID_WORKSCHEDGRAB = 0x20;
22 public static final int CP_EVENTID_WORKSCHEDSUBMIT = 0x21;
23 public static final int CP_EVENTID_TASKDISPATCH = 0x30;
24 public static final int CP_EVENTID_PREPAREMEMQ = 0x31;
25 public static final int CP_EVENTID_TASKEXECUTE = 0x40;
26 public static final int CP_EVENTID_TASKRETIRE = 0x50;
27 public static final int CP_EVENTID_TASKSTALLVAR = 0x60;
28 public static final int CP_EVENTID_TASKSTALLMEM = 0x61;
29 public static final int CP_EVENTID_RCR_TRAVERSE = 0x80;
30 public static final int CP_EVENTID_DEBUG_A = 0x180;
31 public static final int CP_EVENTID_DEBUG_B = 0x181;
32 public static final int CP_EVENTID_DEBUG_C = 0x182;
33 public static final int CP_EVENTID_DEBUG_D = 0x183;
34 public static final int CP_EVENTID_DEBUG_E = 0x184;
35 public static final int CP_EVENTID_DEBUG_F = 0x185;
36 public static final int CP_EVENTID_DEBUG_G = 0x186;
37 public static final int CP_EVENTID_DEBUG_H = 0x187;
38 public static final int CP_EVENTID_DEBUG_I = 0x188;
39 public static final int CP_EVENTID_DEBUG_J = 0x189;
43 eid2name = new Hashtable<Integer, String>();
44 eid2name.put( CP_EVENTID_MAIN, "MAIN " );
45 eid2name.put( CP_EVENTID_RUNMALLOC, "RUNMALLOC " );
46 eid2name.put( CP_EVENTID_RUNFREE, "RUNFREE " );
47 eid2name.put( CP_EVENTID_POOLALLOC, "POOLALLOC " );
48 eid2name.put( CP_EVENTID_COUNT_POOLALLOC, "POOLALLOC CNT " );
49 eid2name.put( CP_EVENTID_COUNT_POOLREUSE, "POOLREUSE CNT " );
50 eid2name.put( CP_EVENTID_WORKSCHEDGRAB, "WORKSCHEDGRAB " );
51 eid2name.put( CP_EVENTID_WORKSCHEDSUBMIT, "WORKSCHEDSUBMIT" );
52 eid2name.put( CP_EVENTID_TASKDISPATCH, "TASKDISPATCH " );
53 eid2name.put( CP_EVENTID_PREPAREMEMQ, "PREPAREMEMQ " );
54 eid2name.put( CP_EVENTID_TASKEXECUTE, "TASKEXECUTE " );
55 eid2name.put( CP_EVENTID_TASKRETIRE, "TASKRETIRE " );
56 eid2name.put( CP_EVENTID_TASKSTALLVAR, "TASKSTALLVAR " );
57 eid2name.put( CP_EVENTID_TASKSTALLMEM, "TASKSTALLMEM " );
58 eid2name.put( CP_EVENTID_RCR_TRAVERSE, "RCR TRAVERSE " );
59 eid2name.put( CP_EVENTID_DEBUG_A, "DEBUG A " );
60 eid2name.put( CP_EVENTID_DEBUG_B, "DEBUG B " );
61 eid2name.put( CP_EVENTID_DEBUG_C, "DEBUG C " );
62 eid2name.put( CP_EVENTID_DEBUG_D, "DEBUG D " );
63 eid2name.put( CP_EVENTID_DEBUG_E, "DEBUG E " );
64 eid2name.put( CP_EVENTID_DEBUG_F, "DEBUG F " );
65 eid2name.put( CP_EVENTID_DEBUG_G, "DEBUG G " );
66 eid2name.put( CP_EVENTID_DEBUG_H, "DEBUG H " );
67 eid2name.put( CP_EVENTID_DEBUG_I, "DEBUG I " );
68 eid2name.put( CP_EVENTID_DEBUG_J, "DEBUG J " );
71 Hashtable<Integer, String> eid2name;
75 public static void main( String args[] ) {
76 if( args.length < 2 ) {
77 System.out.println( "usage: <coreprof.dat file> <trace out file> [-2txt]\n"+
78 "\nThe -2txt option will take the raw binary events and spit\n"+
79 "out every event as text in events.txt, useful for debugging\n"+
80 "event mis-matches." );
83 String inputfile=null;
84 String outputfile=null;
86 HashSet<Integer> eventset=new HashSet<Integer>();
87 boolean hasinput=false;
92 for(int i=0; i<args.length; i++) {
93 if (args[i].equals("-2txt")) {
95 } else if (args[i].equals("-event")) {
96 eventset.add(Integer.parseInt(args[i+1]));
98 } else if (args[i].equals("-maxtime")) {
99 maxtime=Long.parseLong(args[i+1]);
101 } else if (args[i].equals("-mintime")) {
102 mintime=Long.parseLong(args[i+1]);
104 } else if (args[i].equals("-scale")) {
105 scale=Long.parseLong(args[i+1]);
117 Trace t = new Trace(events, inputfile, outputfile, eventset, mintime, maxtime,scale);
122 // event IDs are a word, timestamps are long ints
123 public static final int WORD_SIZE = 4;
124 public static final int EVENT_SIZE = WORD_SIZE;
125 public static final int TIMESTAMP_SIZE = WORD_SIZE*2;
128 ThreadData[] threadData;
129 HashSet<Integer> eventset;
132 BufferedWriter txtStream;
134 boolean convert2plot;
135 BufferedWriter bwPlot;
141 long minObservedTime = Long.MAX_VALUE;
142 long maxObservedTime = Long.MIN_VALUE;
145 public Trace( boolean c2txt, String inFile, String outFile, HashSet<Integer> eventset, long mintime, long maxtime, long scale) {
146 this.eventset=eventset;
147 this.maxtime=maxtime;
148 this.mintime=mintime;
153 openInputStreams( inFile );
159 txtStream = new BufferedWriter( new FileWriter( "events.txt" ) );
160 } catch( Exception e ) { e.printStackTrace(); System.exit( -1 ); }
167 for( int i = 0; i < numThreads; i++ ) {
171 System.out.println( "Minimum observed time stamp: "+minObservedTime );
172 System.out.println( "Maximum observed time stamp: "+maxObservedTime );
174 System.out.println( "\nelapsed time: "+(maxObservedTime - minObservedTime) );
177 printStats( outFile );
182 } catch( Exception e ) { e.printStackTrace(); System.exit( -1 ); }
187 bwPlot.write("plot [0:"+(globendtime/scale)+"] [-1:"+(numThreads+1)+"] -3\n");
189 } catch (IOException e) {
196 public static int readInt( InputStream is ) {
203 int retval = (b4<<24)|(b3<<16)|(b2<<8)|b1;
210 } catch( Exception e ) {
216 public static long readLong( InputStream is ) {
228 (b8<<56)|(b7<<48)|(b6<<40)|(b5<<32)|
229 (b4<<24)|(b3<<16)|(b2<< 8)|b1;
236 } catch( Exception e ) {
242 protected void openInputStreams( String filename ) {
244 BufferedInputStream bis = null;
248 bis = new BufferedInputStream( new FileInputStream( filename ) );
249 offset = readHeader( bis );
252 } catch( Exception e ) {
257 for( int i = 0; i < numThreads; ++i ) {
259 // point a thread's event stream to the
260 // beginning of its data within the input file
261 threadData[i].dataStream =
262 new BufferedInputStream( new FileInputStream( filename ) );
266 skip -= threadData[i].dataStream.skip( skip );
268 threadData[i].dataStream.mark(20);
269 int eventRaw = readInt ( threadData[i].dataStream );
270 long Stamp = readLong( threadData[i].dataStream );
271 threadData[i].dataStream.reset();
273 if (globalstarttime==-1||globalstarttime>Stamp)
274 globalstarttime=Stamp;
277 offset += WORD_SIZE*threadData[i].numDataWords;
279 } catch( Exception e ) {
287 int readHeader( BufferedInputStream bis ) {
290 int version = readInt( bis );
292 throw new Error( "Unsupported Version" );
294 int offset = WORD_SIZE;
296 // read number of threads
297 numThreads = readInt( bis );
300 threadData = new ThreadData[numThreads];
302 // read number of words used for all events, per thread
303 for( int i = 0; i < numThreads; ++i ) {
304 threadData[i] = new ThreadData();
305 threadData[i].numDataWords = readInt( bis );
312 public void readThread( int tNum ) {
314 System.out.print( "Reading thread "+tNum );
318 txtStream.write( "\n\n\n\n" );
319 txtStream.write( "*************************************************\n" );
320 txtStream.write( "** Thread "+tNum+"\n" );
321 txtStream.write( "*************************************************\n" );
322 } catch( IOException e ) {
329 ThreadData tdata = threadData[tNum];
330 tdata.stackDepth = 0;
333 int numProgress = 10;
335 int progressChunk = tdata.numDataWords / numProgress;
337 boolean[] progress = new boolean[numProgress];
338 for( j = 0; j < numProgress; ++j ) {
344 while( i < tdata.numDataWords ) {
346 if( !progress[j] && i > j*progressChunk ) {
347 System.out.print( "." );
349 if( j < numProgress - 1 ) {
354 int eventRaw = readInt ( tdata.dataStream );
355 timeStamp = readLong( tdata.dataStream );
359 if( timeStamp < minObservedTime ) {
360 minObservedTime = timeStamp;
363 if( timeStamp > maxObservedTime ) {
364 maxObservedTime = timeStamp;
368 int eventType = eventRaw & CP_EVENT_MASK;
369 int eventID = eventRaw >> CP_EVENT_BASESHIFT;
371 if (eventset.isEmpty()||eventset.contains(eventID))
372 switch( eventType ) {
374 case CP_EVENTTYPE_BEGIN: {
375 if( eventID == CP_EVENTID_MAIN ) {
376 tSysZero = timeStamp;
378 if( tdata.stackDepth>0 && convert2plot ) {
379 EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
380 long starttime=lasttime>esParent.timeStampBeginLatestInstance?lasttime:esParent.timeStampBeginLatestInstance;
381 addPointToPlot( tNum, esParent.eventID, starttime, timeStamp);
384 pushEvent( tdata, eventID, timeStamp );
387 case CP_EVENTTYPE_END: {
389 EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
390 long starttime=lasttime>esParent.timeStampBeginLatestInstance?lasttime:esParent.timeStampBeginLatestInstance;
392 addPointToPlot( tNum, esParent.eventID, starttime, timeStamp);
395 popEvent( tdata, eventID, timeStamp );
400 System.out.println( "" );
402 while( tdata.stackDepth > 0 ) {
403 // worker threads currently do not exit gracefully, and therefore
404 // may not register END events, so supply them with whatever the
405 // latest known timestamp is
406 EventSummary eventSummary = tdata.eventStack.get( tdata.stackDepth);
408 if( eventSummary == null ) {
409 // if there is no previous event it means there are no children
410 // events with a timestamp for the workaround, so just punt
414 popEvent( tdata, eventSummary.eventID, timeStamp );
422 protected void pushEvent( ThreadData tdata,
426 EventSummary eventSummary = null;
428 if( tdata.stackDepth == 0 ) {
429 // there are no parents, so look in the rootEvents
430 // for an existing EventSummary of this type
431 for( Iterator<EventSummary> itr = tdata.rootEvents.iterator();
434 EventSummary es = itr.next();
435 if( es.eventID == eventID ) {
440 if( eventSummary == null ) {
441 // there is no summary for this event type yet,
443 eventSummary = new EventSummary( eventID );
444 tdata.rootEvents.add( eventSummary );
448 // look through the parent's children for an existing
449 // EventSummary of this type
450 EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
451 for( Iterator<EventSummary> itr = esParent.children.iterator();
454 EventSummary es = itr.next();
455 if( es.eventID == eventID ) {
460 if( eventSummary == null ) {
461 // there is no summary for this event type yet,
462 // under this parent, so add it
463 eventSummary = new EventSummary( eventID );
464 esParent.children.add( eventSummary );
465 eventSummary.parent = esParent;
469 eventSummary.timeStampBeginLatestInstance = timeStamp;
471 eventSummary.instanceCount++;
473 if( tdata.eventStack.size() <= tdata.stackDepth ) {
474 tdata.eventStack.setSize( 2*tdata.stackDepth + 20 );
477 tdata.eventStack.set( tdata.stackDepth, eventSummary );
480 // print to the event text file (if needed) before
481 // updating the stack depth to get tabs right
484 for( int tabs = 0; tabs < tdata.stackDepth; ++tabs ) {
485 txtStream.write( " " );
487 txtStream.write( "begin "+getEventName( eventID )+"@"+timeStamp+"\n" );
488 } catch( IOException e ) {
499 protected void popEvent( ThreadData tdata,
505 // print to the event text file (if needed) after
506 // updating the stack depth to get tabs right
509 for( int tabs = 0; tabs < tdata.stackDepth; ++tabs ) {
510 txtStream.write( " " );
512 txtStream.write( "end "+getEventName( eventID )+"@"+timeStamp+"\n" );
513 } catch( IOException e ) {
520 if( tdata.stackDepth < 0 ) {
521 throw new Error( "Event stack underflow\n" );
524 EventSummary eventSummary = tdata.eventStack.get( tdata.stackDepth );
525 assert eventSummary != null;
527 if( eventSummary.eventID != eventID ) {
528 System.out.println( "Warning: event begin("+
529 getEventName( eventSummary.eventID )+
531 getEventName( eventID )+
536 timeStamp - eventSummary.timeStampBeginLatestInstance;
538 eventSummary.totalTime_ticks += elapsedTime;
539 eventSummary.selfTime_ticks += elapsedTime;
541 if( tdata.stackDepth - 1 >= 0 ) {
542 EventSummary esParent = tdata.eventStack.get( tdata.stackDepth-1 );
543 esParent.selfTime_ticks -= elapsedTime;
547 long globalstarttime=-1;
550 public void addPointToPlot( int thread, int eventID, long starttime, long endtime) {
552 long nstart=starttime-globalstarttime-mintime;
553 long nend=endtime-globalstarttime-mintime;
554 if ((maxtime==-1 || (endtime-globalstarttime)<maxtime)&&(nend>0)) {
555 if (nend>globendtime)
559 bwPlot.write( "set arrow from "+(nstart/scale)+","+thread+
560 " to "+(nend/scale)+","+thread+" lt "+eventID+"\n");
562 } catch( IOException e ) {
570 public void printStats( String filename ) {
572 System.out.println( "Printing..." );
576 new BufferedWriter( new FileWriter( filename ) );
578 for( int i = 0; i < numThreads; ++i ) {
580 ThreadData tdata = threadData[i];
582 bw.write( "----------------------------------\n" );
583 bw.write( "Thread "+i+"\n" );
585 for( Iterator<EventSummary> itr = tdata.rootEvents.iterator();
588 EventSummary es = itr.next();
589 printEventSummary( bw, es, 0 );
596 } catch( IOException e ) {
603 public String getEventName( int eventID ) {
605 eid2name.containsKey( eventID ) ?
606 eid2name.get ( eventID ) :
607 Integer.toString ( eventID );
611 public void printEventSummary( BufferedWriter bw,
616 String strIndent = "";
617 for( int i = 0; i < depth; ++i ) {
621 String strEventName = getEventName( es.eventID );
623 float tOfParent_perc;
624 String strPercParent = "";
625 if( es.parent != null ) {
626 float divisor = new Long( es.parent.totalTime_ticks ).floatValue();
627 if( divisor <= 0.00001f ) {
633 new Long( es.totalTime_ticks ).floatValue() /
636 strPercParent = String.format( " %%ofParent=%5.1f",
642 new Long( es.selfTime_ticks ).floatValue() /
643 new Long( es.totalTime_ticks ).floatValue();
645 String strSelfStats =
646 String.format( " total(ticks)=%12dK, %%self=%5.1f, count=%d, avgTicks=%d",
647 es.totalTime_ticks/1000,
650 (int)((float)es.totalTime_ticks/(float)es.instanceCount) );
658 for( Iterator<EventSummary> itr = es.children.iterator();
661 EventSummary esChild = itr.next();
662 printEventSummary( bw, esChild, depth + 1 );
667 public void printPlotCmd() {
670 new BufferedWriter( new FileWriter( "plot.cmd" ) );
671 } catch( IOException e ) {