Looking for problematic logging with JUnit

Stefan Birkner's System Rules is one of my favorite JUnit extension libraries. I commonly use it to verify System.out and System.err, for example validating audit trail logging.

Growing tired of the same boilerplate, I rolled some simple rules into an aggregated JUnit @Rule, called NiceLoggingRule. It enforces:

• No logging to System.err
• No WARN or ERROR logging to System.out

A more sophisticated version would let the user decide on more than "log level" as to what is an acceptable log line, but it gives a good demonstration of writing complex JUnit rules:

public final class NiceLoggingRule
        implements TestRule {
    private static final Pattern NEWLINE = compile("\n");

    private final SystemOutRule sout = new SystemOutRule().
            enableLog().
            muteForSuccessfulTests();
    private final SystemErrRule serr = new SystemErrRule().
            enableLog();

    private final Pattern logLinePattern;
    private final Predicate<String> problematic;
    private final RuleChain delegate;

    public NiceLoggingRule(final String logLinePattern,
            final Predicate<String> problematic) {
        this.logLinePattern = compile(logLinePattern);
        this.problematic = problematic;
        delegate = outerRule(NiceLoggingStatement::new).
                around(sout).
                around(serr);
    }

    @Override
    public Statement apply(final Statement base,
            final Description description) {
        return delegate.apply(base, description);
    }

    private final class NiceLoggingStatement
            extends Statement {
        private final Statement base;
        private final Description description;

        private NiceLoggingStatement(final Statement base,
                final Description description) {
            this.base = base;
            this.description = description;
        }

        @Override
        public void evaluate()
                throws Throwable {
            base.evaluate();
            checkSystemErr(description);
            checkSystemOut(description);
        }

        private void checkSystemErr(final Description description) {
            final String cleanSerr = serr.getLogWithNormalizedLineSeparator();
            final List<String> errors = NEWLINE.splitAsStream(cleanSerr).
                    collect(toList());
            if (!errors.isEmpty())
                fail("Output to System.err from " + description + ":\n"
                        + cleanSerr);
        }

        private void checkSystemOut(final Description description) {
            final String cleanSout = sout.getLogWithNormalizedLineSeparator();
            final List<LogLine> problems = NEWLINE.splitAsStream(cleanSout).
                    map(LogLine::new).
                    filter(LogLine::problematic).
                    collect(toList());
            if (!problems.isEmpty())
                fail(problems.stream().
                        map(Object::toString).
                        collect(joining("",
                                "Problems to System.out from " + description
                                        + ":\n", "")));
        }
    }

    private final class LogLine {
        @Nonnull
        private final String line;
        @Nonnull
        private final String level;

        private LogLine(@Nonnull final String line) {
            final Matcher match = logLinePattern.matcher(line);
            if (!match.find()) // Not match! Ignore trailing CR?NL
                fail(format(
                        "Log line does not match expected pattern (%s): %s",
                        logLinePattern.pattern(), line));
            this.line = line;
            level = match.group("level");
        }

        public boolean problematic() {
            return problematic.test(level);
        }

        @Override
        public String toString() {
            return line;
        }
    }
}

For example, using it with Spring Boot's default log pattern one might write a factory helper:

public final class SpringDefaultNiceLoggingRule {
    private static final String logLevels = Stream.of(LogLevel.values()).
            filter(level -> OFF != level).
            map(Enum::name).
            collect(joining("|"));

    public static NiceLoggingRule springDefaultNiceLoggingRule() {
        return new NiceLoggingRule(
                "^(?<timestamp>\\d{4,4}-\\d{2,2}-\\d{2,2} \\d{2,2}:\\d{2,2}:\\d{2,2}\\.\\d{3,3}) +(?<level>"
                        + logLevels + ") +",
                SpringDefaultNiceLoggingRule::problematic);
    }

    private static boolean problematic(final String level) {
        return 0 > INFO.compareTo(LogLevel.valueOf(level));
    }
}

Then a simple Spring Boot unit test becomes:

@RunWith(SpringJUnit4ClassRunner.class)
@SpringApplicationConfiguration(classes = MockServletContext.class)
public final class RootControllerTest {
    @Rule
    public final NiceLoggingRule niceLogging = springDefaultNiceLoggingRule();

    private MockMvc mvc;

    @Before
    public void setUp()
            throws Exception {
        mvc = standaloneSetup(new RootController()).build();
    }

    @Test
    public void shouldGetRoot()
            throws Exception {
        mvc.perform(get("/").
                accept(APPLICATION_JSON_UTF8)).
                andExpect(status().isOk()).
                andExpect(jsonPath("$.message", equalTo("Hello, world!")));
    }
}