javaspringlog4j2junit5maven-surefire-plugin

Log4j2 Custom Appender in Maven Surefire: Possible to Reuse Across Threads?

I have a Log4j2 custom appender that's being used in many of my JUnit5 tests.

(For what it's worth, I came across the code in a couple articles and have only made minor adjustments.)

When run in Surefire, the logs generated as part of the system under test don't produce the expected values if I use the default Surefire plugin settings as it uses multiple threads to speed things up.

Specifically, the custom appender's output stream contains what I expect exactly one time, and is empty the others.

This behaviour tracks with Surefire's parallelization: If I set reuseForks to false, everything works just fine, but of course the test suite runs much slower.

I've tried synchronizing the methods in the log extension but to no avail (which I think makes sense given I'm likely at the mercy of the LogManager and the context it hands back, whereas each test should instantiate the registered extension in its own thread). I'm likely misunderstanding something or missing something obvious--or perhaps what I'm trying to do isn't possible and I should be using Spring's OutputCaptureExtension (which would be less-than-ideal for me).

Any help would be greatly appreciated.

Thank you in advance.

LoggerExtension class:

public class LoggerExtension implements BeforeEachCallback, AfterEachCallback {

    private static final String APPENDER_NAME = "TestAppender";
    private ByteArrayOutputStream outContent;

    @Override
    public void beforeEach(ExtensionContext context) {
      if (outContent == null) { 
        outContent = new ByteArrayOutputStream();
      } else {
        outContent.reset();
      }
      
      LoggerContext loggerContext = (LoggerContext) LogManager.getContext(false);
      loggerContext.getConfiguration().getRootLogger().setLevel(Level.INFO);
      Appender appender = WriterAppender.newBuilder()
              .setName(APPENDER_NAME)
              .setTarget(new OutputStreamWriter(outContent))
              .build();
      appender.start();
      loggerContext.getConfiguration().addAppender(appender);
      loggerContext.getRootLogger().addAppender(loggerContext.getConfiguration().getAppender(appender.getName()));
      loggerContext.updateLoggers();
    }

    @Override
    public void afterEach(ExtensionContext context) {
        LoggerContext loggerContext = (LoggerContext) LogManager.getContext();
        Configuration configuration = loggerContext.getConfiguration();
        configuration.getRootLogger().removeAppender(APPENDER_NAME);
    }

    public void verifyMessage(String message) {
        // outContent is ony valid once; every other time it is empty
        assertThat(outContent.toString(), containsString(message));
    }
}

Test Case example:

public class TestCase {
  @RegisterExtension
  public static LoggerExtension logVerifier = new LoggerExtension();

  // ...

  @Test
  public void shouldDoSomething() {
    // code that generates logs here

    logVerifier.verifyMessage("match the log string");
  }
}
Solution

  • Every appender needs to have a unique name. Attempts to add multiple appenders with the same name will end up with some of those being ignored.

    Choosing a different name for each of you appenders, should solve your problem with empty output streams:

          Appender appender = WriterAppender.newBuilder()
              .setName(context.getUniqueId())
              .setTarget(new OutputStreamWriter(outContent))
              .build();

    Remark: In your current setup each of the test appenders will also contain the output of other tests that run at the same time. To solve this problem, you should read this thread on log4j-user@logging.

    To solve that: