QPID-4143: tweaked topic test config to introduce a start delay on message production, allowing the consumers enough time to implicitly create the queues (unfortunately the Qpid client can't explicitly create topics).

Also improved error reporting and increased time outs to better cope with large scale tests.

Applied patch from Philip Harvey <phil@philharveyonline.com>

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

12 files changed, 38 insertions, 20 deletions

diff --git a/qpid/java/perftests/etc/log4j.properties b/qpid/java/perftests/etc/log4j.properties
index 60e15d0817..ec00e022ac 100644
--- a/qpid/java/perftests/etc/log4j.properties
+++ b/qpid/java/perftests/etc/log4j.properties
@@ -25,4 +25,4 @@ log4j.appender.console=org.apache.log4j.ConsoleAppender
 log4j.appender.console.Threshold=all
 log4j.appender.console.layout=org.apache.log4j.PatternLayout
 
-log4j.appender.console.layout.ConversionPattern=%d %p [%c{1}] %m%n
\ No newline at end of file
+log4j.appender.console.layout.ConversionPattern=%d %p [%t] [%c{1}] %m%n
diff --git a/qpid/java/perftests/etc/perftests-jndi.properties b/qpid/java/perftests/etc/perftests-jndi.properties
index 8ad0decaad..04a8ad9101 100644
--- a/qpid/java/perftests/etc/perftests-jndi.properties
+++ b/qpid/java/perftests/etc/perftests-jndi.properties
@@ -23,4 +23,4 @@ java.naming.factory.initial = org.apache.qpid.jndi.PropertiesFileInitialContextF
 # use QpidBrokerTestCase's default port
 connectionfactory.connectionfactory = amqp://guest:guest@clientid/test?brokerlist='tcp://localhost:5672'
 
-destination.controllerqueue = direct://amq.direct//controllerqueue
+destination.controllerqueue = direct://amq.direct//controllerqueue?autodelete='true'
diff --git a/qpid/java/perftests/etc/testdefs/Topic-AckModes.js b/qpid/java/perftests/etc/testdefs/Topic-AckModes.js
index 0ad519aa50..5c4dee88e3 100644
--- a/qpid/java/perftests/etc/testdefs/Topic-AckModes.js
+++ b/qpid/java/perftests/etc/testdefs/Topic-AckModes.js
@@ -30,7 +30,8 @@ var jsonObject = {
                     {
                       "_name": "Producer",
                       "_destinationName": topicName,
-                      "_maximumDuration": duration
+                      "_maximumDuration": duration,
+                      "_startDelay": 2000 // gives the consumers time to implicitly create the topic
                     }
                   ]
                 }
diff --git a/qpid/java/perftests/etc/testdefs/Topic-NumberOfConsumers.js b/qpid/java/perftests/etc/testdefs/Topic-NumberOfConsumers.js
index 9351987115..751b8b1528 100644
--- a/qpid/java/perftests/etc/testdefs/Topic-NumberOfConsumers.js
+++ b/qpid/java/perftests/etc/testdefs/Topic-NumberOfConsumers.js
@@ -26,7 +26,8 @@ for(i=0; i < numbersOfConsumers.length ; i++)
                     {
                       "_name": "Producer1",
                       "_destinationName": topicName,
-                      "_maximumDuration": duration
+                      "_maximumDuration": duration,
+                      "_startDelay": 2000 // gives the consumers time to implicitly create the topic
                     }
                   ]
                 }
diff --git a/qpid/java/perftests/etc/testdefs/Topic-NumberOfTopics.js b/qpid/java/perftests/etc/testdefs/Topic-NumberOfTopics.js
index 227650a16d..89e5ecf56c 100644
--- a/qpid/java/perftests/etc/testdefs/Topic-NumberOfTopics.js
+++ b/qpid/java/perftests/etc/testdefs/Topic-NumberOfTopics.js
@@ -29,7 +29,8 @@ for(i=0; i < numbersOfTopics.length ; i++)
                         {
                           "_name": "Producer-__INDEX",
                           "_destinationName": topicName,
-                          "_maximumDuration": duration
+                          "_maximumDuration": duration,
+                          "_startDelay": 2000 // gives the consumers time to implicitly create the topic
                         }
                       ]
                     }
