QPID-2425 : Augment script to extract latency from csv file. Also updated processAll script to colate the statistics for the given run.

Merged from 0.5.x-dev rev 917482

git-svn-id: https://svn.apache.org/repos/asf/qpid/trunk@933284 13f79535-47bb-0310-9956-ffa450edef68

3 files changed, 113 insertions, 20 deletions

diff --git a/qpid/java/perftests/bin/processing/process.sh b/qpid/java/perftests/bin/processing/process.sh
index f8e13cd5cd..5e0adf1541 100755
--- a/qpid/java/perftests/bin/processing/process.sh
+++ b/qpid/java/perftests/bin/processing/process.sh
@@ -53,7 +53,7 @@ processCMSGCFile()
 
  calculateStats "MEM_PRE" HEAP_PRE_GC.log
  calculateStats "MEM_POST" HEAP_POST_GC.log
- calcualteStatsBC "GC_FREQ" GC_FREQ.log
+ calculateStatsBC "GC_FREQ" GC_FREQ.log
  
      
  # Calculate ParNew GC Cumulative total 
@@ -136,7 +136,7 @@ processG1GCFile()
 calculateStatsBC()
 {
 label=$1
-file=$2
+statFile=$2
 # Calculate GC Frequencies
  prevFreq=0
  countFreq=0
@@ -145,7 +145,7 @@ file=$2
  maxFreq=0
 
  echo "" > GC_FREQ.log
- for time in `cat $file` ; do
+ for time in `cat $statFile` ; do
    if [ $prevFreq == 0 ] ; then
      prevFreq=$time
    else
@@ -167,15 +167,22 @@ file=$2
  done
 
  # Extract Min/Max/Avg
- echo "#type:min/max/avg" > $file.stats
- avgFreq=`echo $gcFreqTotal / $countFreq | bc -l`
- echo "$1:$minFreq/$maxFreq/$avgFreq" >> $file.stats
+ echo "#type:min/max/avg" > $statFile.stats
+ 
+ if [ $countFreq != 0 ] ; then
+   avgFreq=`echo $gcFreqTotal / $countFreq | bc -l 2&> /dev/null`
+    echo "$label:$minFreq/$maxFreq/$avgFreq" >> $statFile.stats
+    echo "Done GC Freq Stat generation for $statFile"
+ else
+    echo "$label:-/-/-" >> $statFile.stats
+    echo "Unable to calculate GC Freq stats as no freq entries found."
+ fi
 }
 
 calculateStats()
 {
 label=$1
-file=$2
+statFile=$2
 
 # Calculate GC Frequencies
  count=0
@@ -184,7 +191,7 @@ file=$2
  max=0
 
 
- for item in `cat $file` ; do
+ for item in `cat $statFile` ; do
      if [ $min == 0 ] ; then
        min=$item
      fi
@@ -202,11 +209,18 @@ file=$2
  done
 
  # Extract Min/Max/Avg
- echo "#type:min/max/avg" > $file.stats
- avg=`echo $gcTotal / $count | bc -l`
- 
- echo "$label:$min/$max/$avg" >> $file.stats
- echo "Done Stat generation for $file"
+ echo "#type:min/max/avg" > $statFile.stats
+    
+ if [ $count != 0 ] ; then
+    avg=`echo $gcTotal / $count | bc -l`
+    
+    echo "$label:$min/$max/$avg" >> $statFile.stats
+    echo "Done $label Stat generation for $statFile"
+ else    
+    echo "$label:-/-/-" >> $statFile.stats    
+    echo "Unable to calculate $label stats as no entries found."
+ fi
+
 }
 
 #
@@ -287,6 +301,12 @@ else
  PLOT="\"GC.Dur.data\" with lines axis x1y1 ti \"G1 Young Time ($youngGCCount)\", "
 fi
 
+#
+# Colate Stats
+#
+echo -n "Colating stat Data : "
+echo "#type:min/max/avg" > $file.statistics.txt 
+find .. -name "*stats" -exec grep -v "type" {} >> $file.statistics.txt \;
 
 
 # Prepare the plot command
@@ -362,4 +382,7 @@ set format x "%H:%M"
 plot "CPU.data" using 1:2 with lines 
 EOGNUPLOT
 
+#" 
+# Pop out of $work directory.
+#
 popd &> /dev/null
