APEXCORE-169 - instantiating DTLoggerFactory during test causes incorrect logging behavior
Project: http://git-wip-us.apache.org/repos/asf/apex-core/repo Commit: http://git-wip-us.apache.org/repos/asf/apex-core/commit/9c48c41e Tree: http://git-wip-us.apache.org/repos/asf/apex-core/tree/9c48c41e Diff: http://git-wip-us.apache.org/repos/asf/apex-core/diff/9c48c41e Branch: refs/heads/master Commit: 9c48c41e989b917a9e6c59e3fb284432cd1664d3 Parents: 8046174 Author: Vlad Rozov <[email protected]> Authored: Thu Aug 25 13:34:33 2016 -0700 Committer: Vlad Rozov <[email protected]> Committed: Thu Aug 25 13:34:33 2016 -0700 ---------------------------------------------------------------------- .../com/datatorrent/stram/util/LoggerUtil.java | 298 ++++++++++--------- .../datatorrent/stram/util/LoggerUtilTest.java | 173 +++++++---- 2 files changed, 282 insertions(+), 189 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/apex-core/blob/9c48c41e/engine/src/main/java/com/datatorrent/stram/util/LoggerUtil.java ---------------------------------------------------------------------- diff --git a/engine/src/main/java/com/datatorrent/stram/util/LoggerUtil.java b/engine/src/main/java/com/datatorrent/stram/util/LoggerUtil.java index 04e6856..e774bea 100644 --- a/engine/src/main/java/com/datatorrent/stram/util/LoggerUtil.java +++ b/engine/src/main/java/com/datatorrent/stram/util/LoggerUtil.java @@ -16,95 +16,202 @@ * specific language governing permissions and limitations * under the License. */ -package org.apache.log4j; +package com.datatorrent.stram.util; import java.util.Enumeration; import java.util.Iterator; import java.util.Map; -import java.util.concurrent.ConcurrentMap; import java.util.regex.Pattern; import javax.annotation.Nonnull; +import javax.annotation.Nullable; +import org.apache.log4j.Appender; +import org.apache.log4j.Category; +import org.apache.log4j.Level; +import org.apache.log4j.LogManager; +import org.apache.log4j.Logger; +import org.apache.log4j.spi.DefaultRepositorySelector; +import org.apache.log4j.spi.HierarchyEventListener; import org.apache.log4j.spi.LoggerFactory; import org.apache.log4j.spi.LoggerRepository; -import org.apache.log4j.spi.RepositorySelector; import com.google.common.base.Function; -import com.google.common.base.Strings; import com.google.common.collect.ImmutableMap; import com.google.common.collect.Maps; -/** - * An implementation of {@link LoggerFactory} - * - * @since 1.0.2 - */ -public class DTLoggerFactory implements LoggerFactory +public class LoggerUtil { - public static final String DT_LOGGERS_LEVEL = "dt.loggers.level"; - private static DTLoggerFactory SINGLETON; + private static final org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(LoggerUtil.class); - public static synchronized DTLoggerFactory getInstance() + private static final Map<String, Level> patternLevel = Maps.newHashMap(); + private static final Map<String, Pattern> patterns = Maps.newHashMap(); + private static final Function<Level, String> levelToString = new Function<Level, String>() { - if (SINGLETON == null) { - SINGLETON = new DTLoggerFactory(); + @Override + public String apply(@Nullable Level input) + { + return input == null ? "" : input.toString(); } - return SINGLETON; - } - - private final ConcurrentMap<String, Logger> loggerMap; - private final Map<String, Level> patternLevel; + }; - public ImmutableMap<String, String> getPatternLevels() + private static class DelegatingLoggerRepository implements LoggerRepository { - return ImmutableMap.copyOf(Maps.transformValues(patternLevel, new Function<Level, String>() + private static class DefaultLoggerFactory implements LoggerFactory { + private static class DefaultLogger extends Logger + { + public DefaultLogger(String name) + { + super(name); + } + } + @Override - public String apply(Level input) + public Logger makeNewLoggerInstance(String name) { - return input == null ? "" : input.toString(); + Logger logger = new DefaultLogger(name); + Level level = getLevelFor(name); + if (level != null) { + logger.setLevel(level); + } + return logger; } - })); - } + } - private final Map<String, Pattern> patterns; - private boolean initialized = false; + private final LoggerFactory loggerFactory = new DefaultLoggerFactory(); + private final LoggerRepository loggerRepository; - private DTLoggerFactory() - { - loggerMap = Maps.newConcurrentMap(); - patternLevel = Maps.newHashMap(); - patterns = Maps.newHashMap(); + private DelegatingLoggerRepository(LoggerRepository loggerRepository) + { + this.loggerRepository = loggerRepository; + } + + @Override + public void addHierarchyEventListener(HierarchyEventListener listener) + { + loggerRepository.addHierarchyEventListener(listener); + } + + @Override + public boolean isDisabled(int level) + { + return loggerRepository.isDisabled(level); + } + + @Override + public void setThreshold(Level level) + { + loggerRepository.setThreshold(level); + } + + @Override + public void setThreshold(String val) + { + loggerRepository.setThreshold(val); + } + + @Override + public void emitNoAppenderWarning(Category cat) + { + loggerRepository.emitNoAppenderWarning(cat); + } + + @Override + public Level getThreshold() + { + return loggerRepository.getThreshold(); + } + + @Override + public Logger getLogger(String name) + { + return loggerRepository.getLogger(name, loggerFactory); + } + + @Override + public Logger getLogger(String name, LoggerFactory factory) + { + return loggerRepository.getLogger(name, factory); + } + + @Override + public Logger getRootLogger() + { + return loggerRepository.getRootLogger(); + } + + @Override + public Logger exists(String name) + { + return loggerRepository.exists(name); + } + + @Override + public void shutdown() + { + loggerRepository.shutdown(); + } + + @Override + public Enumeration<Logger> getCurrentLoggers() + { + return loggerRepository.getCurrentLoggers(); + } + + @Override + public Enumeration<Logger> getCurrentCategories() + { + return loggerRepository.getCurrentCategories(); + } + + @Override + public void fireAddAppenderEvent(Category logger, Appender appender) + { + loggerRepository.fireAddAppenderEvent(logger, appender); + } + + @Override + public void resetConfiguration() + { + loggerRepository.resetConfiguration(); + } } - public synchronized void initialize() + static { + logger.debug("initializing LoggerUtil"); + LogManager.setRepositorySelector(new DefaultRepositorySelector(new DelegatingLoggerRepository(LogManager.getLoggerRepository())), null); + } + + private static synchronized Level getLevelFor(String name) { - if (!initialized) { - LOG.debug("initializing DT Logger Factory"); - new RepositorySelectorImpl().initialize(); - String loggersLevel = System.getProperty(DT_LOGGERS_LEVEL); - if (!Strings.isNullOrEmpty(loggersLevel)) { - Map<String, String> targetChanges = Maps.newHashMap(); - String[] targets = loggersLevel.split(","); - for (String target : targets) { - String[] parts = target.split(":"); - targetChanges.put(parts[0], parts[1]); - } - changeLoggersLevel(targetChanges); + if (patternLevel.isEmpty()) { + return null; + } + String longestPatternKey = null; + for (String patternKey : patternLevel.keySet()) { + Pattern pattern = patterns.get(patternKey); + if (pattern.matcher(name).matches() && (longestPatternKey == null || longestPatternKey.length() < patternKey.length())) { + longestPatternKey = patternKey; } - initialized = true; - } else { - LOG.warn("DT Logger Factory already initialized."); } + if (longestPatternKey != null) { + return patternLevel.get(longestPatternKey); + } + return null; } - public synchronized void changeLoggersLevel(@Nonnull Map<String, String> targetChanges) + public static ImmutableMap<String, String> getPatternLevels() { - /*remove existing patterns which are subsets of new patterns. for eg. if x.y.z.* will be removed if - there is x.y.* in the target changes. - */ + return ImmutableMap.copyOf(Maps.transformValues(patternLevel, levelToString)); + } + + public static synchronized void changeLoggersLevel(@Nonnull Map<String, String> targetChanges) + { + /* remove existing patterns which are subsets of new patterns. for eg. if x.y.z.* will be removed if + * there is x.y.* in the target changes. + */ for (Map.Entry<String, String> changeEntry : targetChanges.entrySet()) { Iterator<Map.Entry<String, Pattern>> patternsIterator = patterns.entrySet().iterator(); while ((patternsIterator.hasNext())) { @@ -146,44 +253,14 @@ public class DTLoggerFactory implements LoggerFactory Level oldLevel = classLogger.getLevel(); Level newLevel = getLevelFor(classLogger.getName()); if (newLevel != null && (oldLevel == null || !newLevel.equals(oldLevel))) { - LOG.info("changing level of " + classLogger.getName() + " to " + newLevel); + logger.info("changing level of {} to {}", classLogger.getName(), newLevel); classLogger.setLevel(newLevel); } } } } - @Override - public Logger makeNewLoggerInstance(String name) - { - Logger newInstance = new Logger(name); - Level level = getLevelFor(name); - if (level != null) { - newInstance.setLevel(level); - } - loggerMap.put(name, newInstance); - return newInstance; - } - - private synchronized Level getLevelFor(String name) - { - if (patternLevel.isEmpty()) { - return null; - } - String longestPatternKey = null; - for (String partternKey : patternLevel.keySet()) { - Pattern pattern = patterns.get(partternKey); - if (pattern.matcher(name).matches() && (longestPatternKey == null || longestPatternKey.length() < partternKey.length())) { - longestPatternKey = partternKey; - } - } - if (longestPatternKey != null) { - return patternLevel.get(longestPatternKey); - } - return null; - } - - public synchronized ImmutableMap<String, String> getClassesMatching(@Nonnull String searchKey) + public static synchronized ImmutableMap<String, String> getClassesMatching(@Nonnull String searchKey) { Pattern searchPattern = Pattern.compile(searchKey); Map<String, String> matchedClasses = Maps.newHashMap(); @@ -198,55 +275,4 @@ public class DTLoggerFactory implements LoggerFactory } return ImmutableMap.copyOf(matchedClasses); } - - private static class RepositorySelectorImpl implements RepositorySelector - { - - private boolean initialized; - private Logger guard; - private Hierarchy hierarchy; - - private RepositorySelectorImpl() - { - initialized = false; - } - - private void initialize() - { - if (!initialized) { - LOG.debug("initializing logger repository selector impl"); - guard = LogManager.getRootLogger(); - LogManager.setRepositorySelector(this, guard); - hierarchy = new LoggerRepositoryImpl(guard); - initialized = true; - } - } - - @Override - public LoggerRepository getLoggerRepository() - { - return hierarchy; - } - } - - private static class LoggerRepositoryImpl extends Hierarchy - { - /** - * Create a new logger hierarchy. - * - * @param root The root of the new hierarchy. - */ - private LoggerRepositoryImpl(Logger root) - { - super(root); - } - - @Override - public Logger getLogger(String name) - { - return super.getLogger(name, DTLoggerFactory.getInstance()); - } - } - - private static final Logger LOG = LogManager.getLogger(DTLoggerFactory.class); } http://git-wip-us.apache.org/repos/asf/apex-core/blob/9c48c41e/engine/src/test/java/com/datatorrent/stram/util/LoggerUtilTest.java ---------------------------------------------------------------------- diff --git a/engine/src/test/java/com/datatorrent/stram/util/LoggerUtilTest.java b/engine/src/test/java/com/datatorrent/stram/util/LoggerUtilTest.java index 5ec5af8..2ad3f4a 100644 --- a/engine/src/test/java/com/datatorrent/stram/util/LoggerUtilTest.java +++ b/engine/src/test/java/com/datatorrent/stram/util/LoggerUtilTest.java @@ -16,86 +16,153 @@ * specific language governing permissions and limitations * under the License. */ -package org.apache.log4j; +package com.datatorrent.stram.util; -import java.lang.reflect.Field; import java.util.Map; -import org.junit.Assert; import org.junit.BeforeClass; +import org.junit.FixMethodOrder; import org.junit.Test; +import org.junit.runners.MethodSorters; import org.slf4j.LoggerFactory; +import org.apache.log4j.Category; +import org.apache.log4j.Level; +import org.apache.log4j.LogManager; + import com.google.common.collect.Maps; -import com.datatorrent.stram.StreamingAppMaster; -import com.datatorrent.stram.api.StramEvent; -import com.datatorrent.stram.client.DTConfiguration; -import com.datatorrent.stram.engine.StreamingContainer; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertSame; +import static org.junit.Assert.assertTrue; -public class DTLoggerFactoryTest +@FixMethodOrder(MethodSorters.NAME_ASCENDING) +public class LoggerUtilTest { + private static final org.slf4j.Logger logger = LoggerFactory.getLogger(LoggerUtilTest.class); @BeforeClass public static void setup() throws Exception { - System.setProperty(DTLoggerFactory.DT_LOGGERS_LEVEL, "com.datatorrent.stram.client.*:INFO,com.datatorrent.stram.api.*:DEBUG"); - Field f = DTLoggerFactory.class.getDeclaredField("initialized"); - f.setAccessible(true); - f.set(DTLoggerFactory.getInstance(), false); - DTLoggerFactory.getInstance().initialize(); + logger.debug("Logger repository before LoggerUtil.changeLoggersLevel() {}", LogManager.getLoggerRepository()); + LoggerUtil.changeLoggersLevel(Maps.<String, String>newHashMap()); + logger.debug("Logger repository after LoggerUtil.changeLoggersLevel() {}", LogManager.getLoggerRepository()); } @Test - public void test() + public void testGetPatternLevels() { - LoggerFactory.getLogger(DTConfiguration.class); - LoggerFactory.getLogger(StramEvent.class); - LoggerFactory.getLogger(StreamingAppMaster.class); - - org.apache.log4j.Logger dtConfigLogger = LogManager.getLogger(DTConfiguration.class); - Assert.assertEquals(dtConfigLogger.getLevel(), Level.INFO); - - org.apache.log4j.Logger stramEventLogger = LogManager.getLogger(StramEvent.class); - Assert.assertEquals(stramEventLogger.getLevel(), Level.DEBUG); - - org.apache.log4j.Logger streamingAppMasterLogger = LogManager.getLogger(StreamingAppMaster.class); - Assert.assertNull(streamingAppMasterLogger.getLevel()); + Map<String, String> changes = Maps.newHashMap(); + changes.put("_.org.apache.*", "WARN"); + changes.put("_.com.datatorrent.io.fs.*", "DEBUG"); + changes.put("_.com.datatorrent.io.*", "ERROR"); + LoggerUtil.changeLoggersLevel(changes); + + Map<String, String> levels = LoggerUtil.getPatternLevels(); + + assertEquals(3, levels.size()); + assertEquals(levels.get("_.org.apache.*"), "WARN"); + assertEquals(levels.get("_.com.datatorrent.io.fs.*"), "DEBUG"); + assertEquals(levels.get("_.com.datatorrent.io.*"), "ERROR"); + + changes.clear(); + changes.put("_.com.datatorrent.*", "WARN"); + LoggerUtil.changeLoggersLevel(changes); + + levels = LoggerUtil.getPatternLevels(); + assertEquals(2, levels.size()); + assertEquals(levels.get("_.org.apache.*"), "WARN"); + assertNull(levels.get("_.com.datatorrent.io.fs.*")); + assertNull(levels.get("_.com.datatorrent.io.*")); + assertEquals(levels.get("_.com.datatorrent.*"), "WARN"); } @Test - public void test1() + public void testLoggerLevels() { - Map<String, String> changes = Maps.newHashMap(); - changes.put("com.datatorrent.*", "DEBUG"); - changes.put("com.datatorrent.stram.engine.*", "ERROR"); - DTLoggerFactory.getInstance().changeLoggersLevel(changes); - - LoggerFactory.getLogger(DTConfiguration.class); - LoggerFactory.getLogger(StramEvent.class); + org.slf4j.Logger sl4jLogger; + org.apache.log4j.Logger log4jLogger; - org.apache.log4j.Logger dtConfigLogger = LogManager.getLogger(DTConfiguration.class); - Assert.assertEquals(dtConfigLogger.getLevel(), Level.DEBUG); - - org.apache.log4j.Logger stramEventLogger = LogManager.getLogger(StramEvent.class); - Assert.assertEquals(stramEventLogger.getLevel(), Level.DEBUG); - - LoggerFactory.getLogger(StreamingContainer.class); - org.apache.log4j.Logger stramChildLogger = LogManager.getLogger(StreamingContainer.class); - Assert.assertEquals(stramChildLogger.getLevel(), Level.ERROR); + Map<String, String> changes = Maps.newHashMap(); + changes.put("_.org.apache.*", "WARN"); + changes.put("_.com.datatorrent.*", "WARN"); + changes.put("_.com.datatorrent.stram.client.*", "INFO"); + changes.put("_.com.datatorrent.stram.api.*", "DEBUG"); + LoggerUtil.changeLoggersLevel(changes); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.client.DTConfiguration"); + assertTrue(sl4jLogger.isInfoEnabled()); + assertFalse(sl4jLogger.isDebugEnabled()); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.api.StramEvent"); + assertTrue(sl4jLogger.isInfoEnabled()); + assertTrue(sl4jLogger.isDebugEnabled()); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.StreamingAppMaster"); + assertFalse(sl4jLogger.isInfoEnabled()); + assertFalse(sl4jLogger.isDebugEnabled()); + + log4jLogger = LogManager.getLogger("_.com.datatorrent.stram.client.DTConfiguration"); + assertSame(log4jLogger.getLevel(), Level.INFO); + assertSame(log4jLogger.getEffectiveLevel(), Level.INFO); + + org.apache.log4j.Logger stramEventLogger = LogManager.getLogger("_.com.datatorrent.stram.api.StramEvent"); + assertSame(stramEventLogger.getLevel(), Level.DEBUG); + assertSame(stramEventLogger.getEffectiveLevel(), Level.DEBUG); + + org.apache.log4j.Logger streamingAppMasterLogger = LogManager.getLogger("_.com.datatorrent.stram.StreamingAppMaster"); + assertSame(streamingAppMasterLogger.getLevel(), Level.WARN); + assertSame(streamingAppMasterLogger.getEffectiveLevel(), Level.WARN); + + changes.clear(); + changes.put("_.com.datatorrent.*", "DEBUG"); + changes.put("_.com.datatorrent.stram.engine.*", "ERROR"); + LoggerUtil.changeLoggersLevel(changes); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.client.DTConfiguration"); + assertTrue(sl4jLogger.isInfoEnabled()); + assertTrue(sl4jLogger.isDebugEnabled()); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.api.StramEvent"); + assertTrue(sl4jLogger.isInfoEnabled()); + assertTrue(sl4jLogger.isDebugEnabled()); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.StreamingAppMaster"); + assertTrue(sl4jLogger.isInfoEnabled()); + assertTrue(sl4jLogger.isDebugEnabled()); + + sl4jLogger = LoggerFactory.getLogger("_.com.datatorrent.stram.engine.StreamingContainer"); + assertFalse(sl4jLogger.isInfoEnabled()); + assertFalse(sl4jLogger.isDebugEnabled()); + + log4jLogger = LogManager.getLogger("_.com.datatorrent.stram.client.DTConfiguration"); + assertSame(log4jLogger.getLevel(), Level.DEBUG); + assertSame(log4jLogger.getEffectiveLevel(), Level.DEBUG); + + log4jLogger = LogManager.getLogger("_.com.datatorrent.stram.api.StramEvent"); + assertSame(log4jLogger.getLevel(), Level.DEBUG); + assertSame(log4jLogger.getEffectiveLevel(), Level.DEBUG); + + log4jLogger = LogManager.getLogger("_.com.datatorrent.stram.StreamingAppMaster"); + assertSame(log4jLogger.getLevel(), Level.DEBUG); + assertSame(log4jLogger.getEffectiveLevel(), Level.DEBUG); + + log4jLogger = LogManager.getLogger("_.com.datatorrent.stram.engine.StreamingContainer"); + assertSame(log4jLogger.getLevel(), Level.ERROR); + assertSame(log4jLogger.getEffectiveLevel(), Level.ERROR); } @Test - public void testGetPatternLevels() + public void testParentLevel() { - Map<String, String> changes = Maps.newHashMap(); - changes.put("com.datatorrent.io.fs.*", "DEBUG"); - changes.put("com.datatorrent.io.*", "ERROR"); - DTLoggerFactory.getInstance().changeLoggersLevel(changes); - - Map<String, String> levels = DTLoggerFactory.getInstance().getPatternLevels(); - - Assert.assertEquals(levels.get("com.datatorrent.io.fs.*"), "DEBUG"); - Assert.assertEquals(levels.get("com.datatorrent.io.*"), "ERROR"); + org.apache.log4j.Logger log4jLogger = LogManager.getLogger("com.datatorrent.stram.util.Unknown"); + assertNull(log4jLogger.getLevel()); + Category parent = log4jLogger.getParent(); + while (parent.getLevel() == null) { + parent = parent.getParent(); + } + assertSame(log4jLogger.getEffectiveLevel(), parent.getLevel()); } }