diff --git a/qpid/java/perftests/etc/testdefs/Topic-Persistence.js b/qpid/java/perftests/etc/testdefs/Topic-Persistence.js
index d843d37861..fd92560fc3 100644
--- a/qpid/java/perftests/etc/testdefs/Topic-Persistence.js
+++ b/qpid/java/perftests/etc/testdefs/Topic-Persistence.js
@@ -32,6 +32,7 @@ var jsonObject = {
                       "_name": "Producer",
                       "_destinationName": topicName,
                       "_maximumDuration": duration,
+                      "_startDelay": 2000 // gives the consumers time to implicitly create the topic
                     }
                   ]
                 }
diff --git a/qpid/java/perftests/example/log4j.properties b/qpid/java/perftests/example/log4j.properties
index 8af70ebef2..cabb774156 100644
--- a/qpid/java/perftests/example/log4j.properties
+++ b/qpid/java/perftests/example/log4j.properties
@@ -25,11 +25,11 @@ log4j.appender.console=org.apache.log4j.ConsoleAppender
 log4j.appender.console.Threshold=all
 log4j.appender.console.layout=org.apache.log4j.PatternLayout
 
-log4j.appender.console.layout.ConversionPattern=%d %p [%c{1}] %m%n
+log4j.appender.console.layout.ConversionPattern=%d %p [%t] [%c{1}] %m%n
 
 log4j.appender.fileApp=org.apache.log4j.FileAppender
 log4j.appender.fileApp.file=perftests.log
 log4j.appender.fileApp.Threshold=info
 log4j.appender.fileApp.append=false
 log4j.appender.fileApp.layout=org.apache.log4j.PatternLayout
-log4j.appender.fileApp.layout.ConversionPattern=%d %p [%c{1}] %m%n
\ No newline at end of file
+log4j.appender.fileApp.layout.ConversionPattern=%d %p [%t] [%c{1}] %m%n
diff --git a/qpid/java/perftests/example/perftests-jndi.properties b/qpid/java/perftests/example/perftests-jndi.properties
index 8ad0decaad..04a8ad9101 100644
--- a/qpid/java/perftests/example/perftests-jndi.properties
+++ b/qpid/java/perftests/example/perftests-jndi.properties
@@ -23,4 +23,4 @@ java.naming.factory.initial = org.apache.qpid.jndi.PropertiesFileInitialContextF
 # use QpidBrokerTestCase's default port
 connectionfactory.connectionfactory = amqp://guest:guest@clientid/test?brokerlist='tcp://localhost:5672'
 
-destination.controllerqueue = direct://amq.direct//controllerqueue
+destination.controllerqueue = direct://amq.direct//controllerqueue?autodelete='true'
diff --git a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/ControllerRunner.java b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/ControllerRunner.java
index 31ba4628c5..aea0ea301a 100644
--- a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/ControllerRunner.java
+++ b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/ControllerRunner.java
@@ -103,6 +103,10 @@ public class ControllerRunner extends AbstractRunner
                 runTest(controller, testConfigFile);
             }
         }
+        catch(Exception e)
+        {
+            LOGGER.error("Problem running test", e);
+        }
         finally
         {
             controller.stopAllRegisteredClients();
diff --git a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/DistributedTestConstants.java b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/DistributedTestConstants.java
index c4892edca9..a6f872e841 100644
--- a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/DistributedTestConstants.java
+++ b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/DistributedTestConstants.java
@@ -26,8 +26,10 @@ public abstract class DistributedTestConstants
     public static final String MSG_COMMAND_PROPERTY = "COMMAND";
     public static final String MSG_JSON_PROPERTY = "JSON";
 
-    public static final long REGISTRATION_TIMEOUT = 60000;
-    public static final long COMMAND_RESPONSE_TIMEOUT = 10000;
+    public static final long REGISTRATION_TIMEOUT = 60 * 1000;
+
+    /** set to a long time out because stopping clients can take a long time */
+    public static final long COMMAND_RESPONSE_TIMEOUT = 120 * 1000;
 
     public static final String CONTROLLER_QUEUE_JNDI_NAME = "controllerqueue";
 }