\ No newline at end of file
diff --git a/qpid/java/perftests/bin/processing/processAll.sh b/qpid/java/perftests/bin/processing/processAll.sh
index da92107ce0..895d59c316 100755
--- a/qpid/java/perftests/bin/processing/processAll.sh
+++ b/qpid/java/perftests/bin/processing/processAll.sh
@@ -48,7 +48,11 @@ for file in `find $1 -name $graphFile` ; do
 
   echo Copying Images
   cp work/*png $root/results/
+
+  echo Copying Stats
+  cp work/*.statistics.txt $root/results/
   
+
   popd &> /dev/null
   echo Done
-done
+done
\ No newline at end of file
diff --git a/qpid/java/perftests/bin/processing/processTests.py b/qpid/java/perftests/bin/processing/processTests.py
index 57c8cc7668..745d9059d1 100755
--- a/qpid/java/perftests/bin/processing/processTests.py
+++ b/qpid/java/perftests/bin/processing/processTests.py
@@ -99,6 +99,8 @@ def main():
 # Process the log files we know of
 #
 def preProcessBrokerLogs(resultDir):
+    
+    print "Pre Processing Broker Logs"
     # Pre-Process GC - no pre processing required 
     
     # Process Log4j - no processing required as file is already time stamped.
@@ -153,7 +155,6 @@ def processCPUUsage(resultDir):
     sumCPU=0.0
     sumMem=0.0
     
-    entries = 0
     output= open(datedFile, "w")
     for line in logfile:        
 	    #
@@ -357,6 +358,7 @@ def createResultSetPackage(root, resultFile):
      
     sliceBrokerLogs(resultDir, start, end)
     createGraphData(resultDir, testName)
+    createTestStatData(resultDir, testName)
     
     log("Created Result Package for:"+ testName)
     
@@ -387,9 +389,7 @@ def sliceCPULog(resultDir, start, end):
     entries=0
     sumCPU=0.0
     sumMem=0.0
-    
-    entries = 0
-    
+
     #
     # Create outputfile
     #
@@ -721,6 +721,73 @@ def extractTestData(property,resultDir,testName,type):
 	    found=True
 	
     return result.strip()    
+
+def createTestStatData(resultDir, testName):
+    csvFilePath=resultDir + os.sep + testName + ".csv"
+   
+    # Open the output file, erasing any existing version
+    # Keep track of the min/max sum and entries,.
+    minLatency=float(sys.maxint)
+    maxLatency=0.0
+    
+    entries=0
+    sumLatency=0.0    
+    
+    #
+    # Open csv File
+    #
+    csvFile = open(csvFilePath,"r")    
+    for line in csvFile:
+	
+        # The PingAsyncTestPerf test class outputs the latency and throughput data.
+    	if line.find("PingAsyncTestPerf") != -1:               
+            #
+            # Data format is
+            # <Test> <TestName> <Thread> <Status> <Time> <Latency> <Concurrency> <Thread> <TestSize>
+            #org.apache.qpid.ping.PingAsyncTestPerf, testAsyncPingOk, Dispatcher-Channel-1, Pass, 209.074, 219.706, 0, 1, 10
+            LatencyIndex = 5 
+            
+        # The PingLatencyTestPerf test class just outputs the latency data.    
+    	if line.find("PingLatencyTestPerf") != -1:               
+            #
+            # Data format is
+            # <Test> <TestName> <Thread> <Status> <Time> <Latency> <Concurrency> <Thread> <TestSize>
+            # org.apache.qpid.ping.PingLatencyTestPerf, testPingLatency, Dispatcher-Channel-1, Pass, 397.05502, 0, 2, 1000
+            LatencyIndex = 4          
+            
+    
+        # Only process the test lines that have 'org.apache.qpid.ping', i.e. skip header and footer.
+        if line.find("org.apache.qpid.ping") != -1:               
+            # Perform stat processing for the min/max/avg            
+            data = line.split(",")
+    
+            # Record entires
+            entries = entries + 1
+            
+            # Record Metrics
+            # Record Lateny data
+            latency = float(data[LatencyIndex])
+            if (latency < minLatency):
+                minLatency = latency
+        
+            if (latency > maxLatency):
+                maxLatency = latency
+            
+            sumLatency = sumLatency + latency
+
+
+    csvFile.close()
+    
+    # Output stats file
+    statFile=resultDir + os.sep + testName+".stats"
+    output= open(statFile, "w")
+    output.write("#type:min/max/avg")        
+    output.write('\n')
+    output.write("LATENCY:"+str(minLatency)+"/"+str(maxLatency)+"/"+str(float(sumLatency)/float(entries)))
+    output.write('\n')
+    output.close
+    
+    log("Generated stat data from test "+testName+" CSV file")    
     
 
 def ackModeToString(ackMode):
@@ -753,6 +820,5 @@ def mkdir(dir):
     if not os.path.exists(dir):
         os.mkdir(dir)
     
-if __name__ == "__main__":
-    
+if __name__ == "__main__":    
     main()
\ No newline at end of file