X-Git-Url: http://plrg.eecs.uci.edu/git/?a=blobdiff_plain;ds=sidebyside;f=Robust%2FCoreProf%2FTrace.java;h=0d4cf9882de653377706b29b410fdea7bc8fba63;hb=3aad6c406abb6535cf0af0d038b16f59dd1a82f3;hp=8a93f4bbdfd404d07e60b3a57fb00b151367078a;hpb=1b594dcff4c5ebbe02fcb1148ebe151e86265f15;p=IRC.git diff --git a/Robust/CoreProf/Trace.java b/Robust/CoreProf/Trace.java index 8a93f4bb..0d4cf988 100644 --- a/Robust/CoreProf/Trace.java +++ b/Robust/CoreProf/Trace.java @@ -12,28 +12,60 @@ public class Trace { public static final int CP_EVENTTYPE_END = 2; public static final int CP_EVENTTYPE_ONEOFF = 3; - 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_WORKSCHEDGRAB = 0x20; - public static final int CP_EVENTID_TASKDISPATCH = 0x30; - public static final int CP_EVENTID_TASKEXECUTE = 0x31; - public static final int CP_EVENTID_TASKRETIRE = 0x32; - public static final int CP_EVENTID_TASKSTALLVAR = 0x40; - public static final int CP_EVENTID_TASKSTALLMEM = 0x41; + 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; + public static final int CP_EVENTID_DEBUG_D = 0x183; + public static final int CP_EVENTID_DEBUG_E = 0x184; + public static final int CP_EVENTID_DEBUG_F = 0x185; + public static final int CP_EVENTID_DEBUG_G = 0x186; + public static final int CP_EVENTID_DEBUG_H = 0x187; + public static final int CP_EVENTID_DEBUG_I = 0x188; + public static final int CP_EVENTID_DEBUG_J = 0x189; void initNames() { eid2name = new Hashtable(); - eid2name.put( CP_EVENTID_MAIN, "MAIN " ); - eid2name.put( CP_EVENTID_RUNMALLOC, "RUNMALLOC " ); - eid2name.put( CP_EVENTID_RUNFREE, "RUNFREE " ); - eid2name.put( CP_EVENTID_WORKSCHEDGRAB, "WORKSCHEDGRAB" ); - eid2name.put( CP_EVENTID_TASKDISPATCH, "TASKDISPATCH " ); - 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_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 eid2name; @@ -41,11 +73,48 @@ public class Trace { public static void main( String args[] ) { - if( args.length != 2 ) { - System.out.println( "usage: " ); + if( args.length < 2 ) { + System.out.println( "usage: [-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 = new Trace( args[0], args[1] ); + String inputfile=null; + String outputfile=null; + boolean events=false; + HashSet eventset=new HashSet(); + boolean hasinput=false; + long maxtime=-1; + long mintime=0; + long scale=1; + + for(int i=0; i 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( String inFile, String outFile ) { + + public Trace( boolean c2txt, String inFile, String outFile, HashSet 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(); + } + } } @@ -129,6 +248,7 @@ public class Trace { bis = new BufferedInputStream( new FileInputStream( filename ) ); offset = readHeader( bis ); bis.close(); + } catch( Exception e ) { e.printStackTrace(); System.exit( -1 ); @@ -145,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; @@ -185,6 +313,19 @@ public class Trace { System.out.print( "Reading thread "+tNum ); + if( convert2txt ) { + try { + txtStream.write( "\n\n\n\n" ); + txtStream.write( "*************************************************\n" ); + txtStream.write( "** Thread "+tNum+"\n" ); + txtStream.write( "*************************************************\n" ); + } catch( IOException e ) { + e.printStackTrace(); + System.exit( -1 ); + } + } + + ThreadData tdata = threadData[tNum]; tdata.stackDepth = 0; long timeStamp = 0; @@ -199,6 +340,7 @@ public class Trace { } j = 0; + long lasttime=-1; while( i < tdata.numDataWords ) { if( !progress[j] && i > j*progressChunk ) { @@ -213,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( "" ); @@ -235,11 +403,19 @@ 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 + // events with a timestamp for the workaround, so just punt + break; + } + popEvent( tdata, eventSummary.eventID, timeStamp ); --tdata.stackDepth; } + } @@ -297,8 +473,25 @@ public class Trace { if( tdata.eventStack.size() <= tdata.stackDepth ) { tdata.eventStack.setSize( 2*tdata.stackDepth + 20 ); } + tdata.eventStack.set( tdata.stackDepth, eventSummary ); + + // print to the event text file (if needed) before + // updating the stack depth to get tabs right + if( convert2txt ) { + try { + for( int tabs = 0; tabs < tdata.stackDepth; ++tabs ) { + txtStream.write( " " ); + } + txtStream.write( "begin "+getEventName( eventID )+"@"+timeStamp+"\n" ); + } catch( IOException e ) { + e.printStackTrace(); + System.exit( -1 ); + } + } + + tdata.stackDepth++; } @@ -307,6 +500,23 @@ public class Trace { int eventID, long timeStamp ) { tdata.stackDepth--; + + + // print to the event text file (if needed) after + // updating the stack depth to get tabs right + if( convert2txt ) { + try { + for( int tabs = 0; tabs < tdata.stackDepth; ++tabs ) { + txtStream.write( " " ); + } + txtStream.write( "end "+getEventName( eventID )+"@"+timeStamp+"\n" ); + } catch( IOException e ) { + e.printStackTrace(); + System.exit( -1 ); + } + } + + if( tdata.stackDepth < 0 ) { throw new Error( "Event stack underflow\n" ); } @@ -334,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)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 ) { @@ -362,8 +593,10 @@ public class Trace { } bw.close(); - - } catch( IOException e ) {} + } catch( IOException e ) { + e.printStackTrace(); + System.exit( -1 ); + } } @@ -410,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+ @@ -428,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 ); + } + } }