Skip to content

Commit

Permalink
Introduce new setting to configure global capture level (#324)
Browse files Browse the repository at this point in the history
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.
  • Loading branch information
youribonnaffe authored Dec 11, 2022
1 parent 9eeddda commit de3bfb9
Show file tree
Hide file tree
Showing 6 changed files with 154 additions and 15 deletions.
6 changes: 5 additions & 1 deletion src/main/java/com/github/valfirst/slf4jtest/TestLogger.java
Original file line number Diff line number Diff line change
Expand Up @@ -457,7 +457,7 @@ private void addLoggingEvent(
final Optional<Throwable> 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);
Expand All @@ -467,6 +467,10 @@ private void addLoggingEvent(
}
}

private boolean enabledByGlobalCaptureLevel(Level level) {
return testLoggerFactory.getCaptureLevel().compareTo(level) <= 0;
}

@SuppressWarnings("unchecked")
private Map<String, String> mdc() {
return ofNullable(MDC.getCopyOfContextMap()).orElseGet(Collections::emptyMap);
Expand Down
45 changes: 36 additions & 9 deletions src/main/java/com/github/valfirst/slf4jtest/TestLoggerFactory.java
Original file line number Diff line number Diff line change
Expand Up @@ -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<String, TestLogger> loggers = new ConcurrentHashMap<>();
private final List<LoggingEvent> allLoggingEvents =
Collections.synchronizedList(new ArrayList<>());
private final ThreadLocal<List<LoggingEvent>> loggingEvents = new ThreadLocal<>(ArrayList::new);
private volatile Level printLevel;
private volatile Level captureLevel;

public static TestLoggerFactory getInstance() {
return INSTANCE.get();
Expand Down Expand Up @@ -81,17 +95,26 @@ public static List<LoggingEvent> 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<String, TestLogger> getAllLoggers() {
return ImmutableMap.copyOf(loggers);
}
Expand Down Expand Up @@ -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);
}
}
5 changes: 5 additions & 0 deletions src/site/markdown/changelog.md
Original file line number Diff line number Diff line change
@@ -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
Expand Down
32 changes: 28 additions & 4 deletions src/site/markdown/usage.md
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand All @@ -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
Expand Down Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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));
}
Expand All @@ -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 {
Expand Down
42 changes: 41 additions & 1 deletion src/test/java/com/github/valfirst/slf4jtest/TestLoggerTests.java
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,7 @@ void afterEach() {
MDC.clear();
TestLoggerFactory.reset();
TestLoggerFactory.getInstance().setPrintLevel(Level.OFF);
TestLoggerFactory.getInstance().setCaptureLevel(Level.TRACE);
}

@Test
Expand Down Expand Up @@ -785,14 +786,53 @@ void printsWhenPrintLevelLessThanEventLevel() {
}

@Test
void doesNotWhenPrintLevelGreaterThanThanEventLevel() {
void doesNotWhenPrintLevelGreaterThanEventLevel() {
TestLoggerFactory.getInstance().setPrintLevel(WARN);

testLogger.info(message);

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<LoggingEvent> 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();
Expand Down

0 comments on commit de3bfb9

Please sign in to comment.