From 91e500e08167792c08db8d565b3a288d4a805dcf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Youri=20Bonnaff=C3=A9?= Date: Sat, 10 Dec 2022 10:57:17 +0100 Subject: [PATCH] GH-314: New setting to configure global capture level Introduce a new global setting `capture.level` to disable storing (and printing) logs at a given level (following the level hierarchy). The implementation is very similar to the `print.level` global setting. This is useful when tests are generating a lot of logging events that are not of interest and don't need to be captured. ArchUnit tests are known to be such tests and can be quite slow when slf4j-test is used. --- .../github/valfirst/slf4jtest/TestLogger.java | 6 ++- .../valfirst/slf4jtest/TestLoggerFactory.java | 45 +++++++++++++++---- src/site/markdown/changelog.md | 5 +++ src/site/markdown/usage.md | 32 +++++++++++-- .../slf4jtest/TestLoggerFactoryTests.java | 39 ++++++++++++++++ .../valfirst/slf4jtest/TestLoggerTests.java | 42 ++++++++++++++++- 6 files changed, 154 insertions(+), 15 deletions(-) diff --git a/src/main/java/com/github/valfirst/slf4jtest/TestLogger.java b/src/main/java/com/github/valfirst/slf4jtest/TestLogger.java index eaabc00f..0b128fe1 100644 --- a/src/main/java/com/github/valfirst/slf4jtest/TestLogger.java +++ b/src/main/java/com/github/valfirst/slf4jtest/TestLogger.java @@ -457,7 +457,7 @@ private void addLoggingEvent( final Optional throwable, final String format, final Object... args) { - if (enabledLevels.get().contains(level)) { + if (enabledLevels.get().contains(level) && enabledByGlobalCaptureLevel(level)) { final LoggingEvent event = new LoggingEvent(of(this), level, mdc(), marker, throwable, format, args); allLoggingEvents.add(event); @@ -467,6 +467,10 @@ private void addLoggingEvent( } } + private boolean enabledByGlobalCaptureLevel(Level level) { + return testLoggerFactory.getCaptureLevel().compareTo(level) <= 0; + } + @SuppressWarnings("unchecked") private Map mdc() { return ofNullable(MDC.getCopyOfContextMap()).orElseGet(Collections::emptyMap); diff --git a/src/main/java/com/github/valfirst/slf4jtest/TestLoggerFactory.java b/src/main/java/com/github/valfirst/slf4jtest/TestLoggerFactory.java index c952a18a..a20680c0 100644 --- a/src/main/java/com/github/valfirst/slf4jtest/TestLoggerFactory.java +++ b/src/main/java/com/github/valfirst/slf4jtest/TestLoggerFactory.java @@ -25,24 +25,38 @@ public final class TestLoggerFactory implements ILoggerFactory { Suppliers.memoize( () -> { try { - final String level = - new OverridableProperties("slf4jtest").getProperty("print.level", "OFF"); - return new TestLoggerFactory(Level.valueOf(level)); - } catch (IllegalArgumentException e) { - throw new IllegalStateException( - "Invalid level name in property print.level of file slf4jtest.properties " - + "or System property slf4jtest.print.level", - e); + OverridableProperties properties = new OverridableProperties("slf4jtest"); + Level printLevel = getLevelProperty(properties, "print.level", "OFF"); + Level captureLevel = getLevelProperty(properties, "capture.level", "TRACE"); + return new TestLoggerFactory(printLevel, captureLevel); } catch (IOException e) { throw new UncheckedIOException(e); } }); + private static Level getLevelProperty( + OverridableProperties properties, String propertyKey, String defaultValue) + throws IOException { + try { + final String printLevelProperty = properties.getProperty(propertyKey, defaultValue); + return Level.valueOf(printLevelProperty); + } catch (IllegalArgumentException e) { + throw new IllegalStateException( + "Invalid level name in property " + + propertyKey + + " of file slf4jtest.properties " + + "or System property slf4jtest." + + propertyKey, + e); + } + } + private final ConcurrentMap loggers = new ConcurrentHashMap<>(); private final List allLoggingEvents = Collections.synchronizedList(new ArrayList<>()); private final ThreadLocal> loggingEvents = new ThreadLocal<>(ArrayList::new); private volatile Level printLevel; + private volatile Level captureLevel; public static TestLoggerFactory getInstance() { return INSTANCE.get(); @@ -81,17 +95,26 @@ public static List getAllLoggingEvents() { } public TestLoggerFactory() { - this(Level.OFF); + this(Level.OFF, Level.TRACE); } public TestLoggerFactory(final Level printLevel) { + this(printLevel, Level.TRACE); + } + + public TestLoggerFactory(final Level printLevel, final Level captureLevel) { this.printLevel = checkNotNull(printLevel); + this.captureLevel = checkNotNull(captureLevel); } public Level getPrintLevel() { return printLevel; } + public Level getCaptureLevel() { + return captureLevel; + } + public ImmutableMap getAllLoggers() { return ImmutableMap.copyOf(loggers); } @@ -141,4 +164,8 @@ void addLoggingEvent(final LoggingEvent event) { public void setPrintLevel(final Level printLevel) { this.printLevel = checkNotNull(printLevel); } + + public void setCaptureLevel(Level captureLevel) { + this.captureLevel = checkNotNull(captureLevel); + } } diff --git a/src/site/markdown/changelog.md b/src/site/markdown/changelog.md index 5773bb7d..07713633 100644 --- a/src/site/markdown/changelog.md +++ b/src/site/markdown/changelog.md @@ -1,5 +1,10 @@ ## Changelog +### Unreleased + +Introduce a new `capture.level` property and API to control captured events globally, +see https://github.com/valfirst/slf4j-test/issues/314. + ### Version 1.2.0 Allows construction of standalone instances to facilitate logging in different diff --git a/src/site/markdown/usage.md b/src/site/markdown/usage.md index d00c3488..f62f73d1 100644 --- a/src/site/markdown/usage.md +++ b/src/site/markdown/usage.md @@ -19,7 +19,7 @@ LoggingEvent. ### Setting the Log Level on a Logger SLF4J Test only stores events for levels which are marked as enabled on the -Logger. By default all levels are enabled; however, this can be programatically +Logger. By default, all levels are enabled; however, this can be programmatically changed on a per logger basis using the following functions: Logger.setEnabledLevels(Level... levels) @@ -33,6 +33,28 @@ Log4J do not permit this. If you wish to test using these common configurations, you should use the constants defined in uk.org.lidalia.slf4jext.ConventionalLevelHierarchy. +### Globally disabling a Log Level + +Storing log events at all levels can slow down test executions. If needed a global +setting can be used to avoid capturing events at a given level or below respecting +the conventional level hierarchy (if the capture level is set to INFO, DEBUG and TRACE +events won't be captured). This can be set in any of the following ways: + +#### Programmatically + TestLoggerFactory.getInstance().setCaptureLevel(Level.INFO); + +#### Via a System Property +Run the JVM with the following: + + -Dslf4jtest.capture.level=INFO + +#### Via a properties file +Place a file called slf4jtest.properties on the classpath with the following +line in it: + + capture.level=INFO + + ### Resetting Stored State In order to have robust tests the in memory state of SLF4J Test must be in a @@ -93,10 +115,12 @@ It can still be useful to print log messages to System out/err as appropriate. SLF4J Test will print messages using a standard (non-configurable) format based on the value of the TestLoggerFactory's printLevel property. For convenience this does respect the conventional level hierarchy where if the print level is -INFO logging events at levels WARN and ERROR will also be printed. This can be -set in any of the following ways: +INFO logging events at levels WARN and ERROR will also be printed. A level that is +disabled [globally](#globally-disabling-a-log-level) will not be printed. + +This can be set in any of the following ways: -#### Programatically +#### Programmatically TestLoggerFactory.getInstance().setPrintLevel(Level.INFO); #### Via a System Property diff --git a/src/test/java/com/github/valfirst/slf4jtest/TestLoggerFactoryTests.java b/src/test/java/com/github/valfirst/slf4jtest/TestLoggerFactoryTests.java index 1e637c75..affea6cf 100644 --- a/src/test/java/com/github/valfirst/slf4jtest/TestLoggerFactoryTests.java +++ b/src/test/java/com/github/valfirst/slf4jtest/TestLoggerFactoryTests.java @@ -248,6 +248,7 @@ public void printLevelTakenFromOverridableProperties() throws Exception { final OverridableProperties properties = mock(OverridableProperties.class); whenNew(OverridableProperties.class).withArguments("slf4jtest").thenReturn(properties); when(properties.getProperty("print.level", "OFF")).thenReturn("INFO"); + when(properties.getProperty("capture.level", "TRACE")).thenReturn("INFO"); assertThat(getInstance().getPrintLevel(), is(Level.INFO)); } @@ -273,6 +274,44 @@ public void printLevelInvalidInOverridableProperties() throws Exception { is("No enum constant " + Level.class.getName() + "." + invalidLevelName)); } + @Test + public void defaultCaptureLevelIsTrace() { + assertThat(getInstance().getCaptureLevel(), is(Level.TRACE)); + } + + @Test + @PrepareForTest(TestLoggerFactory.class) + public void captureLevelTakenFromOverridableProperties() throws Exception { + final OverridableProperties properties = mock(OverridableProperties.class); + whenNew(OverridableProperties.class).withArguments("slf4jtest").thenReturn(properties); + when(properties.getProperty("print.level", "OFF")).thenReturn("INFO"); + when(properties.getProperty("capture.level", "TRACE")).thenReturn("INFO"); + + assertThat(getInstance().getCaptureLevel(), is(Level.INFO)); + } + + @Test + @PrepareForTest(TestLoggerFactory.class) + public void captureLevelInvalidInOverridableProperties() throws Exception { + final OverridableProperties properties = mock(OverridableProperties.class); + whenNew(OverridableProperties.class).withArguments("slf4jtest").thenReturn(properties); + when(properties.getProperty("print.level", "OFF")).thenReturn("INFO"); + final String invalidLevelName = "nonsense"; + when(properties.getProperty("capture.level", "TRACE")).thenReturn(invalidLevelName); + + final IllegalStateException illegalStateException = + assertThrows(IllegalStateException.class, TestLoggerFactory::getInstance); + assertThat( + illegalStateException.getMessage(), + is( + "Invalid level name in property capture.level of file slf4jtest.properties " + + "or System property slf4jtest.capture.level")); + assertThat(illegalStateException.getCause(), instanceOf(IllegalArgumentException.class)); + assertThat( + illegalStateException.getCause().getMessage(), + is("No enum constant " + Level.class.getName() + "." + invalidLevelName)); + } + @Test @PrepareForTest(TestLoggerFactory.class) public void ioExceptionAtPropertiesLoading() throws Exception { diff --git a/src/test/java/com/github/valfirst/slf4jtest/TestLoggerTests.java b/src/test/java/com/github/valfirst/slf4jtest/TestLoggerTests.java index 1f833c47..d167f0a1 100644 --- a/src/test/java/com/github/valfirst/slf4jtest/TestLoggerTests.java +++ b/src/test/java/com/github/valfirst/slf4jtest/TestLoggerTests.java @@ -71,6 +71,7 @@ void afterEach() { MDC.clear(); TestLoggerFactory.reset(); TestLoggerFactory.getInstance().setPrintLevel(Level.OFF); + TestLoggerFactory.getInstance().setCaptureLevel(Level.TRACE); } @Test @@ -785,7 +786,7 @@ void printsWhenPrintLevelLessThanEventLevel() { } @Test - void doesNotWhenPrintLevelGreaterThanThanEventLevel() { + void doesNotWhenPrintLevelGreaterThanEventLevel() { TestLoggerFactory.getInstance().setPrintLevel(WARN); testLogger.info(message); @@ -793,6 +794,45 @@ void doesNotWhenPrintLevelGreaterThanThanEventLevel() { assertThat(getStdOut(), emptyString()); } + @Test + void doesNotCaptureWhenCaptureLevelGreaterThanEventLevel() { + TestLoggerFactory.getInstance().setCaptureLevel(WARN); + + testLogger.setEnabledLevels(ERROR, WARN, INFO, DEBUG, TRACE); + + assertLogsAreCaptured(ERROR, WARN); + } + + @Test + void captureLevelAndLoggerLevelAreChecked() { + TestLoggerFactory.getInstance().setCaptureLevel(INFO); + + testLogger.setEnabledLevels(ERROR, WARN); + + assertLogsAreCaptured(ERROR, WARN); + } + + @Test + void captureAllLevelsByDefault() { + assertLogsAreCaptured(ERROR, WARN, INFO, DEBUG, TRACE); + } + + private void assertLogsAreCaptured(Level... shouldLog) { + testLogger.error(message); + testLogger.warn(message); + testLogger.info(message); + testLogger.debug(message); + testLogger.trace(message); + + List expectedEvents = + Arrays.stream(shouldLog) + .map(level -> new LoggingEvent(level, mdcValues, message)) + .collect(Collectors.toList()); + + assertEquals(expectedEvents, testLogger.getLoggingEvents()); + testLogger.clear(); + } + @Test void nullMdcValue() { MDC.clear();