diff options
Diffstat (limited to 'qpid/java/systests/src/main/java/org/apache/qpid/server/logging')
16 files changed, 4997 insertions, 0 deletions
diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AbstractTestLogging.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AbstractTestLogging.java new file mode 100644 index 0000000000..f56f428f0b --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AbstractTestLogging.java @@ -0,0 +1,448 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import java.io.FileNotFoundException; +import java.io.IOException; +import java.util.HashMap; +import java.util.Iterator; +import java.util.LinkedList; +import java.util.List; + +import org.apache.commons.configuration.ConfigurationException; +import org.apache.qpid.server.configuration.ServerConfiguration; +import org.apache.qpid.server.logging.subjects.AbstractTestLogSubject; +import org.apache.qpid.server.registry.ApplicationRegistry; +import org.apache.qpid.server.util.InternalBrokerBaseCase; +import org.apache.qpid.test.utils.QpidBrokerTestCase; +import org.apache.qpid.util.LogMonitor; + +/** + * Abstract superclass for logging test set up and utility methods. + * + * So named to prevent it being selected itself as a test to run by the test suite. + */ +public class AbstractTestLogging extends QpidBrokerTestCase +{ + public static final long DEFAULT_LOG_WAIT = 2000; + public static final String TEST_LOG_PREFIX = "MESSAGE"; + protected LogMonitor _monitor; + + InternalBrokerBaseCase _configLoader; + + @Override + public void setUp() throws Exception + { + setLogMessagePrefix(); + + super.setUp(); + _monitor = new LogMonitor(_outputFile); + } + + protected ServerConfiguration getServerConfig() throws ConfigurationException + { + ServerConfiguration _serverConfiguration; + if (isExternalBroker()) + { + _serverConfiguration = new ServerConfiguration(_configFile) + { + @Override + public void initialise() throws ConfigurationException + { + //Overriding initialise to only setup the vhosts and not + //perform the ConfigurationPlugin setup, removing need for + //an ApplicationRegistry to be loaded. + setupVirtualHosts(getConfig()); + } + }; + _serverConfiguration.initialise(); + } + else + { + _serverConfiguration = ApplicationRegistry.getInstance().getConfiguration(); + } + + return _serverConfiguration; + } + + protected void setLogMessagePrefix() + { + //set the message prefix to facilitate scraping from the munged test output. + setSystemProperty("qpid.logging.prefix", TEST_LOG_PREFIX); + } + + @Override + public void tearDown() throws Exception + { + _monitor.close(); + if (isExternalBroker() && _configLoader != null) + { + _configLoader.tearDown(); + } + super.tearDown(); + } + + /** + * assert that the requested log message has not occured + * + * @param log + * + * @throws IOException + */ + public void assertLoggingNotYetOccured(String log) throws IOException + { + // Ensure the alert has not occured yet + assertEquals("Message has already occured:" + log, 0, + findMatches(log).size()); + } + + protected void validateMessageID(String id, String log) + { + assertEquals("Incorrect message", id, getMessageID(log)); + } + + protected String getMessageID(String log) + { + String message = fromMessage(log); + + return message.substring(0, message.indexOf(" ")); + } + + /** + * Return the first channel id from the log string + * ' ch;X' if there is no channel id return -1. + * + * @param log the log string to search. + * + * @return channel id or -1 if no channel id exists. + */ + protected int getChannelID(String log) + { + int start = log.indexOf("ch:") + 3; + + // If we do a check for ] as the boundary we will get cases where log + // is presented with the bounding. If we don't match a ] then we can use + // the end of the string as the boundary. + int end = log.indexOf("]", start); + if (end == -1) + { + end = log.length(); + } + + try + { + return Integer.parseInt(log.substring(start, end)); + } + catch (Exception e) + { + return -1; + } + } + + protected String fromMessage(String log) + { + int startSubject = log.indexOf("]") + 1; + int start = log.indexOf("]", startSubject) + 1; + + // If we don't have a subject then the second indexOf will return 0 + // in which case we can use the end of the actor as the index. + if (start == 0) + { + start = startSubject; + } + + return log.substring(start).trim(); + } + + /** + * Extract the Subject from the Log Message. + * + * The subject is the second block inclosed in brackets '[ ]'. + * + * If there is no Subject or the second block of brackets '[ ]' cannot be + * identified then an empty String ("") is returned. + * + * The brackets '[ ]' are not included in the returned String. + * + * @param log The log message to process + * + * @return the Subject string or the empty string ("") if the subject can't be identified. + */ + protected String fromSubject(String log) + { + int start = log.indexOf("[") + 1; + // Take the second index + start = log.indexOf("[", start) + 1; + + // There may not be a subject so in that case return nothing. + if (start == 0) + { + return ""; + } + + int end = log.indexOf("]", start); + try + { + return log.substring(start, end); + } + catch (IndexOutOfBoundsException iobe) + { + return ""; + } + } + + /** + * Extract the actor segment from the log message. + * The Actor segment is the first section enclosed in '[ ]'. + * + * No analysis is performed to ensure that the first '[ ]' section of the + * given log is really an Actor segment. + * + * The brackets '[ ]' are not included in the returned String. + * + * @param log the Log Message + * + * @return the Actor segment or "" if unable to locate '[ ]' section + */ + protected String fromActor(String log) + { + int start = log.indexOf("[") + 1; + int end = log.indexOf("]", start); + try + { + return log.substring(start, end).trim(); + } + catch (IndexOutOfBoundsException iobe) + { + return ""; + } + } + + /** + * Return the message String from the given message section + * + * @param log the Message Section + * + * @return the Message String. + */ + protected String getMessageString(String log) + { + // Remove the Log ID from the returned String + int start = log.indexOf(":") + 1; + + return log.substring(start).trim(); + } + + /** + * Given our log message extract the connection ID: + * + * The log string will contain the connectionID identified by 'con:' + * + * So extract the value shown here by X: + * + * 'con:X(' + * + * Extract the value between the ':' and '(' and process it as an Integer + * + * If we are unable to find the right index or process the substring as an + * Integer then return -1. + * + * @param log the log String to process + * + * @return the connection ID or -1. + */ + protected int getConnectionID(String log) + { + int conIDStart = log.indexOf("con:") + 4; + int conIDEnd = log.indexOf("(", conIDStart); + try + { + return Integer.parseInt(log.substring(conIDStart, conIDEnd)); + } + catch (Exception e) + { + return -1; + } + } + + /** + * Extract the log entry from the raw log line which will contain other + * log4j formatting. + * + * This formatting may impead our testing process so extract the log message + * as we know it to be formatted. + * + * This starts with the string MESSAGE + * + * @param rawLog the raw log + * + * @return the log we are expecting to be printed without the log4j prefixes + */ + protected String getLog(String rawLog) + { + int start = rawLog.indexOf(TEST_LOG_PREFIX); + return rawLog.substring(start); + } + + /** + * Extract the log entry from the result set. Positions are 0-based. + * + * @param results list of log message results to extract from + * @param position position in the list of the message to extract + * @return the message string + */ + protected String getLogMessage(List<String> results, int position) + { + return getLog(results.get(position)); + } + + /** + * Extract the nth-from-last log entry from the result set. + * + * @param results list of log message results to extract from + * @param positionFromEnd position from end of the message list to extract (eg 0 for last) + * @return the message string + */ + protected String getLogMessageFromEnd(List<String> results, int positionFromEnd) + { + int resultSize = results.size(); + return getLogMessage(results, resultSize - 1 - positionFromEnd); + } + + protected List<String> findMatches(String toFind) throws IOException + { + return _monitor.findMatches(toFind); + } + + protected List<String> waitAndFindMatches(String toFind) throws IOException + { + return waitAndFindMatches(toFind, DEFAULT_LOG_WAIT); + } + + protected List<String> waitAndFindMatches(String toFind, long wait) throws IOException + { + return _monitor.waitAndFindMatches(toFind, wait); + } + + public boolean waitForMessage(String message) throws FileNotFoundException, IOException + { + return waitForMessage(message, DEFAULT_LOG_WAIT); + } + + public boolean waitForMessage(String message, long wait) throws FileNotFoundException, IOException + { + return _monitor.waitForMessage(message, wait, true); + } + + /** + * Given a list of messages that have been pulled out of a log file + * Process the results splitting the log statements in to lists based on the + * actor's connection ID. + * + * So for each log entry extract the Connecition ID from the Actor of the log + * + * Then use that as a key to a HashMap storing the list of log messages for + * that connection. + * + * @param logMessages The list of mixed connection log messages + * + * @return Map indexed by connection id to a list of log messages just for that connection. + */ + protected HashMap<Integer, List<String>> splitResultsOnConnectionID(List<String> logMessages) + { + HashMap<Integer, List<String>> connectionSplitList = new HashMap<Integer, List<String>>(); + + for (String log : logMessages) + { + // Get the connectionID from the Actor in the Message Log. + int cID = getConnectionID(fromActor(getLog(log))); + + List<String> connectionData = connectionSplitList.get(cID); + + // Create the initial List if we don't have one already + if (connectionData == null) + { + connectionData = new LinkedList<String>(); + connectionSplitList.put(cID, connectionData); + } + + // Store the log + connectionData.add(log); + } + + return connectionSplitList; + } + + /** + * Filter the give result set by the specficifed virtualhost. + * This is done using the getSlice to identify the virtualhost (vh) in the + * log message + * + * @param results full list of logs + * @param virtualHostName the virtualhostName to filter on + * + * @return the list of messages only for that virtualhost + */ + protected List<String> filterResultsByVirtualHost(List<String> results, String virtualHostName) + { + List<String> filteredResults = new LinkedList<String>(); + Iterator<String> iterator = results.iterator(); + + while (iterator.hasNext()) + { + String log = iterator.next(); + + if (AbstractTestLogSubject.getSlice("vh", log).equals(virtualHostName)) + { + filteredResults.add(log); + } + } + + return filteredResults; + } + + /** + * Dump the log results. + */ + protected void dumpLogs(List<String> results) throws IOException + { + dumpLogs(results, null); + } + + /** + * Dump the log results or if there are none, the contents of the + * monitored log file if the monitor is non-null. + */ + protected void dumpLogs(List<String> results, LogMonitor monitor) throws IOException + { + System.err.println("Log Dump:"); + for (String log : results) + { + System.err.println(log); + } + + if (results.isEmpty() && monitor != null) + { + System.err.println("Monitored file contents:"); + System.err.println(monitor.readFile()); + } + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AccessControlLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AccessControlLoggingTest.java new file mode 100644 index 0000000000..2629e82831 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AccessControlLoggingTest.java @@ -0,0 +1,174 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.qpid.server.logging; + +import java.io.File; +import java.util.List; + +import javax.jms.Connection; +import javax.jms.JMSException; +import javax.jms.Session; + +import org.apache.qpid.AMQException; +import org.apache.qpid.client.AMQSession; +import org.apache.qpid.framing.AMQShortString; +import org.apache.qpid.protocol.AMQConstant; + +/** + * ACL version 2/3 file testing to verify that ACL actor logging works correctly. + * + * This suite of tests validate that the AccessControl messages occur correctly + * and according to the following format: + * + * <pre> + * ACL-1001 : Allowed Operation Object {PROPERTIES} + * ACL-1002 : Denied Operation Object {PROPERTIES} + * </pre> + */ +public class AccessControlLoggingTest extends AbstractTestLogging +{ + private static final String ACL_LOG_PREFIX = "ACL-"; + private static final String USER = "client"; + private static final String PASS = "guest"; + + public void setUp() throws Exception + { + setConfigurationProperty("virtualhosts.virtualhost.test.security.aclv2", + QpidHome + File.separator + "etc" + File.separator + "test-logging.txt"); + + super.setUp(); + } + + /** FIXME This comes from SimpleACLTest and makes me suspicious. */ + @Override + public void tearDown() throws Exception + { + try + { + super.tearDown(); + } + catch (JMSException e) + { + //we're throwing this away as it can happen in this test as the state manager remembers exceptions + //that we provoked with authentication failures, where the test passes - we can ignore on con close + } + } + + /** + * Test that {@code allow} ACL entries do not log anything. + */ + public void testAllow() throws Exception + { + Connection conn = getConnection(USER, PASS); + Session sess = conn.createSession(false, Session.AUTO_ACKNOWLEDGE); + conn.start(); + ((AMQSession<?, ?>) sess).createQueue(new AMQShortString("allow"), false, false, false); + + List<String> matches = findMatches(ACL_LOG_PREFIX); + + assertTrue("Should be no ACL log messages", matches.isEmpty()); + } + + /** + * Test that {@code allow-log} ACL entries log correctly. + */ + public void testAllowLog() throws Exception + { + Connection conn = getConnection(USER, PASS); + Session sess = conn.createSession(false, Session.AUTO_ACKNOWLEDGE); + conn.start(); + ((AMQSession<?, ?>) sess).createQueue(new AMQShortString("allow-log"), false, false, false); + + List<String> matches = findMatches(ACL_LOG_PREFIX); + + assertEquals("Should only be one ACL log message", 1, matches.size()); + + String log = getLogMessage(matches, 0); + String actor = fromActor(log); + String subject = fromSubject(log); + String message = getMessageString(fromMessage(log)); + + validateMessageID(ACL_LOG_PREFIX + 1001, log); + + assertTrue("Actor should contain the user identity", actor.contains(USER)); + assertTrue("Subject should be empty", subject.length() == 0); + assertTrue("Message should start with 'Allowed'", message.startsWith("Allowed")); + assertTrue("Message should contain 'Create Queue'", message.contains("Create Queue")); + assertTrue("Message should have contained the queue name", message.contains("allow-log")); + } + + /** + * Test that {@code deny-log} ACL entries log correctly. + */ + public void testDenyLog() throws Exception + { + Connection conn = getConnection(USER, PASS); + Session sess = conn.createSession(false, Session.AUTO_ACKNOWLEDGE); + conn.start(); + try { + ((AMQSession<?, ?>) sess).createQueue(new AMQShortString("deny-log"), false, false, false); + fail("Should have denied queue creation"); + } + catch (AMQException amqe) + { + // Denied, so exception thrown + assertEquals("Expected ACCESS_REFUSED error code", AMQConstant.ACCESS_REFUSED, amqe.getErrorCode()); + } + + List<String> matches = findMatches(ACL_LOG_PREFIX); + + assertEquals("Should only be one ACL log message", 1, matches.size()); + + String log = getLogMessage(matches, 0); + String actor = fromActor(log); + String subject = fromSubject(log); + String message = getMessageString(fromMessage(log)); + + validateMessageID(ACL_LOG_PREFIX + 1002, log); + + assertTrue("Actor should contain the user identity", actor.contains(USER)); + assertTrue("Subject should be empty", subject.length() == 0); + assertTrue("Message should start with 'Denied'", message.startsWith("Denied")); + assertTrue("Message should contain 'Create Queue'", message.contains("Create Queue")); + assertTrue("Message should have contained the queue name", message.contains("deny-log")); + } + + /** + * Test that {@code deny} ACL entries do not log anything. + */ + public void testDeny() throws Exception + { + Connection conn = getConnection(USER, PASS); + Session sess = conn.createSession(false, Session.AUTO_ACKNOWLEDGE); + conn.start(); + try { + ((AMQSession<?, ?>) sess).createQueue(new AMQShortString("deny"), false, false, false); + fail("Should have denied queue creation"); + } + catch (AMQException amqe) + { + // Denied, so exception thrown + assertEquals("Expected ACCESS_REFUSED error code", AMQConstant.ACCESS_REFUSED, amqe.getErrorCode()); + } + + List<String> matches = findMatches(ACL_LOG_PREFIX); + + assertTrue("Should be no ACL log messages", matches.isEmpty()); + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AlertingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AlertingTest.java new file mode 100644 index 0000000000..05aaf16af1 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/AlertingTest.java @@ -0,0 +1,202 @@ +/* +* +* Licensed to the Apache Software Foundation (ASF) under one +* or more contributor license agreements. See the NOTICE file +* distributed with this work for additional information +* regarding copyright ownership. The ASF licenses this file +* to you under the Apache License, Version 2.0 (the +* "License"); you may not use this file except in compliance +* with the License. You may obtain a copy of the License at +* +* http://www.apache.org/licenses/LICENSE-2.0 +* +* Unless required by applicable law or agreed to in writing, +* software distributed under the License is distributed on an +* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +* KIND, either express or implied. See the License for the +* specific language governing permissions and limitations +* under the License. +* +*/ +package org.apache.qpid.server.logging; + +import javax.jms.Connection; +import javax.jms.Queue; +import javax.jms.Session; + +import org.apache.qpid.client.AMQDestination; +import org.apache.qpid.client.AMQSession; +import org.apache.qpid.framing.AMQShortString; +import org.apache.qpid.server.configuration.ServerConfiguration; +import org.apache.qpid.server.registry.ApplicationRegistry; +import org.apache.qpid.util.FileUtils; + +public class AlertingTest extends AbstractTestLogging +{ + private String VIRTUALHOST = "test"; + private Session _session; + private Connection _connection; + private Queue _destination; + private int _numMessages; + + private static final int ALERT_LOG_WAIT_PERIOD = 5000; + private static final String MESSAGE_COUNT_ALERT = "MESSAGE_COUNT_ALERT"; + + public void setUp() throws Exception + { + // Update the configuration to make our virtualhost Persistent. + makeVirtualHostPersistent(VIRTUALHOST); + setConfigurationProperty("virtualhosts.virtualhost." + VIRTUALHOST + ".housekeeping.expiredMessageCheckPeriod", "5000"); + + _numMessages = 50; + + // Then we do the normal setup stuff like starting the broker, getting a connection etc. + super.setUp(); + + setupConnection(); + } + + @Override + public void tearDown() throws Exception + { + // Ensure queue is clean for next run. + drainQueue(_destination); + super.tearDown(); + } + + + /** + * Create a new connection and ensure taht our destination queue is created + * and bound. + * + * Note that the tests here that restart the broker rely on persistence. + * However, the queue creation here is transient. So the queue will not be + * rebound on restart. Hence the consumer creation here rather than just the + * once. + * + * The persistent messages will recreate the queue but not bind it (as it + * was not a durable queue) However, the consumer creation here will ensure + * that the queue is correctly bound and can receive new messages. + * + * @throws Exception + */ + private void setupConnection() + throws Exception + { + _connection = getConnection(); + _session = _connection.createSession(true, Session.SESSION_TRANSACTED); + _destination = _session.createQueue(getTestQueueName()); + + // Consumer is only used to actually create the destination + _session.createConsumer(_destination).close(); + } + + /** + * Checks the log file for MESSAGE_COUNT_ALERT, fails() the test if it's not found and + * places the entire contents in the message to help debug cruise control failures. + * + * @throws Exception + */ + private void wasAlertFired() throws Exception + { + if (!waitForMessage(MESSAGE_COUNT_ALERT, ALERT_LOG_WAIT_PERIOD)) + { + StringBuffer message = new StringBuffer("Could not find 'MESSAGE_COUNT_ALERT' in log file: " + _monitor.getMonitoredFile().getAbsolutePath()); + message.append("\n"); + + // Add the current contents of the log file to test output + message.append(_monitor.readFile()); + + // Write the test config file to test output + message.append("Server configuration overrides in use:\n"); + message.append(FileUtils.readFileAsString(getTestConfigFile())); + + message.append("\nVirtualhost maxMessageCount:\n"); + ServerConfiguration config = new ServerConfiguration(_configFile); + config.initialise(); + message.append(config.getVirtualHostConfig(VIRTUALHOST).getMaximumMessageCount()); + + fail(message.toString()); + } + } + + public void testAlertingReallyWorks() throws Exception + { + // Send 5 messages, make sure that the alert was fired properly. + sendMessage(_session, _destination, _numMessages + 1); + _session.commit(); + wasAlertFired(); + } + + public void testAlertingReallyWorksWithRestart() throws Exception + { + sendMessage(_session, _destination, _numMessages + 1); + _session.commit(); + _connection.close(); + stopBroker(); + + // Rest the monitoring clearing the current output file. + _monitor.reset(); + startBroker(); + wasAlertFired(); + } + + /** + * Test that if the alert value is change from the previous value we can + * still get alerts. + * + * Test sends two messages to the broker then restarts the broker with new + * configuration. + * + * If the test is running inVM the test validates that the new configuration + * has been applied. + * + * Validates that we only have two messages on the queue and then sends + * enough messages to trigger the alert. + * + * The alert is then validate. + * + * + * @throws Exception + */ + public void testAlertingReallyWorksWithChanges() throws Exception + { + // send some messages and nuke the logs + sendMessage(_session, _destination, 2); + _session.commit(); + // To prevent any failover/retry/connection dropped errors + _connection.close(); + + stopBroker(); + + _monitor.reset(); + + // Change max message count to 5, start broker and make sure that that's triggered at the right time + setConfigurationProperty("virtualhosts.virtualhost." + VIRTUALHOST + ".queues.maximumMessageCount", "5"); + + startBroker(); + + if (!isExternalBroker()) + { + assertEquals("Alert Max Msg Count is not correct", 5, ApplicationRegistry.getInstance().getVirtualHostRegistry(). + getVirtualHost(VIRTUALHOST).getQueueRegistry().getQueue(new AMQShortString(_destination.getQueueName())). + getMaximumMessageCount()); + } + + setupConnection(); + + // Validate the queue depth is as expected + long messageCount = ((AMQSession<?, ?>) _session).getQueueDepth((AMQDestination) _destination); + assertEquals("Broker has invalid message count for test", 2, messageCount); + + // Ensure the alert has not occured yet + assertLoggingNotYetOccured(MESSAGE_COUNT_ALERT); + + // Trigger the new value + sendMessage(_session, _destination, 3); + _session.commit(); + + // Validate that the alert occured. + wasAlertFired(); + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BindingLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BindingLoggingTest.java new file mode 100644 index 0000000000..97914f84a5 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BindingLoggingTest.java @@ -0,0 +1,271 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.qpid.server.logging.subjects.AbstractTestLogSubject; + +import javax.jms.Connection; +import javax.jms.JMSException; +import javax.jms.Queue; +import javax.jms.Session; +import javax.jms.Topic; +import java.io.IOException; +import java.util.List; + +/** + * Binding + * + * The Binding test suite validates that the follow log messages as specified in the Functional Specification. + * + * This suite of tests validate that the Binding messages occur correctly and according to the following format: + * + * BND-1001 : Create [: Arguments : <key=value>] + * BND-1002 : Deleted + */ +public class BindingLoggingTest extends AbstractTestLogging +{ + + static final String BND_PREFIX = "BND-"; + + Connection _connection; + Session _session; + Queue _queue; + Topic _topic; + + @Override + public void setUp() throws Exception + { + super.setUp(); + //Ignore broker startup messages + _monitor.reset(); + + _connection = getConnection(); + + _session = _connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + _queue = _session.createQueue(getName()); + _topic = (Topic) getInitialContext().lookup(TOPIC); + } + + private void validateLogMessage(String log, String messageID, String message, String exchange, String rkey, String queueName) + { + validateMessageID(messageID, log); + + String subject = fromSubject(log); + + assertEquals("Queue not correct.", queueName, + AbstractTestLogSubject.getSlice("qu", subject)); + assertEquals("Routing Key not correct.", rkey, + AbstractTestLogSubject.getSlice("rk", subject)); + assertEquals("Virtualhost not correct.", "/test", + AbstractTestLogSubject.getSlice("vh", subject)); + assertEquals("Exchange not correct.", exchange, + AbstractTestLogSubject.getSlice("ex", subject)); + + assertEquals("Log Message not as expected", message, getMessageString(fromMessage(log))); + } + + /** + * testBindingCreate + * + * Description: + * The binding of a Queue and an Exchange is done via a Binding. When this Binding is created a BND-1001 Create message will be logged. + * Input: + * + * 1. Running Broker + * 2. New Client requests that a Queue is bound to a new exchange. + * Output: + * + * <date> BND-1001 : Create : Arguments : {x-filter-jms-selector=} + * + * Validation Steps: + * 3. The BND ID is correct + * 4. This will be the first message for the given binding + */ + public void testBindingCreate() throws JMSException, IOException + { + _session.createConsumer(_queue).close(); + + List<String> results = waitAndFindMatches(BND_PREFIX); + + // We will have two binds as we bind all queues to the default exchange + assertEquals("Result set larger than expected.", 2, results.size()); + + String exchange = "direct/<<default>>"; + String messageID = "BND-1001"; + String message = "Create"; + String queueName = _queue.getQueueName(); + + validateLogMessage(getLogMessage(results, 0), messageID, message, exchange, queueName, queueName); + + exchange = "direct/amq.direct"; + message = "Create : Arguments : {x-filter-jms-selector=}"; + validateLogMessage(getLogMessage(results, 1), messageID, message, exchange, queueName, queueName); + } + + /** + * Description: + * A Binding can be made with a set of arguments. When this occurs we logged the key,value pairs as part of the Binding log message. When the subscriber with a JMS Selector consumes from an exclusive queue such as a topic. The binding is made with the JMS Selector as an argument. + * Input: + * + * 1. Running Broker + * 2. Java Client consumes from a topic with a JMS selector. + * Output: + * + * <date> BND-1001 : Create : Arguments : {x-filter-jms-selector=<value>} + * + * Validation Steps: + * 3. The BND ID is correct + * 4. The JMS Selector argument is present in the message + * 5. This will be the first message for the given binding + */ + public void testBindingCreateWithArguments() throws JMSException, IOException + { + final String SELECTOR = "Selector='True'"; + + _session.createDurableSubscriber(_topic, getName(), SELECTOR, false).close(); + + List<String> results = waitAndFindMatches(BND_PREFIX); + + // We will have two binds as we bind all queues to the default exchange + assertEquals("Result set larger than expected.", 2, results.size()); + + //Verify the first entry is the default binding + String messageID = "BND-1001"; + String message = "Create"; + + validateLogMessage(getLogMessage(results, 0), messageID, message, + "direct/<<default>>", "clientid:" + getName(), "clientid:" + getName()); + + //Default binding will be without the selector + assertTrue("JMSSelector identified in binding:"+message, !message.contains("jms-selector")); + + // Perform full testing on the second non default binding + message = getMessageString(fromMessage(getLogMessage(results, 1))); + + validateLogMessage(getLogMessage(results, 1), messageID, message, + "topic/amq.topic", "topic", "clientid:" + getName()); + + assertTrue("JMSSelector not identified in binding:"+message, message.contains("jms-selector")); + assertTrue("Selector not part of binding.:"+message, message.contains(SELECTOR)); + + } + + /** + * Description: + * Bindings can be deleted so that a queue can be rebound with a different set of values. + * Input: + * + * 1. Running Broker + * 2. AMQP UnBind Request is made + * Output: + * + * <date> BND-1002 : Deleted + * + * Validation Steps: + * 3. The BND ID is correct + * 4. There must have been a BND-1001 Create message first. + * 5. This will be the last message for the given binding + */ + public void testBindingDelete() throws JMSException, IOException + { + //Closing a consumer on a temporary queue will cause it to autodelete + // and so unbind. + _session.createConsumer(_session.createTemporaryQueue()).close(); + + if(isBroker010()) + { + //auto-delete is at session close for 0-10 + _session.close(); + } + + //wait for the deletion messages to be logged + waitForMessage("BND-1002"); + + //gather all the BND messages + List<String> results = waitAndFindMatches(BND_PREFIX); + + // We will have two binds as we bind all queues to the default exchange + assertEquals("Result not as expected." + results, 4, results.size()); + + + String messageID = "BND-1001"; + String message = "Create"; + + String log = getLogMessage(results, 0); + validateMessageID(messageID, log); + assertEquals("Log Message not as expected", message, getMessageString(fromMessage(log))); + + log = getLogMessage(results, 1); + validateMessageID(messageID, log); + assertEquals("Log Message not as expected", message, getMessageString(fromMessage(log))); + + + String DEFAULT = "direct/<<default>>"; + String DIRECT = "direct/amq.direct"; + + messageID = "BND-1002"; + message = "Deleted"; + + log = getLogMessage(results, 2); + validateMessageID(messageID, log); + + String subject = fromSubject(log); + + validateBindingDeleteArguments(subject, "/test"); + + boolean defaultFirst = DEFAULT.equals(AbstractTestLogSubject.getSlice("ex", subject)); + boolean directFirst = DIRECT.equals(AbstractTestLogSubject.getSlice("ex", subject)); + + assertEquals("Log Message not as expected", message, getMessageString(fromMessage(log))); + + log = getLogMessage(results, 3); + + validateMessageID(messageID, log); + + subject = fromSubject(log); + + validateBindingDeleteArguments(subject, "/test"); + + if (!defaultFirst) + { + assertEquals(DEFAULT, AbstractTestLogSubject.getSlice("ex", subject)); + assertTrue("First Exchange Log was not a direct exchange delete",directFirst); + } + else + { + assertEquals(DIRECT, AbstractTestLogSubject.getSlice("ex", subject)); + assertTrue("First Exchange Log was not a default exchange delete",defaultFirst); + } + + assertEquals("Log Message not as expected", message, getMessageString(fromMessage(log))); + } + + private void validateBindingDeleteArguments(String subject, String vhostName) + { + String routingKey = AbstractTestLogSubject.getSlice("rk", subject); + + assertTrue("Routing Key does not start with TempQueue:"+routingKey, + routingKey.startsWith("TempQueue")); + assertEquals("Virtualhost not correct.", vhostName, + AbstractTestLogSubject.getSlice("vh", subject)); + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BrokerLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BrokerLoggingTest.java new file mode 100644 index 0000000000..8fd2c085c3 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/BrokerLoggingTest.java @@ -0,0 +1,1003 @@ +/* +* +* Licensed to the Apache Software Foundation (ASF) under one +* or more contributor license agreements. See the NOTICE file +* distributed with this work for additional information +* regarding copyright ownership. The ASF licenses this file +* to you under the Apache License, Version 2.0 (the +* "License"); you may not use this file except in compliance +* with the License. You may obtain a copy of the License at +* +* http://www.apache.org/licenses/LICENSE-2.0 +* +* Unless required by applicable law or agreed to in writing, +* software distributed under the License is distributed on an +* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +* KIND, either express or implied. See the License for the +* specific language governing permissions and limitations +* under the License. +* +*/ +package org.apache.qpid.server.logging; + +import junit.framework.AssertionFailedError; +import org.apache.qpid.server.Main; +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.List; + +/** + * Broker Test Suite + * + * The Broker test suite validates that the follow log messages as specified in the Functional Specification. + * + * BRK-1001 : Startup : Version: <Version> Build: <Build> + * BRK-1002 : Starting : Listening on <Transport> port <Port> + * BRK-1003 : Shuting down : <Transport> port <Port> + * BRK-1004 : Ready + * BRK-1005 : Stopped + * BRK-1006 : Using configuration : <path> + * BRK-1007 : Using logging configuration : <path> + * + * These messages should only occur during startup. The tests need to verify the order of messages. In the case of the BRK-1002 and BRK-1003 the respective ports should only be available between the two log messages. + */ +public class BrokerLoggingTest extends AbstractTestLogging +{ + private static final String BRK_LOG_PREFIX = "BRK-"; + + public void setUp() throws Exception + { + setLogMessagePrefix(); + + // We either do this here or have a null check in tearDown. + // As when this test is run against profiles other than java it will NPE + _monitor = new LogMonitor(_outputFile); + //We explicitly do not call super.setUp as starting up the broker is + //part of the test case. + } + + /** + * Description: + * On startup the broker must report the active configuration file. The + * logging system must output this so that we can know what configuration + * is being used for this broker instance. + * + * Input: + * The value of -c specified on the command line. + * Output: + * <date> MESSAGE BRK-1006 : Using configuration : <config file> + * Constraints: + * This MUST BE the first BRK log message. + * + * Validation Steps: + * 1. This is first BRK log message. + * 2. The BRK ID is correct + * 3. The config file is the full path to the file specified on + * the commandline. + * + * @throws Exception caused by broker startup + */ + public void testBrokerStartupConfiguration() throws Exception + { + String TESTID="BRK-1006"; + + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + + + String configFilePath = _configFile.toString(); + + // 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); + + String log = getLogMessage(results, 0); + + //1 + validateMessageID(TESTID, log); + + //2 + results = findMatches(TESTID); + assertEquals("More than one configuration message found.", + 1, results.size()); + + //3 + assertTrue("Config file details not correctly logged", + log.endsWith(configFilePath)); + } + 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. + * 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 + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1007"; + + //Remove test Log4j config from the commandline + _broker = _broker.substring(0, _broker.indexOf("-l")); + + 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 = _configFile.getParent() + "/" + Main.DEFAULT_LOG_CONFIG_FILENAME; + 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. + * Output: + * + * <date> MESSAGE BRK-1007 : Using logging configuration : <log4j file> + * + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This should occur 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 testBrokerStartupCustomLog4j() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + // Get custom -l value used during testing for the broker startup + String customLog4j = _broker.substring(_broker.indexOf("-l") + 2); + + String TESTID = "BRK-1007"; + + 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 + assertTrue("Log4j file details not correctly logged:" + getMessageString(log), + getMessageString(log).endsWith(customLog4j)); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: On startup the broker reports the broker version number and svn build revision. This information is retrieved from the resource 'qpidversion.properties' which is located via the classloader. + * Input: The 'qpidversion.properties' file located on the classpath. + * Output: + * + * <date> MESSAGE BRK-1001 : Startup : qpid Version: 0.6 Build: 767150 + * + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This occurs before any BRK-1002 listening messages are reported. + * + * @throws Exception caused by broker startup + */ + public void testBrokerStartupStartup() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1001"; + + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + + // Ensure we wait for TESTID to be logged + waitAndFindMatches(TESTID); + + // Retrieve all BRK- log messages so we can check for an erroneous + // BRK-1002 message. + List<String> results = findMatches(BRK_LOG_PREFIX); + + try + { + // Validation + + assertTrue("BRKer message not logged", results.size() > 0); + + boolean validation = false; + for (String rawLog : results) + { + if (validation) + { + //Stop checking once we have got to our startup test + break; + } + String log = getLog(rawLog); + + // Ensure we do not have a BRK-1002 message + if (!getMessageID(log).equals(TESTID)) + { + assertFalse(getMessageID(log).equals("BRK-1002")); + continue; + } + + //1 + validateMessageID(TESTID, log); + + //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()); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * On startup the broker may listen on a number of ports and protocols. Each of these must be reported as they are made available. + * Input: + * The default configuration with no SSL + * Output: + * + * <date> MESSAGE BRK-1002 : Starting : Listening on TCP port 5672 + * + * Constraints: + * Additional broker configuration will occur between the Startup(BRK-1001) and Starting(BRK-1002) messages depending on what VirtualHosts are configured. + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This occurs after the BRK-1001 startup message + * 3. Using the default configuration a single BRK-1002 will be printed showing values TCP / 5672 + * + * @throws Exception caused by broker startup + */ + public void testBrokerStartupListeningTCPDefault() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1002"; + + 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); + + // Retrieve all BRK- log messages so we can check for an erroneous + // BRK-1002 message. + List<String> results = findMatches(BRK_LOG_PREFIX); + try + { + // Validation + + assertTrue("BRKer message not logged", results.size() > 0); + + boolean validation = false; + boolean foundBRK1001 = false; + for (String rawLog : results) + { + String log = getLog(rawLog); + + // Ensure we do not have a BRK-1002 message + if (!getMessageID(log).equals(TESTID)) + { + if (getMessageID(log).equals("BRK-1001")) + { + foundBRK1001 = true; + } + continue; + } + + assertTrue("BRK-1001 not logged before this message", foundBRK1001); + + //1 + validateMessageID(TESTID, log); + + //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()); + + //3 + String message = getMessageString(log); + assertTrue("Expected Listen log not correct" + message, + message.endsWith("Listening on TCP port " + getPort())); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * On startup the broker may listen on a number of ports and protocols. Each of these must be reported as they are made available. + * Input: + * The default configuration with SSL enabled + * Output: + * + * <date> MESSAGE BRK-1002 : Starting : Listening on TCP port 5672 + * <date> MESSAGE BRK-1002 : Starting : Listening on TCP/SSL port 8672 + * + * Constraints: + * Additional broker configuration will occur between the Startup(BRK-1001) and Starting(BRK-1002) messages depending on what VirtualHosts are configured. + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This occurs after the BRK-1001 startup message + * 3. With SSL enabled in the configuration two BRK-1002 will be printed (order is not specified) + * 1. One showing values TCP / 5672 + * 2. One showing values TCP/SSL / 5672 + * + * @throws Exception caused by broker startup + */ + public void testBrokerStartupListeningTCPSSL() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1002"; + + // Enable SSL on the connection + setConfigurationProperty("connector.ssl.enabled", "true"); + setConfigurationProperty("connector.ssl.sslOnly", "false"); + setConfigurationProperty("connector.ssl.keyStorePath", getConfigurationStringProperty("management.ssl.keyStorePath")); + setConfigurationProperty("connector.ssl.keyStorePassword", getConfigurationStringProperty("management.ssl.keyStorePassword")); + + Integer sslPort = Integer.parseInt(getConfigurationStringProperty("connector.sslport")); + + 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); + + // Retrieve all BRK- log messages so we can check for an erroneous + // BRK-1002 message. + List<String> results = findMatches(BRK_LOG_PREFIX); + try + { + // Validation + + assertTrue("BRKer message not logged", results.size() > 0); + + boolean validation = false; + boolean foundBRK1001 = false; + for (String rawLog : results) + { + String log = getLog(rawLog); + + // Ensure we do not have a BRK-1002 message + if (!getMessageID(log).equals(TESTID)) + { + if (getMessageID(log).equals("BRK-1001")) + { + foundBRK1001 = true; + } + continue; + } + + assertTrue("BRK-1001 not logged before this message", foundBRK1001); + + //1 + validateMessageID(TESTID, log); + + //2 + //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()); + + //3 + //Check the first + String message = getMessageString(getLog(listenMessages .get(0))); + assertTrue("Expected Listen log not correct" + message, + message.endsWith("Listening on TCP port " + getPort())); + + // Check the third, ssl listen. + message = getMessageString(getLog(listenMessages .get(2))); + assertTrue("Expected Listen log not correct" + message, + message.endsWith("Listening on TCP/SSL port " + sslPort)); + + //4 Test ports open + testSocketOpen(getPort()); + testSocketOpen(sslPort); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * The final message the broker will print when it has performed all initialisation and listener startups will be to log the BRK-1004 Ready message + * Input: + * No input, all successful broker startups will show BRK-1004 messages. + * Output: + * + * 2009-07-09 15:50:20 +0100 MESSAGE BRK-1004 : Qpid Broker Ready + * + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This occurs after the BRK-1001 startup message + * 3. This must be the last message the broker prints after startup. Currently, if there is no further interaction with the broker then there should be no more logging. + * + * @throws Exception caused by broker startup + */ + public void testBrokerStartupReady() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1004"; + + startBroker(); + + //Ensure the broker has fully started up. + getConnection(); + // Ensure we wait for TESTID to be logged + waitAndFindMatches(TESTID); + + // Retrieve all BRK- log messages so we can check for an erroneous + // BRK-1001 message. + List<String> results = findMatches(BRK_LOG_PREFIX); + try + { + // Validation + + assertTrue("BRKer message not logged", results.size() > 0); + + boolean validationComplete = false; + boolean foundBRK1001 = false; + + for (int i=0; i < results.size(); i++) + { + String rawLog = results.get(i); + String log = getLog(rawLog); + + // Ensure we do not have a BRK-1001 message + if (!getMessageID(log).equals(TESTID)) + { + if (getMessageID(log).equals("BRK-1001")) + { + foundBRK1001 = true; + } + continue; + } + + assertTrue("BRK-1001 not logged before this message", foundBRK1001); + + //1 + validateMessageID(TESTID, log); + + //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); + + validationComplete = true; + break; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validationComplete); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * On startup the broker may listen on a number of ports and protocols. Each of these must then report a shutting down message as they stop listening. + * Input: + * The default configuration with no SSL + * Output: + * + * <date> MESSAGE BRK-1003 : Shutting down : TCP port 5672 + * + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. Only TCP is reported with the default configuration with no SSL. + * 3. The default port is correct + * 4. The port is not accessible after this message + * + * @throws Exception caused by broker startup + */ + public void testBrokerShutdownListeningTCPDefault() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1003"; + + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + + stopBroker(); + + //Give broker time to shutdown and flush log + checkSocketClosed(getPort()); + + List<String> results = waitAndFindMatches(BRK_LOG_PREFIX); + try + { + // Validation + + assertTrue("BRKer message not logged", results.size() > 0); + + boolean validation = false; + boolean foundBRK1001 = false; + for (String rawLog : results) + { + String log = getLog(rawLog); + + // Ensure we do not have a BRK-1002 message + if (!getMessageID(log).equals(TESTID)) + { + if (getMessageID(log).equals("BRK-1001")) + { + foundBRK1001 = true; + } + continue; + } + + assertTrue("BRK-1001 not logged before this message", foundBRK1001); + + //1 + validateMessageID(TESTID, log); + + //2 + assertEquals("More than one listen message found.", + 1, findMatches(TESTID).size()); + + //3 + String message = getMessageString(log); + assertTrue("Expected shutdown log not correct" + message, + message.endsWith("TCP port " + getPort())); + + //4 + checkSocketClosed(getPort()); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * On startup the broker may listen on a number of ports and protocols. Each of these must be reported as they are made available. + * Input: + * The default configuration with SSL enabled + * Output: + * + * <date> MESSAGE BRK-1002 : Starting : Listening on TCP port 5672 + * <date> MESSAGE BRK-1002 : Starting : Listening on TCP/SSL port 8672 + * + * Constraints: + * Additional broker configuration will occur between the Startup(BRK-1001) and Starting(BRK-1002) messages depending on what VirtualHosts are configured. + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This occurs after the BRK-1001 startup message + * 3. With SSL enabled in the configuration two BRK-1002 will be printed (order is not specified) + * 1. One showing values TCP / 5672 + * 2. One showing values TCP/SSL / 5672 + * + * @throws Exception caused by broker startup + */ + public void testBrokerShutdownListeningTCPSSL() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1003"; + + // Enable SSL on the connection + setConfigurationProperty("connector.ssl.enabled", "true"); + setConfigurationProperty("connector.ssl.keyStorePath", getConfigurationStringProperty("management.ssl.keyStorePath")); + setConfigurationProperty("connector.ssl.keyStorePassword", getConfigurationStringProperty("management.ssl.keyStorePassword")); + + Integer sslPort = Integer.parseInt(getConfigurationStringProperty("connector.sslport")); + + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + + +// //Clear any startup messages as we don't need them for validation +// _monitor.reset(); + //Stop the broker to get the log messages for testing + stopBroker(); + + //Give broker time to shutdown and flush log + checkSocketClosed(getPort()); + + List<String> results = waitAndFindMatches(TESTID); + try + { + // Validation + + assertTrue(TESTID + " messages not logged", results.size() > 0); + + String log = getLog(results.get(0)); + + //1 + validateMessageID(TESTID, log); + + //2 + List<String> listenMessages = findMatches(TESTID); + assertEquals("Two shutdown messages should be found.", + 2, listenMessages.size()); + + //3 + String message = getMessageString(getLog(listenMessages.get(0))); + assertTrue("Expected shutdown log not correct" + message, + message.endsWith("TCP port " + getPort())); + + // Check second, ssl, listen. + message = getMessageString(getLog(listenMessages.get(1))); + assertTrue("Expected shutdown log not correct" + message, + message.endsWith("TCP/SSL port " + sslPort)); + + //4 + //Test Port closed + checkSocketClosed(getPort()); + //Test SSL Port closed + checkSocketClosed(sslPort); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Description: + * Input: + * No input, all clean broker shutdowns will show BRK-1005 messages. + * Output: + * + * <date> MESSAGE BRK-1005 : Stopped + * + * Constraints: + * This is the LAST message the broker will log. + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This is the last message the broker will log. + * + * @throws Exception caused by broker startup + */ + public void testBrokerShutdownStopped() throws Exception + { + // This logging startup code only occurs when you run a Java broker, + // that broker must be started via Main so not an InVM broker. + if (isJavaBroker() && isExternalBroker()) + { + String TESTID = "BRK-1005"; + + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + + getConnection().close(); + + stopBroker(); + + // Ensure the broker has shutdown before retreving results + checkSocketClosed(getPort()); + + 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) + { + assertFalse("More broker log statements present after ready message", validation); + String log = getLog(rawLog); + + // Ignore all logs until we get to the test id. + if (!getMessageID(log).equals(TESTID)) + { + continue; + } + + //1 + validateMessageID(TESTID, log); + + //2 + assertEquals("More than one ready message found.", + 1, findMatches(TESTID).size()); + + //3 + assertEquals("Stopped message not present", "Stopped", getMessageString(log)); + + validation = true; + } + + assertTrue("Validation not performed: " + TESTID + " not logged", validation); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + } + + /** + * Test that a socket on the given port is closed. + * + * Does this by attempting to connect to the port and expecting a + * ConnectionRefused IOException or a ConnectionException + * + * @param port the port number + */ + private void checkSocketClosed(int port) + { + try + { + Socket socket = new Socket((String) null, port); + fail("Socket not closed on port:" + port); + } + catch (ConnectionException e) + { + //normal path + } + catch (IOException e) + { + if (!e.getMessage().equals("Connection refused")) + { + fail("Socket not closed on port:" + port + ":" + e.getMessage()); + // Keep stack trace for diagnosis. + e.printStackTrace(System.err); + } + } + } + + /** + * Test that a socket on the given port is open. + * + * Does this by attempting to connect to the port and expecting a + * The connection to succeed. + * It then closes the socket and expects that to work cleanly. + * + * @param port the port number + */ + private void testSocketOpen(int port) + { + try + { + Socket socket = new Socket((String) null, port); + socket.close(); + } + catch (IOException e) + { + fail("Unable to open and close socket to port:" + port + + ". Due to:" + e.getMessage()); + } + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ChannelLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ChannelLoggingTest.java new file mode 100644 index 0000000000..02d0d6f334 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ChannelLoggingTest.java @@ -0,0 +1,313 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.qpid.client.AMQConnection; + +import javax.jms.Connection; +import javax.jms.MessageConsumer; +import javax.jms.Queue; +import javax.jms.Session; +import java.util.List; + +public class ChannelLoggingTest extends AbstractTestLogging +{ + private static final String CHANNEL_PREFIX = "CHN-"; + + // No explicit startup configuration is required for this test + // so no setUp() method + + /** + * Description: + * When a new Channel (JMS Session) is created this will be logged as a CHN-1001 Create message. The messages will contain the prefetch details about this new Channel. + * Input: + * + * 1. Running Broker + * 2. New JMS Session/Channel creation + * + * Output: + * <date> CHN-1001 : Create + * <date> CHN-1004 : Prefetch Size (bytes) {0,number} : Count {1,number} + * + * Validation Steps: + * 1. The CHN ID is correct + * 2. The prefetch value matches that defined by the requesting client. + * + * @throws Exception - if an error occurs + */ + public void testChannelCreate() throws Exception + { + assertLoggingNotYetOccured(CHANNEL_PREFIX); + + Connection connection = getConnection(); + + int PREFETCH = 12; + + // Test that calling session.close gives us the expected output + ((AMQConnection)connection).createSession(false, Session.AUTO_ACKNOWLEDGE,PREFETCH); + + // Wait to ensure that the CHN-1001 message is logged + waitForMessage("CHN-1001"); + + List<String> results = findMatches("CHN-1001"); + + // Validation + assertEquals("CHN-1001 messages not logged", 1, results.size()); + + String log = getLogMessage(results, 0); + // MESSAGE [con:0(guest@anonymous(3273383)/test)/ch:1] CHN-1001 : Create + validateMessageID("CHN-1001", log); + assertEquals("Incorrect Channel in actor:"+fromActor(log), isBroker010()? 0 : 1, getChannelID(fromActor(log))); + + if (isBroker08()) + { + // Wait to ensure that the CHN-1004 message is logged + waitForMessage("CHN-1004"); + + results = findMatches("CHN-1004"); + + // Validation + assertEquals("CHN-1004 messages not logged", 1, results.size()); + log = getLogMessage(results, 0); + // MESSAGE [con:0(guest@anonymous(3273383)/test)/ch:1] CHN-1004 : Prefetch Size (bytes) {0,number} : Count {1,number} + validateMessageID("CHN-1004", log); + assertEquals("Incorrect Channel in actor:"+fromActor(log), isBroker010()? 0 : 1, getChannelID(fromActor(log))); + assertTrue("Prefetch Count not correct",getMessageString(fromMessage(log)).endsWith("Count "+PREFETCH)); + } + + connection.close(); + } + + /** + * Description: + * The Java Broker implements consumer flow control for all ack modes except + * No-Ack. When a client connects the session's flow is initially set to + * Stopped. Verify this message appears + * + * Input: + * 1. Running broker + * 2. Create consumer + * Output: + * + * <date> CHN-1002 : Flow Stopped + * + * Validation Steps: + * 4. The CHN ID is correct + * + * @throws Exception - if an error occurs + */ + + public void testChannelStartsFlowStopped() throws Exception + { + assertLoggingNotYetOccured(CHANNEL_PREFIX); + + Connection connection = getConnection(); + + // Create a session to fill up + Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + Queue queue = (Queue) getInitialContext().lookup(QUEUE); + MessageConsumer consumer = session.createConsumer(queue); + + connection.start(); + + // Wait to ensure that the CHN-1002 message is logged + waitForMessage("CHN-1002"); + + List<String> results = findMatches(CHANNEL_PREFIX); + + assertTrue("No CHN messages logged", results.size() > 0); + + // The last channel message should be: + // + // INFO - MESSAGE [con:0(guest@anonymous(4205299)/test)/ch:1] [con:0(guest@anonymous(4205299)/test)/ch:1] CHN-1002 : Flow Stopped + + // Verify the last channel message is stopped + validateChannelStart(results, false); + } + + private void validateChannelStart(List<String> results, boolean flowStarted) + { + String log = getLogMessageFromEnd(results, 0); + + String flow = flowStarted ? "Started" : "Stopped"; + validateMessageID("CHN-1002", log); + assertEquals("Message should be Flow " + flow, "Flow " + flow, getMessageString(fromMessage(log))); + } + + /** + * Description: + * The Java Broker implements consumer flow control for all ack modes except + * No-Ack. When the client first attempts to receive a message then the Flow + * status of the Session is set to Started. + * + * Input: + * 1. Running broker + * 2. Create a consumer + * 3. Attempt to receive a message + * Output: + * + * <date> CHN-1002 : Flow Started + * + * Validation Steps: + * 4. The CHN ID is correct + * + * @throws Exception - if an error occurs + */ + + public void testChannelStartConsumerFlowStarted() throws Exception + { + assertLoggingNotYetOccured(CHANNEL_PREFIX); + + Connection connection = getConnection(); + + // Create a session to fill up + Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + Queue queue = (Queue) getInitialContext().lookup(QUEUE); + MessageConsumer consumer = session.createConsumer(queue); + + connection.start(); + + //Call receive to send the Flow On message + consumer.receiveNoWait(); + + //Wait for up to 2 seconds for message to appear + // ignore response as we will use the findMatches afterwards just + // incase it did take more than 2 seconds to log. + _monitor.waitForMessage(CHANNEL_PREFIX, 2000); + + // Wait to ensure that the CHN-1002 message is logged + waitForMessage("CHN-1002"); + + List<String> results = findMatches(CHANNEL_PREFIX); + + assertTrue("No CHN messages logged", results.size() > 0); + + // The last two channel messages(before the close) should be: + // + // INFO [qpid.message] MESSAGE [con:1(guest@/127.0.0.1:49869/test)/ch:1] [con:1(guest@/127.0.0.1:49869/test)/ch:1] CHN-1002 : Flow Stopped + // INFO [qpid.message] MESSAGE [con:1(guest@/127.0.0.1:49869/test)/ch:1] [con:1(guest@/127.0.0.1:49869/test)/ch:1] CHN-1002 : Flow Started + + // Verify the last channel msg is Started. + validateChannelStart(results, true); + } + + /** + * Description: + * When the client gracefully closes the Connection then a CHN-1003 Close + * message will be issued. This must be the last message logged for this + * Channel. + * Input: + * 1. Running Broker + * 2. Connected Client + * 3. Client then requests that the Connection is closed + * Output: + * + * <date> CHN-1003 : Close + * + * Validation Steps: + * 4. The MST ID is correct + * 5. This must be the last message logged for this Channel. + * + * @throws Exception - if an error occurs + */ + public void testChannelCloseViaConnectionClose() throws Exception + { + assertLoggingNotYetOccured(CHANNEL_PREFIX); + + Connection connection = getConnection(); + + // Create a session + connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + // Close the connection to verify the created session closing is logged. + connection.close(); + + // Wait to ensure that the CHN-1003 message is logged + waitForMessage("CHN-1003"); + + List<String> results = findMatches(CHANNEL_PREFIX); + + assertTrue("No CHN messages logged", results.size() > 0); + + // The last two channel messages should be: + // + // INFO - MESSAGE [con:0(guest@anonymous(4205299)/test)/ch:1] [con:0(guest@anonymous(4205299)/test)/ch:1] CHN-1002 : Flow On + + // Verify + validateChannelClose(results); + } + + /** + * Description: + * When the client gracefully closes the Connection then a CHN-1003 Close + * message will be issued. This must be the last message logged for this + * Channel. + * Input: + * 1. Running Broker + * 2. Connected Client + * 3. Client then requests that the Channel is closed + * Output: + * + * <date> CHN-1003 : Close + * + * Validation Steps: + * 4. The MST ID is correct + * 5. This must be the last message logged for this Channel. + * + * @throws Exception - if an error occurs + */ + public void testChannelCloseViaChannelClose() throws Exception + { + assertLoggingNotYetOccured(CHANNEL_PREFIX); + + Connection connection = getConnection(); + + // Create a session and then close it + Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + waitForMessage("CHN-1001"); + + // Wait to ensure that the CHN-1003 message is logged + session.close(); + waitForMessage("CHN-1003"); + + List<String> results = findMatches(CHANNEL_PREFIX); + + assertTrue("No CHN messages logged", results.size() > 0); + + // Verify + validateChannelClose(results); + } + + private void validateChannelClose(List<String> results) + { + String open = getLogMessage(results, 0); + String close = getLogMessageFromEnd(results, 0); + + validateMessageID("CHN-1001", open); + validateMessageID("CHN-1003", close); + assertEquals("Message should be Close", "Close", getMessageString(fromMessage(close))); + assertEquals("Incorrect Channel ID closed", isBroker010()? 0 : 1, getChannelID(fromSubject(close))); + assertEquals("Channel IDs should be the same", getChannelID(fromActor(open)), getChannelID(fromSubject(close))); + assertEquals("Connection IDs should be the same", getConnectionID(fromActor(open)), getConnectionID(fromSubject(close))); + } +}
\ No newline at end of file diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ConnectionLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ConnectionLoggingTest.java new file mode 100644 index 0000000000..d28429aa39 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ConnectionLoggingTest.java @@ -0,0 +1,192 @@ +/* +* +* Licensed to the Apache Software Foundation (ASF) under one +* or more contributor license agreements. See the NOTICE file +* distributed with this work for additional information +* regarding copyright ownership. The ASF licenses this file +* to you under the Apache License, Version 2.0 (the +* "License"); you may not use this file except in compliance +* with the License. You may obtain a copy of the License at +* +* http://www.apache.org/licenses/LICENSE-2.0 +* +* Unless required by applicable law or agreed to in writing, +* software distributed under the License is distributed on an +* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +* KIND, either express or implied. See the License for the +* specific language governing permissions and limitations +* under the License. +* +*/ +package org.apache.qpid.server.logging; + +import javax.jms.Connection; +import java.util.List; +import java.util.HashMap; +import java.util.TreeSet; + +public class ConnectionLoggingTest extends AbstractTestLogging +{ + private static final String CONNECTION_PREFIX = "CON-"; + + // No explicit startup configuration is required for this test + // so no setUp() method + + /** + * Description: + * When a new connection is made to the broker this must be logged. + * + * Input: + * 1. Running Broker + * 2. Connecting client + * Output: + * <date> CON-1001 : Open : Client ID {0}[ : Protocol Version : {1}] <version> + * + * Validation Steps: + * 1. The CON ID is correct + * 2. This is the first CON message for that Connection + * + * @throws Exception - if an error occurs + */ + public void testConnectionOpen() throws Exception + { + assertLoggingNotYetOccured(CONNECTION_PREFIX); + + Connection connection = getConnection(); + String clientid = connection.getClientID(); + + // Wait until opened + waitForMessage("CON-1001"); + + // Close the conneciton + connection.close(); + + // Wait to ensure that the desired message is logged + waitForMessage("CON-1002"); + + List<String> results = waitAndFindMatches("CON-1001"); + + // Validation + // We should have at least three messages when running InVM but when running External + // we will get 0-10 negotiation on con:0 whcih may close at some random point + // MESSAGE [con:0(/127.0.0.1:46926)] CON-1001 : Open + // MESSAGE [con:0(/127.0.0.1:46926)] CON-1001 : Open : Protocol Version : 0-10 + // MESSAGE [con:1(/127.0.0.1:46927)] CON-1001 : Open + // MESSAGE [con:1(/127.0.0.1:46927)] CON-1001 : Open : Protocol Version : 0-9 + // MESSAGE [con:0(/127.0.0.1:46926)] CON-1002 : Close + // MESSAGE [con:1(/127.0.0.1:46927)] CON-1001 : Open : Client ID : clientid : Protocol Version : 0-9 + + //So check how many connections we have in the result set and extract the last one. + // When running InVM we will have con:0 and externally con:1 + + HashMap<Integer, List<String>> connectionData = splitResultsOnConnectionID(results); + + // Get the last Integer from keySet of the ConnectionData + int connectionID = new TreeSet<Integer>(connectionData.keySet()).last(); + + //Use just the data from the last connection for the test + results = connectionData.get(connectionID); + + // If we are running inVM or with 0-10 we will get three open messagse + // if running externally with 0-8/0-9 we will also have open and close messages from the failed 0-10 negotiation + assertTrue("CON messages not logged:" + results.size(), results.size() >= 3); + + String log = getLogMessage(results, 0); + // MESSAGE [con:1(/127.0.0.1:52540)] CON-1001 : Open + //1 & 2 + validateMessageID("CON-1001",log); + + // validate the last three CON- messages. + // This is because when running externally we may also have logged the failed + // 0-10 negotiation messages if using 0-8/0-9 on the broker. + + // 3 - Assert the options are correct + // MESSAGE [con:1(/127.0.0.1:52540)] CON-1001 : Open : Client ID : clientid : Protocol Version : 0-9 + validateConnectionOpen(results, 0, true, true, clientid); + + // MESSAGE [con:1(/127.0.0.1:52540)] CON-1001 : Open : Protocol Version : 0-9 + validateConnectionOpen(results, 1, true, false, null); + + validateConnectionOpen(results, 2, false, false, null); + } + + private void validateConnectionOpen(List<String> results, int positionFromEnd, + boolean protocolVersionPresent, boolean clientIdOptionPresent, String clientIdValue) + { + String log = getLogMessageFromEnd(results, positionFromEnd); + + validateMessageID("CON-1001",log); + + assertEquals("unexpected Client ID option state", clientIdOptionPresent, fromMessage(log).contains("Client ID :")); + + if(clientIdOptionPresent && clientIdValue != null) + { + assertTrue("Client ID value is not present: " + clientIdValue, fromMessage(log).contains(clientIdValue)); + } + + assertEquals("unexpected Protocol Version option state", + protocolVersionPresent, fromMessage(log).contains("Protocol Version :")); + //fixme there is no way currently to find out the negotiated protocol version + // The delegate is the versioned class ((AMQConnection)connection)._delegate + } + + /** + * Description: + * When a connected client closes the connection this will be logged as a CON-1002 message. + * Input: + * + * 1. Running Broker + * 2. Connected Client + * Output: + * + * <date> CON-1002 : Close + * + * Validation Steps: + * 3. The CON ID is correct + * 4. This must be the last CON message for the Connection + * 5. It must be preceded by a CON-1001 for this Connection + */ + public void testConnectionClose() throws Exception + { + assertLoggingNotYetOccured(CONNECTION_PREFIX); + + Connection connection = getConnection(); + + // Wait until opened + waitForMessage("CON-1001"); + + // Close the conneciton + connection.close(); + + // Wait to ensure that the desired message is logged + waitForMessage("CON-1002"); + + List<String> results = findMatches(CONNECTION_PREFIX); + + // Validation + + // We should have at least four messages + assertTrue("CON messages not logged:" + results.size(), results.size() >= 4); + + // Validate Close message occurs + String log = getLogMessageFromEnd(results, 0); + validateMessageID("CON-1002",log); + assertTrue("Message does not end with close:" + log, log.endsWith("Close")); + + // Extract connection ID to validate there is a CON-1001 messasge for it + int closeConnectionID = getConnectionID(fromSubject(log)); + assertTrue("Could not find connection id in CLOSE", closeConnectionID != -1); + + //Previous log message should be the open + log = getLogMessageFromEnd(results, 1); + // MESSAGE [con:1(/127.0.0.1:52540)] CON-1001 : Open : Client ID : clientid : Protocol Version : 0-9 + validateMessageID("CON-1001",log); + + // Extract connection ID to validate it matches the CON-1002 messasge + int openConnectionID = getConnectionID(fromActor(log)); + assertTrue("Could not find connection id in OPEN", openConnectionID != -1); + + // Check connection ids match + assertEquals("Connection IDs do not match", closeConnectionID, openConnectionID); + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DerbyMessageStoreLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DerbyMessageStoreLoggingTest.java new file mode 100644 index 0000000000..16c529316a --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DerbyMessageStoreLoggingTest.java @@ -0,0 +1,574 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.commons.configuration.Configuration; +import org.apache.qpid.server.configuration.ServerConfiguration; +import org.apache.qpid.server.logging.subjects.AbstractTestLogSubject; + +import javax.jms.Connection; +import javax.jms.Queue; +import javax.jms.Session; +import java.util.List; +import java.io.File; + +/** + * The MessageStore test suite validates that the follow log messages as + * specified in the Functional Specification. + * + * This suite of tests validate that the MessageStore messages occur correctly + * and according to the following format: + * + * MST-1001 : Created : <name> + * MST-1003 : Closed + * + * NOTE: Only for Persistent Stores + * MST-1002 : Store location : <path> + * MST-1004 : Recovery Start [: <queue.name>] + * MST-1005 : Recovered <count> messages for queue <queue.name> + * MST-1006 : Recovery Complete [: <queue.name>] + */ +public class DerbyMessageStoreLoggingTest extends MemoryMessageStoreLoggingTest +{ + + @Override + public void setUp() throws Exception + { + super.setUp(); + // MemoryMessageStoreLoggingTest setUp itself does not call super.setUp + //We call super.setUp but this will not start the broker as that is + //part of the test case. + + // Load the default configuration file to get the list of defined vhosts + ServerConfiguration configuration = new ServerConfiguration(new File(_configFile.getParent() + "/config.xml")); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + // Make them all persistent i.e. Use DerbyMessageStore and + // test that it logs correctly. + for (String vhost : vhosts) + { + makeVirtualHostPersistent(vhost); + } + } + + /** + * Description: + * Persistent MessageStores will require space on disk to persist the data. + * This value will be logged on startup after the MessageStore has been + * created. + * Input: + * Default configuration + * Output: + * + * <date> MST-1002 : Store location : <path> + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. This must occur after MST-1001 + */ + public void testMessageStoreStoreLocation() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1002"); + + assertEquals("Each vhost did not close its store.", vhosts.size(), results.size()); + + for (int index = 0; index < results.size(); index++) + { + String result = getLogMessage(results, index);; + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertTrue("MST-1002 does not contain a store path" + getMessageString(result), + getMessageString(result).length() > 0); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + } + + /** + * Description: + * Persistent message stores may have state on disk that they must recover + * during startup. As the MessageStore starts up it will report that it is + * about to start the recovery process by logging MST-1004. This message + * will always be logged for persistent MessageStores. If there is no data + * to recover then there will be no subsequent recovery messages. + * Input: + * Default persistent configuration + * Output: + * <date> MST-1004 : Recovery Start + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. The MessageStore must have first logged a creation event. + */ + public void testMessageStoreRecoveryStart() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1004"); + + assertTrue("Each vhost did not close its store.", vhosts.size() <= results.size()); + + for (int index = 0; index < results.size(); index++) + { + String result = getLogMessage(results, index);; + + if (getMessageString(result).contains("Recovery Start :")) + { + //Don't test queue start recoveries + continue; + } + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertEquals("MST-1004 does have expected message", "Recovery Start", + getMessageString(result)); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + } + + /** + * Description: + * Once all persistent queues have been recovered and the MessageStore has completed all recovery it must logged that the recovery process has completed. + * Input: + * Default persistent configuration + * Output: + * + * <date> MST-1006 : Recovery Complete + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. This is the last message from the MessageStore during startup. + * 3. This must be proceeded by a MST-1006 Recovery Start. + */ + public void testMessageStoreRecoveryComplete() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1006"); + + assertTrue("Each vhost did not close its store.", vhosts.size() <= results.size()); + + for (int index = 0; index < results.size(); index++) + { + String result = getLogMessage(results, index); + + if (getMessageString(result).contains("Recovery Complete :")) + { + //Don't test queue start recoveries + continue; + } + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertEquals("MST-1006 does have expected message", "Recovery Complete", + getMessageString(result)); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + } + + /** + * Description: + * A persistent MessageStore may have data to recover from disk. The message store will use MST-1004 to report the start of recovery for a specific queue that it has previously persisted. + * Input: + * Default persistent configuration + * Output: + * + * <date> MST-1004 : Recovery Start : <queue.name> + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. This must occur after the recovery start MST-1004 has been logged. + */ + public void testMessageStoreQueueRecoveryStart() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1004 : Recovery Start :"); + + // We are only looking for the default queue defined in local host being + // recovered. If other tests have made queues in test then we want to + // exclude them here. + results = filterResultsByVirtualHost(results, "/localhost"); + + assertEquals("Recovered test queue not found.", 1, results.size()); + + String result = getLogMessage(results, 0); + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertTrue("MST-1006 does end with queue 'test-queue':" + getMessageString(result), + getMessageString(result).endsWith("test-queue")); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + + } + + /** + * Description: + * After the queue has been recovered the store will log that recovery has been completed. The MessageStore must not report further status about the recovery of this queue after this message. In addition every MST-1004 queue recovery start message must be matched with a MST-1006 recovery complete. + * Input: + * Default persistent configuration + * Output: + * + * <date> MST-1006 : Recovery Complete : <queue.name> + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. This must occur after the queue recovery start MST-1004 has been logged. + * 3. The queue.name is non-empty + * 4. The queue.name correlates with a previous recovery start + */ + public void testMessageStoreQueueRecoveryComplete() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1006 : Recovery Complete :"); + + // We are only looking for the default queue defined in local host being + // recovered. If other tests have made queues in test then we want to + // exclude them here. + results = filterResultsByVirtualHost(results, "/localhost"); + + assertEquals("Recovered test queue not found.", 1, results.size()); + + String result = getLogMessage(results, 0); + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertTrue("MST-1006 does end with queue 'test-queue':" + getMessageString(result), + getMessageString(result).endsWith("test-queue")); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + + results = findMatches("MST-1004 : Recovery Start : test-queue"); + + assertEquals("MST-1004 for test-queue not found", 1, results.size()); + } + + /** + * Description: + * A persistent queue must be persisted so that on recovery it can be restored independently of any messages that may be stored on it. This test verifies that the MessageStore will log that it has recovered 0 messages for persistent queues that do not have any messages. + * Input: + * + * 1. Default persistent configuration + * 2. Persistent queue with no messages enqueued + * Output: + * + * <date> MST-1005 : Recovered 0 messages for queue <queue.name> + * + * Validation Steps: + * 3. The MST ID is correct + * 4. This must occur after the queue recovery start MST-1004 has been logged. + * 5. The count is 0 + * 6. 'messages' is correctly printed + * 7. The queue.name is non-empty + */ + public void testMessageStoreQueueRecoveryCountEmpty() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + String queueName = getTestQueueName(); + + startBroker(); + Connection connetion = getConnection(); + Session session = connetion.createSession(false, Session.AUTO_ACKNOWLEDGE); + Queue queue = session.createQueue("direct://amq.direct/" + queueName + "/" + queueName + "?durable='true'"); + + session.createConsumer(queue).close(); + + // Stop the broker so that we can test recovery + stopBroker(); + + int COUNT = 0; + testDurableRecoveryCount(COUNT, queueName); + } + + /** + * Description: + * On recovery all the persistent messages that are stored on disk must be returned to the queue. MST-1005 will report the number of messages that have been recovered from disk. + * Input: + * + * 1. Default persistent configuration + * 2. Persistent queue with multiple messages enqueued + * Output: + * + * <date> MST-1005 : Recovered <count> messages for queue <queue.name> + * + * Validation Steps: + * 3. The MST ID is correct + * 4. This must occur after the queue recovery start MST-1004 has been logged. + * 5. The count is > 1 + * 6. 'messages' is correctly printed + * 7. The queue.name is non-empty + */ + public void testMessageStoreQueueRecoveryCountPlural() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + String queueName = getTestQueueName(); + + int COUNT = 10; + + testDurableRecoveryCount(COUNT, queueName); + } + + /** + * Send a set number of messages to a new durable queue, as specified. Then + * restart the broker and validate that they are restored. + * + * @param COUNT - the count to send + * @param queueName - the new queue name + * @throws Exception - if a problem occured. + */ + private void testDurableRecoveryCount(int COUNT, String queueName) throws Exception + { + startBroker(); + Connection connetion = getConnection(); + Session session = connetion.createSession(false, Session.AUTO_ACKNOWLEDGE); + Queue queue = session.createQueue("direct://amq.direct/" + queueName + "/" + queueName + "?durable='true'"); + + session.createConsumer(queue).close(); + + sendMessage(session, queue, COUNT); + try + { + connetion.close(); + + stopBroker(); + + // Clear our monitor + _monitor.reset(); + + startBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = configuration.getConfig().getList("virtualhosts.virtualhost.name"); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1004 : Recovery Start : " + queueName); + + assertEquals("Recovered test queue not found.", 1, results.size()); + + String result = getLogMessage(results, 0); + + validateMessageID("MST-1004", result); + + assertTrue("MST-1004 does end with queue '" + queueName + "':" + getMessageString(result), + getMessageString(result).endsWith(queueName)); + + results = waitAndFindMatches("MST-1005"); + + assertTrue("Insufficient MST-1005 logged.", results.size()>0); + + result = null; + + // If the first message is not our queue the second one will be + for(String resultEntry : results) + { + // Look for first match and set that to result + if (resultEntry.contains(queueName)) + { + result = getLog(resultEntry); + break; + } + } + + assertNotNull("MST-1005 entry for queue:" + queueName + ". Not found", result); + + // getSlize will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // To get the store class used in the configuration we need to know + // the virtualhost name, found above. AND + // the index that the virtualhost is within the configuration. + // we can retrive that from the vhosts list previously extracted. + String fullStoreName = configuration.getConfig().getString("virtualhosts.virtualhost(" + vhosts.indexOf(vhostName) + ")." + vhostName + ".store.class"); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertTrue("MST-1005 does end with queue 'test-queue':" + getMessageString(result), + getMessageString(result).endsWith(queueName)); + + assertTrue("MST-1005 does end show correct count:" + getMessageString(result), + getMessageString(result).contains("Recovered " + COUNT + " messages")); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + finally + { + //Ensure we attempt to drain the queue. + assertEquals("Unable to drain queue", COUNT, drainQueue(queue)); + } + } + +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DurableQueueLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DurableQueueLoggingTest.java new file mode 100644 index 0000000000..32adc49521 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/DurableQueueLoggingTest.java @@ -0,0 +1,307 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.qpid.AMQException; +import org.apache.qpid.client.AMQSession; +import org.apache.qpid.framing.AMQShortString; + +import javax.jms.Connection; +import javax.jms.JMSException; +import javax.jms.Queue; +import javax.jms.Session; +import javax.naming.NamingException; +import java.io.IOException; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +/** + * The Queue test suite validates that the follow log messages as specified in + * the Functional Specification. + * + * This suite of tests validate that the Queue messages occur correctly and + * according to the following format: + * + * QUE-1001 : Create : [AutoDelete] [Durable|Transient] [Priority:<levels>] [Owner:<name>] + */ +public class DurableQueueLoggingTest extends AbstractTestLogging +{ + protected String DURABLE = "Durable"; + protected String TRANSIENT = "Transient"; + protected boolean _durable; + + protected Connection _connection; + protected Session _session; + private static final String QUEUE_PREFIX = "QUE-"; + private static int PRIORITIES = 6; + + public void setUp() throws Exception + { + super.setUp(); + //Ensure we only have logs from our test + _monitor.reset(); + + _connection = getConnection(); + _session = _connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + _durable = true; + } + + /** + * Description: + * When a simple transient queue is created then a QUE-1001 create message + * is expected to be logged. + * Input: + * 1. Running broker + * 2. Persistent Queue is created from a client + * Output: + * + * <date> QUE-1001 : Create : Owner: '<name>' Durable + * + * Validation Steps: + * 3. The QUE ID is correct + * 4. The Durable tag is present in the message + * 5. The Owner is as expected + * + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + * @throws java.io.IOException + */ + public void testQueueCreateDurableExclusive() throws NamingException, JMSException, IOException + { + String queueName= getTestQueueName(); + // To force a queue Creation Event we need to create a consumer. + Queue queue = (Queue) _session.createQueue("direct://amq.direct/" + queueName + "/" + queueName + "?durable='" + _durable + "'&exclusive='true'"); + + _session.createConsumer(queue); + + List<String> results = waitForMesssage(); + + String clientID = _connection.getClientID(); + assertNotNull("clientID should not be null", clientID); + + validateQueueProperties(results, false, false, clientID); + } + + /** + * Description: + * When a simple transient queue is created then a QUE-1001 create message + * is expected to be logged. + * Input: + * 1. Running broker + * 2. Persistent Queue is created from a client + * Output: + * + * <date> QUE-1001 : Create : Owner: '<name>' Durable + * + * Validation Steps: + * 3. The QUE ID is correct + * 4. The Durable tag is present in the message + * 5. The Owner is as expected + * + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + * @throws java.io.IOException + */ + public void testQueueCreateDurable() throws NamingException, JMSException, IOException + { + String queueName = getTestQueueName(); + + // To force a queue Creation Event we need to create a consumer. + Queue queue = (Queue) _session.createQueue("direct://amq.direct/" + queueName + "/" + queueName + "?durable='" + _durable + "'"); + + _session.createConsumer(queue); + + List<String> results = waitForMesssage(); + + validateQueueProperties(results, false, false, null); + } + + /** + * Description: + * When a simple transient queue is created then a QUE-1001 create message + * is expected to be logged. + * Input: + * 1. Running broker + * 2. AutoDelete Persistent Queue is created from a client + * Output: + * + * <date> QUE-1001 : Create : Owner: '<name>' AutoDelete Durable + * + * Validation Steps: + * 3. The QUE ID is correct + * 4. The Durable tag is present in the message + * 5. The Owner is as expected + * 6. The AutoDelete tag is present in the message + * + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + * @throws java.io.IOException + */ + public void testQueueCreatePersistentAutoDelete() throws NamingException, JMSException, IOException + { + String queueName = getTestQueueName(); + // To force a queue Creation Event we need to create a consumer. + Queue queue = (Queue) _session.createQueue("direct://amq.direct/"+queueName+"/"+queueName+"?durable='"+_durable+"'&autodelete='true'"); + + _session.createConsumer(queue); + + List<String> results = waitForMesssage(); + + validateQueueProperties(results, false, true, null); + } + + /** + * Description: + * When a simple transient queue is created then a QUE-1001 create message + * is expected to be logged. + * Input: + * 1. Running broker + * 2. Persistent Queue is created from a client + * Output: + * + * <date> QUE-1001 : Create : Owner: '<name>' Durable Priority:<levels> + * + * Validation Steps: + * 3. The QUE ID is correct + * 4. The Durable tag is present in the message + * 5. The Owner is as expected + * 6. The Priority level is correctly set + * + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + * @throws java.io.IOException + */ + public void testCreateQueuePersistentPriority() throws NamingException, JMSException, IOException, AMQException + { + // To Create a Priority queue we need to use AMQSession specific code + final Map<String, Object> arguments = new HashMap<String, Object>(); + arguments.put("x-qpid-priorities", PRIORITIES); + // Need to create a queue that does not exist so use test name + final String queueName = getTestQueueName(); + ((AMQSession) _session).createQueue(new AMQShortString(queueName), false, _durable, false, arguments); + + Queue queue = (Queue) _session.createQueue("direct://amq.direct/"+queueName+"/"+queueName+"?durable='"+_durable+"'&autodelete='false'"); + + + //Need to create a Consumer to ensure that the log has had time to write + // as the above Create is Asynchronous + _session.createConsumer(queue); + + List<String> results = waitForMesssage(); + + // Only 1 Queue message should hav been logged + assertEquals("Result set size not as expected", 1, results.size()); + + validateQueueProperties(results, true, false, null); + } + + /** + * Description: + * When a simple transient queue is created then a QUE-1001 create message + * is expected to be logged. + * Input: + * 1. Running broker + * 2. AutoDelete Persistent Queue is created from a client + * Output: + * + * <date> QUE-1001 : Create : Owner: '<name>' Durable Priority:<levels> + * + * Validation Steps: + * 3. The QUE ID is correct + * 4. The Durable tag is present in the message + * 5. The Owner is as expected + * 6. The AutoDelete tag is present in the message + * 7. The Priority level is correctly set + * + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + * @throws java.io.IOException + */ + public void testCreateQueuePersistentAutoDeletePriority() throws NamingException, JMSException, IOException, AMQException + { + // To Create a Priority queue we need to use AMQSession specific code + final Map<String, Object> arguments = new HashMap<String, Object>(); + arguments.put("x-qpid-priorities", PRIORITIES); + // Need to create a queue that does not exist so use test name + final String queueName = getTestQueueName() + "-autoDeletePriority"; + ((AMQSession) _session).createQueue(new AMQShortString(queueName), true, _durable, false, arguments); + + Queue queue = (Queue) _session.createQueue("direct://amq.direct/"+queueName+"/"+queueName+"?durable='"+_durable+"'&autodelete='true'"); + + + //Need to create a Consumer to ensure that the log has had time to write + // as the above Create is Asynchronous + _session.createConsumer(queue); + + List<String> results = waitForMesssage(); + + validateQueueProperties(results, true, true, null); + } + + private List<String> waitForMesssage() throws IOException + { + // Validation + // Ensure we have received the QUE log msg. + waitForMessage("QUE-1001"); + + List<String> results = findMatches(QUEUE_PREFIX); + + // Only 1 Queue message should hav been logged + assertEquals("Result set size not as expected", 1, results.size()); + + return results; + } + + public void validateQueueProperties(List<String> results, boolean hasPriority, boolean hasAutodelete, String clientID) + { + String log = getLogMessage(results, 0); + + // Message Should be a QUE-1001 + validateMessageID("QUE-1001", log); + + // Queue is Durable + assertEquals(DURABLE + " keyword not correct in log entry", + _durable, fromMessage(log).contains(DURABLE)); + + assertEquals(TRANSIENT + " keyword not correct in log entry.", + !_durable, fromMessage(log).contains(TRANSIENT)); + + // Queue is Priority + assertEquals("Unexpected priority status:" + fromMessage(log), hasPriority, + fromMessage(log).contains("Priority: " + PRIORITIES)); + + // Queue is AutoDelete + assertEquals("Unexpected AutoDelete status:" + fromMessage(log), hasAutodelete, + fromMessage(log).contains("AutoDelete")); + + if(clientID != null) + { + assertTrue("Queue does not have correct owner value:" + fromMessage(log), + fromMessage(log).contains("Owner: " + clientID)); + } + else + { + assertFalse("Queue should not contain Owner tag:" + fromMessage(log), + fromMessage(log).contains("Owner")); + } + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ExchangeLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ExchangeLoggingTest.java new file mode 100644 index 0000000000..1e48f34f99 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ExchangeLoggingTest.java @@ -0,0 +1,217 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.qpid.client.AMQConnection; +import org.apache.qpid.client.AMQSession_0_10; +import org.apache.qpid.framing.AMQFrame; +import org.apache.qpid.framing.AMQShortString; +import org.apache.qpid.framing.ExchangeDeleteBody; +import org.apache.qpid.framing.ExchangeDeleteOkBody; +import org.apache.qpid.framing.amqp_8_0.MethodRegistry_8_0; + +import javax.jms.Connection; +import javax.jms.JMSException; +import javax.jms.Queue; +import javax.jms.Session; +import java.io.IOException; +import java.util.List; + +/** + * Exchange + * + * The Exchange test suite validates that the follow log messages as specified in the Functional Specification. + * + * This suite of tests validate that the Exchange messages occur correctly and according to the following format: + * + * EXH-1001 : Create : [Durable] Type:<value> Name:<value> + * EXH-1002 : Deleted + */ +public class ExchangeLoggingTest extends AbstractTestLogging +{ + + static final String EXH_PREFIX = "EXH-"; + + Connection _connection; + Session _session; + Queue _queue; + String _name; + String _type; + + @Override + public void setUp() throws Exception + { + super.setUp(); + + _connection = getConnection(); + + _session = _connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + _type = "direct"; + _name = getTestQueueName()+ "-exchange"; + + _queue = _session.createQueue(_type + "://" + _name + "/queue/queue"); + + } + + /** + * Description: + * When a durable exchange is created an EXH-1001 message is logged with the Durable tag. This will be the first message from this exchange. + * Input: + * + * 1. Running broker + * 2. Client requests a durable exchange be created. + * Output: + * + * <date> EXH-1001 : Create : Durable Type:<value> Name:<value> + * + * Validation Steps: + * 3. The EXH ID is correct + * 4. The Durable tag is present in the message + */ + + public void testExchangeCreateDurable() throws JMSException, IOException + { + // The client cannot create durable exchanges lets just look at the + // ones the broker creates at startup. + + // They should all be durable + + // Ensure we have received the EXH log msg. + waitForMessage("EXH-1001"); + + List<String> results = findMatches(EXH_PREFIX); + + assertTrue("No Results found for Exchange.", results.size()>0); + + validateExchangeCreate(results, true, false); + } + + /** + * Description: + * When an exchange is created an EXH-1001 message is logged. This will be the first message from this exchange. + * Input: + * + * 1. Running broker + * 2. Client requests an exchange be created. + * Output: + * + * <date> EXH-1001 : Create : Type:<value> Name:<value> + * + * Validation Steps: + * 3. The EXH ID is correct + */ + public void testExchangeCreate() throws JMSException, IOException + { + //Ignore broker startup messages + _monitor.reset(); + + _session.createConsumer(_queue); + // Ensure we have received the EXH log msg. + waitForMessage("EXH-1001"); + + List<String> results = findMatches(EXH_PREFIX); + + assertEquals("Result set larger than expected.", 1, results.size()); + + validateExchangeCreate(results, false, true); + } + + private void validateExchangeCreate(List<String> results, boolean durable, boolean checkNameAndType) + { + String log = getLogMessage(results, 0); + String message = getMessageString(fromMessage(log)); + + validateMessageID("EXH-1001", log); + + assertTrue("Log Message does not start with create:" + message, + message.startsWith("Create")); + + assertEquals("Unexpected Durable state:" + message, durable, + message.contains("Durable")); + + if(checkNameAndType) + { + assertTrue("Log Message does not contain Type:" + message, + message.contains("Type: " + _type)); + assertTrue("Log Message does not contain Name:" + message, + message.contains("Name: " + _name)); + } + } + + /** + * Description: + * An Exchange can be deleted through an AMQP ExchangeDelete method. When this is successful an EXH-1002 Delete message will be logged. This will be the last message from this exchange. + * Input: + * + * 1. Running broker + * 2. A new Exchange has been created + * 3. Client requests that the new exchange be deleted. + * Output: + * + * <date> EXH-1002 : Deleted + * + * Validation Steps: + * 4. The EXH ID is correct + * 5. There is a corresponding EXH-1001 Create message logged. + */ + public void testExchangeDelete() throws Exception, IOException + { + //Ignore broker startup messages + _monitor.reset(); + + //create the exchange by creating a consumer + _session.createConsumer(_queue); + + //now delete the exchange + if(isBroker010()) + { + ((AMQSession_0_10) _session).sendExchangeDelete(_name, false); + } + else + { + MethodRegistry_8_0 registry = new MethodRegistry_8_0(); + + ExchangeDeleteBody body = registry.createExchangeDeleteBody(0, new AMQShortString(_name), false, true); + + AMQFrame exchangeDeclare = body.generateFrame(0); + + ((AMQConnection) _connection).getProtocolHandler().syncWrite(exchangeDeclare, ExchangeDeleteOkBody.class); + } + + //Wait and ensure we get our last EXH-1002 msg + waitForMessage("EXH-1002"); + + List<String> results = findMatches(EXH_PREFIX); + + assertEquals("Result set larger than expected.", 2, results.size()); + + validateExchangeCreate(results, false, false); + + String log = getLogMessage(results, 1); + validateMessageID("EXH-1002", log); + + String message = getMessageString(fromMessage(log)); + assertEquals("Log Message not as expected", "Deleted", message); + + } + +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ManagementLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ManagementLoggingTest.java new file mode 100644 index 0000000000..595c0d5f35 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/ManagementLoggingTest.java @@ -0,0 +1,305 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import junit.framework.AssertionFailedError; + +import org.apache.qpid.util.LogMonitor; + +import java.util.List; +import java.io.File; + +/** + * Management Console Test Suite + * + * The Management Console test suite validates that the follow log messages as specified in the Functional Specification. + * + * This suite of tests validate that the management console messages occur correctly and according to the following format: + * + * MNG-1001 : Startup + * MNG-1002 : Starting : <service> : Listening on port <Port> + * MNG-1003 : Shutting down : <service> : port <Port> + * MNG-1004 : Ready + * MNG-1005 : Stopped + * MNG-1006 : Using SSL Keystore : <path> + */ +public class ManagementLoggingTest extends AbstractTestLogging +{ + private static final String MNG_PREFIX = "MNG-"; + + public void setUp() throws Exception + { + setLogMessagePrefix(); + + // We either do this here or have a null check in tearDown. + // As when this test is run against profiles other than java it will NPE + _monitor = new LogMonitor(_outputFile); + //We explicitly do not call super.setUp as starting up the broker is + //part of the test case. + + } + + /** + * Description: + * Using the startup configuration validate that the management startup + * message is logged correctly. + * Input: + * Standard configuration with management enabled + * Output: + * + * <date> MNG-1001 : Startup + * + * Constraints: + * This is the FIRST message logged by MNG + * Validation Steps: + * + * 1. The BRK ID is correct + * 2. This is the FIRST message logged by MNG + */ + public void testManagementStartupEnabled() throws Exception + { + // This test only works on external java brokers due to the fact that + // Management is disabled on InVM brokers. + if (isJavaBroker() && isExternalBroker()) + { + startBrokerAndCreateMonitor(true, false); + + // Ensure we have received the MNG log msg. + waitForMessage("MNG-1001"); + + List<String> results = findMatches(MNG_PREFIX); + + try + { + // Validation + + assertTrue("MNGer message not logged", results.size() > 0); + + String log = getLogMessage(results, 0); + + //1 + validateMessageID("MNG-1001", log); + + //2 + //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()); + + //3 + assertEquals("Startup log message is not 'Startup'.", "Startup", + getMessageString(log)); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + throw afe; + } + } + } + + /** + * Description: + * Verify that when management is disabled in the configuration file the + * startup message is not logged. + * Input: + * Standard configuration with management disabled + * Output: + * NO MNG messages + * Validation Steps: + * + * 1. Validate that no MNG messages are produced. + */ + public void testManagementStartupDisabled() throws Exception + { + // This test only works on external java brokers due to the fact that + // Management is disabled on InVM brokers. + if (isJavaBroker() && isExternalBroker()) + { + startBrokerAndCreateMonitor(false, false); + + List<String> results = findMatches(MNG_PREFIX); + try + { + // Validation + + assertEquals("MNGer messages logged", 0, results.size()); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + throw afe; + } + } + } + + /** + * The two MNG-1002 messages are logged at the same time so lets test them + * at the same time. + * + * Description: + * Using the default configuration validate that the RMI Registry socket is + * correctly reported as being opened + * + * Input: + * The default configuration file + * Output: + * + * <date> MESSAGE MNG-1002 : Starting : RMI Registry : Listening on port 8999 + * + * Constraints: + * The RMI ConnectorServer and Registry log messages do not have a prescribed order + * Validation Steps: + * + * 1. The MNG ID is correct + * 2. The specified port is the correct '8999' + * + * Description: + * Using the default configuration validate that the RMI ConnectorServer + * socket is correctly reported as being opened + * + * Input: + * The default configuration file + * Output: + * + * <date> MESSAGE MNG-1002 : Starting : RMI ConnectorServer : Listening on port 9099 + * + * Constraints: + * The RMI ConnectorServer and Registry log messages do not have a prescribed order + * Validation Steps: + * + * 1. The MNG ID is correct + * 2. The specified port is the correct '9099' + */ + public void testManagementStartupRMIEntries() throws Exception + { + // This test only works on external java brokers due to the fact that + // Management is disabled on InVM brokers. + if (isJavaBroker() && isExternalBroker()) + { + startBrokerAndCreateMonitor(true, false); + + List<String> results = waitAndFindMatches("MNG-1002"); + try + { + // Validation + + //There will be 4 startup messages (two via SystemOut, and two via Log4J) + assertEquals("Unexpected MNG-1002 message count", 4, results.size()); + + String log = getLogMessage(results, 0); + + //1 + validateMessageID("MNG-1002", log); + + //Check the RMI Registry port is as expected + int mPort = getPort() + (DEFAULT_MANAGEMENT_PORT - DEFAULT_PORT); + assertTrue("RMI Registry port not as expected(" + mPort + ").:" + getMessageString(log), + getMessageString(log).endsWith(String.valueOf(mPort))); + + log = getLogMessage(results, 2); + + //1 + validateMessageID("MNG-1002", log); + + // We expect the RMI Registry port (the defined 'management port') to be + // 100 lower than the JMX RMIConnector Server Port (the actual JMX server) + int jmxPort = mPort + 100; + assertTrue("JMX RMIConnectorServer port not as expected(" + jmxPort + ").:" + getMessageString(log), + getMessageString(log).endsWith(String.valueOf(jmxPort))); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + throw afe; + } + } + } + + /** + * Description: + * Using the default configuration with SSL enabled for the management port the SSL Keystore path should be reported via MNG-1006 + * Input: + * Management SSL enabled default configuration. + * Output: + * + * <date> MESSAGE MNG-1006 : Using SSL Keystore : test_resources/ssl/keystore.jks + * + * Validation Steps: + * + * 1. The MNG ID is correct + * 2. The keystore path is as specified in the configuration + */ + public void testManagementStartupSSLKeystore() throws Exception + { + // This test only works on external java brokers due to the fact that + // Management is disabled on InVM brokers. + if (isJavaBroker() && isExternalBroker()) + { + startBrokerAndCreateMonitor(true, true); + + List<String> results = waitAndFindMatches("MNG-1006"); + try + { + // Validation + + assertTrue("MNGer message not logged", results.size() > 0); + + String log = getLogMessage(results, 0); + + //1 + validateMessageID("MNG-1006", log); + + // 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()); + + // Validate the keystore path is as expected + assertTrue("SSL Keystore entry expected.:" + getMessageString(log), + getMessageString(log).endsWith(new File(getConfigurationStringProperty("management.ssl.keyStorePath")).getName())); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + throw afe; + } + } + + } + + private void startBrokerAndCreateMonitor(boolean managementEnabled, boolean useManagementSSL) throws Exception + { + //Ensure management is on + setConfigurationProperty("management.enabled", String.valueOf(managementEnabled)); + + if(useManagementSSL) + { + // This test requires we have an ssl connection + setConfigurationProperty("management.ssl.enabled", "true"); + } + + startBroker(); + + // Now we can create the monitor as _outputFile will now be defined + _monitor = new LogMonitor(_outputFile); + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/MemoryMessageStoreLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/MemoryMessageStoreLoggingTest.java new file mode 100644 index 0000000000..34d9e1f057 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/MemoryMessageStoreLoggingTest.java @@ -0,0 +1,186 @@ +/* +* +* Licensed to the Apache Software Foundation (ASF) under one +* or more contributor license agreements. See the NOTICE file +* distributed with this work for additional information +* regarding copyright ownership. The ASF licenses this file +* to you under the Apache License, Version 2.0 (the +* "License"); you may not use this file except in compliance +* with the License. You may obtain a copy of the License at +* +* http://www.apache.org/licenses/LICENSE-2.0 +* +* Unless required by applicable law or agreed to in writing, +* software distributed under the License is distributed on an +* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +* KIND, either express or implied. See the License for the +* specific language governing permissions and limitations +* under the License. +* +*/ +package org.apache.qpid.server.logging; + +import java.util.Arrays; +import java.util.List; + +import org.apache.qpid.server.configuration.ServerConfiguration; +import org.apache.qpid.server.logging.subjects.AbstractTestLogSubject; +import org.apache.qpid.util.LogMonitor; + +/** + * The MessageStore test suite validates that the follow log messages as + * specified in the Functional Specification. + * + * This suite of tests validate that the MessageStore messages occur correctly + * and according to the following format: + * + * MST-1001 : Created : <name> + * MST-1003 : Closed + * + * NOTE: Only for Persistent Stores + * MST-1002 : Store location : <path> + * MST-1004 : Recovery Start [: <queue.name>] + * MST-1005 : Recovered <count> messages for queue <queue.name> + * MST-1006 : Recovery Complete [: <queue.name>] + */ +public class MemoryMessageStoreLoggingTest extends AbstractTestLogging +{ + protected static final String MESSAGES_STORE_PREFIX = "MST-"; + + public void setUp() throws Exception + { + //We explicitly do not call super.setUp as starting up the broker is + //part of the test case. + // So we have to make the new Log Monitor here + + _monitor = new LogMonitor(_outputFile); + } + + /** + * Description: + * During Virtualhost startup a MessageStore will be created. The first MST + * message that must be logged is the MST-1001 MessageStore creation. + * Input: + * Default configuration + * Output: + * <date> MST-1001 : Created : <name> + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. The <name> is the correct MessageStore type as specified in the Default configuration + * + * @throws Exception caused by broker startup + */ + public void testMessageStoreCreation() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + super.setUp(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + String log = getLogMessage(results, 0); + //1 + assertEquals("MST-1001 is not the first MST message", "MST-1001", getMessageID(fromMessage(log))); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1001"); + + // Load VirtualHost list from file. + List<String> vhosts = Arrays.asList(getServerConfig().getVirtualHosts()); + + assertEquals("Each vhost did not create a store.", vhosts.size(), results.size()); + + for (int index = 0; index < results.size(); index++) + { + String result = getLogMessage(results, index); + + // getSlice will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // Get the store class used in the configuration for the virtualhost. + String fullStoreName = getServerConfig().getVirtualHostConfig(vhostName).getMessageStoreClass(); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertTrue("MST-1001 does not contains correct store name:" + + storeName + ":" + result, getMessageString(result).endsWith(storeName)); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + } + + /** + * Description: + * During shutdown the MessageStore will also cleanly close. When this has + * completed a MST-1003 closed message will be logged. No further messages + * from this MessageStore will be logged after this message. + * + * Input: + * Default configuration + * Output: + * <date> MST-1003 : Closed + * + * Validation Steps: + * + * 1. The MST ID is correct + * 2. This is teh last log message from this MessageStore + * + * @throws Exception caused by broker startup + */ + public void testMessageStoreClose() throws Exception + { + assertLoggingNotYetOccured(MESSAGES_STORE_PREFIX); + + super.setUp(); + + //Stop the broker so we get the close messages. + stopBroker(); + + List<String> results = waitAndFindMatches(MESSAGES_STORE_PREFIX); + + // Validation + + assertTrue("MST messages not logged", results.size() > 0); + + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = Arrays.asList(configuration.getVirtualHosts()); + + //Validate each vhost logs a creation + results = waitAndFindMatches("MST-1003"); + + assertEquals("Each vhost did not close its store.", vhosts.size(), results.size()); + + for (int index = 0; index < results.size(); index++) + { + String result = getLogMessage(results, index); + + // getSlice will return extract the vhost from vh(/test) -> '/test' + // so remove the '/' to get the name + String vhostName = AbstractTestLogSubject.getSlice("vh", result).substring(1); + + // Get the store class used in the configuration for the virtualhost. + String fullStoreName = configuration.getVirtualHostConfig(vhostName).getMessageStoreClass(); + + // Get the Simple class name from the expected class name of o.a.q.s.s.MMS + String storeName = fullStoreName.substring(fullStoreName.lastIndexOf(".") + 1); + + assertEquals("MST-1003 does not close:", + "Closed", getMessageString(result)); + + assertEquals("The store name does not match expected value", + storeName, AbstractTestLogSubject.getSlice("ms", fromSubject(result))); + } + } + +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/QueueLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/QueueLoggingTest.java new file mode 100644 index 0000000000..b8a42c0ab3 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/QueueLoggingTest.java @@ -0,0 +1,183 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import org.apache.qpid.client.AMQSession; +import org.apache.qpid.client.failover.FailoverException; +import org.apache.qpid.server.logging.subjects.AbstractTestLogSubject; +import org.apache.qpid.framing.AMQShortString; +import org.apache.qpid.AMQException; + +import javax.jms.Connection; +import javax.jms.Session; +import javax.jms.Queue; +import javax.jms.JMSException; +import javax.naming.NamingException; +import java.util.List; +import java.io.IOException; + +/** + * The Queue test suite validates that the follow log messages as specified in + * the Functional Specification. + * + * This suite of tests validate that the Queue messages occur correctly and + * according to the following format: + * + * QUE-1002 : Deleted + */ +public class QueueLoggingTest extends AbstractTestLogging +{ + protected Connection _connection; + protected Session _session; + private static final String QUEUE_PREFIX = "QUE-"; + + public void setUp() throws Exception + { + super.setUp(); + //Remove broker startup logging messages + _monitor.reset(); + + _connection = getConnection(); + _session = _connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + } + + /** + * Description: + * An explict QueueDelete request must result in a QUE-1002 Deleted message + * being logged. This can be done via an explict AMQP QueueDelete method. + * Input: + * + * 1. Running Broker + * 2. Queue created on the broker with no subscribers + * 3. Client requests the queue be deleted via a QueueDelete + * Output: + * + * <date> QUE-1002 : Deleted + * + * Validation Steps: + * + * 4. The QUE ID is correct + * + * @throws java.io.IOException + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + */ + public void testQueueDelete() throws NamingException, JMSException, IOException, FailoverException, AMQException + { + // To force a queue Creation Event we need to create a consumer. + Queue queue = _session.createQueue(getTestQueueName()); + + _session.createConsumer(queue); + + // Delete Queue + ((AMQSession)_session).sendQueueDelete(new AMQShortString(queue.getQueueName())); + + //Perform a synchronous action to ensure that the above log will be on disk + _session.close(); + + // Validation + //Ensure that we wait for the QUE log message + waitAndFindMatches("QUE-1002"); + + List<String> results = findMatches(QUEUE_PREFIX); + + // Only 1 Queue message should hav been logged + assertEquals("Result set size not as expected", 2, results.size()); + + String log = getLogMessage(results, 0); + + // Message Should be a QUE-1001 + validateMessageID("QUE-1001", log); + + String createdQueueName = AbstractTestLogSubject.getSlice("qu", fromSubject(log)); + + log = getLogMessage(results, 1); + // Message Should be a QUE-1002 + validateMessageID("QUE-1002", log); + + assertEquals("Log Message is incorrect ", "Deleted", getMessageString(fromMessage(log))); + + assertEquals("Queue Delete not for created queue:", createdQueueName, + AbstractTestLogSubject.getSlice("qu", fromSubject(log))); + } + + + /** + * Description: + * An explict QueueDelete request must result in a QUE-1002 Deleted message + * being logged. This can be done via an explict AMQP QueueDelete method. + * Input: + * + * 1. Running Broker + * 2. Queue created on the broker with no subscribers + * 3. Client creates a temporary queue then disconnects + * Output: + * + * <date> QUE-1002 : Deleted + * + * Validation Steps: + * + * 4. The QUE ID is correct + * + * @throws java.io.IOException + * @throws javax.jms.JMSException + * @throws javax.naming.NamingException + */ + public void testQueueAutoDelete() throws NamingException, JMSException, IOException + { + // Create a temporary queue so that when we consume from it and + // then close the consumer it will be autoDeleted. + _session.createConsumer(_session.createTemporaryQueue()).close(); + + if(isBroker010()) + { + //auto-delete is at session close for 0-10 + _session.close(); + } + + // Validation + //Ensure that we wait for the QUE log message + waitAndFindMatches("QUE-1002"); + + List<String> results = findMatches(QUEUE_PREFIX); + + // Only 1 Queue message should hav been logged + assertEquals("Result set size not as expected", 2, results.size()); + + String log = getLogMessage(results, 0); + + // Message Should be a QUE-1001 + validateMessageID("QUE-1001", log); + + String createdQueueName = AbstractTestLogSubject.getSlice("qu", fromSubject(log)); + + log = getLogMessage(results, 1); + // Message Should be a QUE-1002 + validateMessageID("QUE-1002", log); + + assertEquals("Log Message is incorrect ", "Deleted", getMessageString(fromMessage(log))); + + assertEquals("Queue Delete not for created queue:", createdQueueName, + AbstractTestLogSubject.getSlice("qu", fromSubject(log))); + + } + +}
\ No newline at end of file diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/SubscriptionLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/SubscriptionLoggingTest.java new file mode 100644 index 0000000000..6e156f091e --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/SubscriptionLoggingTest.java @@ -0,0 +1,458 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +import junit.framework.AssertionFailedError; +import org.apache.qpid.client.AMQConnection; + +import javax.jms.Connection; +import javax.jms.JMSException; +import javax.jms.MessageConsumer; +import javax.jms.Queue; +import javax.jms.Session; +import javax.jms.Topic; +import javax.jms.Message; +import java.io.IOException; +import java.util.List; + +/** + * Subscription + * + * The Subscription test suite validates that the follow log messages as specified in the Functional Specification. + * + * This suite of tests validate that the Subscription messages occur correctly and according to the following format: + * + * SUB-1001 : Create : [Durable] [Arguments : <key=value>] + * SUB-1002 : Close + * SUB-1003 : State : <state> + */ +public class SubscriptionLoggingTest extends AbstractTestLogging +{ + static final String SUB_PREFIX = "SUB-"; + + Connection _connection; + Session _session; + Queue _queue; + Topic _topic; + + @Override + public void setUp() throws Exception + { + super.setUp(); + //Remove broker startup logging messages + _monitor.reset(); + + _connection = getConnection(); + + _session = _connection.createSession(false, Session.AUTO_ACKNOWLEDGE); + + _queue = (Queue) getInitialContext().lookup(QUEUE); + _topic = (Topic) getInitialContext().lookup(TOPIC); + } + + /** + * Description: + * When a Subscription is created it will be logged. This test validates that Subscribing to a transient queue is correctly logged. + * Input: + * + * 1. Running Broker + * 2. Create a new Subscription to a transient queue/topic. + * Output: 6 + * + * <date> SUB-1001 : Create + * + * Validation Steps: + * 3. The SUB ID is correct + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionCreate() throws JMSException, IOException + { + _session.createConsumer(_queue); + + //Validate + + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1001"); + + List<String> results = findMatches(SUB_PREFIX); + + assertEquals("Result set larger than expected.", 1, results.size()); + + String log = getLogMessage(results, 0); + + validateMessageID("SUB-1001", log); + + assertEquals("Log Message not as expected", "Create", getMessageString(fromMessage(log))); + } + + /** + * Description: + * The creation of a Durable Subscription, such as a JMS DurableTopicSubscriber will result in an extra Durable tag being included in the Create log message + * Input: + * + * 1. Running Broker + * 2. Creation of a JMS DurableTopicSubiber + * Output: + * + * <date> SUB-1001 : Create : Durable + * + * Validation Steps: + * 3. The SUB ID is correct + * 4. The Durable tag is present in the message + * NOTE: A Subscription is not Durable, the queue it consumes from is. + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionCreateDurable() throws JMSException, IOException + { + _session.createDurableSubscriber(_topic, getName()); + + //Validate + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1001"); + + List<String> results = findMatches(SUB_PREFIX); + + assertEquals("Result set not as expected.", 1, results.size()); + + String log = getLogMessage(results, 0); + + validateMessageID("SUB-1001", log); + + String message = getMessageString(fromMessage(log)); + assertTrue("Durable not on log message:" + message, message.contains("Durable")); + } + + /** + * Description: + * The creation of a QueueBrowser will provides a number arguments and so should form part of the SUB-1001 Create message. + * Input: + * + * 1. Running Broker + * 2. Java Client creates a QueueBroweser + * Output: + * + * <date> SUB-1001 : Create : Arguments : <key=value> + * + * Validation Steps: + * 3. The SUB ID is correct + * 4. The Arguments are present in the message + * 5. Arguments keys include AutoClose and Browser. + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionCreateQueueBrowser() throws JMSException, IOException + { + _session.createBrowser(_queue); + + //Validate + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1001"); + + List<String> results = findMatches(SUB_PREFIX); + + assertEquals("Result set larger than expected.", 2, results.size()); + + String log = getLogMessage(results, 0); + + validateMessageID("SUB-1001", log); + + String message = getMessageString(fromMessage(log)); + assertTrue("Browser not on log message:" + message, message.contains("Browser")); + if(!isBroker010()) + { + assertTrue("AutoClose not on log message:" + message, message.contains("AutoClose")); + } + + // Beacause it is an auto close and we have no messages on the queue we + // will get a close message + log = getLogMessage(results, 1); + validateMessageID("SUB-1002", log); + + } + + /** + * Description: + * The creation of a Subscriber with a JMS Selector will result in the Argument field being populated. These argument key/value pairs are then shown in the log message. + * Input: + * + * 1. Running Broker + * 2. Subscriber created with a JMS Selector. + * Output: + * + * <date> SUB-1001 : Create : Arguments : <key=value> + * + * Validation Steps: + * 3. The SUB ID is correct + * 4. Argument tag is present in the message + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionCreateWithArguments() throws JMSException, IOException + { + final String SELECTOR = "Selector='True'"; + _session.createConsumer(_queue, SELECTOR); + + //Validate + + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1001"); + + List<String> results = findMatches(SUB_PREFIX); + + assertEquals("Result set larger than expected.", 1, results.size()); + + String log = getLogMessage(results, 0); + + validateMessageID("SUB-1001", log); + + String message = getMessageString(fromMessage(log)); + assertTrue("Selector not on log message:" + message, message.contains(SELECTOR)); + } + + /** + * Description: + * The final combination of SUB-1001 Create messages involves the creation of a Durable Subscription that also contains a set of Arguments, such as those provided via a JMS Selector. + * Input: + * + * 1. Running Broker + * 2. Java Client creates a Durable Subscription with Selector + * Output: + * + * <date> SUB-1001 : Create : Durable Arguments : <key=value> + * + * Validation Steps: + * 3. The SUB ID is correct + * 4. The tag Durable is present in the message + * 5. The Arguments are present in the message + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionCreateDurableWithArguments() throws JMSException, IOException + { + final String SELECTOR = "Selector='True'"; + _session.createDurableSubscriber(_topic, getName(), SELECTOR, false); + + //Validate + + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1001"); + + List<String> results = findMatches(SUB_PREFIX); + + assertEquals("Result set larger than expected.", 1, results.size()); + + String log = getLogMessage(results, 0); + + validateMessageID("SUB-1001", log); + + String message = getMessageString(fromMessage(log)); + assertTrue("Durable not on log message:" + message, message.contains("Durable")); + assertTrue("Selector not on log message:" + message, message.contains(SELECTOR)); + } + + /** + * Description: + * When a Subscription is closed it will log this so that it can be correlated with the Create. + * Input: + * + * 1. Running Broker + * 2. Client with a subscription. + * 3. The subscription is then closed. + * Output: + * + * <date> SUB-1002 : Close + * + * Validation Steps: + * 1. The SUB ID is correct + * 2. There must be a SUB-1001 Create message preceding this message + * 3. This must be the last message from the given Subscription + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionClose() throws JMSException, IOException + { + _session.createConsumer(_queue).close(); + + //Validate + //Ensure that we wait for the SUB log message + waitAndFindMatches("SUB-1002"); + + List<String> results = findMatches(SUB_PREFIX); + + //3 + assertEquals("Result set larger than expected.", 2, results.size()); + + // 2 + String log = getLogMessage(results, 0); + validateMessageID("SUB-1001", log); + // 1 + log = getLogMessage(results, 1); + validateMessageID("SUB-1002", log); + + String message = getMessageString(fromMessage(log)); + assertEquals("Log message is not close", "Close", message); + + } + + /** + * Description: + * When a Subscription fills its prefetch it will become suspended. This + * will be logged as a SUB-1003 message. + * Input: + * + * 1. Running broker + * 2. Message Producer to put more data on the queue than the client's prefetch + * 3. Client that ensures that its prefetch becomes full + * Output: + * + * <date> SUB-1003 : State : <state> + * + * Validation Steps: + * 1. The SUB ID is correct + * 2. The state is correct + * + * @throws java.io.IOException - if there is a problem getting the matches + * @throws javax.jms.JMSException - if there is a problem creating the consumer + */ + public void testSubscriptionSuspend() throws Exception, IOException + { + //Close session with large prefetch + _connection.createSession(false, Session.AUTO_ACKNOWLEDGE).close(); + + int PREFETCH = 15; + + //Create new session with small prefetch + _session = ((AMQConnection) _connection).createSession(true, Session.SESSION_TRANSACTED, PREFETCH); + + MessageConsumer consumer = _session.createConsumer(_queue); + + _connection.start(); + + //Start the dispatcher & Unflow the channel. + consumer.receiveNoWait(); + + //Fill the prefetch and two extra so that our receive bellow allows the + // subscription to become active + // Previously we set this to 17 so that it would return to a suspended + // state. However, testing has shown that the state change can occur + // sufficiently quickly that logging does not occur consistently enough + // for testing. + int SEND_COUNT = 16; + sendMessage(_session, _queue, SEND_COUNT); + _session.commit(); + // Retreive the first message, and start the flow of messages + Message msg = consumer.receive(1000); + assertNotNull("First message not retreived", msg); + _session.commit(); + + // Drain the queue to ensure there is time for the ACTIVE log message + // Check that we can received all the messages + int receivedCount = 0; + while (msg != null) + { + receivedCount++; + msg = consumer.receive(1000); + _session.commit(); + } + + //Validate we received all the messages + assertEquals("Not all sent messages received.", SEND_COUNT, receivedCount); + + // Fill the queue again to suspend the consumer + sendMessage(_session, _queue, SEND_COUNT); + _session.commit(); + + //Validate + List<String> results = waitAndFindMatches("SUB-1003"); + + try + { + // Validation expects three messages. + // The Actor can be any one of the following depending on the exactly what is going on on the broker. + // Ideally we would test that we can get all of them but setting up + // the timing to do this in a consistent way is not benefitial. + // Ensuring the State is as expected is sufficient. +// INFO - MESSAGE [vh(/test)/qu(example.queue)] [sub:6(qu(example.queue))] SUB-1003 : State : +// INFO - MESSAGE [con:6(guest@anonymous(26562441)/test)/ch:3] [sub:6(qu(example.queue))] SUB-1003 : State : +// INFO - MESSAGE [sub:6(vh(test)/qu(example.queue))] [sub:6(qu(example.queue))] SUB-1003 : State : + + assertEquals("Result set not expected size:", 3, results.size()); + + // Validate Initial Suspension + String expectedState = "SUSPENDED"; + String log = getLogMessage(results, 0); + validateSubscriptionState(log, expectedState); + + // After being suspended the subscription should become active. + expectedState = "ACTIVE"; + log = getLogMessage(results, 1); + validateSubscriptionState(log, expectedState); + + // Validate that it was re-suspended + expectedState = "SUSPENDED"; + log = getLogMessage(results, 2); + validateSubscriptionState(log, expectedState); + // We only need validate the state. + } + catch (AssertionFailedError afe) + { + System.err.println("Log Dump:"); + for (String log : results) + { + System.err.println(log); + } + throw afe; + } + _connection.close(); + + //Ensure the queue is drained before the test ends + drainQueue(_queue); + + } + + /** + * Validate that the given log statement is a well formatted SUB-1003 + * message. That means the ID and expected state are correct. + * + * @param log the log to test + * @param expectedState the state that should be logged. + */ + private void validateSubscriptionState(String log, String expectedState) + { + validateMessageID("SUB-1003", log); + String logMessage = getMessageString(fromMessage(log)); + assertTrue("Log Message does not start with 'State'" + logMessage, + logMessage.startsWith("State")); + + assertTrue("Log Message does not have expected State of '" + + expectedState + "'" + logMessage, + logMessage.endsWith(expectedState)); + } + +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/TransientQueueLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/TransientQueueLoggingTest.java new file mode 100644 index 0000000000..29f74c5818 --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/TransientQueueLoggingTest.java @@ -0,0 +1,30 @@ +/* + * + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + */ +package org.apache.qpid.server.logging; + +public class TransientQueueLoggingTest extends DurableQueueLoggingTest +{ + public void setUp() throws Exception + { + super.setUp(); + _durable = false; + } +} diff --git a/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/VirtualHostLoggingTest.java b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/VirtualHostLoggingTest.java new file mode 100644 index 0000000000..a23e40ecce --- /dev/null +++ b/qpid/java/systests/src/main/java/org/apache/qpid/server/logging/VirtualHostLoggingTest.java @@ -0,0 +1,134 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + * + * + */ + +package org.apache.qpid.server.logging; + +import java.util.Arrays; +import java.util.List; + +import junit.framework.AssertionFailedError; + +import org.apache.qpid.server.configuration.ServerConfiguration; + +/** + * Virtualhost Test Cases + * The virtualhost test suite validates that the follow log messages as specified in the Functional Specification. + * <p/> + * This suite of tests validate that the management console messages occur correctly and according to the following format: + * <p/> + * VHT-1001 : Created : <name> + * VHT-1002 : Work directory : <path> + * VHT-1003 : Closed + */ +public class VirtualHostLoggingTest extends AbstractTestLogging +{ + private static final String VHT_PREFIX = "VHT-"; + + /** + * Description: + * Testing can be performed using the default configuration. The goal is to validate that for each virtualhost defined in the configuration file a VHT-1001 Created message is provided. + * Input: + * The default configuration file + * Output: + * <p/> + * <date> VHT-1001 : Created : <name> + * Validation Steps: + * <p/> + * The VHT ID is correct + * A VHT-1001 is printed for each virtualhost defined in the configuration file. + * This must be the first message for the specified virtualhost. + * + * @throws Exception caused by broker startup + */ + public void testVirtualhostCreation() throws Exception + { + //Wait for the correct VHT message to arrive. + waitForMessage(VHT_PREFIX + "1001"); + + //Validate each vhost logs a creation + List<String> results = findMatches(VHT_PREFIX + "1001"); + + try + { + List<String> vhosts = Arrays.asList(getServerConfig().getVirtualHosts()); + + assertEquals("Each vhost did not create a store.", vhosts.size(), results.size()); + + for (int index = 0; index < results.size(); index++) + { + // Retrieve the vhostname from the log entry message 'Created : <vhostname>' + String result = getLogMessage(results, index); + String vhostName = getMessageString(fromMessage(result)).split(" ")[2]; + + assertTrue("Virtualhost named in log not found in config file:" + vhostName + ":" + vhosts, vhosts.contains(vhostName)); + } + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + + /** + * Description: + * Testing can be performed using the default configuration. During broker shutdown a VHT-1002 Closed message will be printed for each of the configured virtualhosts. For every virtualhost that was started a close must be logged. After the close message has been printed no further logging will be performed by this virtualhost. + * Input: + * The default configuration file + * Output: + * <p/> + * <date> VHT-1002 : Closed + * Validation Steps: + * <p/> + * The VHT ID is correct + * This is the last VHT message for the given virtualhost. + * + * @throws Exception caused by broker startup + */ + public void testVirtualhostClosure() throws Exception + { + stopBroker(); + + // Wait for the correct VHT message to arrive. + waitForMessage(VHT_PREFIX + "1002"); + + // Validate each vhost logs a closure + List<String> results = findMatches(VHT_PREFIX + "1002"); + + try + { + // Load VirtualHost list from file. + ServerConfiguration configuration = new ServerConfiguration(_configFile); + configuration.initialise(); + List<String> vhosts = Arrays.asList(configuration.getVirtualHosts()); + + assertEquals("Each vhost did not close their store.", vhosts.size(), results.size()); + } + catch (AssertionFailedError afe) + { + dumpLogs(results, _monitor); + + throw afe; + } + } + +} |