QPID-6265: Change system tests to have one log per file configured using Log4j, simplify QBTC

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

8 files changed, 83 insertions, 127 deletions

diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/server/BrokerStartupTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/server/BrokerStartupTest.java
index e267bf439b..c475432113 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/server/BrokerStartupTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/server/BrokerStartupTest.java
@@ -77,7 +77,7 @@ public class BrokerStartupTest extends AbstractTestLogging
                 brokerConfigFile.delete();
             }
 
-            startBroker(port, null);
+            startBroker(port, null, null);
 
             AMQConnectionURL url = new AMQConnectionURL(String.format("amqp://"
                                                                       + GUEST_USERNAME
@@ -209,7 +209,7 @@ public class BrokerStartupTest extends AbstractTestLogging
                 brokerConfigFile.delete();
             }
 
-            startBroker(port, null);
+            startBroker(port, null, null);
 
             AMQConnectionURL url = new AMQConnectionURL(String.format("amqp://"
                     + GUEST_USERNAME
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/server/logging/BrokerLoggingTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/server/logging/BrokerLoggingTest.java
index 4952c4e10e..f7953e56d1 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/server/logging/BrokerLoggingTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/server/logging/BrokerLoggingTest.java
@@ -22,13 +22,15 @@ package org.apache.qpid.server.logging;
 
 import junit.framework.AssertionFailedError;
 
-import org.apache.qpid.server.BrokerOptions;
+import org.apache.log4j.FileAppender;
+import org.apache.log4j.LogManager;
 import org.apache.qpid.server.model.Port;
 import org.apache.qpid.server.model.Transport;
 import org.apache.qpid.test.utils.TestBrokerConfiguration;
 import org.apache.qpid.transport.ConnectionException;
 import org.apache.qpid.util.LogMonitor;
 
+import java.io.File;
 import java.io.IOException;
 import java.net.Socket;
 import java.util.Collections;
@@ -59,6 +61,7 @@ public class BrokerLoggingTest extends AbstractTestLogging
     private static final Pattern BROKER_MESSAGE_LOG_PATTERN = Pattern.compile(BROKER_MESSAGE_LOG_REG_EXP);
     private static final String BRK_LOG_PREFIX = "BRK-";
 
+    @Override
     public void setUp() throws Exception
     {
         setLogMessagePrefix();
@@ -146,94 +149,6 @@ public class BrokerLoggingTest extends AbstractTestLogging
 
     /**
      * Description:
-     * On startup the broker must report correctly report the log4j file in use. This is important as it can help diagnose why logging messages are not being reported.
-     * Input:
-     * No custom -l value should be provided on the command line so that the default value is correctly reported.
-     * Output:
-     *
-     * <date> MESSAGE BRK-1007 : Using logging configuration : <$QPID_HOME>/etc/log4j.xml
-     *
-     * Validation Steps:
-     *
-     * 1. The BRK ID is correct
-     * 2. This occurs before the BRK-1001 startup message.
-     * 3. The log4j file is the full path to the file specified on the commandline.
-     *
-     * @throws Exception caused by broker startup
-     */
-    public void testBrokerStartupDefaultLog4j() throws Exception
-    {
-        if (isJavaBroker() && isExternalBroker() && !isInternalBroker())
-        {
-            String TESTID = "BRK-1007";
-
-            _brokerCommandHelper.removeBrokerCommandLog4JFile();
-
-            startBroker();
-
-            // Now we can create the monitor as _outputFile will now be defined
-            _monitor = new LogMonitor(_outputFile);
-
-            // Ensure broker has fully started up.
-            getConnection();
-
-            // Ensure we wait for TESTID to be logged
-            waitAndFindMatches(TESTID);
-
-            List<String> results = waitAndFindMatches(BRK_LOG_PREFIX);
-            try
-            {
-                // Validation
-
-                assertTrue("BRKer message not logged", results.size() > 0);
-
-                boolean validation = false;
-                for (String rawLog : results)
-                {
-                    // We don't care about messages after we have our log config
-                    if (validation)
-                    {
-                        break;
-                    }
-
-                    String log = getLog(rawLog);
-
-                    // Ensure we do not have a BRK-1001 message before
-                    if (!getMessageID(log).equals(TESTID))
-                    {
-                        assertFalse(getMessageID(log).equals("BRK-1001"));
-                        continue;
-                    }
-
-                    //1
-                    validateMessageID(TESTID, log);
-
-                    //2
-                    //There will be 1 copy of this startup message (via SystemOut)
-                    assertEquals("Unexpected log4j configuration message count.",
-                                 1, findMatches(TESTID).size());
-
-                    //3
-                    String defaultLog4j = System.getProperty(QPID_HOME) + "/" + BrokerOptions.DEFAULT_LOG_CONFIG_FILE;
-                    assertTrue("Log4j file(" + defaultLog4j + ") details not correctly logged:" + getMessageString(log),
-                               getMessageString(log).endsWith(defaultLog4j));
-
-                    validation = true;
-                }
-
-                assertTrue("Validation not performed: " + TESTID + " not logged", validation);
-            }
-            catch (AssertionFailedError afe)
-            {
-                dumpLogs(results, _monitor);
-
-                throw afe;
-            }
-        }
-    }
-
-    /**
-     * Description:
      * On startup the broker must report correctly report the log4j file in use. This is important as it can help diagnose why logging messages are not being reported. The broker must also be capable of correctly recognising the command line property to specify the custom logging configuration.
      * Input:
      * The value of -l specified on the command line.
@@ -254,11 +169,17 @@ public class BrokerLoggingTest extends AbstractTestLogging
         // This logging startup code only occurs when you run a Java broker
         if (isJavaBroker())
         {
-            String customLog4j = getBrokerCommandLog4JFile().getAbsolutePath();
+            // Log4j properties expects this to be set
+            System.setProperty("qpid.testMethod", "-" + getName() + ".customLog4j");
+            System.setProperty("qpid.testClass", getClass().getName() );
+
+            String customLog4j = System.getProperty("log4j.configuration.file");
 
             String TESTID = "BRK-1007";
 
-            startBroker();
+            startBroker(0, false, customLog4j);
+            _outputFile = new File(((FileAppender) LogManager.getRootLogger().getAllAppenders().nextElement()).getFile());
+
 
             // Now we can create the monitor as _outputFile will now be defined
             _monitor = new LogMonitor(_outputFile);
@@ -385,7 +306,7 @@ public class BrokerLoggingTest extends AbstractTestLogging
                     //2
                     //There will be 2 copies of the startup message (one via SystemOut, and one via Log4J)
                     assertEquals("Unexpected startup message count",
-                                 2, findMatches(TESTID).size());
+                                 1, findMatches(TESTID).size());
 
                     validation = true;
                 }
@@ -471,9 +392,8 @@ public class BrokerLoggingTest extends AbstractTestLogging
                     assertEquals("Incorrect message", TESTID, id);
 
                     //2
-                    //There will be 2 copies of the startup message (one via SystemOut, and one via Log4J)
                     assertEquals("Unexpected listen message count",
-                                 2, findMatches(TESTID).size());
+                                 1, findMatches(TESTID).size());
 
                     //3
                     String message = getMessageString(log);
@@ -587,7 +507,7 @@ public class BrokerLoggingTest extends AbstractTestLogging
                     //There will be 4 copies of the startup message (two via SystemOut, and two via Log4J)
                     List<String> listenMessages  = findMatches(TESTID);
                     assertEquals("Four listen messages should be found.",
-                                 4, listenMessages .size());
+                                 2, listenMessages .size());
 
                     int tcpStarted = 0;
                     int sslStarted = 0;
@@ -604,8 +524,8 @@ public class BrokerLoggingTest extends AbstractTestLogging
                         }
                     }
 
-                    assertEquals("Unexpected number of logs 'Listening on TCP port'", 2, tcpStarted);
-                    assertEquals("Unexpected number of logs 'Listening on SSL port'", 2, sslStarted);
+                    assertEquals("Unexpected number of logs 'Listening on TCP port'", 1, tcpStarted);
+                    assertEquals("Unexpected number of logs 'Listening on SSL port'", 1, sslStarted);
 
                     //4 Test ports open
                     testSocketOpen(getPort());
@@ -690,10 +610,9 @@ public class BrokerLoggingTest extends AbstractTestLogging
                     //2
                     assertEquals("Ready message not present", "Qpid Broker Ready", getMessageString(log));
                     
-                    //There will be 2 copies of the startup message (one via SystemOut, and one via Log4J)
                     assertEquals("Unexpected ready message count",
-                                 2, findMatches(TESTID).size());
-                    assertEquals("The ready messages should have been the last 2 messages", results.size() - 2, i);
+                                 1, findMatches(TESTID).size());
+                    assertEquals("The ready messages should have been the last 2 messages", results.size() - 1, i);
 
                     validationComplete = true;
                     break;
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/server/security/acl/AbstractACLTestCase.java b/qpid/java/systests/src/test/java/org/apache/qpid/server/security/acl/AbstractACLTestCase.java
index 789ad420d8..f7722a8384 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/server/security/acl/AbstractACLTestCase.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/server/security/acl/AbstractACLTestCase.java
@@ -59,7 +59,7 @@ public abstract class AbstractACLTestCase extends QpidBrokerTestCase implements
     @Override
     public void setUp() throws Exception
     {
-        getBrokerConfiguration().addGroupFileConfiguration(System.getProperty(QPID_HOME) + "/etc/groups-systests");
+        getBrokerConfiguration().addGroupFileConfiguration(QPID_HOME + "/etc/groups-systests");
 
         // run test specific setup
         String testSetup = StringUtils.replace(getName(), "test", "setUp");
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/LoggingManagementTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/LoggingManagementTest.java
index 3717c1594d..a06ed7be52 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/LoggingManagementTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/LoggingManagementTest.java
@@ -25,6 +25,7 @@ import javax.management.openmbean.CompositeData;
 import javax.management.openmbean.TabularData;
 
 import org.apache.qpid.management.common.mbeans.LoggingManagement;
+import org.apache.qpid.server.configuration.BrokerProperties;
 import org.apache.qpid.server.logging.log4j.LoggingManagementFacadeTest;
 import org.apache.qpid.test.utils.JMXTestUtils;
 import org.apache.qpid.test.utils.QpidBrokerTestCase;
@@ -35,7 +36,6 @@ import org.apache.qpid.util.LogMonitor;
  * System test for Logging Management.  <b>These tests rely on value set within
  * test-profiles/log4j-test.xml</b>.
  *
- * @see LoggingManagementMBeanTest
  * @see LoggingManagementFacadeTest
  *
  */
@@ -44,7 +44,9 @@ public class LoggingManagementTest extends QpidBrokerTestCase
     private JMXTestUtils _jmxUtils;
     private LoggingManagement _loggingManagement;
     private LogMonitor _monitor;
+    private File _logConfig;
 
+    @Override
     public void setUp() throws Exception
     {
         getBrokerConfiguration().addJmxManagementConfiguration();
@@ -56,8 +58,9 @@ public class LoggingManagementTest extends QpidBrokerTestCase
 
         File tmpLogFile = File.createTempFile("log4j" + "." + getName(), ".xml");
         tmpLogFile.deleteOnExit();
-        FileUtils.copy(getBrokerCommandLog4JFile(), tmpLogFile);
+        FileUtils.copy(new File(System.getProperty("log4j.configuration.file")), tmpLogFile);
         setBrokerCommandLog4JFile(tmpLogFile);
+        _logConfig = tmpLogFile;
 
         super.setUp();
         _jmxUtils.open();
@@ -66,6 +69,12 @@ public class LoggingManagementTest extends QpidBrokerTestCase
         _monitor = new LogMonitor(_outputFile);
     }
 
+    public void startBroker() throws Exception
+    {
+        super.startBroker(0, false, _logConfig.getAbsolutePath());
+    }
+
+    @Override
     public void tearDown() throws Exception
     {
         try
@@ -74,6 +83,11 @@ public class LoggingManagementTest extends QpidBrokerTestCase
             {
                 _jmxUtils.close();
             }
+
+            if (_logConfig != null)
+            {
+               _logConfig.delete();
+            }
         }
         finally
         {
@@ -122,7 +136,7 @@ public class LoggingManagementTest extends QpidBrokerTestCase
         _loggingManagement.setConfigFileLoggerLevel(operationalLoggingLogger, "OFF");
 
         List<String> matches = _monitor.waitAndFindMatches("Setting level to OFF for logger 'qpid.message'", 5000);
-        assertEquals(1, matches.size());
+        assertTrue(matches.size()>=1);
 
         assertEffectiveLoggingLevel(operationalLoggingLogger, "INFO");
 
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/ManagementLoggingTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/ManagementLoggingTest.java
index cb6eae013e..4df81845d8 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/ManagementLoggingTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/systest/management/jmx/ManagementLoggingTest.java
@@ -104,7 +104,7 @@ public class ManagementLoggingTest extends AbstractTestLogging
             //There will be 2 copies of the startup message (one via SystemOut, and one via Log4J)
             results = findMatches("MNG-1001");
             assertEquals("Unexpected startup message count.",
-                         2, results.size());
+                         1, results.size());
 
             //3
             assertEquals("Startup log message is not 'Startup'.", "JMX Management Startup",
@@ -185,7 +185,7 @@ public class ManagementLoggingTest extends AbstractTestLogging
             // Validation
 
             //There will be 4 startup messages (two via SystemOut, and two via Log4J)
-            assertEquals("Unexpected MNG-1002 message count", 4, results.size());
+            assertEquals("Unexpected MNG-1002 message count", 2, results.size());
 
             String log = getLogMessage(results, 0);
 
@@ -197,7 +197,7 @@ public class ManagementLoggingTest extends AbstractTestLogging
             assertTrue("RMI Registry port not as expected(" + mPort + ").:" + getMessageString(log),
                        getMessageString(log).endsWith(String.valueOf(mPort)));
 
-            log = getLogMessage(results, 2);
+            log = getLogMessage(results, 1);
 
             //1
             validateMessageID("MNG-1002", log);
@@ -243,7 +243,7 @@ public class ManagementLoggingTest extends AbstractTestLogging
             // Validate we only have two MNG-1002 (one via stdout, one via log4j)
             results = findMatches("MNG-1006");
             assertEquals("Upexpected SSL Keystore message count",
-                         2, results.size());
+                         1, results.size());
 
             // Validate the keystore path is as expected
             assertTrue("SSL Keystore entry expected.:" + getMessageString(log),
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/KeyStoreRestTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/KeyStoreRestTest.java
index 4b881d1e9f..169ece986e 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/KeyStoreRestTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/KeyStoreRestTest.java
@@ -56,7 +56,7 @@ public class KeyStoreRestTest extends QpidRestTestCase
 
         Map<String, Object> keystore = keyStores.get(0);
         assertKeyStoreAttributes(keystore, TestBrokerConfiguration.ENTRY_NAME_SSL_KEYSTORE,
-                System.getProperty(QPID_HOME) + "/../" + TestSSLConstants.BROKER_KEYSTORE, null);
+                QPID_HOME + "/../" + TestSSLConstants.BROKER_KEYSTORE, null);
     }
 
     public void testCreate() throws Exception
@@ -98,7 +98,7 @@ public class KeyStoreRestTest extends QpidRestTestCase
         List<Map<String, Object>> keyStores = assertNumberOfKeyStores(1);
         Map<String, Object> keystore = keyStores.get(0);
         assertKeyStoreAttributes(keystore, TestBrokerConfiguration.ENTRY_NAME_SSL_KEYSTORE,
-                System.getProperty(QPID_HOME) + "/../" + TestSSLConstants.BROKER_KEYSTORE, null);
+                QPID_HOME + "/../" + TestSSLConstants.BROKER_KEYSTORE, null);
     }
 
     public void testDeleteFailsWhenKeyStoreInUse() throws Exception
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/LogViewerTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/LogViewerTest.java
index f2fb2581f7..a7bf743e72 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/LogViewerTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/LogViewerTest.java
@@ -28,25 +28,40 @@ import java.util.Map;
 import java.util.zip.ZipEntry;
 import java.util.zip.ZipInputStream;
 
-import org.apache.qpid.server.BrokerOptions;
+import org.apache.log4j.FileAppender;
+import org.apache.log4j.Logger;
+import org.apache.log4j.SimpleLayout;
+import org.apache.qpid.server.configuration.BrokerProperties;
 
 public class LogViewerTest extends QpidRestTestCase
 {
-    public static final String DEFAULT_FILE_APPENDER_NAME = "FileAppender";
     private String _expectedLogFileName;
+    private FileAppender _fileAppender;
+    private String _appenderName;
 
+    @Override
     public void setUp() throws Exception
     {
-        setSystemProperty("logsuffix", "-" + getTestQueueName());
-        _expectedLogFileName = System.getProperty("logprefix", "") + "qpid" + System.getProperty("logsuffix", "") + ".log";
-
-        // use real broker log file
-        File brokerLogFile = new File(System.getProperty(QPID_HOME), BrokerOptions.DEFAULT_LOG_CONFIG_FILE);
-        setBrokerCommandLog4JFile(brokerLogFile);
+        _appenderName = getTestQueueName();
+        _expectedLogFileName =  "qpid-" + _appenderName + ".log";
 
+        _fileAppender = new FileAppender(new SimpleLayout(),
+                System.getProperty(BrokerProperties.PROPERTY_QPID_WORK)  + File.separator +  _expectedLogFileName, false);
+        _fileAppender.setName(_appenderName);
+        Logger.getRootLogger().addAppender(_fileAppender);
         super.setUp();
     }
 
+    @Override
+    public void tearDown() throws Exception
+    {
+        if (_fileAppender != null)
+        {
+            Logger.getRootLogger().removeAppender(_fileAppender);
+        }
+        super.tearDown();
+    }
+
     public void testGetLogFiles() throws Exception
     {
         List<Map<String, Object>> logFiles = getRestTestHelper().getJsonAsList("/service/logfilenames");
@@ -54,24 +69,32 @@ public class LogViewerTest extends QpidRestTestCase
 
         // 1 file appender is configured in QPID default log4j xml:
         assertTrue("Unexpected number of log files", logFiles.size() > 0);
+        Map<String, Object> logFileDetails = null;
+        for (Map<String, Object> appenderDetails: logFiles)
+        {
+            if (_appenderName.equals(appenderDetails.get("appenderName")))
+            {
+                logFileDetails = appenderDetails;
+                break;
+            }
+        }
 
-        Map<String, Object> logFileDetails = logFiles.get(0);
         assertEquals("Unexpected log file name", _expectedLogFileName, logFileDetails.get("name"));
         assertEquals("Unexpected log file mime type", "text/plain", logFileDetails.get("mimeType"));
-        assertEquals("Unexpected log file appender",DEFAULT_FILE_APPENDER_NAME, logFileDetails.get("appenderName"));
+        assertEquals("Unexpected log file appender",_appenderName, logFileDetails.get("appenderName"));
         assertTrue("Unexpected log file size", ((Number)logFileDetails.get("size")).longValue()>0);
         assertTrue("Unexpected log file modification time", ((Number)logFileDetails.get("lastModified")).longValue()>0);
     }
 
     public void testDownloadExistingLogFiles() throws Exception
     {
-        byte[] bytes = getRestTestHelper().getBytes("/service/logfile?l=" + DEFAULT_FILE_APPENDER_NAME + "%2F" + _expectedLogFileName);
+        byte[] bytes = getRestTestHelper().getBytes("/service/logfile?l=" + _appenderName + "%2F" + _expectedLogFileName);
 
         ZipInputStream zis = new ZipInputStream(new ByteArrayInputStream(bytes));
         try
         {
             ZipEntry entry = zis.getNextEntry();
-            assertEquals("Unexpected broker log file name", DEFAULT_FILE_APPENDER_NAME + "/" + _expectedLogFileName, entry.getName());
+            assertEquals("Unexpected broker log file name", _appenderName + "/" + _expectedLogFileName, entry.getName());
             ByteArrayOutputStream baos = new ByteArrayOutputStream();
             byte[] buffer = new byte[1024];
             int len;
@@ -91,7 +114,7 @@ public class LogViewerTest extends QpidRestTestCase
 
     public void testDownloadNonExistingLogFiles() throws Exception
     {
-        int responseCode = getRestTestHelper().submitRequest("/service/logfile?l=" + DEFAULT_FILE_APPENDER_NAME + "%2F"
+        int responseCode = getRestTestHelper().submitRequest("/service/logfile?l=" + _appenderName + "%2F"
                 + _expectedLogFileName + "_" + System.currentTimeMillis(), "GET");
 
         assertEquals("Unexpected response code", 404, responseCode);
diff --git a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/TrustStoreRestTest.java b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/TrustStoreRestTest.java
index 5d2e9de3fa..1aac22d0aa 100644
--- a/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/TrustStoreRestTest.java
+++ b/qpid/java/systests/src/test/java/org/apache/qpid/systest/rest/TrustStoreRestTest.java
@@ -56,7 +56,7 @@ public class TrustStoreRestTest extends QpidRestTestCase
 
         Map<String, Object> truststore = trustStores.get(0);
         assertTrustStoreAttributes(truststore, TestBrokerConfiguration.ENTRY_NAME_SSL_TRUSTSTORE,
-                System.getProperty(QPID_HOME) + "/../" + TestSSLConstants.BROKER_TRUSTSTORE, false);
+                QPID_HOME + "/../" + TestSSLConstants.BROKER_TRUSTSTORE, false);
     }
 
     public void testCreate() throws Exception
@@ -96,7 +96,7 @@ public class TrustStoreRestTest extends QpidRestTestCase
         List<Map<String, Object>> trustStores = assertNumberOfTrustStores(1);
         Map<String, Object> truststore = trustStores.get(0);
         assertTrustStoreAttributes(truststore, TestBrokerConfiguration.ENTRY_NAME_SSL_TRUSTSTORE,
-                System.getProperty(QPID_HOME) + "/../" + TestSSLConstants.BROKER_TRUSTSTORE, false);
+                QPID_HOME + "/../" + TestSSLConstants.BROKER_TRUSTSTORE, false);
     }
 
     public void testDeleteFailsWhenTrustStoreInUse() throws Exception