Seemingly Random Test Failure With Maven & Spring Boot 2 When A WebFluxTest Is Introduced

Question

Environment

• OSX 10.13.5
• Java 10.0.1 2018-04-17
• Apache Maven 3.5.2
• Spring Boot 2.0.3.RELEASE
• Maven Surefire plugin 2.22.0

Issue

I have a test which reliably passes:

public class TransformerTest {

    private final MyTransformer transformer = new MyTransformerImpl();

    @Rule
    public final OutputCapture outputCapture = new OutputCapture();

    @Test
    public void successShouldLogSuccessMessages() {
        final B result = transformer.transform(new A());
        outputCapture.expect(containsString("First message"));
        outputCapture.expect(containsString("Second message"));
    }

}

The transformer uses log4j to log two lines via log.debug("First message") and log.debug("Second message"). I can run this test 1,000 times and it will pass.

When I introduce this test class

@WebFluxTest
@RunWith(SpringRunner.class)
public class DummyTest {

    @Autowired
    private WebTestClient client;

    @MockBean
    private MyService service;

    @Test
    public void dummyTest() {
        doRequest()
            .expectStatus().isAccepted()
            .expectBody().isEmpty();
    }

    private WebTestClient.ResponseSpec doRequest() {
        return client.post()
            .uri("/")
            .exchange();
    }
}

The new test reliably passes - however the first test (which is seemingly unrelated to this one) now fails only when the build is run with Maven.

• Running the first test standalone via the IDE will yield a 100% reliable pass.
• Running the entire test suite of the project in the IDE (not via Maven) also yields a 100% reliable pass.
• Removing the second test results in the first passing again 100% reliably - and this is the only source code difference.

The failure message is:

TransformerTest.successShouldLogSuccessMessages Expected: (a string containing "First message" and a string containing "Second message") but: a string containing "First message" was ""

Does anyone know what might be going on? Is the first test already fundamentally flawed and the introduction of the second test is simply exposing this flaw or has the introduction of the second test fundamentally altered the behaviour of the test suite?

Configuration

My entire surefire configuration is:

<plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>2.22.0</version>
            <configuration>
                <excludedGroups>com.example.IntegrationTest</excludedGroups>
            </configuration>
</plugin>

Neither of these tests are part of the integration test group. I have not modified the surefire defaults for parallelism or forking. Since this is just an issue I experience when running with Maven via surefire, is it possible that it's a race condition?

I can reproduce this issue with 100% reliability on more than one machine.

Threonine

I doubt it's a race condition but a test ordering condition. There's no guarantee that the tests will run in the same order on the command line as they do in your IDE. You could use the Suite runner and @SuiteClasses to create a small suite that run the two tests in a particular order. Using that in your IDE may give you an easier way to debug things and start to figure out what's going on. – Reposition

Thanks for the advice, I can confirm that with a suite I can reproduce failure if the webflux test runs first and pass if it runs after. Now to debug why... – Threonine

I figured out the cause. It's actually simple, the second test (webflux one) seems to "reset" the log level. The first test was expecting the log level to be DEBUG and it changed to INFO once I add this second test. The only thing I don't understand is why the change to the log level persists after the webflux test is "finished". I can fix this by adding this to the webflux test @TestPropertySource(properties = "logging.level.com.example=DEBUG") but this feels hacky (setting a log level in this test so other tests can pass). – Threonine

A continuation of the above, a off topic from the point of the question - but given the first original test isn't a spring context test i can't use @TestPropertySource(properties = "logging.level.com.example=DEBUG") in that one. What is the recommended way to set logback log levels on a per test basis for the duration of a test – Threonine