This is related to QPId-1161.

Modified the soak tests to print latency samples and throughput rates for every iteration.
Added run_soak_client.sh soak_report.sh as an example of how to use soak test and produce a report.
Modified other scripts to add comments.




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

6 files changed, 58 insertions, 11 deletions

diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/BaseTest.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/BaseTest.java
index be8c4bbc75..0c3a17b3d8 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/BaseTest.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/BaseTest.java
@@ -22,6 +22,8 @@ package org.apache.qpid.testkit.soak;
 
 
 import java.text.DateFormat;
+import java.text.DecimalFormat;
+import java.text.NumberFormat;
 import java.text.SimpleDateFormat;
 import java.util.Date;
 
@@ -54,6 +56,7 @@ public class BaseTest
     protected AMQConnection con;
     protected Destination dest = null;
     protected DateFormat df = new SimpleDateFormat("yyyy.MM.dd 'at' HH:mm:ss");
+    protected NumberFormat nf = new DecimalFormat("##.00");
 
     public BaseTest()
     {
diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedConsumer.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedConsumer.java
index 3117d268a3..a44760be46 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedConsumer.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedConsumer.java
@@ -48,6 +48,9 @@ public class MultiThreadedConsumer extends BaseTest
     {
         super();
         transacted = Boolean.getBoolean("transacted");
+        // needed only to calculate throughput.
+        // If msg_count is different set it via -Dmsg_count
+        msg_count = 10;
     }
 
     /**
@@ -75,14 +78,33 @@ public class MultiThreadedConsumer extends BaseTest
                             consumer.setMessageListener(new MessageListener()
                             {
 
+                                private boolean startIteration = true;
+                                private long startTime = 0;
+
                                 public void onMessage(Message m)
                                 {
                                     try
                                     {
-                                        String payload = ((TextMessage) m).getText();
-                                        if (payload.equals("End"))
+                                        long now = System.currentTimeMillis();
+                                        if (startIteration)
+                                        {
+                                            startTime = m.getJMSTimestamp();
+                                            startIteration = false;
+                                        }
+
+                                        if (m instanceof TextMessage && ((TextMessage) m).getText().equals("End"))
                                         {
-                                            System.out.println(m.getJMSMessageID() + "," + System.currentTimeMillis());
+                                            startIteration = true;
+                                            long totalIterationTime = now - startTime;
+                                            double throughput = ((double)msg_count/(double)totalIterationTime) * 1000;
+                                            long latencySample = now - m.getJMSTimestamp();
+
+                                            StringBuilder sb = new StringBuilder();
+                                            sb.append(m.getJMSMessageID()).append(",").
+                                            append(nf.format(throughput)).append(",").append(latencySample);
+
+                                            System.out.println(sb.toString());
+
                                             MessageProducer temp = session.createProducer(m.getJMSReplyTo());
                                             Message controlMsg = session.createTextMessage();
                                             temp.send(controlMsg);
diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedProducer.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedProducer.java
index 886c64bb81..279e5ea0bf 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedProducer.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/MultiThreadedProducer.java
@@ -117,7 +117,6 @@ public class MultiThreadedProducer extends SimpleProducer
                                 }
 
                                 TextMessage m = session.createTextMessage("End");
-                                m.setJMSMessageID("ID:" + UUID.randomUUID());
                                 m.setJMSReplyTo(feedbackQueue);
                                 prod.send(m);
 
@@ -126,7 +125,7 @@ public class MultiThreadedProducer extends SimpleProducer
                                     session.commit();
                                 }
 
-                                System.out.println(m.getJMSMessageID() + "," + System.currentTimeMillis());
+                                System.out.println(df.format(System.currentTimeMillis()));
                                 feedbackConsumer.receive();
                                 if (transacted)
                                 {
diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/ResourceLeakTest.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/ResourceLeakTest.java
index 1faa9be864..c33f9ffbf2 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/ResourceLeakTest.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/ResourceLeakTest.java
@@ -103,6 +103,7 @@ public class ResourceLeakTest extends BaseTest
                       j++;
                     }
                 }
+                System.out.println(df.format(System.currentTimeMillis()));
                 Thread.sleep(connection_idle_time);
 
                 try
diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleConsumer.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleConsumer.java
index 5ef72d7538..d353e44816 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleConsumer.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleConsumer.java
@@ -53,6 +53,9 @@ public class SimpleConsumer extends BaseTest
     public SimpleConsumer()
     {
         super();
+        //needed only to calculate throughput.
+        // If msg_count is different set it via -Dmsg_count
+        msg_count = 10;
     }
 
     public void test()
@@ -69,14 +72,34 @@ public class SimpleConsumer extends BaseTest
                 cons[i].setMessageListener(new MessageListener()
                 {
 
+                    private boolean startIteration = true;
+                    private long startTime = 0;
+
                     public void onMessage(Message m)
                     {
                         try
                         {
-                            String payload = ((TextMessage) m).getText();
-                            if (payload.equals("End"))
+                            long now = System.currentTimeMillis();
+                            if (startIteration)
+                            {
+                                startTime = m.getJMSTimestamp();
+                                startIteration = false;
+                            }
+
+                            if (m instanceof TextMessage && ((TextMessage) m).getText().equals("End"))
                             {
-                                System.out.println(m.getJMSMessageID() + "," + System.currentTimeMillis());
+
+                                long totalIterationTime = now - startTime;
+                                startIteration = true;
+                                double throughput = ((double)msg_count/(double)totalIterationTime) * 1000;
+                                long latencySample = now - m.getJMSTimestamp();
+
+                                StringBuilder sb = new StringBuilder();
+                                sb.append(m.getJMSMessageID()).append(",").
+                                append(nf.format(throughput)).append(",").append(latencySample);
+
+                                System.out.println(sb.toString());
+
                                 MessageProducer temp = sessions[0].createProducer(m.getJMSReplyTo());
                                 Message controlMsg = sessions[0].createTextMessage();
                                 temp.send(controlMsg);
diff --git a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleProducer.java b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleProducer.java
index bdae79fd41..1080092536 100644
--- a/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleProducer.java
+++ b/java/testkit/src/main/java/org/apache/qpid/testkit/soak/SimpleProducer.java
@@ -109,7 +109,7 @@ public class SimpleProducer extends BaseTest
                 for (int i = 0; i < msg_count - 1; i++)
                 {
                     Message msg = getNextMessage();
-                    msg.setJMSMessageID("ID:" + UUID.randomUUID());
+                    msg.setJMSTimestamp(System.currentTimeMillis());
                     prods[prod_pointer].send(msg);
                     if (multi_session)
                     {
@@ -122,10 +122,9 @@ public class SimpleProducer extends BaseTest
                 }
 
                 TextMessage m = sessions[0].createTextMessage("End");
-                m.setJMSMessageID("ID:" + UUID.randomUUID());
                 m.setJMSReplyTo(feedbackQueue);
                 prods[prod_pointer].send(m);
-                System.out.println(m.getJMSMessageID() + "," + System.currentTimeMillis());
+                System.out.println(df.format(System.currentTimeMillis()));
                 feedbackConsumer.receive();
                 Thread.sleep(1000);
             }