diff --git a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/Controller.java b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/Controller.java
index 7c935065f0..513e633566 100644
--- a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/Controller.java
+++ b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/Controller.java
@@ -92,15 +92,18 @@ public class Controller
         }
     }
 
-    private void awaitLatch(CountDownLatch latch, long timeout, String messageWithOneDecimalPlaceholder)
+    private void awaitStopResponses(CountDownLatch latch, long timeout)
     {
+        String message = "Timed out after %d waiting for stop command responses. Expecting %d more responses.";
+
         try
         {
-            final boolean countedDownOK = latch.await(timeout, TimeUnit.MILLISECONDS);
+            boolean countedDownOK = latch.await(timeout, TimeUnit.MILLISECONDS);
             if (!countedDownOK)
             {
-                final long latchCount = latch.getCount();
-                String formattedMessage = String.format(messageWithOneDecimalPlaceholder, latchCount);
+                long latchCount = latch.getCount();
+                String formattedMessage = String.format(message, timeout, latchCount);
+                LOGGER.error(formattedMessage);
                 throw new DistributedTestException(formattedMessage);
             }
         }
@@ -141,7 +144,7 @@ public class Controller
             _jmsDelegate.sendCommandToClient(clientName, command);
         }
 
-        awaitLatch(_stopClientsResponseLatch, _commandResponseTimeout, "Timed out waiting for stop command responses. Expecting %d more responses.");
+        awaitStopResponses(_stopClientsResponseLatch, _commandResponseTimeout);
 
         LOGGER.info("Stopped all clients");
     }
diff --git a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/TestRunner.java b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/TestRunner.java
index eb110a4234..4ad282b039 100644
--- a/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/TestRunner.java
+++ b/qpid/java/perftests/src/main/java/org/apache/qpid/disttest/controller/TestRunner.java
@@ -104,6 +104,11 @@ public class TestRunner
 
             return _testResult;
         }
+        catch(RuntimeException e)
+        {
+            LOGGER.error("Couldn't run test", e);
+            throw e;
+        }
         finally
         {
             _jmsDelegate.removeCommandListener(participantResultListener);
@@ -140,7 +145,6 @@ public class TestRunner
             }
 
             Runtime.getRuntime().removeShutdownHook(_removeQueuesShutdownHook);
-
         }
     }
 
@@ -176,7 +180,7 @@ public class TestRunner
 
     void awaitCommandResponses()
     {
-        awaitLatch(_commandResponseLatch, _commandResponseTimeout, "Timed out waiting for command responses. Expecting %d more responses.");
+        awaitLatch(_commandResponseLatch, _commandResponseTimeout, "Timed out waiting for command responses");
     }
 
 
@@ -204,7 +208,7 @@ public class TestRunner
         {
             try
             {
-                awaitLatch(_testResultsLatch, interval, "Waiting for participant results... Expecting %d more responses.");
+                awaitLatch(_testResultsLatch, interval, "Timed out waiting for participant results");
             }
             catch (DistributedTestException e)
             {
@@ -276,7 +280,7 @@ public class TestRunner
         _jmsDelegate.sendCommandToClient(registeredClientName, command);
     }
 
-    private void awaitLatch(CountDownLatch latch, long timeout, String messageWithOneDecimalPlaceholder)
+    private void awaitLatch(CountDownLatch latch, long timeout, String message)
     {
         try
         {
@@ -284,7 +288,8 @@ public class TestRunner
             if (!countedDownOK)
             {
                 final long latchCount = latch.getCount();
-                String formattedMessage = String.format(messageWithOneDecimalPlaceholder, latchCount);
+                String formattedMessage = "After " + timeout + "ms ... " + message + " ... Expecting " + latchCount + " more responses.";
+                LOGGER.error(formattedMessage);
                 throw new DistributedTestException(formattedMessage);
             }
         }