Logs truncated when using SystemErrGuard

[chiaradiamarcelo]

Description

In test classes annotated with @ExtendWith(SystemErrGuard.class) and with multiple test cases that sniff the System.Err, the logs are truncated after the execution of the first test case.

An instance of java.util.logging.Logger uses by default ConsoleHandler that is bounded to a reference of the System.Err.
This binding happens upon creation of the Consolehandler, which is lazily instantiated, for example when logging a message with the logger for the first time (ie, LOGGER.info("message")).

If the System.Err is changed (ie, System.setErr(newSystemStream)), all the already existent instances of ConsoleHandler are not updated, so they don't log to the new System.Err.

Steps to Reproduce

1. Implement the following classes

import java.util.logging.Logger;
public final class TesteableClass {
    public static final Logger LOGGER = Logger.getLogger(TesteableClass.class.getName());

    public static String testeableMethod() {
            LOGGER.info("TESTEABLE LOG MESSAGE");
    }
}

@ExtendWith(SystemErrGuard.class)
class TestClass {
    @Test
    void firstTestCase(final Capturable stream) {
          stream.capture();
          TesteableClass.testeableMethod();
          assertThat(stream.getCapturedData(), containsString("TESTEABLE LOG MESSAGE"));
    }
    @Test
    void secondTestCase(final Capturable stream) {
          stream.capture();
          TesteableClass.testeableMethod();
          assertThat(stream.getCapturedData(), containsString("TESTEABLE LOG MESSAGE"));
    }
}

2. Execute the tests.
3. Verify the console does not show all the logs (you can see in the console only one "TESTEABLE LOG MESSAGE" message instead of two)
4. As a work around, you can reset the ConsoleHandler before executing each tests and disabling the use of the parent ConsoleHandler (cause if not it would log twice, once for each handler, during the execution of the first test), for example:

    @BeforeEach
    void beforeEach() {
        TesteableClass.LOGGER.setUseParentHandlers(false);
        final Handler[] handlers = TesteableClass.LOGGER.getHandlers();
        for (final Handler handler : handlers) {
            TesteableClass.LOGGER.removeHandler(handler);
        }
        TesteableClass.LOGGER.addHandler(new ConsoleHandler());
    }

Expected behavior

Tests should pass and "TESTEABLE LOG MESSAGE" should be visible twice in the console.

Environment

• JUnit5 System Extensions: 1.1.0
• OS: Ubuntu 20.04.1
• Java Version: 11
• Maven Version (in case of build problems only): 3.6.3

[jakobbraun]

We discussed moving the injection of the log sniffer from beforeEach to beforeAll. This fixes the issue described above at first glance.
But, in case multiple test classes test code that uses the same logger the issue could still appear. (Singleton lifecycle is bound to JVM to test class)

[jakobbraun]

So the only possible solution I can think of is creating a singleton, that injects the log sniffer directly at its creation (for all test classes).
This is, however, quite an invasive approach and could lead to unexpected behavior if something goes wrong. (Tests fail even so this plugin was used in a different test class)

[chiaradiamarcelo]

Restarting the root logger in every iteration also does the trick, but it might be dangerous and could lead to unexpected behavior as well