package jmri.util; import java.io.IOException; import java.io.Serializable; import java.util.*; import javax.annotation.CheckForNull; import javax.annotation.Nonnull; import org.apache.commons.lang3.StringUtils; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.core.*; import org.apache.logging.log4j.core.appender.AbstractAppender; import org.apache.logging.log4j.core.appender.AppenderLoggingException; import org.apache.logging.log4j.core.config.Property; import org.apache.logging.log4j.core.config.plugins.*; import org.apache.logging.log4j.core.layout.PatternLayout; import org.junit.jupiter.api.Assertions; /** * Log4J2 Appender Plugin that works with JUnit tests to check for expected vs * unexpected log messages. * Used by tests_lcf.xml * Most tests log at WARN or ERROR, the root logging level within tests_lcf.xml * Much of the interface is static to avoid lots of instance() calls, but this * is not a problem as there should be only one of these while tests are running * * level.isLessSpecificThan(Level.WARN) true if level DEBUG / INFO / WARN * level.isMoreSpecificThan(Level.WARN) true if level WARN / ERROR * * ( level.compareTo(Level.WARN) > 0 ) true if level DEBUG / INFO * ( level.compareTo(Level.WARN) >= 0 ) true if level DEBUG / INFO / WARN * ( level.compareTo(Level.WARN) == 0 ) true if level WARN * ( level.compareTo(Level.WARN) <= 0 ) true if level WARN / ERROR * ( level.compareTo(Level.WARN) < 0 ) true if level ERROR * * Level.ERROR = 200 * Level.DEBUG = 500 * @see jmri.util.JUnitUtil * * @author Bob Jacobsen - Copyright 2007 */ @Plugin(name="JUnitAppender", category="Core", elementType="appender", printObject=true) public class JUnitAppender extends AbstractAppender { protected JUnitAppender(final String name, final Filter filter, final Layout extends Serializable> layout, final boolean ignoreExceptions, final Property[] properties) { super(name, filter, layout, ignoreExceptions, properties ); activateInstance(); } /** * Create an Appender. *
* Log4j will parse the configuration and call this factory method to * construct an Appender instance with the configured attributes. *
* @param name Plugin Name
* @param layout Layout to use, if null uses standard PatternLayout
* @param filter A Filter in use
* @return New Appender.
*/
@PluginFactory
public static JUnitAppender createAppender(
@PluginAttribute("name") String name,
@PluginElement("Layout") Layout extends Serializable> layout,
@PluginElement("Filter") final Filter filter) {
if (name == null) {
LOGGER.error("No name provided for MyCustomAppenderImpl");
return null;
}
if (layout == null) {
layout = PatternLayout.createDefaultLayout();
}
return new JUnitAppender(name, filter, layout, true, Property.EMPTY_ARRAY);
}
private static final java.util.ArrayList
* This causes log messages to be held for examination.
*/
public static void startLogging() {
hold = true;
}
/**
* Tell appender that the JUnit test is ended.
*
* Any queued messages at this point will be passed through to the actual
* log.
*/
public static void end() {
hold = false;
while (!list.isEmpty()) {
LogEvent evt = list.remove(0);
instance().superappend(evt);
}
}
/**
* do common local processing of event, then pass up to super class
*
* @param l the event to process
*/
private void superappend(LogEvent l) {
if (l.getLevel() == Level.FATAL) {
setUnexpectedFatalSeen(true);
setUnexpectedFatalContent(l.getMessage().getFormattedMessage());
}
if (l.getLevel() == Level.ERROR) {
if (compare(l, "Uncaught Exception caught by jmri.util.exceptionhandler.UncaughtExceptionHandler")) {
// still an error, just suppressed
} else {
setUnexpectedErrorSeen(true);
setUnexpectedErrorContent(l.getMessage().getFormattedMessage());
}
}
if (l.getLevel() == Level.WARN) {
setUnexpectedWarnSeen(true);
setUnexpectedWarnContent(l.getMessage().getFormattedMessage());
}
if (l.getLevel() == Level.INFO) {
setUnexpectedInfoSeen(true);
setUnexpectedInfoContent(l.getMessage().getFormattedMessage());
}
sendToConsole(l);
}
/**
* Remove any messages stored up, returning how many there were.
* This is used to skip over messages that don't matter,
* e.g. during setting up a test.
* Please check the return value of this method against the expected number.
* Please do not use this method to clear the backlog without checking.
* The majority of tests are set to only log at the Levels WARN / ERROR so
* INFO / DEBUG levels are not normally included.
* Removed messages are not sent for further logging.
*
* @param l lowest level counted in return value, e.g. WARN means WARN
* and higher will be counted
* @return count of skipped messages
* @see #clearBacklog()
*/
public static int clearBacklog(org.slf4j.event.Level l) {
return clearBacklog(convertSlf4jLevelToLog4jLevel(l));
}
private static int clearBacklog(Level level) {
if (list.isEmpty()) {
return 0;
}
int retval = 0;
for (LogEvent event : list) {
if (event != null && event.getLevel() != null && event.getLevel().isMoreSpecificThan(level)) {
retval++; // higher number -> more severe, specific, limited
}
}
list.clear();
return retval;
}
/**
* Remove any messages stored up, returning how many of WARN or higher
* severity there are.
* This is used to skip over messages that don't matter,
* e.g. during setting up a test.
* Removed messages are not sent for further logging.
* Please check the return value of this method against the expected number.
* Please do not use this method to clear the backlog without checking.
* @return count of skipped messages of WARN or more specific level
* @see #clearBacklog(Level)
*/
@SuppressWarnings("javadoc")
public static int clearBacklog() {
return clearBacklog(Level.WARN);
}
/**
* Returns the backlog.
* @return the backlog, unmodifiable.
*/
@Nonnull
public static List
* Invokes a JUnit Assert if the message doesn't match.
*
* @param msg the message to assert exists
*/
public static void assertErrorMessage(String msg) {
assertNextMessage(msg, Level.ERROR, Level.INFO);
}
private static void assertNextMessage(String msg, Level level, Level exclude) {
if (list.isEmpty()) {
Assertions.fail("No " + level.name()+ " message present: \"" + msg + "\"");
return;
}
LogEvent evt = list.remove(0);
while ((evt.getLevel().isLessSpecificThan(exclude))) {
if (list.isEmpty()) {
Assertions.fail("Only " + exclude.name() + " or less severe messages present: Looking for "
+ level.name()+ " \""+ msg + "\"");
return;
}
evt = list.remove(0);
}
// check the remaining message, if any
if ( (evt.getLevel() != level) || !compare(evt, msg)) {
Assertions.fail("Looking for " + level.name() + " message \"" + msg + "\" got "
+ evt.getLevel().name() + "\"" + evt.getMessage().getFormattedMessage() + "\"");
}
}
/**
* Check that the next queued message was of Error severity,
* and text is at start of this message.
* White space is ignored.
* Prior TRACE / DEBUG / INFO level messages are ignored.
* Prior messages of level WARN or ERROR are NOT ignored.
*
* Invokes a JUnit Assert if the message doesn't match.
*
* @param msg the message to assert exists
*/
public static void assertErrorMessageStartsWith(String msg) {
assertNextMessageStartsWith(Level.ERROR, msg);
}
/**
* Check that the next queued message was of Warn severity,
* and text is at start of this message.
* White space is ignored.
* Prior TRACE / DEBUG / INFO level messages are ignored.
* Prior messages of level WARN or ERROR are NOT ignored.tt
*
* Invokes a JUnit Assert if the message doesn't match.
*
* @param msg the message to assert starts with
*/
public static void assertWarnMessageStartsWith(String msg) {
assertNextMessageStartsWith(Level.WARN, msg);
}
/**
* Assert that a message exists of a given level and message String.
* Strips INFO / DEBUG / TRACE messages,
* then checks the next message in the queue.
* @param level the level to match
* @param msg the message to match
*/
private static void assertNextMessageStartsWith(Level level, String msg) {
if (list.isEmpty()) {
Assertions.fail("No " + level + " message present: " + msg);
return;
}
LogEvent evt = list.remove(0);
while (evt.getLevel().isLessSpecificThan(Level.INFO) ) {
if (list.isEmpty()) {
Assertions.fail("Only debug/info messages present when looking to Assert "
+ level.name() + " StartsWith: " + msg);
return;
}
evt = list.remove(0);
}
// check the remaining message, if any
if ( (evt.getLevel() != level ) || !compareStartsWith(evt, msg)) {
Assertions.fail("Looking for " + level.name() + " message starting with \"" + msg + "\" got "
+ evt.getLevel().name() + "\"" + evt.getMessage().getFormattedMessage() + "\"");
}
}
/**
* If there's a last matching message of specific severity, just ignore it.
* Not an error if not present; mismatch is an error.
* Removes messages of lower or equal severity while looking for the specific one.
* White space is ignored.
*
* @param level the level at which to suppress the message
* @param msg the message to suppress
*/
private static void suppressMessage(Level level, String msg) {
if (list.isEmpty()) {
return;
}
LogEvent evt = list.remove(0);
// TODO test while ( level.compareTo(evt.getLevel() ) < 0 ) {
while ( level.compareTo(evt.getLevel() ) <= 0 ) {
if (list.isEmpty()) {
return;
}
evt = list.remove(0);
}
// check the remaining message, if any
if ( (evt.getLevel() != level) || !compare(evt, msg)) {
Assertions.fail("Looking to suppress " + level + " message \"" + msg + "\" got "
+ evt.getLevel().name()+ " \"" + evt.getMessage().getFormattedMessage() + "\"");
}
}
/**
* If there's a next matching message of specific severity, just ignore it.
* Not an error if not present; mismatch is an error.
* Removes messages of lower or equal severity while looking for a matching one.
* White space is ignored.
*
* @param level the level at which to suppress the message
* @param msg text at start of the message to suppress
*/
private static void suppressMessageStartsWith(Level level, String msg) {
if (list.isEmpty()) {
return;
}
LogEvent evt = list.remove(0);
// TODO test while ( level.compareTo(evt.getLevel() ) < 0 ) {
while ( level.compareTo(evt.getLevel() ) <= 0 ) {
if (list.isEmpty()) {
return;
}
evt = list.remove(0);
}
// check the remaining message, if any
if ( (evt.getLevel() != level) || !compareStartsWith(evt, msg)) {
Assertions.fail("Looking to suppress " + level + " message starting with \"" + msg + "\" got "
+ evt.getLevel() + " \"" + evt.getMessage().getFormattedMessage() + "\"");
}
}
/**
* If there's a next matching message of Error severity, just ignore it.
* Not an error if not present; mismatch is an error.
* White space is ignored.
*
* @param msg the message to suppress
*/
public static void suppressErrorMessage(String msg) {
suppressMessage(Level.ERROR, msg);
}
/**
* If there's a next matching message of Error severity, just ignore it.
* Not an error if not present; mismatch is an error.
* White space is ignored.
* Removes messages of lower or equal severity while looking for a matching one.
* @param msg text at start of the message to suppress
*/
public static void suppressErrorMessageStartsWith(String msg) {
suppressMessageStartsWith(Level.ERROR, msg);
}
/**
* If there's a next matching message of Warn severity, just ignore it.
* Not an error if not present; mismatch is an error.
* White space is ignored.
*
* @param msg the message to suppress
*/
public static void suppressWarnMessage(String msg) {
suppressMessage(Level.WARN, msg);
}
/**
* If there's a next matching message of Warn severity, just ignore it.
* Not an error if not present; mismatch is an error.
* White space is ignored.
* Removes messages of lower or equal severity while looking for a matching one.
* @param msg text at start of the message to suppress
*/
public static void suppressWarnMessageStartsWith(String msg) {
suppressMessageStartsWith(Level.WARN, msg);
}
/**
* See if a message (completely matching particular text) has been emitted
* yet.
* White space is ignored.
* All messages of any severity sent before the matching String are dropped.
* If the requested message hasn't been issued, this means that the
* message queue is cleared.
*
* @param msg the message text to check for
* @return null if not present, else the LoggingEvent for possible further
* checks of level, etc
*/
@CheckForNull
public static LogEvent checkForMessage(String msg) {
if (list.isEmpty()) {
return null;
}
LogEvent evt = list.remove(0);
while (!compare(evt, msg)) {
if (list.isEmpty()) {
return null; // normal to not find it
}
evt = list.remove(0);
}
// fall through with a match
return evt;
}
/**
* See if a message that starts with particular text has been emitted yet.
* White space is ignored.
* All messages OF ANY SEVERITY before the matching one are dropped.
* If a matching message hasn't been issued, this means that the message
* queue is cleared.
*
* @param msg the message text to check for
* @return null if not present, else the LoggingEvent for possible further
* checks of level, etc
*/
@CheckForNull
public static LogEvent checkForMessageStartingWith(String msg) {
if (list.isEmpty()) {
return null;
}
String tmsg = StringUtils.deleteWhitespace(msg);
LogEvent evt = list.remove(0);
while (!StringUtils.deleteWhitespace(evt.getMessage().getFormattedMessage()).startsWith(tmsg)) {
if (list.isEmpty()) {
return null; // normal to not find it
}
evt = list.remove(0);
}
// fall through with a match
return evt;
}
/**
* Check that the next queued message was of Warn severity, and has a
* specific message.
* ALL messages of ANY severity sent before the matching one are dropped.
* White space is ignored.
*
* Invokes a JUnit Assert if the message doesn't match.
*
* @param msg the message to assert exists
*/
public static void assertWarnMessage(String msg) {
assertMessage(msg, Level.WARN);
}
/**
* Check that the next queued message has a specific message
* and matches the expected severity level.
* White space is ignored.
* ALL messages of ANY severity sent before the matching one are dropped.
* Invokes a JUnit Assertion Fail if the message doesn't match,
* or if the Logging Level is different.
*
* @param msg the message to assert exists
* @param level the Logging Level which should match
*/
public static void assertMessage(String msg, org.slf4j.event.Level level) {
assertMessage(msg, convertSlf4jLevelToLog4jLevel(level));
}
/**
* Assert Message with matching String and Level.
* All messages of any severity sent before the matching one are dropped.
* @param msg the Message String to match.
* @param level the expected level of the LogEvent.
*/
private static void assertMessage(String msg, @Nonnull Level level) {
LogEvent evt = checkForMessage(msg);
if (evt == null) {
Assertions.fail("Looking for " + level.name() + " message \"" + msg + "\" and didn't find it");
return;
}
if (level != evt.getLevel() ){
Assertions.fail("Incorrect logging level for \"" + msg
+ "\" expecting " + level + " was " + evt.getLevel());
}
}
/**
* Check that the next queued message was of Warn severity, and has a
* specific message.
* ALL messages of ANY severity sent before the matching one are dropped.
* White space is ignored.
*
* Invokes a JUnit Assert if the message doesn't match.
* Does NOT currently ensure correct logging level ( WARN ) is matched.
* @param msg the message to assert exists
*/
@jmri.util.junit.annotations.ToDo("Add check for message Level severity")
public static void assertWarnMessageStartingWith(String msg) {
if (list.isEmpty()) {
Assertions.fail("No message present: " + msg);
return;
}
LogEvent evt = checkForMessageStartingWith(msg);
// TODO - add check the message found is actually a WARN, currently passes ANY level
if (evt == null) {
Assertions.fail("Looking for WARN message starting with \"" + msg + "\" and didn't find it");
}
}
/**
* Assert that a specific message, of any severity, has been logged.
* White space is ignored.
* Does not remove any other messages of any severity from the message queue.
*
* Invokes a JUnit Assert if no matching message is found, but doesn't
* require it to be the next message.
* This allows use e.g. for debug-severity messages.
*
* @param msg the message to assert exists
*/
public static void assertMessage(String msg) {
Iterator