close this file so it actually writes out
[IRC.git] / Robust / CoreProf / Trace.java
index 40ca7f607330862924ce23a9e9453ba2f690bf24..0d4cf9882de653377706b29b410fdea7bc8fba63 100644 (file)
@@ -15,15 +15,18 @@ public class Trace {
   public static final int CP_EVENTID_MAIN             = 0x04;
   public static final int CP_EVENTID_RUNMALLOC        = 0x10;
   public static final int CP_EVENTID_RUNFREE          = 0x11;
+  public static final int CP_EVENTID_POOLALLOC        = 0x14;
   public static final int CP_EVENTID_COUNT_POOLALLOC  = 0x15;
   public static final int CP_EVENTID_COUNT_POOLREUSE  = 0x16;
   public static final int CP_EVENTID_WORKSCHEDGRAB    = 0x20;
+  public static final int CP_EVENTID_WORKSCHEDSUBMIT  = 0x21;
   public static final int CP_EVENTID_TASKDISPATCH     = 0x30;
   public static final int CP_EVENTID_PREPAREMEMQ      = 0x31;
   public static final int CP_EVENTID_TASKEXECUTE      = 0x40;
   public static final int CP_EVENTID_TASKRETIRE       = 0x50;
   public static final int CP_EVENTID_TASKSTALLVAR     = 0x60;
   public static final int CP_EVENTID_TASKSTALLMEM     = 0x61;
+  public static final int CP_EVENTID_RCR_TRAVERSE     = 0x80;
   public static final int CP_EVENTID_DEBUG_A          = 0x180;
   public static final int CP_EVENTID_DEBUG_B          = 0x181;
   public static final int CP_EVENTID_DEBUG_C          = 0x182;
@@ -38,28 +41,31 @@ public class Trace {
 
   void initNames() {
     eid2name = new Hashtable<Integer, String>();
-    eid2name.put( CP_EVENTID_MAIN,              "MAIN         " );
-    eid2name.put( CP_EVENTID_RUNMALLOC,         "RUNMALLOC    " );
-    eid2name.put( CP_EVENTID_RUNFREE,           "RUNFREE      " );
-    eid2name.put( CP_EVENTID_RUNFREE,           "POOLALLOC    " );
-    eid2name.put( CP_EVENTID_RUNFREE,           "POOLREUSE    " );
-    eid2name.put( CP_EVENTID_WORKSCHEDGRAB,     "WORKSCHEDGRAB" );
-    eid2name.put( CP_EVENTID_TASKDISPATCH,      "TASKDISPATCH " );
-    eid2name.put( CP_EVENTID_PREPAREMEMQ,       "PREPAREMEMQ  " );
-    eid2name.put( CP_EVENTID_TASKEXECUTE,       "TASKEXECUTE  " );
-    eid2name.put( CP_EVENTID_TASKRETIRE,        "TASKRETIRE   " );
-    eid2name.put( CP_EVENTID_TASKSTALLVAR,      "TASKSTALLVAR " );
-    eid2name.put( CP_EVENTID_TASKSTALLMEM,      "TASKSTALLMEM " );
-    eid2name.put( CP_EVENTID_DEBUG_A,           "DEBUG A      " );
-    eid2name.put( CP_EVENTID_DEBUG_B,           "DEBUG B      " );
-    eid2name.put( CP_EVENTID_DEBUG_C,           "DEBUG C      " );
-    eid2name.put( CP_EVENTID_DEBUG_D,           "DEBUG D      " );
-    eid2name.put( CP_EVENTID_DEBUG_E,           "DEBUG E      " );
-    eid2name.put( CP_EVENTID_DEBUG_F,           "DEBUG F      " );
-    eid2name.put( CP_EVENTID_DEBUG_G,           "DEBUG G      " );
-    eid2name.put( CP_EVENTID_DEBUG_H,           "DEBUG H      " );
-    eid2name.put( CP_EVENTID_DEBUG_I,           "DEBUG I      " );
-    eid2name.put( CP_EVENTID_DEBUG_J,           "DEBUG J      " );
+    eid2name.put( CP_EVENTID_MAIN,              "MAIN           " );
+    eid2name.put( CP_EVENTID_RUNMALLOC,         "RUNMALLOC      " );
+    eid2name.put( CP_EVENTID_RUNFREE,           "RUNFREE        " );
+    eid2name.put( CP_EVENTID_POOLALLOC,         "POOLALLOC      " );
+    eid2name.put( CP_EVENTID_COUNT_POOLALLOC,   "POOLALLOC CNT  " );
+    eid2name.put( CP_EVENTID_COUNT_POOLREUSE,   "POOLREUSE CNT  " );
+    eid2name.put( CP_EVENTID_WORKSCHEDGRAB,     "WORKSCHEDGRAB  " );
+    eid2name.put( CP_EVENTID_WORKSCHEDSUBMIT,   "WORKSCHEDSUBMIT" );
+    eid2name.put( CP_EVENTID_TASKDISPATCH,      "TASKDISPATCH   " );
+    eid2name.put( CP_EVENTID_PREPAREMEMQ,       "PREPAREMEMQ    " );
+    eid2name.put( CP_EVENTID_TASKEXECUTE,       "TASKEXECUTE    " );
+    eid2name.put( CP_EVENTID_TASKRETIRE,        "TASKRETIRE     " );
+    eid2name.put( CP_EVENTID_TASKSTALLVAR,      "TASKSTALLVAR   " );
+    eid2name.put( CP_EVENTID_TASKSTALLMEM,      "TASKSTALLMEM   " );
+    eid2name.put( CP_EVENTID_RCR_TRAVERSE,      "RCR TRAVERSE   " );
+    eid2name.put( CP_EVENTID_DEBUG_A,           "DEBUG A        " );
+    eid2name.put( CP_EVENTID_DEBUG_B,           "DEBUG B        " );
+    eid2name.put( CP_EVENTID_DEBUG_C,           "DEBUG C        " );
+    eid2name.put( CP_EVENTID_DEBUG_D,           "DEBUG D        " );
+    eid2name.put( CP_EVENTID_DEBUG_E,           "DEBUG E        " );
+    eid2name.put( CP_EVENTID_DEBUG_F,           "DEBUG F        " );
+    eid2name.put( CP_EVENTID_DEBUG_G,           "DEBUG G        " );
+    eid2name.put( CP_EVENTID_DEBUG_H,           "DEBUG H        " );
+    eid2name.put( CP_EVENTID_DEBUG_I,           "DEBUG I        " );
+    eid2name.put( CP_EVENTID_DEBUG_J,           "DEBUG J        " );
   }
 
   Hashtable<Integer, String> eid2name;
@@ -67,21 +73,48 @@ public class Trace {
 
 
   public static void main( String args[] ) {
-    if( args.length < 2 ||
-        args.length > 3 ) {
-      System.out.println( "usage: [-2txt] <coreprof.dat file> <trace out file>" );
-      System.out.println( "The -2txt option will take the raw binary events and spit\n"+
+    if( args.length < 2 ) {
+      System.out.println( "usage: <coreprof.dat file> <trace out file> [-2txt]\n"+
+                          "\nThe -2txt option will take the raw binary events and spit\n"+
                           "out every event as text in events.txt, useful for debugging\n"+
                           "event mis-matches." );
       System.exit( 0 );
     }
-
-    Trace t;
-    if( args[0].equals( "-2txt" ) ) {
-      t = new Trace( true,  args[1], args[2] );
-    } else {
-      t = new Trace( false, args[0], args[1] );
+    String inputfile=null;
+    String outputfile=null;
+    boolean events=false;
+    HashSet<Integer> eventset=new HashSet<Integer>();
+    boolean hasinput=false;
+    long maxtime=-1;
+    long mintime=0;
+    long scale=1;
+
+    for(int i=0; i<args.length; i++) {
+      if (args[i].equals("-2txt")) {
+       events=true;
+      } else if (args[i].equals("-event")) {
+       eventset.add(Integer.parseInt(args[i+1]));
+       i++;
+      } else if (args[i].equals("-maxtime")) {
+       maxtime=Long.parseLong(args[i+1]);
+       i++;
+      } else if (args[i].equals("-mintime")) {
+       mintime=Long.parseLong(args[i+1]);
+       i++;
+      } else if (args[i].equals("-scale")) {
+       scale=Long.parseLong(args[i+1]);
+       i++;
+      } else {
+       if (hasinput) {
+         outputfile=args[i];
+       } else {
+         hasinput=true;
+         inputfile=args[i];
+       }
+      }
     }
+
+    Trace t = new Trace(events, inputfile, outputfile, eventset, mintime, maxtime,scale);
   }
 
 
@@ -93,25 +126,70 @@ public class Trace {
 
   int          numThreads;
   ThreadData[] threadData;
+  HashSet<Integer> eventset;
 
   boolean        convert2txt;
   BufferedWriter txtStream;
 
+  boolean             convert2plot;
+  BufferedWriter      bwPlot;
+  long                tSysZero;
+  long maxtime;
+  long mintime;
+  long scale;
 
+  long minObservedTime = Long.MAX_VALUE;
+  long maxObservedTime = Long.MIN_VALUE;
 
-  public Trace( boolean c2txt, String inFile, String outFile ) {
 
-    convert2txt = c2txt;
+  public Trace( boolean c2txt, String inFile, String outFile,  HashSet<Integer> eventset, long mintime, long maxtime, long scale) {
+    this.eventset=eventset;
+    this.maxtime=maxtime;
+    this.mintime=mintime;
+    this.scale=scale;
+    convert2txt  = c2txt;
+    convert2plot = true;
 
     openInputStreams( inFile );
 
     initNames();
 
+    if( convert2txt ) {
+      try { 
+        txtStream = new BufferedWriter( new FileWriter( "events.txt" ) ); 
+      } catch( Exception e ) { e.printStackTrace(); System.exit( -1 ); }
+    }
+
+    if (convert2plot) {
+      printPlotCmd();
+    }
+
     for( int i = 0; i < numThreads; i++ ) {
       readThread( i );
     }
 
+    System.out.println( "Minimum observed time stamp: "+minObservedTime );
+    System.out.println( "Maximum observed time stamp: "+maxObservedTime );
+    
+    System.out.println( "\nelapsed time: "+(maxObservedTime - minObservedTime) );
+
+
     printStats( outFile );
+
+    if( convert2txt ) {
+      try {
+        txtStream.close();
+      } catch( Exception e ) { e.printStackTrace(); System.exit( -1 ); }
+    }
+
+    if( convert2plot ) {
+      try {
+       bwPlot.write("plot [0:"+(globendtime/scale)+"] [-1:"+(numThreads+1)+"] -3\n");
+       bwPlot.close();
+      } catch (IOException e) {
+       e.printStackTrace();
+      }
+    }
   }
 
 
@@ -171,10 +249,6 @@ public class Trace {
       offset = readHeader( bis );
       bis.close();
 
-      if( convert2txt ) {
-        txtStream = new BufferedWriter( new FileWriter( "events.txt" ) );
-      }
-
     } catch( Exception e ) {
       e.printStackTrace();
       System.exit( -1 );
@@ -191,6 +265,14 @@ public class Trace {
        while( skip > 0 ) {
          skip -= threadData[i].dataStream.skip( skip );
        }
+       threadData[i].dataStream.mark(20);
+       int eventRaw = readInt ( threadData[i].dataStream );
+       long Stamp    = readLong( threadData[i].dataStream );
+       threadData[i].dataStream.reset();
+       
+       if (globalstarttime==-1||globalstarttime>Stamp)
+         globalstarttime=Stamp;
+
 
        offset += WORD_SIZE*threadData[i].numDataWords;
 
@@ -243,6 +325,7 @@ public class Trace {
       }
     }
 
+
     ThreadData tdata = threadData[tNum];
     tdata.stackDepth = 0;
     long timeStamp   = 0;
@@ -257,6 +340,7 @@ public class Trace {
     }
     j = 0;
     
+    long lasttime=-1;
     while( i < tdata.numDataWords ) {
       
       if( !progress[j] && i > j*progressChunk ) {
@@ -271,20 +355,46 @@ public class Trace {
       timeStamp    = readLong( tdata.dataStream );
       i += 3;
 
+      
+      if( timeStamp < minObservedTime ) {
+        minObservedTime = timeStamp;
+      }
+
+      if( timeStamp > maxObservedTime ) {
+        maxObservedTime = timeStamp;
+      }
+
+
       int eventType = eventRaw &  CP_EVENT_MASK;
       int eventID   = eventRaw >> CP_EVENT_BASESHIFT;
 
-      switch( eventType ) {
+      if (eventset.isEmpty()||eventset.contains(eventID))
+       switch( eventType ) {
 
         case CP_EVENTTYPE_BEGIN: {
-          pushEvent( tdata, eventID, timeStamp );
+          if( eventID == CP_EVENTID_MAIN ) {
+            tSysZero = timeStamp;
+          }
+         if( tdata.stackDepth>0 && convert2plot ) {
+           EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
+           long starttime=lasttime>esParent.timeStampBeginLatestInstance?lasttime:esParent.timeStampBeginLatestInstance;
+           addPointToPlot( tNum, esParent.eventID, starttime, timeStamp);
+         }
+
+          pushEvent( tdata, eventID, timeStamp );          
         } break;
 
         case CP_EVENTTYPE_END: {
+         if( convert2plot ) {
+           EventSummary esParent = tdata.eventStack.get( tdata.stackDepth - 1 );
+           long starttime=lasttime>esParent.timeStampBeginLatestInstance?lasttime:esParent.timeStampBeginLatestInstance;
+
+           addPointToPlot( tNum, esParent.eventID, starttime, timeStamp);
+           lasttime=timeStamp;
+         }
           popEvent( tdata, eventID, timeStamp );
         } break;    
-    
-      }
+       }
     }
 
     System.out.println( "" );
@@ -293,7 +403,7 @@ public class Trace {
       // worker threads currently do not exit gracefully, and therefore
       // may not register END events, so supply them with whatever the
       // latest known timestamp is
-      EventSummary eventSummary = tdata.eventStack.get( tdata.stackDepth );
+      EventSummary eventSummary = tdata.eventStack.get( tdata.stackDepth);
 
       if( eventSummary == null ) {
         // if there is no previous event it means there are no children
@@ -305,6 +415,7 @@ public class Trace {
 
       --tdata.stackDepth;
     }
+
   }
 
 
@@ -433,6 +544,27 @@ public class Trace {
     }
   }
 
+  long globalstarttime=-1;
+  long globendtime=-1;
+
+  public void addPointToPlot( int thread, int eventID, long starttime, long endtime) {
+    try {
+      long nstart=starttime-globalstarttime-mintime;
+      long nend=endtime-globalstarttime-mintime;
+      if ((maxtime==-1 || (endtime-globalstarttime)<maxtime)&&(nend>0)) {
+       if (nend>globendtime)
+         globendtime=nend;
+       if (nstart<0)
+         nstart=0;
+       bwPlot.write( "set arrow from "+(nstart/scale)+","+thread+
+                      " to "+(nend/scale)+","+thread+" lt "+eventID+"\n");
+      }
+    } catch( IOException e ) {
+      e.printStackTrace();
+      System.exit( -1 );
+    }
+  }
+
 
 
   public void printStats( String filename ) {
@@ -511,10 +643,11 @@ public class Trace {
       new Long( es.totalTime_ticks ).floatValue();      
 
     String strSelfStats =
-      String.format( " total(ticks)=%12dK, %%self=%5.1f, count=%d",
+      String.format( " total(ticks)=%12dK, %%self=%5.1f, count=%d, avgTicks=%d",
                      es.totalTime_ticks/1000,
                      tSelf_perc,
-                     es.instanceCount );
+                     es.instanceCount,
+                     (int)((float)es.totalTime_ticks/(float)es.instanceCount) );
 
     bw.write( strIndent+
               strEventName+
@@ -529,4 +662,15 @@ public class Trace {
       printEventSummary( bw, esChild, depth + 1 );
     }    
   }
+
+
+  public void printPlotCmd() {
+    try {
+      bwPlot = 
+        new BufferedWriter( new FileWriter( "plot.cmd" ) );
+    } catch( IOException e ) {
+      e.printStackTrace();
+      System.exit( -1 );
+    }    
+  }
 }