I have a weird behaviour in my integration test for capturing logs when using the annotation SpringBootTest alongside with autowiring a service. I use LogCaptor to capture logs.
With a specific setup I am not able to capture logs and I cannot understand why this is happening. I am not sure if I missed something with the spring boot test configuration or if it is something else.
So let's assume there is a FooService:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;
@Service
public class FooService {
private static final Logger LOGGER = LoggerFactory.getLogger(FooService.class);
public String hello() {
LOGGER.error("Expected error message");
return "hello";
}
}
And the integration test:
This one fails
import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import static org.assertj.core.api.Assertions.assertThat;
@SpringBootTest
public class AppIT {
private static final LogCaptor logcaptor = LogCaptor.forClass(FooService.class);
@Autowired
private FooService fooService;
@Test
void testMethod() {
fooService.hello();
assertThat(logcaptor.getErrorLogs()).containsExactly("Expected error message");
}
}
The above test will fail, but when I don't use SpringBootTest annotation and just initialias FooService within the test method it passes:
These all passes
import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;
import static org.assertj.core.api.Assertions.assertThat;
public class AppIT {
private static final LogCaptor logcaptor = LogCaptor.forClass(FooService.class);
@Test
void testMethod() {
new FooService().hello();
assertThat(logcaptor.getErrorLogs()).containsExactly("Expected error message");
}
}
import nl.altindag.log.LogCaptor;
import nl.altindag.server.service.FooService;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import javax.annotation.PostConstruct;
import static org.assertj.core.api.Assertions.assertThat;
@SpringBootTest
public class AppIT {
private FooService fooService;
private LogCaptor logcaptor;
@Autowired
AppIT(FooService fooService) {
this.fooService = fooService;
}
@PostConstruct
void init() {
this.logcaptor = LogCaptor.forClass(FooService.class);
}
@Test
void testMethod() {
fooService.hello();
assertThat(logcaptor.getErrorLogs()).containsExactly("Expected error message");
}
}
import nl.altindag.log.LogCaptor;
import nl.altindag.server.service.FooService;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import static org.assertj.core.api.Assertions.assertThat;
@SpringBootTest
public class AppIT {
private FooService fooService;
private LogCaptor logcaptor;
@Autowired
AppIT(FooService fooService) {
this.fooService = fooService;
this.logcaptor = LogCaptor.forClass(FooService.class);
}
@Test
void testMethod() {
fooService.hello();
assertThat(logcaptor.getErrorLogs()).containsExactly("Expected error message");
}
}
The following libraries have been used:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
<version>2.6.1</version>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot</artifactId>
<version>2.6.1</version>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<version>2.6.1</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.junit.jupiter</groupId>
<artifactId>junit-jupiter-api</artifactId>
<version>5.8.1</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.junit.jupiter</groupId>
<artifactId>junit-jupiter-engine</artifactId>
<version>5.8.1</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.assertj</groupId>
<artifactId>assertj-core</artifactId>
<version>3.21.0</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.github.hakky54</groupId>
<artifactId>logcaptor</artifactId>
<version>2.7.2</version>
<scope>test</scope>
</dependency>
I have tried to use postconstruct in the test and other setups like having a constructor and annotating that with autowired and putting the logcaptor setup there which do work, but I don't understand why the specific situation above is failing. Anyone any idea what could be the issue?
The problem in the failing test is that the class variable logcaptor
is created before the test application context is created. During the bootstrapping of the test application context, Spring Boot will completely configure logback from scratch. This causes the appender that was added in LogCaptor::forClass
to get lost.
In the successful @SpringBootTest
tests, the appender is added in a much later stage of the context lifecycle.
You can get the test to pass when you take any of the two passing @SpringBootTest
tests and execute them together as long as the failing test is not executed first. That's because the Spring test framework will not bootstrap a new context but re-use the context of the first test that was run. You can get the test back to failing if you annotate its class with @DirtiesContext(classMode = ClassMode.BEFORE_CLASS)
because then again a new context will be created after the class variable logcaptor
is assigned.
I'm afraid that there is little one can do about this. This comment on github by the Spring Boot team is about a similar problem: https://github.com/spring-projects/spring-boot/issues/19323#issuecomment-563166919