Development is fun and sometimes frustrating too. Everything comes with some kind or other issues attached.
Scenario
Lately, I had to switch Spring Boot out-of-the-box Logback to Log4j2 logging, and specifically to JSON format. One of the test-cases that I had written was to test a feature-flag-based conditional scenario. The conditional code that depends on the feature-flag which is exposed as an external property and injected via @ConfigurationProperties bean into a service, when disabled writes a log message at WARN level to indicate that the feature is disabled. The unit-test has a test case written to test the disabled scenario which also tests the expected log message by leveraging Spring provided OutputCaptureExtension. This annotation, when used at test class level or method level like: @ExtendWith(OutputCaptureExtension.class) makes output log available to the test-case for verification.
That test-case when I switched logging to JSON using Log4j2 failed due to output log unavailable.
Environment: Java 21, Spring Boot 3.2.5, maven 3.9.6 on macOS Catalina 10.15.7
This post is about few things learned along the way: Log4j2 JSON logging, Spring Boot's JUnit Jupiter extension to capture System output, and the Log4j2 JSON Layout property to let the output be captured and available.
JSON logs
To switch Spring boot application logging to JSON using Log4j2 the following dependencies need to be added to maven build file pom.xml. Also, make sure to run mvn dependency:tree and see if you see spring-boot-starter-logging. If you have that as a transitive dependency, exclude it from all dependencies that bring it in. In the following dependencies, I had Spring Modulith that I had to exclude it from.
<dependency>
<groupId>org.springframework.modulith</groupId>
<artifactId>spring-modulith-starter-core</artifactId>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>
<!-- logging -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-layout-template-json</artifactId>
</dependency>
<dependency>
<groupId>com.fasterxml.jackson.dataformat</groupId>
<artifactId>jackson-dataformat-yaml</artifactId>
</dependency>
Add the following configuration file: main/resources/log4j2.yml. Log4j2 supports XML and YML:
Configuration:
name: default
Appenders:
Console:
name: console_appender
target: SYSTEM_OUT
follow: true
JSONLayout:
compact: true
objectMessageAsJsonObject: true
eventEol: true
stacktraceAsString: true
properties: true
KeyValuePair:
- key: '@timestamp'
value: '$${date:yyyy-MM-dd HH:mm:ss.SSS}'
Loggers:
Root:
name: root.logger
level: info
AppenderRef:
ref: console_appender
With the above changes, application logs will be in JSON format.
Assert Captured output in a test-case
If you have any test-case that was verifying the captured log output in a test-case, it would fail.
For instance, I had a test-case like the following which was verifying the log message logged by myService.method(). To make it work, the above highlighted property - follow: true needs to be added in the log4j2.yml configuration. The details about this console appender property is documented in the OutputCaptureExtension Java doc.
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.mockito.junit.jupiter.MockitoExtension;
import org.springframework.boot.test.system.CapturedOutput;
import org.springframework.boot.test.system.OutputCaptureExtension;
import org.springframework.test.util.ReflectionTestUtils;
import static org.assertj.core.api.Assertions.*;
import static org.junit.jupiter.api.Assertions.assertAll;
import static org.mockito.Mockito.verify;
@ExtendWith(MockitoExtension.class)
@ExtendWith(OutputCaptureExtension.class)
class MyFeatureFlagTest {
@InjectMocks
private MyService myService;
@Test
void call_should_not_handleEvent_when_featureFlag_is_disabled(CapturedOutput output) {
// given: mocked behavior
ReflectionTestUtils.setField(myService, "featureFlag", false);
// when: method under test is called
myService.method();
// verify: the output captured
assertAll(
() -> assertThat(output).contains("The featureFlag is DISABLED.");
}
}
That's it.
Posts
