Apply logging levels in hierarchical order

This commit adds a test for applying logging levels in hierarchical
order, and addresses an issue with restoring the logging levels at the
end of a test or suite.
This commit is contained in:
Jason Tedor 2016-12-23 06:36:00 -05:00
parent baea17b53f
commit 432ec54347
3 changed files with 84 additions and 44 deletions

View File

@ -1001,7 +1001,6 @@
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]engine[/\\]AssertingSearcher.java" checks="LineLength" />
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]engine[/\\]MockEngineSupport.java" checks="LineLength" />
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]hamcrest[/\\]ElasticsearchAssertions.java" checks="LineLength" />
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]junit[/\\]listeners[/\\]LoggingListener.java" checks="LineLength" />
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]store[/\\]MockFSDirectoryService.java" checks="LineLength" />
<suppress files="test[/\\]framework[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]test[/\\]store[/\\]MockFSIndexStore.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]common[/\\]cli[/\\]CliTool.java" checks="LineLength" />

View File

@ -16,6 +16,7 @@
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.test.junit.listeners;
import org.apache.logging.log4j.Logger;
@ -26,19 +27,18 @@ import org.junit.runner.Description;
import org.junit.runner.Result;
import org.junit.runner.notification.RunListener;
import java.util.HashMap;
import java.util.Collections;
import java.util.Map;
import java.util.TreeMap;
/**
* A {@link RunListener} that allows to change the log level for a specific test method.
* When a test method is annotated with the {@link org.elasticsearch.test.junit.annotations.TestLogging} annotation, the level for the specified loggers
* will be internally saved before the test method execution and overridden with the specified ones.
* At the end of the test method execution the original loggers levels will be restored.
* A {@link RunListener} that allows changing the log level for a specific test method. When a test method is annotated with the
* {@link TestLogging} annotation, the level for the specified loggers will be internally saved before the test method execution and
* overridden with the specified ones. At the end of the test method execution the original loggers levels will be restored.
*
* Note: This class is not thread-safe. Given the static nature of the logging api, it assumes that tests
* are never run concurrently in the same jvm. For the very same reason no synchronization has been implemented
* regarding the save/restore process of the original loggers levels.
* This class is not thread-safe. Given the static nature of the logging API, it assumes that tests are never run concurrently in the same
* JVM. For the very same reason no synchronization has been implemented regarding the save/restore process of the original loggers
* levels.
*/
public class LoggingListener extends RunListener {
@ -47,29 +47,35 @@ public class LoggingListener extends RunListener {
private Map<String, String> previousPackageLoggingMap;
@Override
public void testRunStarted(Description description) throws Exception {
public void testRunStarted(final Description description) throws Exception {
Package testClassPackage = description.getTestClass().getPackage();
previousPackageLoggingMap = processTestLogging(testClassPackage != null ? testClassPackage.getAnnotation(TestLogging.class) : null);
previousClassLoggingMap = processTestLogging(description.getAnnotation(TestLogging.class));
}
@Override
public void testRunFinished(Result result) throws Exception {
public void testRunFinished(final Result result) throws Exception {
previousClassLoggingMap = reset(previousClassLoggingMap);
previousPackageLoggingMap = reset(previousPackageLoggingMap);
}
@Override
public void testStarted(Description description) throws Exception {
public void testStarted(final Description description) throws Exception {
final TestLogging testLogging = description.getAnnotation(TestLogging.class);
previousLoggingMap = processTestLogging(testLogging);
}
@Override
public void testFinished(Description description) throws Exception {
public void testFinished(final Description description) throws Exception {
previousLoggingMap = reset(previousLoggingMap);
}
/**
* Obtain the logger with the given name.
*
* @param loggerName the logger to obtain
* @return the logger
*/
private static Logger resolveLogger(String loggerName) {
if (loggerName.equalsIgnoreCase("_root")) {
return ESLoggerFactory.getRootLogger();
@ -77,49 +83,69 @@ public class LoggingListener extends RunListener {
return Loggers.getLogger(loggerName);
}
private Map<String, String> processTestLogging(TestLogging testLogging) {
Map<String, String> map = getLoggersAndLevelsFromAnnotation(testLogging);
/**
* Applies the test logging annotation and returns the existing logging levels.
*
* @param testLogging the test logging annotation to apply
* @return the existing logging levels
*/
private Map<String, String> processTestLogging(final TestLogging testLogging) {
final Map<String, String> map = getLoggersAndLevelsFromAnnotation(testLogging);
if (map == null) {
return null;
}
// sort the logging keys so they wouldn't override each other.
// for example, processing org.elasticsearch:DEBUG after org.elasticsearch.transport:TRACE
// will reset the later
TreeMap<String, String> sortedLogNames = new TreeMap<>(String::compareTo);
sortedLogNames.putAll(map);
Map<String, String> previousValues = new HashMap<>();
for (Map.Entry<String, String> entry : sortedLogNames.entrySet()) {
Logger logger = resolveLogger(entry.getKey());
previousValues.put(entry.getKey(), logger.getLevel().toString());
Loggers.setLevel(logger, entry.getValue());
}
return previousValues;
return Collections.emptyMap();
}
public static Map<String, String> getLoggersAndLevelsFromAnnotation(TestLogging testLogging) {
if (testLogging == null) {
return null;
// obtain the existing logging levels so that we can restore them at the end of the test; we have to do this separately from setting
// the logging levels so that setting foo does not impact the logging level for foo.bar when we check the existing logging level for
// for.bar
final Map<String, String> existing = new TreeMap<>();
for (final Map.Entry<String, String> entry : map.entrySet()) {
final Logger logger = resolveLogger(entry.getKey());
existing.put(entry.getKey(), logger.getLevel().toString());
}
Map<String, String> map = new HashMap<>();
for (final Map.Entry<String, String> entry : map.entrySet()) {
final Logger logger = resolveLogger(entry.getKey());
Loggers.setLevel(logger, entry.getValue());
}
return existing;
}
/**
* Obtain the logging levels from the test logging annotation.
*
* @param testLogging the test logging annotation
* @return a map from logger name to logging level
*/
private static Map<String, String> getLoggersAndLevelsFromAnnotation(final TestLogging testLogging) {
if (testLogging == null) {
return Collections.emptyMap();
}
// use a sorted set so that we apply a parent logger before its children thus not overwriting the child setting when processing the
// parent setting
final Map<String, String> map = new TreeMap<>();
final String[] loggersAndLevels = testLogging.value().split(",");
for (String loggerAndLevel : loggersAndLevels) {
String[] loggerAndLevelArray = loggerAndLevel.split(":");
for (final String loggerAndLevel : loggersAndLevels) {
final String[] loggerAndLevelArray = loggerAndLevel.split(":");
if (loggerAndLevelArray.length >= 2) {
String loggerName = loggerAndLevelArray[0];
String level = loggerAndLevelArray[1];
map.put(loggerName, level);
map.put(loggerAndLevelArray[0], loggerAndLevelArray[1]);
}
}
return map;
}
private Map<String, String> reset(Map<String, String> map) {
if (map != null) {
for (Map.Entry<String, String> previousLogger : map.entrySet()) {
Logger logger = resolveLogger(previousLogger.getKey());
/**
* Reset the logging levels to the state provided by the map.
*
* @param map the logging levels to apply
* @return an empty map
*/
private Map<String, String> reset(final Map<String, String> map) {
for (final Map.Entry<String, String> previousLogger : map.entrySet()) {
final Logger logger = resolveLogger(previousLogger.getKey());
Loggers.setLevel(logger, previousLogger.getValue());
}
}
return null;
return Collections.emptyMap();
}
}

View File

@ -82,27 +82,42 @@ public class LoggingListenerTests extends ESTestCase {
Logger abcLogger = Loggers.getLogger("abc");
Logger xyzLogger = Loggers.getLogger("xyz");
// we include foo and foo.bar to maintain that logging levels are applied from the top of the hierarchy down; this ensures that
// setting the logging level for a parent logger and a child logger applies the parent level first and then the child as otherwise
// setting the parent level would overwrite the child level
Logger fooLogger = Loggers.getLogger("foo");
Logger fooBarLogger = Loggers.getLogger("foo.bar");
final Level level = ESLoggerFactory.getRootLogger().getLevel();
assertThat(xyzLogger.getLevel(), equalTo(level));
assertThat(abcLogger.getLevel(), equalTo(level));
assertThat(fooLogger.getLevel(), equalTo(level));
assertThat(fooBarLogger.getLevel(), equalTo(level));
loggingListener.testRunStarted(suiteDescription);
assertThat(xyzLogger.getLevel(), equalTo(level));
assertThat(abcLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooBarLogger.getLevel(), equalTo(Level.ERROR));
Description testDescription = Description.createTestDescription(LoggingListenerTests.class, "test");
loggingListener.testStarted(testDescription);
assertThat(xyzLogger.getLevel(), equalTo(level));
assertThat(abcLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooBarLogger.getLevel(), equalTo(Level.ERROR));
loggingListener.testFinished(testDescription);
assertThat(xyzLogger.getLevel(), equalTo(level));
assertThat(abcLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooLogger.getLevel(), equalTo(Level.WARN));
assertThat(fooBarLogger.getLevel(), equalTo(Level.ERROR));
loggingListener.testRunFinished(new Result());
assertThat(xyzLogger.getLevel(), equalTo(level));
assertThat(abcLogger.getLevel(), equalTo(level));
assertThat(fooLogger.getLevel(), equalTo(level));
assertThat(fooBarLogger.getLevel(), equalTo(level));
}
public void testCustomLevelPerClassAndPerMethod() throws Exception {
@ -151,7 +166,7 @@ public class LoggingListenerTests extends ESTestCase {
/**
* dummy class used to create a junit suite description that has the @TestLogging annotation
*/
@TestLogging("abc:WARN")
@TestLogging("abc:WARN,foo:WARN,foo.bar:ERROR")
public static class AnnotatedTestClass {
}
@ -162,7 +177,7 @@ public class LoggingListenerTests extends ESTestCase {
public static class TestClass {
@SuppressWarnings("unused")
@TestLogging("xyz:TRACE")
@TestLogging("xyz:TRACE,foo:WARN,foo.bar:ERROR")
public void annotatedTestMethod() {}
@SuppressWarnings("unused")