8

I am using org.springframework.boot.test.OutputCapture to test an annotation that logs something.

It works brilliantly for a single test and when tests are run individually if there a multiple tests using output capture in a source file, but when multiple tests are run together only the first test run gets the captured output, the others get empty strings.

Is there any way to avoid this, I can't see any configuration possibilities?

This is a simplified test illustrating the problem import static org.hamcrest.Matchers.; import static org.junit.Assert.;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.junit.FixMethodOrder;
import org.junit.Rule;
import org.junit.Test;
import org.mockito.InjectMocks;
import org.mockito.junit.MockitoJUnit;
import org.mockito.junit.MockitoRule;
import org.springframework.boot.test.OutputCapture;

/** 
 * Simplest implementation that illustrates my problem using {@link OutputCapture}. 
 * <p>
 * If both tests are run, the second test run will not have any output captured so fails. 
 * If tests are run individually they both pass.
 * <p>
 * It is somehow related to 
 * 1) mocking with mockito which is not actually needed in this simplified implementation: without @InjectMocks no output is captured at all and both test fail. 
 * 2) if use System.out.println not log4j, both tests pass and output is captured without mocking as well. 
 */
@FixMethodOrder // done to illustrate error
public class OutputCaptureTests {

    @Rule 
    public OutputCapture outputCapture = new OutputCapture();

    @InjectMocks 
    private InternalTestListener listener;// = new InternalTestListener();

    @Rule
    public MockitoRule rule = MockitoJUnit.rule();

    @Test 
    public void test1() {

        listener.doIt( 1 );
        assertThat( outputCapture.toString() , containsString( "doIt "+1 ) );
    }

    @Test 
    public void test2() {

        listener.doIt( 2 );
        assertThat( outputCapture.toString() , containsString( "doIt "+2 ) );
    }

    static class InternalTestListener{

        private static final Logger LOGGER = LogManager.getLogger( InternalTestListener.class );

        public void doIt( int x ){

            LOGGER.info( "doIt "+x );
//            System.out.println( "doIt "+x );
        }
    }
}
stephen newman
  • 533
  • 4
  • 17
  • Can you provide an example? We use OutputCapture in several places in Boot's own tests and don't have the problem that you've described. – Andy Wilkinson May 23 '16 at 07:44
  • I have add a test case to the original question. Seems to be related to mocking, see comments in the test case. – stephen newman May 23 '16 at 22:54
  • Both tests pass for me. They also pass when I remove `@InjectMocks`. Given that it works for you when you use `System.out` and it always works for me, I would guess that the problem lies somewhere in your logging configuration. – Andy Wilkinson May 24 '16 at 15:50

2 Answers2

8

I had the same problem and I resolved it like following:

Specifically was missing follow="true" to be added in the Console appender:

<Appenders>
<Console name="LogToConsole" target="SYSTEM_OUT" follow="true">
  ...
</Console>

In my case, as @Andy Wilkinson mentioned, was a configuration problem.

Dharman
  • 30,962
  • 25
  • 85
  • 135
Iker Aguayo
  • 3,980
  • 4
  • 37
  • 49
  • What file in Spring Boot do you add those lines? I tried adding follow="true" to "resources/log4j.properties" but it didn't work. – emeraldhieu May 02 '23 at 09:44
2

To expand a bit on @Iker's answer..

The OutputCapture rule sets up a new SystemCapture instance and associates it with the variable that you use to capture the output (outputCapture in the OPs code).

The SystemCapture constructor resets the value of System.out and System.err to buffers that capture the output:

SystemCapture() {
    this.out = new PrintStreamCapture(System.out, this::captureOut);
    this.err = new PrintStreamCapture(System.err, this::captureErr);
    System.setOut(this.out);
    System.setErr(this.err);
}

The follow="true" setting ensures that the log4j appender sends the message to the current value of System.out (see https://stackoverflow.com/a/71158324/3059685).

If follow is false (the default) then it tries to send it to the old (stale) value of System.out and in my case this resulted in an exception: org.springframework.boot.test.system.OutputCaptureRule@xxxxx (renderer threw IllegalStateException).

Joman68
  • 2,248
  • 3
  • 34
  • 36