You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@lucene.apache.org by ho...@apache.org on 2019/12/17 21:58:56 UTC
[lucene-solr] branch master updated: SOLR-14099: Fixed @LogLevel
annotation in test-framework to correctly 'unset' Loggers after test
This is an automated email from the ASF dual-hosted git repository.
hossman pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/lucene-solr.git
The following commit(s) were added to refs/heads/master by this push:
new cc4262a SOLR-14099: Fixed @LogLevel annotation in test-framework to correctly 'unset' Loggers after test
cc4262a is described below
commit cc4262a8ec37b2420e1d80a392c5e8019f43e24c
Author: Chris Hostetter <ho...@apache.org>
AuthorDate: Tue Dec 17 14:58:45 2019 -0700
SOLR-14099: Fixed @LogLevel annotation in test-framework to correctly 'unset' Loggers after test
---
solr/CHANGES.txt | 3 +-
.../solr/handler/admin/LoggingHandlerTest.java | 59 +++++++----
.../src/java/org/apache/solr/util/LogLevel.java | 33 ++++--
.../org/apache/solr/TestLogLevelAnnotations.java | 113 +++++++++++++++++++--
4 files changed, 165 insertions(+), 43 deletions(-)
diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt
index e7295e8..e6a2d15 100644
--- a/solr/CHANGES.txt
+++ b/solr/CHANGES.txt
@@ -121,7 +121,8 @@ Optimizations
Bug Fixes
---------------------
-(No changes)
+
+* SOLR-14099: Fixed @LogLevel annotation in test-framework to correctly 'unset' Loggers after test (hossman)
Other Changes
---------------------
diff --git a/solr/core/src/test/org/apache/solr/handler/admin/LoggingHandlerTest.java b/solr/core/src/test/org/apache/solr/handler/admin/LoggingHandlerTest.java
index 933b126..d98c65b 100644
--- a/solr/core/src/test/org/apache/solr/handler/admin/LoggingHandlerTest.java
+++ b/solr/core/src/test/org/apache/solr/handler/admin/LoggingHandlerTest.java
@@ -19,19 +19,22 @@ package org.apache.solr.handler.admin;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
-import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LoggerContext;
-import org.apache.logging.log4j.core.config.LoggerConfig;
+import org.apache.logging.log4j.core.config.Configuration;
import org.apache.solr.SolrTestCaseJ4;
import org.apache.solr.common.params.CommonParams;
import org.apache.solr.common.util.SuppressForbidden;
+import org.apache.solr.util.LogLevel;
import org.junit.BeforeClass;
import org.junit.Test;
@SuppressForbidden(reason = "test uses log4j2 because it tests output at a specific level")
+@LogLevel("org.apache.solr.bogus_logger_package.BogusLoggerClass=DEBUG")
public class LoggingHandlerTest extends SolrTestCaseJ4 {
-
+ private final String PARENT_LOGGER_NAME = "org.apache.solr.bogus_logger_package";
+ private final String CLASS_LOGGER_NAME = PARENT_LOGGER_NAME + ".BogusLoggerClass";
+
// TODO: This only tests Log4j at the moment, as that's what's defined
// through the CoreContainer.
@@ -45,36 +48,48 @@ public class LoggingHandlerTest extends SolrTestCaseJ4 {
@Test
public void testLogLevelHandlerOutput() throws Exception {
- Logger tst = LogManager.getLogger("org.apache.solr.SolrTestCaseJ4");
-
- LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
- LoggerConfig loggerConfig = ctx.getConfiguration().getLoggerConfig(tst.getName());
- loggerConfig.setLevel(Level.INFO);
- ctx.updateLoggers();
+
+ // sanity check our setup...
+ assertNotNull(this.getClass().getAnnotation(LogLevel.class));
+ final String annotationConfig = this.getClass().getAnnotation(LogLevel.class).value();
+ assertTrue("WTF: " + annotationConfig, annotationConfig.startsWith( PARENT_LOGGER_NAME ));
+ assertTrue("WTF: " + annotationConfig, annotationConfig.startsWith( CLASS_LOGGER_NAME ));
+ assertTrue("WTF: " + annotationConfig, annotationConfig.endsWith( Level.DEBUG.toString() ));
+
+ assertEquals(Level.DEBUG, LogManager.getLogger( CLASS_LOGGER_NAME ).getLevel());
+
+ final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
+ final Configuration config = ctx.getConfiguration();
- // HACK: work around for SOLR-14099...
- Logger apache = LogManager.getLogger("org.apache");
- final String apache_level = null == apache.getLevel()
- ? "null[@name='level']"
- : "str[@name='level'][.='"+apache.getLevel()+"']";
+ assertEquals("Unexpected config for " + PARENT_LOGGER_NAME + " ... expected 'root' config",
+ config.getRootLogger(),
+ config.getLoggerConfig(PARENT_LOGGER_NAME));
+ assertEquals(Level.DEBUG, config.getLoggerConfig(CLASS_LOGGER_NAME).getLevel());
-
assertQ("Show Log Levels OK",
req(CommonParams.QT,"/admin/logging")
- ,"//arr[@name='loggers']/lst/str[.='"+tst.getName()+"']/../str[@name='level'][.='"+tst.getLevel()+"']"
- ,"//arr[@name='loggers']/lst/str[.='org.apache']/../" + apache_level
+ ,"//arr[@name='loggers']/lst/str[.='"+CLASS_LOGGER_NAME+"']/../str[@name='level'][.='DEBUG']"
+ ,"//arr[@name='loggers']/lst/str[.='"+PARENT_LOGGER_NAME+"']/../null[@name='level']"
);
- assertQ("Set a level",
+ assertQ("Set a (new) level",
req(CommonParams.QT,"/admin/logging",
- "set", tst.getName()+":TRACE")
- ,"//arr[@name='loggers']/lst/str[.='"+tst.getName()+"']/../str[@name='level'][.='TRACE']"
+ "set", PARENT_LOGGER_NAME+":TRACE")
+ ,"//arr[@name='loggers']/lst/str[.='"+PARENT_LOGGER_NAME+"']/../str[@name='level'][.='TRACE']"
);
+ assertEquals(Level.TRACE, config.getLoggerConfig(PARENT_LOGGER_NAME).getLevel());
+ assertEquals(Level.DEBUG, config.getLoggerConfig(CLASS_LOGGER_NAME).getLevel());
+ // NOTE: LoggeringHandler doesn't actually "remove" the LoggerConfig, ...
+ // evidently so people using they UI can see that it was explicitly turned "OFF" ?
assertQ("Remove a level",
req(CommonParams.QT,"/admin/logging",
- "set", tst.getName()+":null")
- ,"//arr[@name='loggers']/lst/str[.='"+tst.getName()+"']/../str[@name='level'][.='OFF']"
+ "set", PARENT_LOGGER_NAME+":null")
+ ,"//arr[@name='loggers']/lst/str[.='"+PARENT_LOGGER_NAME+"']/../str[@name='level'][.='OFF']"
);
+ assertEquals(Level.OFF, config.getLoggerConfig(PARENT_LOGGER_NAME).getLevel());
+ assertEquals(Level.DEBUG, config.getLoggerConfig(CLASS_LOGGER_NAME).getLevel());
+
+
}
}
diff --git a/solr/test-framework/src/java/org/apache/solr/util/LogLevel.java b/solr/test-framework/src/java/org/apache/solr/util/LogLevel.java
index d064263..0e488e7 100644
--- a/solr/test-framework/src/java/org/apache/solr/util/LogLevel.java
+++ b/solr/test-framework/src/java/org/apache/solr/util/LogLevel.java
@@ -77,21 +77,32 @@ public @interface LogLevel {
}
private static Map<String, Level> setLogLevels(Map<String, Level> logLevels) {
- LoggerContext ctx = LoggerContext.getContext(false);
- Configuration config = ctx.getConfiguration();
+ final LoggerContext ctx = LoggerContext.getContext(false);
+ final Configuration config = ctx.getConfiguration();
- Map<String, Level> oldLevels = new HashMap<>();
- logLevels.forEach((loggerName, level) -> {
- LoggerConfig logConfig = config.getLoggerConfig(loggerName);
- // what the initial logger level was. It will use the root value if logger is being defined for the first time
- oldLevels.put(loggerName, logConfig.getLevel());
+ final Map<String, Level> oldLevels = new HashMap<>();
+ logLevels.forEach((loggerName, newLevel) -> {
+ final LoggerConfig logConfig = config.getLoggerConfig(loggerName);
if (loggerName.equals(logConfig.getName())) {
- logConfig.setLevel(level);
+ // we have an existing LoggerConfig for this specific loggerName
+ // record the existing 'old' level...
+ oldLevels.put(loggerName, logConfig.getLevel());
+ // ...and set the new one (or remove if null) ...
+ if (null == newLevel) {
+ config.removeLogger(loggerName);
+ } else {
+ logConfig.setLevel(newLevel);
+ }
} else {
- LoggerConfig loggerConfig = new LoggerConfig(loggerName, level, true);
- loggerConfig.setLevel(level);
- config.addLogger(loggerName, loggerConfig);
+ // there is no existing configuration for the exact loggerName, logConfig is some ancestor
+ // record an 'old' level of 'null' to track the lack of any configured level...
+ oldLevels.put(loggerName, null);
+ // ...and now create a new logger config wih our new level
+ final LoggerConfig newLoggerConfig = new LoggerConfig(loggerName, newLevel, true);
+ config.addLogger(loggerName, newLoggerConfig);
}
+
+ assert oldLevels.containsKey(loggerName);
});
ctx.updateLoggers();
return oldLevels;
diff --git a/solr/test-framework/src/test/org/apache/solr/TestLogLevelAnnotations.java b/solr/test-framework/src/test/org/apache/solr/TestLogLevelAnnotations.java
index cfc9d93..22c0bb6 100644
--- a/solr/test-framework/src/test/org/apache/solr/TestLogLevelAnnotations.java
+++ b/solr/test-framework/src/test/org/apache/solr/TestLogLevelAnnotations.java
@@ -17,27 +17,122 @@
package org.apache.solr;
+import java.util.Map;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.core.LoggerContext;
+import org.apache.logging.log4j.core.config.Configuration;
import org.apache.solr.common.util.SuppressForbidden;
import org.apache.solr.util.LogLevel;
-import org.junit.Test;
+import org.junit.AfterClass;
+import org.junit.BeforeClass;
@SuppressForbidden(reason="We need to use log4J2 classes to access the log levels")
-@LogLevel("org.apache.solr.ClassLogLevel=error;org.apache.solr.MethodLogLevel=warn")
+@LogLevel("org.apache.solr.bogus_logger.ClassLogLevel=error;org.apache.solr.bogus_logger.MethodLogLevel=warn")
public class TestLogLevelAnnotations extends SolrTestCaseJ4 {
- @Test
+ private static final String bogus_logger_prefix = "org.apache.solr.bogus_logger";
+
+ /**
+ * We don't want a hardocded assumption here because it may change based on how the user runs the test.
+ */
+ public static final Level DEFAULT_LOG_LEVEL = LogManager.getRootLogger().getLevel();
+
+ /**
+ * Sanity check that our <code>AfterClass</code> logic is valid, and isn't broken right from the start
+ *
+ * @see #checkLogLevelsAfterClass
+ */
+ @BeforeClass
+ public static void checkLogLevelsBeforeClass() {
+ final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
+ final Configuration config = ctx.getConfiguration();
+
+ // NOTE: we're checking the CONFIGURATION of the loggers, not the "effective" value of the Logger
+ assertEquals(DEFAULT_LOG_LEVEL, config.getRootLogger().getLevel());
+ assertEquals("Your Logger conf sets a level on a bogus package that breaks this test: "
+ + bogus_logger_prefix,
+ config.getRootLogger(),
+ config.getLoggerConfig(bogus_logger_prefix));
+ assertEquals(Level.ERROR, config.getLoggerConfig(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.WARN, config.getLoggerConfig(bogus_logger_prefix + ".MethodLogLevel").getLevel());
+
+ // Now sanity check the EFFECTIVE Level of these loggers before the methods run...
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getRootLogger().getLevel());
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getLogger(bogus_logger_prefix).getLevel());
+ assertEquals(Level.ERROR, LogManager.getLogger(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.WARN, LogManager.getLogger(bogus_logger_prefix + ".MethodLogLevel").getLevel());
+ }
+
+ /**
+ * Check that the expected log level <em>configurations</em> have been reset after the test
+ * <p>
+ * <b>NOTE:</b> We only validate <code>@LogLevel</code> modifications made at the
+ * {@link #testMethodLogLevels} level, not at the 'class' level, because of the lifecycle of junit
+ * methods: This <code>@AfterClass</code> will run before the <code>SolrTestCaseJ4</code>
+ * <code>@AfterClass</code> method where the 'class' <code>@LogLevel</code> modifications will be reset.
+ * </p>
+ *
+ * @see #checkLogLevelsBeforeClass
+ * @see #testWhiteBoxMethods
+ */
+ @AfterClass
+ public static void checkLogLevelsAfterClass() {
+ final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
+ final Configuration config = ctx.getConfiguration();
+
+ // NOTE: we're checking the CONFIGURATION of the loggers, not the "effective" value of the Logger
+ assertEquals(DEFAULT_LOG_LEVEL, config.getRootLogger().getLevel());
+ assertEquals(bogus_logger_prefix
+ + " should have had it's config unset; should now return the 'root' LoggerConfig",
+ config.getRootLogger(),
+ config.getLoggerConfig(bogus_logger_prefix));
+ assertEquals(Level.ERROR, config.getLoggerConfig(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.WARN, config.getLoggerConfig(bogus_logger_prefix + ".MethodLogLevel").getLevel());
+
+ // Now sanity check the EFFECTIVE Level of these loggers...
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getRootLogger().getLevel());
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getLogger(bogus_logger_prefix).getLevel());
+ assertEquals(Level.ERROR, LogManager.getLogger(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.WARN, LogManager.getLogger(bogus_logger_prefix + ".MethodLogLevel").getLevel());
+ }
+
public void testClassLogLevels() {
- assertEquals(Level.ERROR, LogManager.getLogger("org.apache.solr.ClassLogLevel").getLevel());
- assertEquals(Level.WARN, LogManager.getLogger("org.apache.solr.MethodLogLevel").getLevel());
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getLogger("org.apache.solr.bogus_logger").getLevel());
+ assertEquals(Level.ERROR, LogManager.getLogger(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.WARN, LogManager.getLogger(bogus_logger_prefix + ".MethodLogLevel").getLevel());
}
- @Test
- @LogLevel("org.apache.solr.MethodLogLevel=debug")
+ @LogLevel("org.apache.solr.bogus_logger.MethodLogLevel=debug;org.apache.solr.bogus_logger=INFO")
public void testMethodLogLevels() {
- assertEquals(Level.ERROR, LogManager.getLogger("org.apache.solr.ClassLogLevel").getLevel());
- assertEquals(Level.DEBUG, LogManager.getLogger("org.apache.solr.MethodLogLevel").getLevel());
+ assertEquals(Level.INFO, LogManager.getLogger(bogus_logger_prefix + ".BogusClass").getLevel());
+ assertEquals(Level.ERROR, LogManager.getLogger(bogus_logger_prefix + ".ClassLogLevel").getLevel());
+ assertEquals(Level.DEBUG, LogManager.getLogger(bogus_logger_prefix + ".MethodLogLevel").getLevel());
}
+ /**
+ * Directly test the methods in the {@link LogLevel} annotation class
+ */
+ @LogLevel("org.apache.solr.bogus_logger.MethodLogLevel=TRACE")
+ public void testWhiteBoxMethods() {
+ final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
+ final Configuration config = ctx.getConfiguration();
+
+ final Map<String,Level> oldLevels = LogLevel.Configurer.setLevels(bogus_logger_prefix + "=TRACE");
+ //
+ assertEquals(oldLevels.toString(), 1, oldLevels.size());
+ assertNull(oldLevels.get(bogus_logger_prefix));
+ //
+ assertEquals(Level.TRACE, config.getLoggerConfig(bogus_logger_prefix).getLevel());
+ assertEquals(Level.TRACE, LogManager.getLogger(bogus_logger_prefix).getLevel());
+
+ // restore (to 'unset' values)...
+ LogLevel.Configurer.restoreLogLevels(oldLevels);
+ assertEquals(bogus_logger_prefix
+ + " should have had it's config unset; should now return the 'root' LoggerConfig",
+ config.getRootLogger(),
+ config.getLoggerConfig(bogus_logger_prefix));
+ assertEquals(DEFAULT_LOG_LEVEL, LogManager.getLogger(bogus_logger_prefix).getLevel());
+
+ }
}